From 1af35aad672ba86f5d67e1ff69c35e05a2f047ea Mon Sep 17 00:00:00 2001 From: Trevor Scheer Date: Wed, 24 Aug 2022 13:47:35 -0700 Subject: [PATCH 1/3] Reproduction --- .../server/src/__tests__/runQuery.test.ts | 39 +++++++++++++++++++ 1 file changed, 39 insertions(+) diff --git a/packages/server/src/__tests__/runQuery.test.ts b/packages/server/src/__tests__/runQuery.test.ts index d50df0d6f98..2ba64c3e1df 100644 --- a/packages/server/src/__tests__/runQuery.test.ts +++ b/packages/server/src/__tests__/runQuery.test.ts @@ -22,6 +22,7 @@ import { GraphQLRequestListenerParsingDidEnd, GraphQLRequestListenerValidationDidEnd, } from '..'; +import { mockLogger } from './mockLogger'; async function runQuery( config: ApolloServerOptions, @@ -425,6 +426,44 @@ describe('request pipeline life-cycle hooks', () => { expect(executionDidStart).toHaveBeenCalledTimes(1); expect(executionDidEnd).toHaveBeenCalledTimes(1); }); + + it('is called twice if it throws (undesirable)', async () => { + const executionDidEnd = jest.fn(() => { + throw new Error('boom'); + }); + + const plugins = [ + { + async requestDidStart() { + return { + async executionDidStart() { + return { + executionDidEnd, + }; + }, + }; + }, + }, + ]; + + const logger = mockLogger(); + + await expect( + runQuery( + { + schema, + plugins, + logger, + }, + { query: '{ testString }' }, + ), + ).rejects.toThrowError(/Internal server error/); + + expect(executionDidEnd).toHaveBeenCalledTimes(2); + expect(logger.error).toHaveBeenCalledWith( + 'Unexpected error processing request: Error: boom', + ); + }); }); describe('willResolveField', () => { From e483629f2c0dc841a3dd2cbc69c6e13aea99339e Mon Sep 17 00:00:00 2001 From: Trevor Scheer Date: Wed, 24 Aug 2022 13:48:33 -0700 Subject: [PATCH 2/3] Fix, update tests --- packages/server/src/__tests__/runQuery.test.ts | 4 ++-- packages/server/src/requestPipeline.ts | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/packages/server/src/__tests__/runQuery.test.ts b/packages/server/src/__tests__/runQuery.test.ts index 2ba64c3e1df..d280d249f9f 100644 --- a/packages/server/src/__tests__/runQuery.test.ts +++ b/packages/server/src/__tests__/runQuery.test.ts @@ -427,7 +427,7 @@ describe('request pipeline life-cycle hooks', () => { expect(executionDidEnd).toHaveBeenCalledTimes(1); }); - it('is called twice if it throws (undesirable)', async () => { + it('is only called once if it throws', async () => { const executionDidEnd = jest.fn(() => { throw new Error('boom'); }); @@ -459,7 +459,7 @@ describe('request pipeline life-cycle hooks', () => { ), ).rejects.toThrowError(/Internal server error/); - expect(executionDidEnd).toHaveBeenCalledTimes(2); + expect(executionDidEnd).toHaveBeenCalledTimes(1); expect(logger.error).toHaveBeenCalledWith( 'Unexpected error processing request: Error: boom', ); diff --git a/packages/server/src/requestPipeline.ts b/packages/server/src/requestPipeline.ts index 6a81e117810..3a461a76e63 100644 --- a/packages/server/src/requestPipeline.ts +++ b/packages/server/src/requestPipeline.ts @@ -459,8 +459,6 @@ export async function processGraphQLRequest( ...result, errors: resultErrors ? formatErrors(resultErrors) : undefined, }; - - await Promise.all(executionListeners.map((l) => l.executionDidEnd?.())); } catch (executionMaybeError: unknown) { const executionError = ensureError(executionMaybeError); await Promise.all( @@ -472,6 +470,8 @@ export async function processGraphQLRequest( newHTTPGraphQLHead(statusIfExecuteThrows), ); } + + await Promise.all(executionListeners.map((l) => l.executionDidEnd?.())); } await invokeWillSendResponse(); From dd3270c300440631b66524921b41e299e543630c Mon Sep 17 00:00:00 2001 From: Trevor Scheer Date: Wed, 24 Aug 2022 13:40:03 -0700 Subject: [PATCH 3/3] changeset --- .changeset/spotty-days-eat.md | 5 +++++ 1 file changed, 5 insertions(+) create mode 100644 .changeset/spotty-days-eat.md diff --git a/.changeset/spotty-days-eat.md b/.changeset/spotty-days-eat.md new file mode 100644 index 00000000000..b033a37649f --- /dev/null +++ b/.changeset/spotty-days-eat.md @@ -0,0 +1,5 @@ +--- +"@apollo/server": patch +--- + +Ensure executionDidEnd hooks are only called once (when they throw)