usage reporting: allow sending traces for unexecutable operations (#6194

)

In #5963 we added `!!metrics.captureTraces` to the condition for
considering sending an operation as a trace to Studio. This makes sense
for operations which start to execute (don't send something as a trace
if we didn't record a trace for it!) but if the reason `captureTraces`
is unset is because we never successfully resolved an operation, it
still can be interesting to send a trace, for the sake of the Errors
page.  So we allow sending traces for unexecutable operations (though it
still goes through our standard sampling algorithm).

In order to make sure the recently added Trace.fieldExecutionWeight is
set to the default value of 1 in this case, we set it when initially
creating the Trace rather than in didResolveOperation.

Fixes #6193.

CHANGELOG.md

@@ -9,6 +9,8 @@ The version headers in this history reflect the versions of Apollo Server itself
 
 ## vNEXT
 
+- `apollo-server-core`: Fixes a regression in v3.6.0 where usage reporting would never send traces for unexecutable operations (parse errors, validation errors, and unknown operation name errors). While "traces" for these operations won't actually contain an execution tree, they can contain interesting errors. [Issue #6193](https://github.com/apollographql/apollo-server/issues/6193) [PR #6194](https://github.com/apollographql/apollo-server/pull/6194)
+
 ## v3.6.3
 
 - `apollo-server-core`: The inline trace plugin will now include the full query plan and subgraph traces if manually installed in an Apollo Gateway. (Previously, you technically could install this plugin in a Gateway but it would not have any real trace data.) This is recommended for development use only and not in production servers. [PR #6017](https://github.com/apollographql/apollo-server/pull/6017)

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

@@ -11,7 +11,17 @@ function internalError(message: string) {
 export class TraceTreeBuilder {
   private rootNode = new Trace.Node();
   private logger: Logger = console;
-  public trace = new Trace({ root: this.rootNode });
+  public trace = new Trace({
+    root: this.rootNode,
+    // By default, each trace counts as one operation for the sake of field
+    // execution counts. If we end up calling the fieldLevelInstrumentation
+    // callback (once we've successfully resolved the operation) then we
+    // may set this to a higher number; but we'll start it at 1 so that traces
+    // that don't successfully resolve the operation (eg parse failures) or
+    // where we don't call the callback because a plugin set captureTraces to
+    // true have a reasonable default.
+    fieldExecutionWeight: 1,
+  });
   public startHrTime?: [number, number];
   private stopped = false;
   private nodes = new Map<string, Trace.Node>([

packages/apollo-server-core/src/plugin/usageReporting/__tests__/plugin.test.ts

@@ -214,7 +214,13 @@ describe('end-to-end', () => {
         (contextualizedStats) =>
           contextualizedStats.queryLatencyStats?.requestCount ?? 0,
       );
-      expect(operationsSentAsTrace + operationsSentAsStats).toBe(1);
+      // Since we only ever run a single operation, the cache in
+      // defaultSendOperationsAsTrace should always be empty and we should
+      // always send this as a trace, not stats. This is even the case if it's a
+      // pre-execution error, because the error itself is an interesting thing
+      // to send in a trace even if the tree part of the trace is trivial.
+      expect(operationsSentAsTrace).toBe(1);
+      expect(operationsSentAsStats).toBe(0);
     }),
   );
 

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

@@ -538,11 +538,6 @@ export function ApolloServerPluginUsageReporting<TContext>(
 
                 metrics.captureTraces =
                   !!treeBuilder.trace.fieldExecutionWeight;
-              } else if (metrics.captureTraces) {
-                // Some other plugin already decided that we are capturing traces.
-                // (For example, you may be running ApolloServerPluginInlineTrace
-                // and this is a request with the header that requests tracing.)
-                treeBuilder.trace.fieldExecutionWeight = 1;
               }
             }
           },
@@ -644,6 +639,8 @@ export function ApolloServerPluginUsageReporting<TContext>(
                 statsReportKey = `## GraphQLUnknownOperationName\n`;
               }
 
+              const isExecutable = statsReportKey === undefined;
+
               if (statsReportKey) {
                 if (options.sendUnexecutableOperationDocuments) {
                   trace.unexecutedOperationBody = requestContext.source;
@@ -675,9 +672,16 @@ export function ApolloServerPluginUsageReporting<TContext>(
                 // organization's plan allows for viewing traces *and* we
                 // actually captured this as a full trace *and*
                 // sendOperationAsTrace says so.
+                //
+                // (As an edge case, if the reason metrics.captureTraces is
+                // falsey is that this is an unexecutable operation and thus we
+                // never ran the code in didResolveOperation that sets
+                // metrics.captureTrace, we allow it to be sent as a trace. This
+                // means we'll still send some parse and validation failures as
+                // traces, for the sake of the Errors page.)
                 asTrace:
                   graphMightSupportTraces &&
-                  !!metrics.captureTraces &&
+                  (!isExecutable || !!metrics.captureTraces) &&
                   sendOperationAsTrace(trace, statsReportKey),
                 includeTracesContributingToStats,
                 referencedFieldsByType,