fix!: always assign a trace ID to each request (#1033)

BREAKING CHANGE: When initialized with `clsMechanism: 'none'`, calling `Tracer#createChildSpan` will potentially result in a warning, as these spans are considered to be uncorrelated. To ensure that warnings do not occur, disable any plugins that patch modules that create outgoing RPCs (gRPC, HTTP client and database calls). (Use of the custom span API `Tracer#createChildSpan` is not recommended in this configuration -- use `RootSpan#createChildSpan` instead.)

Author: kjin

src/cls.ts

@@ -25,7 +25,7 @@ import { SingularCLS } from './cls/singular';
 import { SpanType } from './constants';
 import { Logger } from './logger';
 import { RootSpan } from './plugin-types';
-import { UNCORRELATED_ROOT_SPAN, UNTRACED_ROOT_SPAN } from './span-data';
+import { UNCORRELATED_ROOT_SPAN, DISABLED_ROOT_SPAN } from './span-data';
 import { Trace, TraceSpan } from './trace';
 import { Singleton } from './util';
 
@@ -38,7 +38,7 @@ export interface RealRootContext {
 }
 
 export interface PhantomRootContext {
-  readonly type: SpanType.UNCORRELATED | SpanType.UNTRACED;
+  readonly type: SpanType.UNCORRELATED | SpanType.UNSAMPLED | SpanType.DISABLED;
 }
 
 /**
@@ -104,7 +104,7 @@ export class TraceCLS implements CLS<RootContext> {
   private enabled = false;
 
   static UNCORRELATED: RootContext = UNCORRELATED_ROOT_SPAN;
-  static UNTRACED: RootContext = UNTRACED_ROOT_SPAN;
+  static DISABLED: RootContext = DISABLED_ROOT_SPAN;
 
   /**
    * Stack traces are captured when a root span is started. Because the stack
@@ -147,7 +147,7 @@ export class TraceCLS implements CLS<RootContext> {
     this.logger.info(
       `TraceCLS#constructor: Created [${config.mechanism}] CLS instance.`
     );
-    this.currentCLS = new NullCLS(TraceCLS.UNTRACED);
+    this.currentCLS = new NullCLS(TraceCLS.DISABLED);
     this.currentCLS.enable();
   }
 
@@ -156,9 +156,7 @@ export class TraceCLS implements CLS<RootContext> {
   }
 
   enable(): void {
-    // if this.CLSClass = NullCLS, the user specifically asked not to use
-    // any context propagation mechanism. So nothing should change.
-    if (!this.enabled && this.CLSClass !== NullCLS) {
+    if (!this.enabled) {
       this.logger.info('TraceCLS#enable: Enabling CLS.');
       this.currentCLS.disable();
       this.currentCLS = new this.CLSClass(TraceCLS.UNCORRELATED);
@@ -171,7 +169,7 @@ export class TraceCLS implements CLS<RootContext> {
     if (this.enabled && this.CLSClass !== NullCLS) {
       this.logger.info('TraceCLS#disable: Disabling CLS.');
       this.currentCLS.disable();
-      this.currentCLS = new NullCLS(TraceCLS.UNTRACED);
+      this.currentCLS = new NullCLS(TraceCLS.DISABLED);
       this.currentCLS.enable();
     }
     this.enabled = false;

src/constants.ts

@@ -57,17 +57,17 @@ export enum SpanType {
   UNCORRELATED = 'UNCORRELATED',
 
   /**
-   * This span object was created in circumstances where a trace span could not
-   * be created for one of the following reasons:
-   * (1) The Trace Agent is disabled, either explicitly or because a project ID
-   *     couldn't be determined.
-   * (2) The configured tracing policy disallows tracing for this request
-   *     (due to sampling restrictions, ignored URLs, etc.)
-   * (3) The current incoming request contains trace context headers that
-   *     explicitly disable local tracing for the request.
+   * This span object was created by a disabled Trace Agent, either explicitly
+   * or because a project ID couldn't be determined.
+   */
+  DISABLED = 'DISABLED',
+
+  /**
+   * This span object represents an unsampled request, and will not be
+   * published.
    * Getting a span object of this type should not be considered an error.
    */
-  UNTRACED = 'UNTRACED',
+  UNSAMPLED = 'UNSAMPLED',
 
   /**
    * This span object was created by StackdriverTracer#runInRootSpan, and

src/span-data.ts

@@ -18,7 +18,7 @@ import * as crypto from 'crypto';
 import * as util from 'util';
 
 import { Constants, SpanType } from './constants';
-import { RootSpan, Span, SpanOptions } from './plugin-types';
+import { RootSpan, Span, SpanOptions, TraceContext } from './plugin-types';
 import { SpanKind, Trace, TraceSpan } from './trace';
 import { TraceLabels } from './trace-labels';
 import { traceWriter } from './trace-writer';
@@ -226,6 +226,47 @@ function createPhantomSpanData<T extends SpanType>(
   );
 }
 
+/**
+ * Helper (and base) class for UntracedRootSpanData. Represents an untraced
+ * child span.
+ */
+class UntracedSpanData implements Span {
+  readonly type = SpanType.UNSAMPLED;
+  protected readonly traceContext: TraceContext;
+
+  constructor(traceId: string) {
+    this.traceContext = {
+      traceId,
+      spanId: randomSpanId(),
+      options: 0, // Not traced.
+    };
+  }
+
+  getTraceContext(): traceUtil.TraceContext | null {
+    return this.traceContext;
+  }
+
+  // No-op.
+  addLabel(): void {}
+  // No-op.
+  endSpan(): void {}
+}
+
+/**
+ * Represents an "untraced" root span (aka not published).
+ * For distributed trace context propagation purposes.
+ */
+export class UntracedRootSpanData extends UntracedSpanData implements RootSpan {
+  private child: Span | null = null;
+
+  createChildSpan(): Span {
+    if (!this.child) {
+      this.child = new UntracedSpanData(this.traceContext.traceId);
+    }
+    return this.child;
+  }
+}
+
 /**
  * A virtual trace span that indicates that a real child span couldn't be
  * created because the correct root span couldn't be determined.
@@ -236,10 +277,9 @@ export const UNCORRELATED_CHILD_SPAN = createPhantomSpanData(
 
 /**
  * A virtual trace span that indicates that a real child span couldn't be
- * created because the corresponding root span was disallowed by user
- * configuration.
+ * created because the Trace Agent was disabled.
  */
-export const UNTRACED_CHILD_SPAN = createPhantomSpanData(SpanType.UNTRACED);
+export const DISABLED_CHILD_SPAN = createPhantomSpanData(SpanType.DISABLED);
 
 /**
  * A virtual trace span that indicates that a real root span couldn't be
@@ -260,13 +300,13 @@ export const UNCORRELATED_ROOT_SPAN = Object.freeze(
  * A virtual trace span that indicates that a real root span couldn't be
  * created because it was disallowed by user configuration.
  */
-export const UNTRACED_ROOT_SPAN = Object.freeze(
+export const DISABLED_ROOT_SPAN = Object.freeze(
   Object.assign(
     {
       createChildSpan() {
-        return UNTRACED_CHILD_SPAN;
+        return DISABLED_CHILD_SPAN;
       },
     },
-    UNTRACED_CHILD_SPAN
+    DISABLED_CHILD_SPAN
   )
 );

src/trace-api.ts

@@ -34,8 +34,9 @@ import {
   RootSpanData,
   UNCORRELATED_CHILD_SPAN,
   UNCORRELATED_ROOT_SPAN,
-  UNTRACED_CHILD_SPAN,
-  UNTRACED_ROOT_SPAN,
+  DISABLED_CHILD_SPAN,
+  DISABLED_ROOT_SPAN,
+  UntracedRootSpanData,
 } from './span-data';
 import { TraceLabels } from './trace-labels';
 import { traceWriter } from './trace-writer';
@@ -191,7 +192,7 @@ export class StackdriverTracer implements Tracer {
 
   runInRootSpan<T>(options: RootSpanOptions, fn: (span: RootSpan) => T): T {
     if (!this.isActive()) {
-      return fn(UNTRACED_ROOT_SPAN);
+      return fn(DISABLED_ROOT_SPAN);
     }
 
     options = options || { name: '' };
@@ -234,23 +235,25 @@ export class StackdriverTracer implements Tracer {
       options,
     });
 
+    const traceId = traceContext
+      ? traceContext.traceId
+      : uuid
+          .v4()
+          .split('-')
+          .join('');
     let rootContext: RootSpan & RootContext;
 
-    // Don't create a root span if the trace policy disallows it.
+    // Create an "untraced" root span (one that won't be published) if the
+    // trace policy disallows it.
     if (!shouldTrace) {
-      rootContext = UNTRACED_ROOT_SPAN;
+      rootContext = new UntracedRootSpanData(traceId);
     } else {
       // Create a new root span, and invoke fn with it.
       rootContext = new RootSpanData(
         // Trace object
         {
           projectId: '',
-          traceId: traceContext
-            ? traceContext.traceId
-            : uuid
-                .v4()
-                .split('-')
-                .join(''),
+          traceId,
           spans: [],
         },
         // Span name
@@ -269,7 +272,7 @@ export class StackdriverTracer implements Tracer {
 
   getCurrentRootSpan(): RootSpan {
     if (!this.isActive()) {
-      return UNTRACED_ROOT_SPAN;
+      return DISABLED_ROOT_SPAN;
     }
     return cls.get().getContext();
   }
@@ -301,7 +304,7 @@ export class StackdriverTracer implements Tracer {
 
   createChildSpan(options?: SpanOptions): Span {
     if (!this.isActive()) {
-      return UNTRACED_CHILD_SPAN;
+      return DISABLED_CHILD_SPAN;
     }
 
     options = options || { name: '' };
@@ -387,10 +390,11 @@ export class StackdriverTracer implements Tracer {
         }] Created child span [${options.name}]`
       );
       return childContext;
-    } else if (rootSpan.type === SpanType.UNTRACED) {
-      // Context wasn't lost, but there's no root span, indicating that this
-      // request should not be traced.
-      return UNTRACED_CHILD_SPAN;
+    } else if (rootSpan.type === SpanType.UNSAMPLED) {
+      // "Untraced" child spans don't incur a memory penalty.
+      return rootSpan.createChildSpan();
+    } else if (rootSpan.type === SpanType.DISABLED) {
+      return DISABLED_CHILD_SPAN;
     } else {
       // Context was lost.
       this.logger!.warn(

test/test-cls.ts

@@ -242,7 +242,7 @@ describe('Continuation-Local Storage', () => {
       },
       {
         config: { mechanism: TraceCLSMechanism.NONE },
-        expectedDefaultType: SpanType.UNTRACED,
+        expectedDefaultType: SpanType.UNCORRELATED,
       },
     ];
     if (asyncAwaitSupported) {
@@ -273,7 +273,7 @@ describe('Continuation-Local Storage', () => {
         it(`when disabled, doesn't throw and has reasonable default values`, () => {
           c.disable();
           assert.ok(!c.isEnabled());
-          assert.ok(c.getContext().type, SpanType.UNTRACED);
+          assert.ok(c.getContext().type, SpanType.UNSAMPLED);
           assert.ok(c.runWithContext(() => 'hi', TraceCLS.UNCORRELATED), 'hi');
           const fn = () => {};
           assert.strictEqual(c.bindWithCurrentContext(fn), fn);

test/test-default-ignore-ah-health.ts

@@ -22,7 +22,7 @@ describe('Trace API', () => {
   it('should ignore /_ah/health traces by default', () => {
     const traceApi = trace.start();
     traceApi.runInRootSpan({ name: 'root', url: '/_ah/health' }, rootSpan => {
-      assert.strictEqual(rootSpan.type, traceApi.spanTypes.UNTRACED);
+      assert.strictEqual(rootSpan.type, traceApi.spanTypes.UNSAMPLED);
     });
   });
 });

test/test-index.ts

@@ -31,18 +31,18 @@ describe('index.js', function() {
     assert.ok(!disabledAgent.isActive()); // ensure it's disabled first
     let ranInRootSpan = false;
     disabledAgent.runInRootSpan({ name: '' }, (span) => {
-      assert.strictEqual(span.type, SpanType.UNTRACED);
+      assert.strictEqual(span.type, SpanType.DISABLED);
       ranInRootSpan = true;
     });
     assert.ok(ranInRootSpan);
     assert.strictEqual(disabledAgent.enhancedDatabaseReportingEnabled(), false);
     assert.strictEqual(disabledAgent.getCurrentContextId(), null);
     assert.strictEqual(disabledAgent.getWriterProjectId(), null);
-    assert.strictEqual(disabledAgent.getCurrentRootSpan().type, SpanType.UNTRACED);
+    assert.strictEqual(disabledAgent.getCurrentRootSpan().type, SpanType.DISABLED);
     // getting project ID should reject.
     await disabledAgent.getProjectId().then(
         () => Promise.reject(new Error()), () => Promise.resolve());
-    assert.strictEqual(disabledAgent.createChildSpan({ name: '' }).type, SpanType.UNTRACED);
+    assert.strictEqual(disabledAgent.createChildSpan({ name: '' }).type, SpanType.DISABLED);
     assert.strictEqual(disabledAgent.getResponseTraceContext({
       traceId: '1',
       spanId: '1'

test/test-trace-api-none-cls.ts

@@ -74,7 +74,7 @@ describe('Custom Trace API with CLS disabled', () => {
       traceApi.runInRootSpan({ name: 'root' }, identity)
     );
     const child = traceApi.createChildSpan({ name: 'child' });
-    assert.strictEqual(child.type, SpanType.UNTRACED);
+    assert.strictEqual(child.type, SpanType.UNCORRELATED);
     child.endSpan();
     root.endSpan();
   });

test/test-trace-api.ts

@@ -32,7 +32,7 @@ import {
   StackdriverTracerConfig,
 } from '../src/trace-api';
 import { traceWriter } from '../src/trace-writer';
-import { alwaysTrace } from '../src/tracing-policy';
+import { alwaysTrace, neverTrace } from '../src/tracing-policy';
 import { FORCE_NEW, TraceContext } from '../src/util';
 
 import { TestLogger } from './logger';
@@ -200,21 +200,38 @@ describe('Trace Interface', () => {
       });
     });
 
-    it('should return null context id when one does not exist', () => {
+    it('should return null context ID when one does not exist', () => {
       const traceAPI = createTraceAgent();
       assert.strictEqual(traceAPI.getCurrentContextId(), null);
     });
 
-    it('should return the appropriate trace id', () => {
+    it('should return the appropriate context ID', () => {
       const traceAPI = createTraceAgent();
       traceAPI.runInRootSpan({ name: 'root' }, rootSpan => {
         const id = traceAPI.getCurrentContextId();
+        assert.ok(rootSpan.getTraceContext());
+        assert.strictEqual(id, rootSpan.getTraceContext()!.traceId);
         rootSpan.endSpan();
         // getOneTrace asserts that there is exactly one trace.
         testTraceModule.getOneTrace(trace => trace.traceId === id);
       });
     });
 
+    it('should return a context ID even if in an untraced request', () => {
+      const traceAPI = createTraceAgent({}, { tracePolicy: neverTrace() });
+      traceAPI.runInRootSpan({ name: '' }, rootSpan => {
+        assert.strictEqual(rootSpan.type, SpanType.UNSAMPLED);
+        assert.notStrictEqual(traceAPI.getCurrentContextId(), null);
+        assert.ok(rootSpan.getTraceContext());
+        assert.strictEqual(
+          traceAPI.getCurrentContextId(),
+          rootSpan.getTraceContext()!.traceId
+        );
+        assert.ok(rootSpan.createChildSpan().getTraceContext());
+        assert.ok(traceAPI.createChildSpan().getTraceContext());
+      });
+    });
+
     it('should return the project ID from the Trace Writer (promise api)', async () => {
       const traceApi = createTraceAgent();
       assert.strictEqual(await traceApi.getProjectId(), 'project-1');
@@ -245,7 +262,7 @@ describe('Trace Interface', () => {
         };
         const beforeRootSpan = Date.now();
         traceAPI.runInRootSpan(rootSpanOptions, rootSpan => {
-          assert.strictEqual(rootSpan.type, SpanType.UNTRACED);
+          assert.strictEqual(rootSpan.type, SpanType.UNSAMPLED);
           rootSpan.endSpan();
         });
         const afterRootSpan = Date.now();
@@ -267,7 +284,7 @@ describe('Trace Interface', () => {
       {
         const rootSpanOptions = { name: 'root' };
         traceAPI.runInRootSpan(rootSpanOptions, rootSpan => {
-          assert.strictEqual(rootSpan.type, SpanType.UNTRACED);
+          assert.strictEqual(rootSpan.type, SpanType.UNSAMPLED);
           rootSpan.endSpan();
         });
         assert.ok(tracePolicy.capturedShouldTraceParam);