From 4c8f1000bd87f1d6372458b54ddebc359dcedef6 Mon Sep 17 00:00:00 2001
From: David Glasser <glasser@apollographql.com>
Date: Fri, 3 Jun 2022 17:42:21 -0700
Subject: [PATCH] usage reporting: don't throw errors if willResolveField is
 called "late" (#6398)

The comment explains this in detail. Basically, this "shouldn't happen"
error actually could happen. In theory, the times it could happen are
the exact times that the error itself would be swallowed rather than
becoming visible... but a graphql-js bug meant that sometimes they would
become visible anyway.

Fixes #4472.
---
 CHANGELOG.md                                  |  4 ++
 .../src/plugin/traceTreeBuilder.ts            | 44 ++++++++++++++++++-
 2 files changed, 47 insertions(+), 1 deletion(-)

diff --git a/CHANGELOG.md b/CHANGELOG.md
index 9151f21f5eb..1ba960b5d19 100644
--- a/CHANGELOG.md
+++ b/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)
diff --git a/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts b/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts
index 9adee45a45b..71bc52578bd 100644
--- a/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts
+++ b/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;