Skip to content

Commit

Permalink
Make top-level errors consistent and observable (#6514)
Browse files Browse the repository at this point in the history
Previously, errors that weren't specially cased as part of the "request
pipeline" were not observable by plugins. (In some but not all cases,
they were visible to formatError hooks.) Some "HTTP-level" errors were
handled by returning text/plain responses, whereas many other errors
were handled by returning GraphQL-style JSON responses (using
the formatError hook).

This change makes things more consistent by returning all errors as JSON
responses (using the formatError hook). In addition, for better
observability, several new top-level plugin APIs are introduced that are
called when various kinds of errors occur. Specifically:

- New plugin hook `startupDidFail`. This is called once if startup fails
  (eg, if a serverWillStart plugin throws or if gateway fails to load
  the schema). (If this hook throws, its error is logged.) Future calls to
  executeHTTPGraphQLRequest (if the server was started in the
  background) now return a formatted JSON error instead of throwing.

- New plugin hook `contextCreationDidFail`. (If this hook throws, its
  error is logged.) As before, these errors are sent as formatted JSON
  errors.

- New plugin hook `invalidRequestWasReceived`. This is called for all
  the errors that occur before being able to construct a GraphQLRequest
  from an HTTPGraphQLRequest; this includes things like the top-level
  fields being of the wrong type, missing body, CSRF failure, etc).
  These errors are now sent as formatted JSON instead of as text/plain.

- New plugin hook `unexpectedErrorProcessingRequest`. This is called if
  `processGraphQLRequest` throws (typically because a plugin hook
  threw). We are making the assumption that this means there is a
  programming error, so we are making the behavior change that the
  thrown error will be logged and "Internal server error" will be sent
  in the HTTP response.

- Fix grammar of "GET supports only query operation" and don't return it
  if the operation is unknown.

Fixes #6140. Part of #6053.
  • Loading branch information
