From 2b43448027b5d6e9f5f79811bdb283aa44e8ba50 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 09:37:17 +0100 Subject: [PATCH 01/11] Test status code of requests with undefined queries --- test/tests/logger-dev.test.js | 6 ++++-- test/tests/logger-prod.test.js | 6 ++++-- 2 files changed, 8 insertions(+), 4 deletions(-) diff --git a/test/tests/logger-dev.test.js b/test/tests/logger-dev.test.js index d80b1b8e..b351394d 100644 --- a/test/tests/logger-dev.test.js +++ b/test/tests/logger-dev.test.js @@ -23,7 +23,8 @@ describe('graphql - query logging in development', () => { describe('POST requests', () => { test('Do not log requests with undefined queries', async () => { - await POST('/graphql') + const response = await POST('/graphql') + expect(response.status).toEqual(400) expect(_log.mock.calls.length).toEqual(0) }) @@ -138,7 +139,8 @@ describe('graphql - query logging in development', () => { describe('GET requests', () => { test('Do not log requests with undefined queries', async () => { - await GET('/graphql') + const response = await GET('/graphql') + expect(response.status).toEqual(400) expect(_log.mock.calls.length).toEqual(0) }) diff --git a/test/tests/logger-prod.test.js b/test/tests/logger-prod.test.js index 7df56054..e40b937c 100644 --- a/test/tests/logger-prod.test.js +++ b/test/tests/logger-prod.test.js @@ -30,7 +30,8 @@ describe('graphql - query logging with sanitization in production', () => { describe('POST requests', () => { test('Do not log requests with undefined queries', async () => { - await POST('/graphql') + const response = await POST('/graphql') + expect(response.status).toEqual(400) expect(_log.mock.calls.length).toEqual(0) }) @@ -147,7 +148,8 @@ describe('graphql - query logging with sanitization in production', () => { describe('GET requests', () => { test('Do not log requests with undefined queries', async () => { - await GET('/graphql') + const response = await GET('/graphql') + expect(response.status).toEqual(400) expect(_log.mock.calls.length).toEqual(0) }) From 4444443f399b5b78c01b4c69956a8fb3e7f8cd92 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 09:41:16 +0100 Subject: [PATCH 02/11] Fix trying to set stacktrace in extensions when error isn't GraphQLError --- lib/resolvers/error.js | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/lib/resolvers/error.js b/lib/resolvers/error.js index 5f190570..fffac637 100644 --- a/lib/resolvers/error.js +++ b/lib/resolvers/error.js @@ -74,12 +74,14 @@ const _log = error => { } const formatError = error => { + // Note: not all errors are instances of GraphQLError -> e.g. not all errors have extensions + // CDS errors have already been logged and already have a stacktrace in extensions if (error.originalError?._cdsError) return error if (LOG_GRAPHQL._error) LOG_GRAPHQL.error(error) - if (!IS_PRODUCTION) error.extensions.stacktrace = error.stack.split('\n') + if (!IS_PRODUCTION && error.extensions) error.extensions.stacktrace = error.stack.split('\n') return error } From 5b325492317055f2750429abb8e1f5a608b4340d Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 09:43:07 +0100 Subject: [PATCH 03/11] Reorder function declarations --- lib/resolvers/error.js | 15 ++++++++------- 1 file changed, 8 insertions(+), 7 deletions(-) diff --git a/lib/resolvers/error.js b/lib/resolvers/error.js index fffac637..03157c7d 100644 --- a/lib/resolvers/error.js +++ b/lib/resolvers/error.js @@ -33,15 +33,8 @@ const _cdsToGraphQLError = (context, err) => { return Object.defineProperty(graphQLError, '_cdsError', { value: true, writable: false, enumerable: false }) } -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) - _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. @@ -73,6 +66,14 @@ const _log = error => { } } +const _ensureError = error => (error instanceof Error ? error : new Error(error)) + +const handleCDSError = (context, error) => { + error = _ensureError(error) + _log(error) + return _cdsToGraphQLError(context, error) +} + const formatError = error => { // Note: not all errors are instances of GraphQLError -> e.g. not all errors have extensions From ae8b3ab2bc75109b4ff91ed5c115e662d8390d38 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 09:45:03 +0100 Subject: [PATCH 04/11] Prettier format --- test/tests/localized.test.js | 2 +- test/tests/logger-dev.test.js | 2 +- test/tests/logger-prod.test.js | 2 +- test/tests/mutations/create.test.js | 2 +- test/tests/mutations/delete.test.js | 2 +- test/tests/mutations/update.test.js | 2 +- test/tests/queries/filter.test.js | 2 +- test/tests/queries/queries.test.js | 2 +- test/tests/types.test.js | 2 +- 9 files changed, 9 insertions(+), 9 deletions(-) diff --git a/test/tests/localized.test.js b/test/tests/localized.test.js index 375d9044..d1f012e5 100644 --- a/test/tests/localized.test.js +++ b/test/tests/localized.test.js @@ -8,7 +8,7 @@ describe('graphql - queries with localized data', () => { axios.defaults.validateStatus = false beforeEach(async () => { - await data.reset() + await data.reset() }) test('query with default locale', async () => { diff --git a/test/tests/logger-dev.test.js b/test/tests/logger-dev.test.js index b351394d..842041e8 100644 --- a/test/tests/logger-dev.test.js +++ b/test/tests/logger-dev.test.js @@ -13,7 +13,7 @@ describe('graphql - query logging in development', () => { let _log beforeEach(async () => { - await data.reset() + await data.reset() _log = jest.spyOn(console, 'info') }) diff --git a/test/tests/logger-prod.test.js b/test/tests/logger-prod.test.js index e40b937c..492bb08d 100644 --- a/test/tests/logger-prod.test.js +++ b/test/tests/logger-prod.test.js @@ -20,7 +20,7 @@ describe('graphql - query logging with sanitization in production', () => { }) beforeEach(async () => { - await data.reset() + await data.reset() _log = jest.spyOn(console, 'info') }) diff --git a/test/tests/mutations/create.test.js b/test/tests/mutations/create.test.js index 72492d3d..ee5a04cb 100644 --- a/test/tests/mutations/create.test.js +++ b/test/tests/mutations/create.test.js @@ -8,7 +8,7 @@ describe('graphql - create mutations', () => { axios.defaults.validateStatus = false beforeEach(async () => { - await data.reset() + await data.reset() }) test('create empty entry', async () => { diff --git a/test/tests/mutations/delete.test.js b/test/tests/mutations/delete.test.js index e6f87d3d..919a19c0 100644 --- a/test/tests/mutations/delete.test.js +++ b/test/tests/mutations/delete.test.js @@ -8,7 +8,7 @@ describe('graphql - delete mutations', () => { axios.defaults.validateStatus = false beforeEach(async () => { - await data.reset() + await data.reset() }) test('delete no entries', async () => { diff --git a/test/tests/mutations/update.test.js b/test/tests/mutations/update.test.js index 6d24c176..00112db6 100644 --- a/test/tests/mutations/update.test.js +++ b/test/tests/mutations/update.test.js @@ -8,7 +8,7 @@ describe('graphql - update mutations', () => { axios.defaults.validateStatus = false beforeEach(async () => { - await data.reset() + await data.reset() }) test('update no entries', async () => { diff --git a/test/tests/queries/filter.test.js b/test/tests/queries/filter.test.js index a3e98f84..e96272fd 100644 --- a/test/tests/queries/filter.test.js +++ b/test/tests/queries/filter.test.js @@ -8,7 +8,7 @@ describe('graphql - filter', () => { axios.defaults.validateStatus = false beforeEach(async () => { - await data.reset() + await data.reset() }) // REVISIT: unskip for support of configurable schema flavors diff --git a/test/tests/queries/queries.test.js b/test/tests/queries/queries.test.js index 135ff4f1..0f1de2ad 100644 --- a/test/tests/queries/queries.test.js +++ b/test/tests/queries/queries.test.js @@ -8,7 +8,7 @@ describe('graphql - queries', () => { axios.defaults.validateStatus = false beforeEach(async () => { - await data.reset() + await data.reset() }) // REVISIT: unskip for support of configurable schema flavors diff --git a/test/tests/types.test.js b/test/tests/types.test.js index 8ec770a5..1323e2e4 100644 --- a/test/tests/types.test.js +++ b/test/tests/types.test.js @@ -49,7 +49,7 @@ describe('graphql - types parsing and validation', () => { axios.defaults.validateStatus = false beforeEach(async () => { - await data.reset() + await data.reset() }) describe('cds.Binary', () => { From b7eccce2d1206a9fe25473c4e2712a065e1b3bc8 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 09:51:47 +0100 Subject: [PATCH 05/11] Add changelog entry --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 51200005..7376c883 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -22,6 +22,7 @@ contained the precise initial segment of the outer stack trace. ### Fixed - Load custom `errorFormatter` relative to CDS project root +- Fix internal server error when formatting errors that aren't CDS errors (thrown by CDS or in custom handlers) or instances of GraphQLError, such as the error caused by requests with undefined `query` property ### Removed From 4e215a024953df57d86b754147c9422d5da404c2 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 09:52:37 +0100 Subject: [PATCH 06/11] Format changelog --- CHANGELOG.md | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 7376c883..fb2ac342 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -16,8 +16,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - 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. +- 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 From c71ed4615865730788086c6b586f338f4f650fb8 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 10:01:43 +0100 Subject: [PATCH 07/11] Improve comment --- lib/resolvers/error.js | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/lib/resolvers/error.js b/lib/resolvers/error.js index 03157c7d..58ec3040 100644 --- a/lib/resolvers/error.js +++ b/lib/resolvers/error.js @@ -75,13 +75,14 @@ const handleCDSError = (context, error) => { } const formatError = error => { - // Note: not all errors are instances of GraphQLError -> e.g. not all errors have extensions + // Note: error is not always an instance of GraphQLError // CDS errors have already been logged and already have a stacktrace in extensions if (error.originalError?._cdsError) return error if (LOG_GRAPHQL._error) LOG_GRAPHQL.error(error) + // error does not have an extensions property when it is not an instance of GraphQLError if (!IS_PRODUCTION && error.extensions) error.extensions.stacktrace = error.stack.split('\n') return error From 2643ea6860759a580b7053389285edd535afda14 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 10:08:26 +0100 Subject: [PATCH 08/11] Destructure response in tests --- test/tests/logger-dev.test.js | 8 ++++---- test/tests/logger-prod.test.js | 8 ++++---- 2 files changed, 8 insertions(+), 8 deletions(-) diff --git a/test/tests/logger-dev.test.js b/test/tests/logger-dev.test.js index 842041e8..2358028a 100644 --- a/test/tests/logger-dev.test.js +++ b/test/tests/logger-dev.test.js @@ -23,8 +23,8 @@ describe('graphql - query logging in development', () => { describe('POST requests', () => { test('Do not log requests with undefined queries', async () => { - const response = await POST('/graphql') - expect(response.status).toEqual(400) + const { status } = await POST('/graphql') + expect(status).toEqual(400) expect(_log.mock.calls.length).toEqual(0) }) @@ -139,8 +139,8 @@ describe('graphql - query logging in development', () => { describe('GET requests', () => { test('Do not log requests with undefined queries', async () => { - const response = await GET('/graphql') - expect(response.status).toEqual(400) + const { status } = await GET('/graphql') + expect(status).toEqual(400) expect(_log.mock.calls.length).toEqual(0) }) diff --git a/test/tests/logger-prod.test.js b/test/tests/logger-prod.test.js index 492bb08d..c1e28dea 100644 --- a/test/tests/logger-prod.test.js +++ b/test/tests/logger-prod.test.js @@ -30,8 +30,8 @@ describe('graphql - query logging with sanitization in production', () => { describe('POST requests', () => { test('Do not log requests with undefined queries', async () => { - const response = await POST('/graphql') - expect(response.status).toEqual(400) + const { status } = await POST('/graphql') + expect(status).toEqual(400) expect(_log.mock.calls.length).toEqual(0) }) @@ -148,8 +148,8 @@ describe('graphql - query logging with sanitization in production', () => { describe('GET requests', () => { test('Do not log requests with undefined queries', async () => { - const response = await GET('/graphql') - expect(response.status).toEqual(400) + const { status } = await GET('/graphql') + expect(status).toEqual(400) expect(_log.mock.calls.length).toEqual(0) }) From ce1ea287fec133c06e2c5a9ec384f82ee515d8a6 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 10:12:05 +0100 Subject: [PATCH 09/11] Fix expects for GET requests --- test/tests/logger-dev.test.js | 5 +++-- test/tests/logger-prod.test.js | 5 +++-- 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/test/tests/logger-dev.test.js b/test/tests/logger-dev.test.js index 2358028a..7f1d38df 100644 --- a/test/tests/logger-dev.test.js +++ b/test/tests/logger-dev.test.js @@ -139,8 +139,9 @@ describe('graphql - query logging in development', () => { describe('GET requests', () => { test('Do not log requests with undefined queries', async () => { - const { status } = await GET('/graphql') - expect(status).toEqual(400) + const response = await GET('/graphql') + expect(response.status).toEqual(200) + expect(response.data).toMatch(/html/i) expect(_log.mock.calls.length).toEqual(0) }) diff --git a/test/tests/logger-prod.test.js b/test/tests/logger-prod.test.js index c1e28dea..72af51a0 100644 --- a/test/tests/logger-prod.test.js +++ b/test/tests/logger-prod.test.js @@ -148,8 +148,9 @@ describe('graphql - query logging with sanitization in production', () => { describe('GET requests', () => { test('Do not log requests with undefined queries', async () => { - const { status } = await GET('/graphql') - expect(status).toEqual(400) + const response = await GET('/graphql') + expect(response.status).toEqual(200) + expect(response.data).toMatch(/html/i) expect(_log.mock.calls.length).toEqual(0) }) From 183ca96bc0bfa511de3149364ad480f5cfbfa92a Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 10:15:26 +0100 Subject: [PATCH 10/11] Improve expects for POST requests --- test/tests/logger-dev.test.js | 5 +++-- test/tests/logger-prod.test.js | 5 +++-- 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/test/tests/logger-dev.test.js b/test/tests/logger-dev.test.js index 7f1d38df..942d1195 100644 --- a/test/tests/logger-dev.test.js +++ b/test/tests/logger-dev.test.js @@ -23,8 +23,9 @@ describe('graphql - query logging in development', () => { describe('POST requests', () => { test('Do not log requests with undefined queries', async () => { - const { status } = await POST('/graphql') - expect(status).toEqual(400) + const response = await POST('/graphql') + expect(response.status).toEqual(400) + expect(response.data.errors[0]).toEqual({ message: 'Missing query' }) expect(_log.mock.calls.length).toEqual(0) }) diff --git a/test/tests/logger-prod.test.js b/test/tests/logger-prod.test.js index 72af51a0..217f19c0 100644 --- a/test/tests/logger-prod.test.js +++ b/test/tests/logger-prod.test.js @@ -30,8 +30,9 @@ describe('graphql - query logging with sanitization in production', () => { describe('POST requests', () => { test('Do not log requests with undefined queries', async () => { - const { status } = await POST('/graphql') - expect(status).toEqual(400) + const response = await POST('/graphql') + expect(response.status).toEqual(400) + expect(response.data.errors[0]).toEqual({ message: 'Missing query' }) expect(_log.mock.calls.length).toEqual(0) }) From 965af1d08b9552b270d13385ffacbc02eb393456 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Thu, 16 Nov 2023 10:26:37 +0100 Subject: [PATCH 11/11] Add comments about GraphiQL to expected HTML --- test/tests/logger-dev.test.js | 2 +- test/tests/logger-prod.test.js | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/test/tests/logger-dev.test.js b/test/tests/logger-dev.test.js index 942d1195..4385a419 100644 --- a/test/tests/logger-dev.test.js +++ b/test/tests/logger-dev.test.js @@ -142,7 +142,7 @@ describe('graphql - query logging in development', () => { test('Do not log requests with undefined queries', async () => { const response = await GET('/graphql') expect(response.status).toEqual(200) - expect(response.data).toMatch(/html/i) + expect(response.data).toMatch(/html/i) // GraphiQL is returned expect(_log.mock.calls.length).toEqual(0) }) diff --git a/test/tests/logger-prod.test.js b/test/tests/logger-prod.test.js index 217f19c0..707c28ed 100644 --- a/test/tests/logger-prod.test.js +++ b/test/tests/logger-prod.test.js @@ -151,7 +151,7 @@ describe('graphql - query logging with sanitization in production', () => { test('Do not log requests with undefined queries', async () => { const response = await GET('/graphql') expect(response.status).toEqual(200) - expect(response.data).toMatch(/html/i) + expect(response.data).toMatch(/html/i) // GraphiQL is returned expect(_log.mock.calls.length).toEqual(0) })