From 68f65af508d895d83e9240ea68e9659290a8b68e Mon Sep 17 00:00:00 2001 From: David Thyresson Date: Wed, 15 Jun 2022 10:41:20 -0400 Subject: [PATCH] fix: RedwoodLogger -- Mask errors, but include stack trace in formatter (#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 --- .../src/__tests__/logFormatter.test.ts | 27 +++++++++++++++++ packages/api-server/src/logFormatter/index.ts | 29 +++++++++++++++---- .../graphql-server/src/functions/graphql.ts | 10 ++++--- .../__tests__/useRedwoodLogger.test.ts | 25 +++++++++++++++- .../src/plugins/useRedwoodLogger.ts | 14 ++++----- 5 files changed, 87 insertions(+), 18 deletions(-) diff --git a/packages/api-server/src/__tests__/logFormatter.test.ts b/packages/api-server/src/__tests__/logFormatter.test.ts index cd0d23e99367..4f71aa127583 100644 --- 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 index 6e1acc5c4a20..9c8b2c704be5 100644 --- 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 index 72fe23947e44..93b9b69c365c 100644 --- 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 index 437c0720e440..f3693b830e67 100644 --- 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 index e4d3a4c5523f..6b6c6116e21b 100644 --- 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}` ) } })