Enables context creation to be async and capture errors with opt-in logging

.circleci/config.yml

@@ -36,10 +36,6 @@ jobs:
   # Platform tests, each with the same tests but different platform or version.
   # The docker tag represents the Node.js version and the full list is available
   # at https://hub.docker.com/r/circleci/node/.
-  Node.js 4:
-    docker: [ { image: 'circleci/node:4' } ]
-    <<: *common_test_steps
-
   Node.js 6:
     docker: [ { image: 'circleci/node:6' } ]
     <<: *common_test_steps
@@ -73,7 +69,6 @@ workflows:
   version: 2
   Build and Test:
     jobs:
-      - Node.js 4
       - Node.js 6
       - Node.js 8
       - Node.js 9

packages/apollo-server-core/src/ApolloServer.ts

@@ -17,9 +17,9 @@ import {
   ExecutionParams,
 } from 'subscriptions-transport-ws';
 
-import { internalFormatError } from './errors';
+import { formatApolloErrors } from './errors';
 import { GraphQLServerOptions as GraphQLOptions } from './graphqlOptions';
-import { LogFunction } from './runQuery';
+import { LogFunction, LogAction, LogStep } from './logging';
 
 import {
   Config,
@@ -213,7 +213,12 @@ export class ApolloServerBase<Request = RequestInit> {
           connection.formatResponse = (value: ExecutionResult) => ({
             ...value,
             errors:
-              value.errors && value.errors.map(err => internalFormatError(err)),
+              value.errors &&
+              formatApolloErrors(value.errors, {
+                formatter: this.requestOptions.formatError,
+                debug: this.requestOptions.debug,
+                logFunction: this.requestOptions.logFunction,
+              }),
           });
           let context: Context = this.context ? this.context : { connection };
 
@@ -223,8 +228,11 @@ export class ApolloServerBase<Request = RequestInit> {
                 ? await this.context({ connection })
                 : context;
           } catch (e) {
-            console.error(e);
-            throw e;
+            throw formatApolloErrors([e], {
+              formatter: this.requestOptions.formatError,
+              debug: this.requestOptions.debug,
+              logFunction: this.requestOptions.logFunction,
+            })[0];
           }
 
           return { ...connection, context };
@@ -270,17 +278,16 @@ export class ApolloServerBase<Request = RequestInit> {
   async request(request: Request) {
     let context: Context = this.context ? this.context : { request };
 
+    //Differ context resolution to inside of runQuery
     context =
       typeof this.context === 'function'
-        ? await this.context({ req: request })
+        ? async () => this.context({ req: request })
         : context;
 
     return {
       schema: this.schema,
       tracing: Boolean(this.engineEnabled),
       cacheControl: Boolean(this.engineEnabled),
-      formatError: (e: GraphQLError) =>
-        internalFormatError(e, this.requestOptions.debug),
       context,
       // allow overrides from options
       ...this.requestOptions,

packages/apollo-server-core/src/errors.ts

@@ -1,4 +1,5 @@
 import { GraphQLError } from 'graphql';
+import { LogStep, LogAction, LogMessage, LogFunction } from './logging';
 
 export class ApolloError extends Error {
   public extensions;
@@ -8,14 +9,20 @@ export class ApolloError extends Error {
     properties?: Record<string, any>,
   ) {
     super(message);
-    this.extensions = { ...properties, code };
+
+    if (properties) {
+      Object.keys(properties).forEach(key => {
+        this[key] = properties[key];
+      });
+    }
+
+    //extensions are flattened to be included in the root of GraphQLError's, so
+    //don't add properties to extensions
+    this.extensions = { code };
   }
 }
 
-export function internalFormatError(
-  error: GraphQLError,
-  debug: boolean = false,
-) {
+export function enrichError(error: GraphQLError, debug: boolean = false) {
   const expanded: GraphQLError = {
     message: error.message,
     path: error.path,
@@ -95,7 +102,7 @@ export function fromGraphQLError(error: GraphQLError, options?: ErrorOptions) {
   //copy the original error, while keeping all values non-enumerable, so they
   //are not printed unless directly referenced
   Object.defineProperty(copy, 'originalError', { value: {} });
-  Reflect.ownKeys(error).forEach(key => {
+  Object.getOwnPropertyNames(error).forEach(key => {
     Object.defineProperty(copy.originalError, key, { value: error[key] });
   });
 
@@ -133,3 +140,40 @@ export class ForbiddenError extends ApolloError {
     super(message, 'FORBIDDEN');
   }
 }
+
+export function formatApolloErrors(
+  errors: Array<Error>,
+  options?: {
+    formatter?: Function;
+    logFunction?: LogFunction;
+    debug?: boolean;
+  },
+): Array<Error> {
+  const { formatter, debug, logFunction } = options;
+  return errors.map(error => enrichError(error, debug)).map(error => {
+    if (formatter !== undefined) {
+      try {
+        return formatter(error);
+      } catch (err) {
+        logFunction({
+          action: LogAction.cleanup,
+          step: LogStep.status,
+          data: err,
+          key: 'error',
+        });
+
+        if (debug) {
+          return enrichError(err, debug);
+        } else {
+          //obscure error
+          const newError: GraphQLError = fromGraphQLError(
+            new GraphQLError('Internal server error'),
+          );
+          return enrichError(newError, debug);
+        }
+      }
+    } else {
+      return error;
+    }
+  }) as Array<Error>;
+}

packages/apollo-server-core/src/graphqlOptions.ts

@@ -3,7 +3,7 @@ import {
   ValidationContext,
   GraphQLFieldResolver,
 } from 'graphql';
-import { LogFunction } from './runQuery';
+import { LogFunction } from './logging';
 import { GraphQLExtension } from 'graphql-extensions';
 
 /*
@@ -21,7 +21,11 @@ import { GraphQLExtension } from 'graphql-extensions';
  * - (optional) debug: a boolean that will print additional debug logging if execution errors occur
  *
  */
-export interface GraphQLServerOptions<TContext = any> {
+export interface GraphQLServerOptions<
+  TContext =
+    | (() => Promise<Record<string, any>> | Record<string, any>)
+    | Record<string, any>
+> {
   schema: GraphQLSchema;
   formatError?: Function;
   rootValue?: any;
@@ -40,15 +44,15 @@ export interface GraphQLServerOptions<TContext = any> {
 export default GraphQLServerOptions;
 
 export async function resolveGraphqlOptions(
-  options: GraphQLServerOptions | Function,
-  ...args
+  options:
+    | GraphQLServerOptions
+    | ((
+        ...args: Array<any>
+      ) => Promise<GraphQLServerOptions> | GraphQLServerOptions),
+  ...args: Array<any>
 ): Promise<GraphQLServerOptions> {
   if (typeof options === 'function') {
-    try {
-      return await options(...args);
-    } catch (e) {
-      throw new Error(`Invalid options provided to ApolloServer: ${e.message}`);
-    }
+    return await options(...args);
   } else {
     return options;
   }

packages/apollo-server-core/src/index.ts

@@ -1,10 +1,5 @@
-export {
-  runQuery,
-  LogFunction,
-  LogMessage,
-  LogStep,
-  LogAction,
-} from './runQuery';
+export { runQuery } from './runQuery';
+export { LogFunction, LogMessage, LogStep, LogAction } from './logging';
 export { runHttpQuery, HttpQueryRequest, HttpQueryError } from './runHttpQuery';
 export {
   default as GraphQLOptions,
@@ -17,7 +12,7 @@ export {
   ValidationError,
   AuthenticationError,
   ForbiddenError,
-  internalFormatError,
+  formatApolloErrors,
 } from './errors';
 
 // ApolloServer Base class

packages/apollo-server-core/src/logging.ts

@@ -0,0 +1,25 @@
+export enum LogAction {
+  request,
+  parse,
+  validation,
+  execute,
+  setup,
+  cleanup,
+}
+
+export enum LogStep {
+  start,
+  end,
+  status,
+}
+
+export interface LogMessage {
+  action: LogAction;
+  step: LogStep;
+  key?: string;
+  data?: any;
+}
+
+export interface LogFunction {
+  (message: LogMessage);
+}

packages/apollo-server-core/src/runHttpQuery.ts

@@ -4,12 +4,12 @@ import {
   default as GraphQLOptions,
   resolveGraphqlOptions,
 } from './graphqlOptions';
-import { internalFormatError } from './errors';
+import { formatApolloErrors } from './errors';
 
 export interface HttpQueryRequest {
   method: string;
   query: Record<string, any>;
-  options: GraphQLOptions | Function;
+  options: GraphQLOptions | (() => Promise<GraphQLOptions> | GraphQLOptions);
 }
 
 export class HttpQueryError extends Error {
@@ -42,20 +42,31 @@ export async function runHttpQuery(
 ): Promise<string> {
   let isGetRequest: boolean = false;
   let optionsObject: GraphQLOptions;
+  const debugDefault =
+    process.env.NODE_ENV !== 'production' && process.env.NODE_ENV !== 'test';
 
   try {
     optionsObject = await resolveGraphqlOptions(
       request.options,
       ...handlerArguments,
     );
   } catch (e) {
-    throw new HttpQueryError(500, e.message);
+    // The options can be generated asynchronously, so we don't have access to
+    // the normal options provided by the user, such as: formatError,
+    // logFunction, debug. Therefore, we need to do some unnatural things, such
+    // as use NODE_ENV to determine the debug settings
+    e.message = `Invalid options provided to ApolloServer: ${e.message}`;
+    throw new HttpQueryError(
+      500,
+      JSON.stringify({
+        errors: formatApolloErrors([e], { debug: debugDefault }),
+      }),
+      true,
+      {
+        'Content-Type': 'application/json',
+      },
+    );
   }
-  const formatErrorFn = optionsObject.formatError
-    ? error => optionsObject.formatError(internalFormatError(error))
-    : internalFormatError;
-  const debugDefault =
-    process.env.NODE_ENV !== 'production' && process.env.NODE_ENV !== 'test';
   const debug =
     optionsObject.debug !== undefined ? optionsObject.debug : debugDefault;
   let requestPayload;
@@ -99,7 +110,7 @@ export async function runHttpQuery(
     requestPayload = [requestPayload];
   }
 
-  const requests: Array<ExecutionResult> = requestPayload.map(requestParams => {
+  const requests = requestPayload.map(async requestParams => {
     try {
       let query = requestParams.query;
       let extensions = requestParams.extensions;
@@ -179,9 +190,30 @@ export async function runHttpQuery(
         }
       }
 
-      let context = optionsObject.context || {};
-      if (typeof context === 'function') {
-        context = context();
+      let context = optionsObject.context;
+      if (!context) {
+        //appease typescript compiler, otherwise could use || {}
+        context = {};
+      } else if (typeof context === 'function') {
+        try {
+          context = await context();
+        } catch (e) {
+          e.message = `Context creation failed: ${e.message}`;
+          throw new HttpQueryError(
+            500,
+            JSON.stringify({
+              errors: formatApolloErrors([e], {
+                formatter: optionsObject.formatError,
+                debug,
+                logFunction: optionsObject.logFunction,
+              }),
+            }),
+            true,
+            {
+              'Content-Type': 'application/json',
+            },
+          );
+        }
       } else if (isBatch) {
         context = Object.assign(
           Object.create(Object.getPrototypeOf(context)),
@@ -198,7 +230,7 @@ export async function runHttpQuery(
         operationName: operationName,
         logFunction: optionsObject.logFunction,
         validationRules: optionsObject.validationRules,
-        formatError: formatErrorFn,
+        formatError: optionsObject.formatError,
         formatResponse: optionsObject.formatResponse,
         fieldResolver: optionsObject.fieldResolver,
         debug: optionsObject.debug,
@@ -218,9 +250,16 @@ export async function runHttpQuery(
         return Promise.reject(e);
       }
 
-      return Promise.resolve({ errors: [formatErrorFn(e)] });
+      return Promise.resolve({
+        errors: formatApolloErrors([e], {
+          formatter: optionsObject.formatError,
+          debug,
+          logFunction: optionsObject.logFunction,
+        }),
+      });
     }
-  });
+  }) as Array<Promise<ExecutionResult>>;
+
   const responses = await Promise.all(requests);
 
   if (!isBatch) {

packages/apollo-server-core/src/runQuery.test.ts

@@ -12,7 +12,8 @@ import {
   parse,
 } from 'graphql';
 
-import { runQuery, LogAction, LogStep } from './runQuery';
+import { runQuery } from './runQuery';
+import { LogAction, LogStep } from './logging';
 
 // Make the global Promise constructor Fiber-aware to simulate a Meteor
 // environment.