fix: RedwoodLogger -- Mask errors, but include stack trace in formatt…

…er (#5704) * Mask errors, but include stack trasce in formatter * Fix tests for new error attribute in log data * Adds test to log stack traces * Tests log error formatter * style: remove extra space between error and stack Co-authored-by: Dominic Saadi <[email protected]>
redwoodjs · Jun 15, 2022 · 68f65af · 68f65af
1 parent 88ad01a
commit 68f65af
Show file tree

Hide file tree

Showing 5 changed files with 87 additions and 18 deletions.
diff --git a/packages/api-server/src/__tests__/logFormatter.test.ts b/packages/api-server/src/__tests__/logFormatter.test.ts
@@ -175,4 +175,31 @@ describe('LogFormatter', () => {
       })
     ).toMatch('"foo": "bar"')
   })
+
+  test('Should format error stack traces', () => {
+    expect(
+      logFormatter({
+        level: 50,
+        err: {
+          message: 'This error has a stack traces',
+          stack:
+            'A stack trace \n will have \n several lines \n at some line number \n at some code',
+        },
+      })
+    ).toMatch(/at some line number/)
+  })
+
+  test('Should format error and include the error type', () => {
+    expect(
+      logFormatter({
+        level: 50,
+        err: {
+          type: 'GraphQL Error',
+          message: 'This error has a stack traces',
+          stack:
+            'A stack trace \n will have \n several lines \n at some line number \n at some code',
+        },
+      })
+    ).toMatch(/GraphQL Error Info/)
+  })
 })
diff --git a/packages/api-server/src/logFormatter/index.ts b/packages/api-server/src/logFormatter/index.ts
@@ -176,14 +176,14 @@ export const LogFormatter = () => {
       output.push(formatTracing(tracing))
     }
 
-    if (stack != null) {
-      output.push(formatStack(stack))
-    }
-
     if (err != null) {
       output.push(formatErrorProp(err))
     }
 
+    if (stack != null) {
+      output.push(formatStack(stack))
+    }
+
     return output.filter(noEmpty).join(' ')
   }
 
@@ -223,7 +223,20 @@ export const LogFormatter = () => {
   }
 
   const formatErrorProp = (errorPropValue: any) => {
-    return newline + JSON.stringify({ err: errorPropValue }, null, 2)
+    const errorType = errorPropValue['type'] || 'Error'
+    delete errorPropValue['message']
+    delete errorPropValue['stack']
+    delete errorPropValue['type']
+
+    return chalk.redBright(
+      newline +
+        newline +
+        `🚨 ${errorType} Info` +
+        newline +
+        newline +
+        JSON.stringify(errorPropValue, null, 2) +
+        newline
+    )
   }
 
   const formatLevel = (level: any) => {
@@ -321,7 +334,11 @@ export const LogFormatter = () => {
   }
 
   const formatStack = (stack: any) => {
-    return stack ? newline + stack : ''
+    return chalk.redBright(
+      stack
+        ? newline + '🥞 Error Stack' + newline + newline + stack + newline
+        : ''
+    )
   }
 
   const formatTracing = (data: any) => {

diff --git a/packages/graphql-server/src/functions/graphql.ts b/packages/graphql-server/src/functions/graphql.ts
@@ -3,7 +3,6 @@ import {
   EnvelopError,
   FormatErrorHandler,
   GraphQLYogaError,
-  useMaskedErrors,
 } from '@graphql-yoga/common'
 import type { PluginOrDisabledPlugin } from '@graphql-yoga/common'
 
@@ -163,14 +162,17 @@ export const createGraphQLHandler = ({
     plugins.push(...extraPlugins)
   }
 
-  // Must be "last" in plugin chain so can process any data added to results and extensions
+  // Must be "last" in plugin chain, but before error masking
+  // so can process any data added to results and extensions
   plugins.push(useRedwoodLogger(loggerConfig))
 
-  plugins.push(useMaskedErrors({ formatError, errorMessage: defaultError }))
   const yoga = createServer({
     schema,
     plugins,
-    maskedErrors: false,
+    maskedErrors: {
+      formatError,
+      errorMessage: defaultError,
+    },
     logging: logger,
     graphiql: isDevEnv
       ? {

diff --git a/packages/graphql-server/src/plugins/__tests__/useRedwoodLogger.test.ts b/packages/graphql-server/src/plugins/__tests__/useRedwoodLogger.test.ts
@@ -198,13 +198,36 @@ describe('Populates context', () => {
     expect(errorLogStatement).toHaveProperty('level')
     expect(errorLogStatement).toHaveProperty('time')
     expect(errorLogStatement).toHaveProperty('msg')
-    expect(errorLogStatement).toHaveProperty('error')
+    expect(errorLogStatement).toHaveProperty('err')
 
     expect(errorLogStatement.name).toEqual('graphql-server')
     expect(errorLogStatement.level).toEqual(50)
     expect(errorLogStatement.msg).toEqual('You are forbidden')
   })
 
+  it('Should log an error with type and stack trace info when the resolver raises an exception', async () => {
+    const loggerConfig = {
+      logger,
+      options: {},
+    } as LoggerConfig
+
+    const testkit = createTestkit([useRedwoodLogger(loggerConfig)], testSchema)
+
+    await testkit.execute(testErrorQuery, {}, {})
+
+    await watchFileCreated(logFile)
+
+    const logStatements = parseLogFile(logFile)
+
+    const errorLogStatement = logStatements.pop()
+
+    expect(errorLogStatement).toHaveProperty('err')
+    expect(errorLogStatement.err).toHaveProperty('stack')
+    expect(errorLogStatement.err.type).toEqual('GraphQLError')
+    expect(errorLogStatement.err.path).toContain('forbiddenUser')
+    expect(errorLogStatement.err.message).toEqual('You are forbidden')
+  })
+
   it('Should not log filtered graphql operations', async () => {
     const loggerConfig = {
       logger,

diff --git a/packages/graphql-server/src/plugins/useRedwoodLogger.ts b/packages/graphql-server/src/plugins/useRedwoodLogger.ts
@@ -135,19 +135,19 @@ const logResult =
             error.originalError instanceof ForbiddenError)
         ) {
           envelopLogger.warn(
-            {
-              error,
-            },
+            error,
+
             `'${error?.extensions?.code || 'authentication'}' error '${
               error.message
             }' occurred in ${operationName}`
           )
         } else {
           envelopLogger.error(
-            {
-              error,
-            },
-            error.message || `Error in GraphQL execution: ${operationName}`
+            error,
+
+            error?.originalError?.message ||
+              error.message ||
+              `Error in GraphQL execution: ${operationName}`
           )
         }
       })