diff --git a/CHANGELOG.md b/CHANGELOG.md index 569b20bd..51200005 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,10 +9,15 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added +- Message interpolation of logged errors, transforming error message placeholders into human-readable text (default locale) + ### Changed - Moved registration of `cds.compile.to.gql` and `cds.compile.to.graphql` targets from `@sap/cds` to `@cap-js/graphql` - Improve merging of custom `graphql` protocol configuration with plugin default configuration +- Errors representing client errors (`4xx` range) are now logged as warnings instead of errors +- Exclude the stack trace of the outer logged error message in multiple error scenarios, as the inner stack trace already +contained the precise initial segment of the outer stack trace. ### Fixed diff --git a/lib/resolvers/error.js b/lib/resolvers/error.js index 308a2cce..5f190570 100644 --- a/lib/resolvers/error.js +++ b/lib/resolvers/error.js @@ -1,10 +1,13 @@ const cds = require('@sap/cds') +const { i18n } = cds.env const LOG_CDS = cds.log() const LOG_GRAPHQL = cds.log('graphql') -const { normalizeError } = require('@sap/cds/libx/_runtime/common/error/frontend') const { GraphQLError } = require('graphql') const { IS_PRODUCTION } = require('../utils') +// FIXME: importing internal modules from @sap/cds is discouraged and not recommended for external usage +const { normalizeError, isClientError } = require('@sap/cds/libx/_runtime/common/error/frontend') + const _reorderProperties = error => { // 'stack' and 'stacktrace' to cover both common cases that a custom error formatter might return let { code, message, details, stack, stacktrace } = error @@ -31,14 +34,45 @@ const _cdsToGraphQLError = (context, err) => { } const _ensureError = error => (error instanceof Error ? error : new Error(error)) +const _clone = obj => Object.create(Object.getPrototypeOf(obj), Object.getOwnPropertyDescriptors(obj)) const handleCDSError = (context, error) => { error = _ensureError(error) - // TODO: choose log level depending on type of error analogous to OData adapter - if (LOG_CDS._error) LOG_CDS.error(error) + _log(error) return _cdsToGraphQLError(context, error) } +// TODO: Revise this logging functionality, as it's not specific to protocol adapters. +// This function should be relocated and/or cleaned up when the new abstract/generic +// protocol adapter is designed and implemented. +const _log = error => { + // log errors and warnings only + if (LOG_CDS.level <= cds.log.levels.WARN) return + + // Clone of the original error object to prevent mutation and unintended side-effects. + // Notice that the cloned error is logged to standard output in its default language, + // whereas the original error message is locale-dependent as it is usually sent in the + // HTTP response to HTTP Clients to be displayed in the user interface. + let error2log = _clone(error) + if (error.details) { + error2log.details = error.details.map(error => _clone(error)) + + // Excluding the stack trace for the outer error as the inner stack trace already + // contains the initial segment of the outer stack trace. + delete error2log.stack + } + + error2log = normalizeError(error2log, { locale: i18n.default_language }, error => error).error + + // determine if the status code represents a client error (4xx range) + if (isClientError(error2log)) { + if (LOG_CDS._warn) LOG_CDS.warn(error2log) + } else { + // server error + if (LOG_CDS._error) LOG_CDS.error(error2log) + } +} + const formatError = error => { // CDS errors have already been logged and already have a stacktrace in extensions if (error.originalError?._cdsError) return error diff --git a/lib/resolvers/response.js b/lib/resolvers/response.js index 2453c903..3cb62c0a 100644 --- a/lib/resolvers/response.js +++ b/lib/resolvers/response.js @@ -3,8 +3,8 @@ const { handleCDSError } = require('./error') const setResponse = async (context, response, key, value) => { try { response[key] = await value - } catch (e) { - response[key] = handleCDSError(context, e) + } catch (error) { + response[key] = handleCDSError(context, error) } } diff --git a/test/tests/error-handling-prod.test.js b/test/tests/error-handling-prod.test.js index 9852c0b4..e7089e31 100644 --- a/test/tests/error-handling-prod.test.js +++ b/test/tests/error-handling-prod.test.js @@ -8,6 +8,15 @@ describe('graphql - error handling in production', () => { // Prevent axios from throwing errors for non 2xx status codes axios.defaults.validateStatus = false + beforeEach(() => { + jest.spyOn(console, 'warn') + jest.spyOn(console, 'error') + }) + + afterEach(() => { + jest.clearAllMocks() + }) + describe('Errors thrown by CDS', () => { test('Single @mandatory validation error', async () => { const query = gql` @@ -33,6 +42,17 @@ describe('graphql - error handling in production', () => { const response = await POST('/graphql', { query }) expect(response.data).toMatchObject({ errors }) expect(response.data.errors[0].extensions).not.toHaveProperty('stacktrace') // No stacktrace in production + expect(console.warn.mock.calls[0][1]).toMatchObject({ + code: '400', + element: 'notEmptyI', + entity: 'ValidationErrorsService.A', + message: 'Value is required', + numericSeverity: 4, + target: 'notEmptyI', + type: 'cds.Integer', + value: undefined, + stack: expect.any(String) + }) }) test('Multiple @mandatory validation errors', async () => { @@ -137,6 +157,38 @@ describe('graphql - error handling in production', () => { expect(response.data.errors[0].extensions).not.toHaveProperty('stacktrace') // No stacktrace outside of error details expect(response.data.errors[0].extensions.details[0]).not.toHaveProperty('stacktrace') // No stacktrace in production expect(response.data.errors[0].extensions.details[1]).not.toHaveProperty('stacktrace') // No stacktrace in production + expect(console.warn.mock.calls[0][1]).toMatchObject({ + code: '400', + message: 'Multiple errors occurred. Please see the details for more information.', + details: [ + { + args: ['inRange'], + code: '400', + element: 'inRange', + entity: 'ValidationErrorsService.C', + message: 'Value is required', + numericSeverity: 4, + target: 'inRange', + type: 'cds.Integer', + value: undefined, + stack: expect.any(String) + }, + { + args: ['"foo"', '"high", "medium", "low"'], + code: '400', + element: 'oneOfEnumValues', + entity: 'ValidationErrorsService.C', + enum: ['@assert.range', 'type', 'enum'], + message: 'Value "foo" is invalid according to enum declaration {"high", "medium", "low"}', + numericSeverity: 4, + target: 'oneOfEnumValues', + type: 'cds.String', + value: 'foo', + stack: expect.any(String) + } + ] + }) + expect(console.warn.mock.calls[0][1]).not.toHaveProperty('stacktrace') // No stacktrace outside of error details }) }) @@ -310,6 +362,29 @@ describe('graphql - error handling in production', () => { expect(response.data.errors[0].extensions).not.toHaveProperty('stacktrace') // No stacktrace outside of error details expect(response.data.errors[0].extensions.details[0]).not.toHaveProperty('stacktrace') // No stacktrace in production expect(response.data.errors[0].extensions.details[1]).not.toHaveProperty('stacktrace') // No stacktrace in production + expect(console.error.mock.calls[0][1]).toMatchObject({ + code: '500', + message: 'Multiple errors occurred. Please see the details for more information.', + details: [ + { + code: 'Some-Custom-Code1', + message: 'Some Custom Error Message 1', + numericSeverity: 4, + status: 418, + target: 'some_field', + stack: expect.any(String) + }, + { + code: 'Some-Custom-Code2', + message: 'Some Custom Error Message 2', + numericSeverity: 4, + status: 500, + target: 'some_field', + stack: expect.any(String) + } + ] + }) + expect(console.error.mock.calls[0][1]).not.toHaveProperty('stacktrace') // No stacktrace outside of error details }) test('Thrown error is modified in srv.on(error) handler', async () => {