Fix stack trace when using apollo-server-testing

[parshap]

Using apollo-server-testing, I'm running into an issue where an error thrown in a resolver function while executing a query provides no stack trace. My test code that call's apollo-server-testing's query() gets a response with response.errors present, but there is no stack trace in the response. Additionally, my ApolloServer's formatError() function gets called, but error.extensions.exception.stacktrace is not present.

I'm using apollo-server-testing v2.8.1 (latest as of writing).

Reproducible example

This example demonstrates the current problem. Save the following as test.js:

const { ApolloServer, gql } = require('apollo-server-express');
const { createTestClient } = require('apollo-server-testing');

const server = new ApolloServer({
  debug: true,
  typeDefs: gql`
    type Query {
      test: String
    }
  `,
  resolvers: {
    Query: {
      test: () => {
        throw new Error('Some error');
      },
    },
  },
  formatError: error => {
    console.log(`Apollo Server error: ${error.message}`);
    console.log(error);
    if (error.extensions.exception) {
      console.log(error.extensions.exception.stacktrace);
    }
  },
});


const main = async () => {
  const { query } = createTestClient(server);
  const result = await query({
    query: gql`
      {
        test
      }
    `,
  });
  console.log('result', result);
}

main();

Then run:

$ npm i apollo-server-express apollo-server-testing graphql
$ node test.js

Expected behavior

If a resolver throws an error, I expect my formatError() function to be called with error.extensions.exception.stacktrace present.

Actual behavior

error.extensions.exception.stacktrace is not present. Program output:

$ node test.js
Apollo Server error: Some error
error { [GraphQLError: Some error]
  message: 'Some error',
  locations: [ { line: 2, column: 3 } ],
  path: [ 'test' ],
  extensions: { code: 'INTERNAL_SERVER_ERROR' } }
result { http:
   { headers: Headers { [Symbol(map)]: [Object: null prototype] {} } },
  errors: [ undefined ],
  data: [Object: null prototype] { test: null },
  extensions: undefined }

Actual behavior when fixed

And here's the behavior I get after I apply one of the fixes I describe below:

$ node test.js
Apollo Server error: Some error
error { [GraphQLError: Some error]
  message: 'Some error',
  locations: [ { line: 2, column: 3 } ],
  path: [ 'test' ],
  extensions:
   { code: 'INTERNAL_SERVER_ERROR',
     exception: { stacktrace: [Array] } } }
[ 'Error: Some error',
  '    at test (/private/tmp/apollo-testing-stacktrace-test/test.js:14:15)',
  '    at field.resolve (/private/tmp/apollo-testing-stacktrace-test/node_modules/graphql-extensions/dist/index.js:133:26)',
  '    at resolveFieldValueOrError (/private/tmp/apollo-testing-stacktrace-test/node_modules/graphql/execution/execute.js:503:18)',
  '    at resolveField (/private/tmp/apollo-testing-stacktrace-test/node_modules/graphql/execution/execute.js:470:16)',
  '    at executeFields (/private/tmp/apollo-testing-stacktrace-test/node_modules/graphql/execution/execute.js:311:18)',
  '    at executeOperation (/private/tmp/apollo-testing-stacktrace-test/node_modules/graphql/execution/execute.js:255:122)',
  '    at executeImpl (/private/tmp/apollo-testing-stacktrace-test/node_modules/graphql/execution/execute.js:102:14)',
  '    at Object.execute (/private/tmp/apollo-testing-stacktrace-test/node_modules/graphql/execution/execute.js:62:35)',
  '    at /private/tmp/apollo-testing-stacktrace-test/node_modules/apollo-server-core/dist/requestPipeline.js:239:46',
  '    at Generator.next (<anonymous>)' ]
result { http:
   { headers: Headers { [Symbol(map)]: [Object: null prototype] {} } },
  errors: [ undefined ],
  data: [Object: null prototype] { test: null },
  extensions: undefined }

What I'm trying to accomplish

My schema test code uses this approach to execute queries against the schema during tests. If there's a programming error in a resolver that results in an error being thrown, I want the developer running tests to see the resolver error and its stack trace.

I'm wondering if, aside from this issue, logging error.extensions.exception.stacktrace in formatError() the best approach to accomplish this in the first place?

What I've found so far

The reason extensions.exception.stacktrace gets omitted is because requestContext.debug if falsy here:

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

Lines 533 to 536 in d5015f4

	return formatApolloErrors(errors, {
	formatter: config.formatError,
	debug: requestContext.debug,
	});

However, config.debug is in the same scope true.

The call site that's passing requestContext into that scope does not pass debug at all:

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

Lines 769 to 780 in d5015f4

	const requestCtx: GraphQLRequestContext = {
	request,
	context: options.context || Object.create(null),
	cache: options.cache!,
	response: {
	http: {
	headers: new Headers(),
	},
	},
	};
	return processGraphQLRequest(options, requestCtx);

I'm not sure what would be setting requestContext.debug or why the function looks there, I'd expect debug to be present in the server config object, not requestContext.

Potential solutions

I came across two straightforward ways to fix this:

1) Read from config.debug

Change the following line:

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

Line 535 in d5015f4

debug: requestContext.debug,

To:

- debug: requestContext.debug,
+ debug: requestContext.debug != null ? requestContext.debug : config.debug,

2) Pass requestContext.debug

Alternatively, pass debug from the call site that creates requestContext:

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

Line 780 in d5015f4

return processGraphQLRequest(options, requestCtx);

  const requestCtx: GraphQLRequestContext = {
    request,
    context: options.context || Object.create(null),
    cache: options.cache!,
    response: {
      http: {
        headers: new Headers(),
      },
    },
+   debug: options.debug,
  };

  return processGraphQLRequest(options, requestCtx);

This PR

This PR applies the first fix described above. I'm looking for:

• Feedback on the fix
• Feedback on whether logging error.extensions.exception.stacktrace in formatError() the best approach to get stack traces in the first place

[apollo-cla]

@parshap: Thank you for submitting a pull request! Before we can merge it, you'll need to sign the Meteor Contributor Agreement here: https://contribute.meteor.com/

[moberegger]

Just ran into this problem myself. Would love to see this merged!

[parshap]

@abernix any context around closing this? Is this issue resolved? I'd like to know because if so our code can move back to using apollo-server-testing!

[abernix]

It was unintentional closing! Sorry for the confusion. Please stand-by and see #4304 for details. I will handle re-opening after GitHub Support gets back to me, as appropriate.

[ibratoev]

I looked into this PR and it seems the second approach described here makes more sense. I will prepare a PR for it as this seems to not be active anymore.

[glasser]

@parshap Thanks for the excellent detailed report. Sorry for the delay.

I agree with @ibratoev that approach 2 looks better, so I'll close this in favor of #4948, but thanks for the work you put in to get here!