glasser authored Jun 3, 2022
1 parent 29124a9 commit 1aeb215
Show file tree
Hide file tree
Showing 11 changed files with 497 additions and 299 deletions.
215 changes: 151 additions & 64 deletions packages/server/src/ApolloServer.ts
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,7 @@ import Negotiator from 'negotiator';
import * as uuid from 'uuid';
import { newCachePolicy } from './cachePolicy';
import { ApolloConfig, determineApolloConfig } from './config';
import { formatApolloErrors } from './errors';
import { BadRequestError, ensureError, formatApolloErrors } from './errors';
import type {
ApolloServerPlugin,
BaseContext,
Expand All @@ -35,6 +35,7 @@ import type {
LandingPage,
PluginDefinition,
} from './externalTypes';
import type { HTTPGraphQLHead } from './externalTypes/http';
import { runPotentiallyBatchedHttpQuery } from './httpBatching';
import { InternalPluginId, pluginIsInternal } from './internalPlugin';
import {
Expand All @@ -52,6 +53,7 @@ import {
} from './preventCsrf';
import { APQ_CACHE_PREFIX, processGraphQLRequest } from './requestPipeline';
import {
badMethodErrorMessage,
cloneObject,
HeaderMap,
newHTTPGraphQLHead,
Expand Down Expand Up @@ -489,10 +491,24 @@ export class ApolloServer<TContext extends BaseContext = BaseContext> {
toDispose,
toDisposeLast,
};
} catch (error) {
} catch (maybeError: unknown) {
const error = ensureError(maybeError);

try {
await Promise.all(
this.internals.plugins.map(async (plugin) =>
plugin.startupDidFail?.({ error }),
),
);
} catch (pluginError) {
this.internals.logger.error(
`startupDidFail hook threw: ${pluginError}`,
);
}

this.internals.state = {
phase: 'failed to start',
error: error as Error,
error: error,
};
throw error;
} finally {
Expand Down Expand Up @@ -959,79 +975,130 @@ export class ApolloServer<TContext extends BaseContext = BaseContext> {
}

// TODO(AS4): Make sure we like the name of this function.
// TODO(AS4): Should we make this into a function that never throws?
public async executeHTTPGraphQLRequest({
httpGraphQLRequest,
context,
}: {
httpGraphQLRequest: HTTPGraphQLRequest;
context: ContextThunk<TContext>;
}): Promise<HTTPGraphQLResponse> {
// TODO(AS4): This throws if we started in the background and there was an
// error, but instead of throwing it should return an appropriate error
// response. Note that we can make the serverIsStartedInBackground case of
// the `rejected load promise is thrown by server.start` test tighter once
// we fix this.
const runningServerState = await this._ensureStarted();
try {
let runningServerState;
try {
runningServerState = await this._ensureStarted();
} catch (error: unknown) {
// This is typically either the masked error from when background startup
// failed, or related to invoking this function before startup or
// during/after shutdown (due to lack of draining).
return this.errorResponse(error);
}

if (
runningServerState.landingPage &&
this.prefersHTML(httpGraphQLRequest)
) {
return {
headers: new HeaderMap([['content-type', 'text/html']]),
completeBody: runningServerState.landingPage.html,
bodyChunks: null,
};
}
if (
runningServerState.landingPage &&
this.prefersHTML(httpGraphQLRequest)
) {
return {
headers: new HeaderMap([['content-type', 'text/html']]),
completeBody: runningServerState.landingPage.html,
bodyChunks: null,
};
}

// If enabled, check to ensure that this request was preflighted before doing
// anything real (such as running the context function).
if (this.internals.csrfPreventionRequestHeaders) {
preventCsrf(
httpGraphQLRequest.headers,
this.internals.csrfPreventionRequestHeaders,
);
}

let contextValue: TContext;
try {
contextValue = await context();
} catch (maybeError: unknown) {
const error = ensureError(maybeError);
try {
await Promise.all(
this.internals.plugins.map(async (plugin) =>
plugin.contextCreationDidFail?.({
error,
}),
),
);
} catch (pluginError) {
this.internals.logger.error(
`contextCreationDidFail hook threw: ${pluginError}`,
);
}

error.message = `Context creation failed: ${error.message}`;
// If we explicitly provide an error code that isn't
// INTERNAL_SERVER_ERROR, we'll treat it as a client error.
const statusCode =
error instanceof GraphQLError &&
error.extensions.code &&
error.extensions.code !== 'INTERNAL_SERVER_ERROR'
? 400
: 500;
return this.errorResponse(error, newHTTPGraphQLHead(statusCode));
}

// If enabled, check to ensure that this request was preflighted before doing
// anything real (such as running the context function).
if (this.internals.csrfPreventionRequestHeaders) {
// TODO(AS4): We introduced an error handling bug when we ported this to
// version-4: this throws HttpQueryError but we don't treat that specially
// here.
preventCsrf(
httpGraphQLRequest.headers,
this.internals.csrfPreventionRequestHeaders,
return await runPotentiallyBatchedHttpQuery(
httpGraphQLRequest,
contextValue,
runningServerState.schemaManager.getSchemaDerivedData(),
this.internals,
);
} catch (maybeError_: unknown) {
const maybeError = maybeError_; // fixes inference because catch vars are not const
if (maybeError instanceof BadRequestError) {
try {
await Promise.all(
this.internals.plugins.map(async (plugin) =>
plugin.invalidRequestWasReceived?.({ error: maybeError }),
),
);
} catch (pluginError) {
this.internals.logger.error(
`invalidRequestWasReceived hook threw: ${pluginError}`,
);
}
return this.errorResponse(
maybeError,
// Quite hacky, but beats putting more stuff on GraphQLError
// subclasses, maybe?
maybeError.message === badMethodErrorMessage
? {
statusCode: 405,
headers: new HeaderMap([['allow', 'GET, POST']]),
}
: newHTTPGraphQLHead(400),
);
}
return this.errorResponse(maybeError);
}
}

let contextValue: TContext;
try {
contextValue = await context();
} catch (e: any) {
// XXX `any` isn't ideal, but this is the easiest thing for now, without
// introducing a strong `instanceof GraphQLError` requirement.
e.message = `Context creation failed: ${e.message}`;
// For errors that are not internal, such as authentication, we
// should provide a 400 response
const statusCode =
e.extensions &&
e.extensions.code &&
e.extensions.code !== 'INTERNAL_SERVER_ERROR'
? 400
: 500;
return {
statusCode,
headers: new HeaderMap([['content-type', 'application/json']]),
completeBody: prettyJSONStringify({
errors: formatApolloErrors([e as Error], {
includeStackTracesInErrorResponses:
this.internals.includeStackTracesInErrorResponses,
formatError: this.internals.formatError,
}),
private errorResponse(
error: unknown,
httpGraphQLHead: HTTPGraphQLHead = newHTTPGraphQLHead(),
): HTTPGraphQLResponse {
return {
statusCode: httpGraphQLHead.statusCode ?? 500,
headers: new HeaderMap([
...httpGraphQLHead.headers,
['content-type', 'application/json'],
]),
completeBody: prettyJSONStringify({
errors: formatApolloErrors([error], {
includeStackTracesInErrorResponses:
this.internals.includeStackTracesInErrorResponses,
formatError: this.internals.formatError,
}),
bodyChunks: null,
};
}

return await runPotentiallyBatchedHttpQuery(
httpGraphQLRequest,
contextValue,
runningServerState.schemaManager.getSchemaDerivedData(),
this.internals,
);
}),
bodyChunks: null,
};
}

private prefersHTML(request: HTTPGraphQLRequest): boolean {
Expand Down Expand Up @@ -1146,7 +1213,27 @@ export async function internalExecuteOperation<TContext extends BaseContext>({
metrics: {},
overallCachePolicy: newCachePolicy(),
};
await processGraphQLRequest(schemaDerivedData, internals, requestContext);

try {
await processGraphQLRequest(schemaDerivedData, internals, requestContext);
} catch (maybeError: unknown) {
// processGraphQLRequest throwing usually means that either there's a bug in
// Apollo Server or some plugin hook threw unexpectedly.
const error = ensureError(maybeError);
// If *these* hooks throw then we'll still get a 500 but won't mask its
// error.
await Promise.all(
internals.plugins.map(async (plugin) =>
plugin.unexpectedErrorProcessingRequest?.({
requestContext,
error,
}),
),
);
// Mask unexpected error externally.
internals.logger.error(`Unexpected error processing request: ${error}`);
throw new Error('Internal server error');
}
return requestContext.response;
}

Expand Down
66 changes: 48 additions & 18 deletions packages/server/src/__tests__/ApolloServer.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -134,16 +134,23 @@ const failToStartPlugin: ApolloServerPlugin<BaseContext> = {
};

describe('ApolloServer start', () => {
const redactedMessage =
'This data graph is missing a valid configuration. More details may be available in the server logs.';

it('start throws on startup error', async () => {
const startupDidFail = jest.fn();
const server = new ApolloServer({
typeDefs,
resolvers,
plugins: [failToStartPlugin],
plugins: [failToStartPlugin, { startupDidFail }],
});
await expect(server.start()).rejects.toThrow('nope');
expect(startupDidFail.mock.calls).toMatchInlineSnapshot(`
Array [
Array [
Object {
"error": [Error: nope],
},
],
]
`);
});

it('stop throws on stop error', async () => {
Expand Down Expand Up @@ -176,7 +183,7 @@ describe('ApolloServer start', () => {
// We care more specifically about this in the background start case because
// integrations shouldn't call executeHTTPGraphQLRequest if a "foreground"
// start fails.
it('executeHTTPGraphQLRequest throws redacted message if background start fails', async () => {
it('executeHTTPGraphQLRequest returns redacted error if background start fails', async () => {
const error = jest.fn();
const logger = {
debug: jest.fn(),
Expand All @@ -191,21 +198,44 @@ describe('ApolloServer start', () => {
plugins: [failToStartPlugin],
logger,
});

server.startInBackgroundHandlingStartupErrorsByLoggingAndFailingAllRequests();

for (const _ in [1, 2]) {
await expect(
server.executeHTTPGraphQLRequest({
httpGraphQLRequest: {
method: 'POST',
headers: new HeaderMap([['content-type', 'application-json']]),
body: JSON.stringify({ query: '{__typename}' }),
searchParams: {},
},
context: async () => ({}),
}),
).rejects.toThrow(redactedMessage);
}
const request = {
httpGraphQLRequest: {
method: 'POST',
headers: new HeaderMap([['content-type', 'application-json']]),
body: JSON.stringify({ query: '{__typename}' }),
searchParams: {},
},
context: async () => ({}),
};

expect(await server.executeHTTPGraphQLRequest(request))
.toMatchInlineSnapshot(`
Object {
"bodyChunks": null,
"completeBody": "{\\"errors\\":[{\\"message\\":\\"This data graph is missing a valid configuration. More details may be available in the server logs.\\",\\"extensions\\":{\\"code\\":\\"INTERNAL_SERVER_ERROR\\"}}]}
",
"headers": Map {
"content-type" => "application/json",
},
"statusCode": 500,
}
`);

expect(await server.executeHTTPGraphQLRequest(request))
.toMatchInlineSnapshot(`
Object {
"bodyChunks": null,
"completeBody": "{\\"errors\\":[{\\"message\\":\\"This data graph is missing a valid configuration. More details may be available in the server logs.\\",\\"extensions\\":{\\"code\\":\\"INTERNAL_SERVER_ERROR\\"}}]}
",
"headers": Map {
"content-type" => "application/json",
},
"statusCode": 500,
}
`);

// Three times: once for the actual background _start call, twice for the
// two operations.
Expand Down
Loading

0 comments on commit 1aeb215

Please sign in to comment.