usage reporting: don't throw errors if willResolveField is called "late"

CHANGELOG.md

@@ -7,6 +7,10 @@ The version headers in this history reflect the versions of Apollo Server itself
 - [`@apollo/gateway`](https://github.com/apollographql/federation/blob/HEAD/gateway-js/CHANGELOG.md)
 - [`@apollo/federation`](https://github.com/apollographql/federation/blob/HEAD/federation-js/CHANGELOG.md)
 
+## vNEXT
+
+- `apollo-server-core`: Fix usage reporting plugin "willResolveField called after stopTiming!" error caused by a race condition related to null bubbling. [Issue #4472](https://github.com/apollographql/apollo-server/issues/4472) [PR #6398](https://github.com/apollographql/apollo-server/pull/6398)
+
 ## v3.8.1
 
 - This is a patch release strictly for republishing over what appears to be a hiccup in NPMs service. [Issue #6469](https://github.com/apollographql/apollo-server/issues/6469)

packages/apollo-server-core/src/plugin/traceTreeBuilder.ts

@@ -68,7 +68,49 @@ export class TraceTreeBuilder {
       throw internalError('willResolveField called before startTiming!');
     }
     if (this.stopped) {
-      throw internalError('willResolveField called after stopTiming!');
+      // We've been stopped, which means execution is done... and yet we're
+      // still resolving more fields? How can that be? Shouldn't we throw an
+      // error or something?
+      //
+      // Well... we used to do exactly that. But this "shouldn't happen" error
+      // showed up in practice! Turns out that graphql-js can actually continue
+      // to execute more fields indefinitely long after `execute()` resolves!
+      // That's because parallelism on a selection set is implemented using
+      // `Promise.all`, and as soon as one of its arguments (ie, one field)
+      // throws an error, the combined Promise resolves, but there's no
+      // "cancellation" of the Promises that are the other arguments to
+      // `Promise.all`. So the code contributing to those Promises keeps on
+      // chugging away indefinitely.
+      //
+      // Concrete example: let’s say you have
+      //
+      //    { x y { ARBITRARY_SELECTION_SET } }
+      //
+      // where x has a non-null return type, and x and y both have resolvers
+      // that return Promises. And let’s say that x returns a Promise that
+      // rejects (or resolves to null). What this means is that we’re going to
+      // eventually end up with `data: null` (nothing under y will actually
+      // matter), but graphql-js execution will continue running whatever is
+      // under ARBITRARY_SELECTION_SET without any sort of short circuiting. In
+      // fact, the Promise returned from execute itself can happily resolve
+      // while execution is still chugging away on an arbitrary amount of fields
+      // under that ARBITRARY_SELECTION_SET. There’s no way to detect from the
+      // outside "all the execution related to this operation is done", nor to
+      // "short-circuit" execution so that it stops going.
+      //
+      // So, um. We will record any field whose execution we manage to observe
+      // before we "stop" the TraceTreeBuilder (whether it is one that actually
+      // ends up in the response or whether it gets thrown away due to null
+      // bubbling), but if we get any more fields afterwards, we just ignore
+      // them rather than throwing a confusing error.
+      //
+      // (That said, the error we used to throw here generally was hidden
+      // anyway, for the same reason: it comes from a branch of execution that
+      // ends up not being included in the response. But
+      // https://github.com/graphql/graphql-js/pull/3529 means that this
+      // sometimes crashed execution anyway. Our error never caught any actual
+      // problematic cases, so keeping it around doesn't really help.)
+      return () => {};
     }
 
     const path = info.path;