ref: SpanRecorder

Author: HazAT

packages/apm/src/hubextensions.ts

@@ -44,10 +44,15 @@ function startSpan(spanOrSpanContext?: Span | SpanContext, makeRoot: boolean = f
   const client = hub.getClient();
   let span;
 
+  // This flag determines if we already added the span as a child to the span that currently lives on the scope
+  // If we do not have this, we will add it later on twice to the span recorder and therefore have too many spans
+  let addedAsChild = false;
+
   if (!isSpanInstance(spanOrSpanContext) && !makeRoot && scope) {
     const parentSpan = scope.getSpan() as Span;
     if (parentSpan) {
       span = parentSpan.child(spanOrSpanContext);
+      addedAsChild = true;
     }
   }
 
@@ -63,7 +68,7 @@ function startSpan(spanOrSpanContext?: Span | SpanContext, makeRoot: boolean = f
 
   // We only want to create a span list if we sampled the transaction
   // in case we will discard the span anyway because sampled == false, we safe memory and do not store child spans
-  if (span.sampled) {
+  if (span.sampled && !addedAsChild) {
     const experimentsOptions = (client && client.getOptions()._experiments) || {};
     span.initSpanRecorder(experimentsOptions.maxSpans as number);
   }

packages/apm/src/integrations/tracing.ts

@@ -1,4 +1,5 @@
-import { Event, EventProcessor, Hub, Integration, Span, SpanContext, SpanStatus } from '@sentry/types';
+import { Hub, Scope } from '@sentry/hub';
+import { Event, EventProcessor, Integration, Span, SpanContext, SpanStatus } from '@sentry/types';
 import {
   addInstrumentationHandler,
   getGlobalObject,
@@ -272,6 +273,19 @@ export class Tracing implements Integration {
    * Unsets the current active transaction + activities
    */
   private static _resetActiveTransaction(): void {
+    // We want to clean up after ourselves
+    // If there is still the active transaction on the scope we remove it
+    const _getCurrentHub = Tracing._getCurrentHub;
+    if (_getCurrentHub) {
+      const hub = _getCurrentHub();
+      const scope = hub.getScope();
+      if (scope) {
+        if (scope.getSpan() === Tracing._activeTransaction) {
+          scope.setSpan(undefined);
+        }
+      }
+    }
+    // ------------------------------------------------------------------
     Tracing._activeTransaction = undefined;
     Tracing._activities = {};
   }
@@ -365,6 +379,13 @@ export class Tracing implements Integration {
       true,
     );
 
+    // We set the transaction on the scope so if there are any other spans started outside of this integration
+    // we also add them to this transaction.
+    // Once the idle transaction is finished, we make sure to remove it again.
+    hub.configureScope((scope: Scope) => {
+      scope.setSpan(Tracing._activeTransaction);
+    });
+
     // The reason we do this here is because of cached responses
     // If we start and transaction without an activity it would never finish since there is no activity
     const id = Tracing.pushActivity('idleTransactionStarted');
@@ -405,13 +426,6 @@ export class Tracing implements Integration {
 
     const timeOrigin = Tracing._msToSec(performance.timeOrigin);
 
-    // tslint:disable-next-line: completed-docs
-    function addSpan(span: SpanClass): void {
-      if (transactionSpan.spanRecorder) {
-        transactionSpan.spanRecorder.finishSpan(span);
-      }
-    }
-
     // tslint:disable-next-line: completed-docs
     function addPerformanceNavigationTiming(parent: SpanClass, entry: { [key: string]: number }, event: string): void {
       const span = parent.child({
@@ -420,7 +434,6 @@ export class Tracing implements Integration {
       });
       span.startTimestamp = timeOrigin + Tracing._msToSec(entry[`${event}Start`]);
       span.timestamp = timeOrigin + Tracing._msToSec(entry[`${event}End`]);
-      addSpan(span);
     }
 
     // tslint:disable-next-line: completed-docs
@@ -431,14 +444,13 @@ export class Tracing implements Integration {
       });
       request.startTimestamp = timeOrigin + Tracing._msToSec(entry.requestStart);
       request.timestamp = timeOrigin + Tracing._msToSec(entry.responseEnd);
-      addSpan(request);
+
       const response = parent.child({
         description: 'response',
         op: 'browser',
       });
       response.startTimestamp = timeOrigin + Tracing._msToSec(entry.responseStart);
       response.timestamp = timeOrigin + Tracing._msToSec(entry.responseEnd);
-      addSpan(response);
     }
 
     let entryScriptSrc: string | undefined;
@@ -492,14 +504,13 @@ export class Tracing implements Integration {
             if (tracingInitMarkStartTime === undefined && entry.name === 'sentry-tracing-init') {
               tracingInitMarkStartTime = mark.startTimestamp;
             }
-            addSpan(mark);
             break;
           case 'resource':
             const resourceName = entry.name.replace(window.location.origin, '');
             if (entry.initiatorType === 'xmlhttprequest' || entry.initiatorType === 'fetch') {
               // We need to update existing spans with new timing info
               if (transactionSpan.spanRecorder) {
-                transactionSpan.spanRecorder.finishedSpans.map((finishedSpan: SpanClass) => {
+                transactionSpan.spanRecorder.spans.map((finishedSpan: SpanClass) => {
                   if (finishedSpan.description && finishedSpan.description.indexOf(resourceName) !== -1) {
                     finishedSpan.startTimestamp = timeOrigin + startTime;
                     finishedSpan.timestamp = finishedSpan.startTimestamp + duration;
@@ -517,7 +528,6 @@ export class Tracing implements Integration {
               if (entryScriptStartEndTime === undefined && (entryScriptSrc || '').includes(resourceName)) {
                 entryScriptStartEndTime = resource.timestamp;
               }
-              addSpan(resource);
             }
             break;
           default:
@@ -532,7 +542,6 @@ export class Tracing implements Integration {
       });
       evaluation.startTimestamp = entryScriptStartEndTime;
       evaluation.timestamp = tracingInitMarkStartTime;
-      addSpan(evaluation);
     }
 
     Tracing._performanceCursor = Math.max(performance.getEntries().length - 1, 0);

packages/apm/src/span.ts

@@ -18,8 +18,7 @@ export const TRACEPARENT_REGEXP = new RegExp(
  */
 class SpanRecorder {
   private readonly _maxlen: number;
-  private _openSpanCount: number = 0;
-  public finishedSpans: Span[] = [];
+  public spans: Span[] = [];
 
   public constructor(maxlen: number = 1000) {
     this._maxlen = maxlen;
@@ -31,19 +30,12 @@ class SpanRecorder {
    * trace tree (i.e.the first n spans with the smallest
    * start_timestamp).
    */
-  public startSpan(span: Span): void {
-    if (this._openSpanCount > this._maxlen) {
+  public add(span: Span): void {
+    if (this.spans.length > this._maxlen) {
       span.spanRecorder = undefined;
+    } else {
+      this.spans.push(span);
     }
-    this._openSpanCount++;
-  }
-
-  /**
-   * Appends a span to finished spans table
-   * @param span Span to be added
-   */
-  public finishSpan(span: Span): void {
-    this.finishedSpans.push(span);
   }
 }
 
@@ -176,7 +168,7 @@ export class Span implements SpanInterface, SpanContext {
     if (!this.spanRecorder) {
       this.spanRecorder = new SpanRecorder(maxlen);
     }
-    this.spanRecorder.startSpan(this);
+    this.spanRecorder.add(this);
   }
 
   /**
@@ -194,7 +186,7 @@ export class Span implements SpanInterface, SpanContext {
 
     span.spanRecorder = this.spanRecorder;
     if (span.spanRecorder) {
-      span.spanRecorder.startSpan(span);
+      span.spanRecorder.add(span);
     }
 
     return span;
@@ -297,15 +289,13 @@ export class Span implements SpanInterface, SpanContext {
       return undefined;
     }
 
-    this.spanRecorder.finishSpan(this);
-
     if (this.sampled !== true) {
       // At this point if `sampled !== true` we want to discard the transaction.
       logger.warn('Discarding transaction Span because it was span.sampled !== true');
       return undefined;
     }
 
-    const finishedSpans = this.spanRecorder ? this.spanRecorder.finishedSpans.filter(s => s !== this) : [];
+    const finishedSpans = this.spanRecorder ? this.spanRecorder.spans.filter(s => s !== this && s.timestamp) : [];
 
     if (trimEnd && finishedSpans.length > 0) {
       this.timestamp = finishedSpans.reduce((prev: Span, current: Span) => {
@@ -348,7 +338,16 @@ export class Span implements SpanInterface, SpanContext {
   /**
    * @inheritDoc
    */
-  public getTraceContext(): object {
+  public getTraceContext(): {
+    data?: { [key: string]: any };
+    description?: string;
+    op?: string;
+    parent_span_id?: string;
+    span_id: string;
+    status?: string;
+    tags?: { [key: string]: string };
+    trace_id: string;
+  } {
     return dropUndefinedKeys({
       data: Object.keys(this.data).length > 0 ? this.data : undefined,
       description: this.description,
@@ -364,7 +363,19 @@ export class Span implements SpanInterface, SpanContext {
   /**
    * @inheritDoc
    */
-  public toJSON(): object {
+  public toJSON(): {
+    data?: { [key: string]: any };
+    description?: string;
+    op?: string;
+    parent_span_id?: string;
+    sampled?: boolean;
+    span_id: string;
+    start_timestamp: number;
+    tags?: { [key: string]: string };
+    timestamp?: number;
+    trace_id: string;
+    transaction?: string;
+  } {
     return dropUndefinedKeys({
       data: Object.keys(this.data).length > 0 ? this.data : undefined,
       description: this.description,

packages/apm/test/span.test.ts

@@ -238,7 +238,9 @@ describe('Span', () => {
         spanTwo.finish();
 
         expect(spy).not.toHaveBeenCalled();
-        expect((spanOne as any).spanRecorder.finishedSpans).toHaveLength(2);
+        expect((spanOne as any).spanRecorder.spans).toHaveLength(3);
+        // We only want two finished spans
+        expect((spanOne as any).spanRecorder.spans.filter((s: Span) => !!s.timestamp)).toHaveLength(2);
       });
 
       test("finish a span with another one on the scope shouldn't override contexts.trace", () => {
@@ -294,6 +296,62 @@ describe('Span', () => {
         expect((span as any).spanRecorder).toBeUndefined();
         expect(spy).not.toHaveBeenCalled();
       });
+
+      test('mixing hub.startSpan + span.child + maxSpans', () => {
+        const _hub = new Hub(
+          new BrowserClient({
+            _experiments: { maxSpans: 2 },
+            tracesSampleRate: 1,
+          }),
+        );
+        const spy = jest.spyOn(_hub as any, 'captureEvent') as any;
+
+        const spanOne = _hub.startSpan();
+        const childSpanOne = spanOne.child({ op: '1' });
+        childSpanOne.finish();
+
+        _hub.configureScope(scope => {
+          scope.setSpan(spanOne);
+        });
+
+        const spanTwo = _hub.startSpan({ op: '2' });
+        spanTwo.finish();
+
+        const spanThree = _hub.startSpan({ op: '3' });
+        spanThree.finish();
+
+        spanOne.finish();
+
+        expect(spy).toHaveBeenCalled();
+        expect(spy.mock.calls[0][0].spans).toHaveLength(2);
+      });
+
+      test('tree structure of spans should be correct when mixing it with span on scope', () => {
+        const spy = jest.spyOn(hub as any, 'captureEvent') as any;
+
+        const spanOne = hub.startSpan();
+        const childSpanOne = spanOne.child();
+
+        const childSpanTwo = childSpanOne.child();
+        childSpanTwo.finish();
+
+        childSpanOne.finish();
+
+        hub.configureScope(scope => {
+          scope.setSpan(spanOne);
+        });
+
+        const spanTwo = hub.startSpan();
+        spanTwo.finish();
+        spanOne.finish();
+
+        expect(spy).toHaveBeenCalled();
+        expect(spy.mock.calls[0][0].spans).toHaveLength(3);
+        expect(spy.mock.calls[0][0].contexts.trace).toEqual(spanOne.getTraceContext());
+        expect(childSpanOne.toJSON().parent_span_id).toEqual(spanOne.toJSON().span_id);
+        expect(childSpanTwo.toJSON().parent_span_id).toEqual(childSpanOne.toJSON().span_id);
+        expect(spanTwo.toJSON().parent_span_id).toEqual(spanOne.toJSON().span_id);
+      });
     });
   });
 

packages/types/src/span.ts

@@ -5,9 +5,30 @@ export interface Span {
   /** Return a traceparent compatible header string */
   toTraceparent(): string;
   /** Convert the object to JSON for w. spans array info only */
-  getTraceContext(): object;
+  getTraceContext(): {
+    data?: { [key: string]: any };
+    description?: string;
+    op?: string;
+    parent_span_id?: string;
+    span_id: string;
+    status?: string;
+    tags?: { [key: string]: string };
+    trace_id: string;
+  };
   /** Convert the object to JSON */
-  toJSON(): object;
+  toJSON(): {
+    data?: { [key: string]: any };
+    description?: string;
+    op?: string;
+    parent_span_id?: string;
+    sampled?: boolean;
+    span_id: string;
+    start_timestamp: number;
+    tags?: { [key: string]: string };
+    timestamp?: number;
+    trace_id: string;
+    transaction?: string;
+  };
 
   /**
    * Sets the tag attribute on the current span
@@ -39,7 +60,9 @@ export interface Span {
    * Creates a new `Span` while setting the current `Span.id` as `parentSpanId`.
    * Also the `sampled` decision will be inherited.
    */
-  child(spanContext?: Pick<SpanContext, Exclude<keyof SpanContext, 'spanId' | 'sampled' | 'traceId' | 'parentSpanId'>>): Span;
+  child(
+    spanContext?: Pick<SpanContext, Exclude<keyof SpanContext, 'spanId' | 'sampled' | 'traceId' | 'parentSpanId'>>,
+  ): Span;
 
   /**
    * Determines whether span was successful (HTTP200)