fix(server): properly log thrown errors (#3072)

packages/server/logging/expressLogging.ts

@@ -6,7 +6,7 @@ import pino from 'pino'
 import type { SerializedResponse } from 'pino'
 import type { GenReqId } from 'pino-http'
 import type { IncomingMessage, ServerResponse } from 'http'
-import type { Optional } from '@speckle/shared'
+import { ensureError, type Optional } from '@speckle/shared'
 import { getRequestPath } from '@/modules/core/helpers/server'
 import { get } from 'lodash'
 
@@ -79,31 +79,37 @@ export const LoggingExpressMiddleware = HttpLogger({
 
   customSuccessObject(req, res, val: Record<string, unknown>) {
     const isCompleted = !req.readableAborted && res.writableEnded
-    const requestStatus = isCompleted ? 'completed' : 'aborted'
+    const isError = !!req.context?.err
+    const requestStatus = isCompleted ? (isError ? 'errored' : 'completed') : 'aborted'
     const requestPath = getRequestPath(req) || 'unknown'
     const country = req.headers['cf-ipcountry'] as Optional<string>
 
     return {
       ...val,
       requestStatus,
       requestPath,
-      country
+      country,
+      err: req.context?.err
     }
   },
 
   customErrorMessage() {
     return '{requestPath} request {requestStatus} in {responseTime} ms'
   },
-  customErrorObject(req, _res, _err, val: Record<string, unknown>) {
+  customErrorObject(req, _res, err, val: Record<string, unknown>) {
     const requestStatus = 'failed'
     const requestPath = getRequestPath(req) || 'unknown'
     const country = req.headers['cf-ipcountry'] as Optional<string>
+    let e: Error | undefined = undefined
+    if (err) e = ensureError(err)
+    if (!err && req.context?.err) e = req.context.err
 
     return {
       ...val,
       requestStatus,
       requestPath,
-      country
+      country,
+      err: e
     }
   },
 

packages/server/modules/core/rest/defaultErrorHandler.ts

@@ -21,16 +21,21 @@ const resolveStatusCode = (e: Error): number => {
 
 const resolveErrorInfo = (e: Error): Record<string, unknown> => {
   const cause = getCause(e)
+  const message = e.message
+  let info = undefined
+  if (e instanceof BaseError) {
+    info = e.info()
+  }
 
   return {
-    message: e.message,
+    message,
     code: (e instanceof BaseError ? e.info().code : get(e, 'code')) || e.name,
     ...(isDevEnv()
       ? {
           stack: e.stack,
           ...(e instanceof BaseError
             ? {
-                info: e.info(),
+                info,
                 stack: VError.fullStack(e)
               }
             : {}),
@@ -49,6 +54,8 @@ export const defaultErrorHandler: ErrorRequestHandler = (err, req, res, next) =>
   }
 
   const e = ensureError(err)
+  // Add the error to the request context, this allows it to be logged by pino-http
+  if (!req.context.err) req.context.err = e
   res.status(resolveStatusCode(e)).json({
     error: resolveErrorInfo(e)
   })