feat(otel): Implement basic SpanProcessor

Author: mydea

packages/opentelemetry-node/package.json

@@ -28,7 +28,8 @@
   },
   "devDependencies": {
     "@opentelemetry/api": "^1.2.0",
-    "@opentelemetry/sdk-trace-base": "^1.7.0"
+    "@opentelemetry/sdk-trace-base": "^1.7.0",
+    "@opentelemetry/sdk-trace-node": "^1.7.0"
   },
   "scripts": {
     "build": "run-p build:rollup build:types",

packages/opentelemetry-node/src/spanprocessor.ts

@@ -2,85 +2,85 @@ import { Context } from '@opentelemetry/api';
 import { Span as OtelSpan, SpanProcessor as OtelSpanProcessor } from '@opentelemetry/sdk-trace-base';
 import { getCurrentHub } from '@sentry/core';
 import { Span as SentrySpan, TransactionContext } from '@sentry/types';
+import { logger } from '@sentry/utils';
 
 /**
  * Converts OpenTelemetry Spans to Sentry Spans and sends them to Sentry via
  * the Sentry SDK.
  */
 export class SentrySpanProcessor implements OtelSpanProcessor {
-  private readonly _map: Record<SentrySpan['spanId'], [SentrySpan, SentrySpan | undefined]> = {};
+  // public only for testing
+  public readonly _map: Map<SentrySpan['spanId'], SentrySpan> = new Map<SentrySpan['spanId'], SentrySpan>();
 
   /**
    * @inheritDoc
    */
   public onStart(otelSpan: OtelSpan, _parentContext: Context): void {
     const hub = getCurrentHub();
     if (!hub) {
+      __DEBUG_BUILD__ && logger.error('SentrySpanProcessor has triggered onStart before a hub has been setup.');
       return;
     }
     const scope = hub.getScope();
     if (!scope) {
+      __DEBUG_BUILD__ && logger.error('SentrySpanProcessor has triggered onStart before a scope has been setup.');
       return;
     }
 
+    // TODO: handle sentry requests
     // if isSentryRequest(otelSpan) return;
 
     const otelSpanId = otelSpan.spanContext().spanId;
+    const otelParentSpanId = otelSpan.parentSpanId;
+
+    // Otel supports having multiple non-nested spans at the same time
+    // so we cannot use hub.getSpan(), as we cannot rely on this being on the current span
+    const sentryParentSpan = otelParentSpanId && this._map.get(otelParentSpanId);
 
-    const sentryParentSpan = scope.getSpan();
     if (sentryParentSpan) {
       const sentryChildSpan = sentryParentSpan.startChild({
         description: otelSpan.name,
         // instrumentor: 'otel',
         startTimestamp: otelSpan.startTime[0],
+        spanId: otelSpanId,
       });
-      sentryChildSpan.spanId = otelSpanId;
-      console.log(sentryParentSpan, sentryChildSpan, otelSpan);
 
-      this._map[otelSpanId] = [sentryChildSpan, sentryParentSpan];
-      scope.setSpan(sentryChildSpan);
+      this._map.set(otelSpanId, sentryChildSpan);
     } else {
       const traceCtx = getTraceData(otelSpan);
       const transaction = hub.startTransaction({
         name: otelSpan.name,
         ...traceCtx,
         // instrumentor: 'otel',
         startTimestamp: otelSpan.startTime[0],
+        spanId: otelSpanId,
       });
-      transaction.spanId = otelSpanId;
-
-      this._map[otelSpanId] = [transaction, undefined];
 
-      scope.setSpan(transaction);
+      this._map.set(otelSpanId, transaction);
     }
   }
 
   /**
    * @inheritDoc
    */
   public onEnd(otelSpan: OtelSpan): void {
-    const hub = getCurrentHub();
-    if (!hub) {
-      return;
-    }
-    const scope = hub.getScope();
-    if (!scope) {
+    const otelSpanId = otelSpan.spanContext().spanId;
+    const mapVal = this._map.get(otelSpanId);
+
+    if (!mapVal) {
+      __DEBUG_BUILD__ &&
+        logger.error(`SentrySpanProcessor could not find span with OTEL-spanId ${otelSpanId} to finish.`);
       return;
     }
 
-    const otelSpanId = otelSpan.spanContext().spanId;
-    const mapVal = this._map[otelSpanId];
+    const sentrySpan = mapVal;
 
-    if (mapVal) {
-      const [sentrySpan, sentryParentSpan] = mapVal;
+    // TODO: actually add context etc. to span
+    // updateSpanWithOtelData(sentrySpan, otelSpan);
 
-      // updateSpanWithOtelData(sentrySpan, otelSpan);
+    sentrySpan.finish(otelSpan.endTime[0]);
 
-      sentrySpan.finish(otelSpan.endTime[0]);
-      scope.setSpan(sentryParentSpan);
-      // eslint-disable-next-line @typescript-eslint/no-dynamic-delete
-      delete this._map[otelSpanId];
-    }
+    this._map.delete(otelSpanId);
   }
 
   /**

packages/opentelemetry-node/test/spanprocessor.test.ts

@@ -1,5 +1,6 @@
 import * as OpenTelemetry from '@opentelemetry/api';
-import { BasicTracerProvider, Span as OtelSpan } from '@opentelemetry/sdk-trace-base';
+import { Span as OtelSpan } from '@opentelemetry/sdk-trace-base';
+import { NodeTracerProvider } from '@opentelemetry/sdk-trace-node';
 import { Hub, makeMain } from '@sentry/core';
 import { addExtensionMethods, Span as SentrySpan, Transaction } from '@sentry/tracing';
 
@@ -13,68 +14,128 @@ beforeAll(() => {
 
 describe('SentrySpanProcessor', () => {
   let hub: Hub;
+  let provider: NodeTracerProvider;
+  let spanProcessor: SentrySpanProcessor;
+
   beforeEach(() => {
     hub = new Hub();
     makeMain(hub);
 
-    const provider = new BasicTracerProvider();
-    provider.addSpanProcessor(new SentrySpanProcessor());
+    spanProcessor = new SentrySpanProcessor();
+    provider = new NodeTracerProvider();
+    provider.addSpanProcessor(spanProcessor);
     provider.register();
   });
 
-  describe('onStart', () => {
-    it('create a transaction', () => {
-      const otelSpan = OpenTelemetry.trace.getTracer('default').startSpan('GET /users') as OtelSpan;
-      const sentrySpanTransaction = hub.getScope()?.getSpan() as Transaction;
-      expect(sentrySpanTransaction).toBeInstanceOf(Transaction);
+  afterEach(async () => {
+    await provider.forceFlush();
+    await provider.shutdown();
+  });
 
-      // Make sure name is set
-      expect(sentrySpanTransaction?.name).toBe('GET /users');
+  function getSpanForOtelSpan(otelSpan: OtelSpan | OpenTelemetry.Span) {
+    return spanProcessor._map.get(otelSpan.spanContext().spanId) as SentrySpan | undefined;
+  }
 
-      // Enforce we use otel timestamps
-      expect(sentrySpanTransaction.startTimestamp).toEqual(otelSpan.startTime[0]);
+  it('creates a transaction', async () => {
+    const startTime = otelNumberToHrtime(new Date().valueOf());
 
-      // Check for otel trace context
-      expect(sentrySpanTransaction.traceId).toEqual(otelSpan.spanContext().traceId);
-      expect(sentrySpanTransaction.parentSpanId).toEqual(otelSpan.parentSpanId);
-      expect(sentrySpanTransaction.spanId).toEqual(otelSpan.spanContext().spanId);
-    });
+    const otelSpan = provider.getTracer('default').startSpan('GET /users', { startTime }) as OtelSpan;
+
+    const sentrySpanTransaction = getSpanForOtelSpan(otelSpan) as Transaction | undefined;
+    expect(sentrySpanTransaction).toBeInstanceOf(Transaction);
 
-    it.only('creates a child span if there is a running transaction', () => {
-      const tracer = OpenTelemetry.trace.getTracer('default');
+    expect(sentrySpanTransaction?.name).toBe('GET /users');
+    expect(sentrySpanTransaction?.startTimestamp).toEqual(otelSpan.startTime[0]);
+    expect(sentrySpanTransaction?.startTimestamp).toEqual(startTime[0]);
+    expect(sentrySpanTransaction?.traceId).toEqual(otelSpan.spanContext().traceId);
+    expect(sentrySpanTransaction?.parentSpanId).toEqual(otelSpan.parentSpanId);
+    expect(sentrySpanTransaction?.spanId).toEqual(otelSpan.spanContext().spanId);
 
-      tracer.startActiveSpan('GET /users', parentOtelSpan => {
-        // console.log((parentOtelSpan as any).spanContext());
-        // console.log(hub.getScope()?.getSpan()?.traceId);
-        tracer.startActiveSpan('SELECT * FROM users;', child => {
-          const childOtelSpan = child as OtelSpan;
+    expect(hub.getScope()?.getSpan()).toBeUndefined();
 
-          const sentrySpan = hub.getScope()?.getSpan();
-          expect(sentrySpan).toBeInstanceOf(SentrySpan);
-          // console.log(hub.getScope()?.getSpan()?.traceId);
-          // console.log(sentrySpan);
+    const endTime = otelNumberToHrtime(new Date().valueOf());
+    otelSpan.end(endTime);
 
-          // Make sure name is set
-          expect(sentrySpan?.description).toBe('SELECT * FROM users;');
+    expect(sentrySpanTransaction?.endTimestamp).toBe(endTime[0]);
+    expect(sentrySpanTransaction?.endTimestamp).toBe(otelSpan.endTime[0]);
 
-          // Enforce we use otel timestamps
-          expect(sentrySpan?.startTimestamp).toEqual(childOtelSpan.startTime[0]);
+    expect(hub.getScope()?.getSpan()).toBeUndefined();
+  });
 
-          // Check for otel trace context
-          expect(sentrySpan?.spanId).toEqual(childOtelSpan.spanContext().spanId);
+  it('creates a child span if there is a running transaction', () => {
+    const tracer = provider.getTracer('default');
 
-          childOtelSpan.end();
-        });
+    tracer.startActiveSpan('GET /users', parentOtelSpan => {
+      tracer.startActiveSpan('SELECT * FROM users;', child => {
+        const childOtelSpan = child as OtelSpan;
 
-        parentOtelSpan.end();
+        const sentrySpanTransaction = getSpanForOtelSpan(parentOtelSpan) as Transaction | undefined;
+        expect(sentrySpanTransaction).toBeInstanceOf(Transaction);
+
+        const sentrySpan = getSpanForOtelSpan(childOtelSpan);
+        expect(sentrySpan).toBeInstanceOf(SentrySpan);
+        expect(sentrySpan?.description).toBe('SELECT * FROM users;');
+        expect(sentrySpan?.startTimestamp).toEqual(childOtelSpan.startTime[0]);
+        expect(sentrySpan?.spanId).toEqual(childOtelSpan.spanContext().spanId);
+        expect(sentrySpan?.parentSpanId).toEqual(sentrySpanTransaction?.spanId);
+
+        expect(hub.getScope()?.getSpan()).toBeUndefined();
+
+        const endTime = otelNumberToHrtime(new Date().valueOf());
+        child.end(endTime);
+
+        expect(sentrySpan?.endTimestamp).toEqual(childOtelSpan.endTime[0]);
+        expect(sentrySpan?.endTimestamp).toEqual(endTime[0]);
       });
+
+      parentOtelSpan.end();
     });
   });
 
-  // it('Creates a transaction if there is no running ', () => {
-  // const otelSpan = OpenTelemetry.trace.getTracer('default').startSpan('GET /users') as OtelSpan;
-  // processor.onStart(otelSpan, OpenTelemetry.context.active());
+  it('allows to create multiple child spans on same level', () => {
+    const tracer = provider.getTracer('default');
 
-  // const sentrySpanTransaction = hub.getScope()?.getSpan() as Transaction;
-  // });
+    tracer.startActiveSpan('GET /users', parentOtelSpan => {
+      const sentrySpanTransaction = getSpanForOtelSpan(parentOtelSpan) as Transaction | undefined;
+
+      expect(sentrySpanTransaction).toBeInstanceOf(SentrySpan);
+      expect(sentrySpanTransaction?.name).toBe('GET /users');
+
+      // Create some parallel, independent spans
+      const span1 = tracer.startSpan('SELECT * FROM users;') as OtelSpan;
+      const span2 = tracer.startSpan('SELECT * FROM companies;') as OtelSpan;
+      const span3 = tracer.startSpan('SELECT * FROM locations;') as OtelSpan;
+
+      const sentrySpan1 = getSpanForOtelSpan(span1);
+      const sentrySpan2 = getSpanForOtelSpan(span2);
+      const sentrySpan3 = getSpanForOtelSpan(span3);
+
+      expect(sentrySpan1?.parentSpanId).toEqual(sentrySpanTransaction?.spanId);
+      expect(sentrySpan2?.parentSpanId).toEqual(sentrySpanTransaction?.spanId);
+      expect(sentrySpan3?.parentSpanId).toEqual(sentrySpanTransaction?.spanId);
+
+      expect(sentrySpan1?.description).toEqual('SELECT * FROM users;');
+      expect(sentrySpan2?.description).toEqual('SELECT * FROM companies;');
+      expect(sentrySpan3?.description).toEqual('SELECT * FROM locations;');
+
+      span1.end();
+      span2.end();
+      span3.end();
+
+      parentOtelSpan.end();
+    });
+  });
 });
+
+// OTEL expects a custom date format
+const NANOSECOND_DIGITS = 9;
+const SECOND_TO_NANOSECONDS = Math.pow(10, NANOSECOND_DIGITS);
+
+function otelNumberToHrtime(epochMillis: number): OpenTelemetry.HrTime {
+  const epochSeconds = epochMillis / 1000;
+  // Decimals only.
+  const seconds = Math.trunc(epochSeconds);
+  // Round sub-nanosecond accuracy to nanosecond.
+  const nanos = Number((epochSeconds - seconds).toFixed(NANOSECOND_DIGITS)) * SECOND_TO_NANOSECONDS;
+  return [seconds, nanos];
+}

packages/types/src/span.ts

@@ -132,9 +132,7 @@ export interface Span extends SpanContext {
    * Creates a new `Span` while setting the current `Span.id` as `parentSpanId`.
    * Also the `sampled` decision will be inherited.
    */
-  startChild(
-    spanContext?: Pick<SpanContext, Exclude<keyof SpanContext, 'spanId' | 'sampled' | 'traceId' | 'parentSpanId'>>,
-  ): Span;
+  startChild(spanContext?: Pick<SpanContext, Exclude<keyof SpanContext, 'sampled' | 'traceId' | 'parentSpanId'>>): Span;
 
   /**
    * Determines whether span was successful (HTTP200)

yarn.lock

@@ -3898,6 +3898,11 @@
   resolved "https://registry.yarnpkg.com/@opentelemetry/api/-/api-1.2.0.tgz#89ef99401cde6208cff98760b67663726ef26686"
   integrity sha512-0nBr+VZNKm9tvNDZFstI3Pq1fCTEDK5OZTnVKNvBNAKgd0yIvmwsP4m61rEv7ZP+tOUjWJhROpxK5MsnlF911g==
 
+"@opentelemetry/[email protected]":
+  version "1.7.0"
+  resolved "https://registry.yarnpkg.com/@opentelemetry/context-async-hooks/-/context-async-hooks-1.7.0.tgz#b78d1f4f30b484d92d7926dc9d29ec1ccd489cf5"
+  integrity sha512-g4bMzyVW5dVBeMkyadaf3NRFpmNrdD4Pp9OJsrP29HwIam/zVMNfIWQpT5IBzjtTSMhl/ED5YQYR+UOSjVq3sQ==
+
 "@opentelemetry/context-base@^0.12.0":
   version "0.12.0"
   resolved "https://registry.yarnpkg.com/@opentelemetry/context-base/-/context-base-0.12.0.tgz#4906ae27359d3311e3dea1b63770a16f60848550"
@@ -3924,6 +3929,20 @@
     "@opentelemetry/context-base" "^0.12.0"
     semver "^7.1.3"
 
+"@opentelemetry/[email protected]":
+  version "1.7.0"
+  resolved "https://registry.yarnpkg.com/@opentelemetry/propagator-b3/-/propagator-b3-1.7.0.tgz#8c089c2bab733ea7122cb4a5f7ffaaa355127555"
+  integrity sha512-8kKGS1KwArvkThdhubMZlomuREE9FaBcn9L4JrYHh2jly1FZpqOtFNO2byHymVRjH59d43Pa+eJuFpD0Fp7kSw==
+  dependencies:
+    "@opentelemetry/core" "1.7.0"
+
+"@opentelemetry/[email protected]":
+  version "1.7.0"
+  resolved "https://registry.yarnpkg.com/@opentelemetry/propagator-jaeger/-/propagator-jaeger-1.7.0.tgz#1c1439866e05ba81da303ad28286aa25d129bf03"
+  integrity sha512-V7i/L1bx+R/ve4z6dTdn2jtvFxGThRsXS2wNb/tWZVfV8gqnePQp+HfoLrqB/Yz2iRPUcMWrcjx6vV78umvJFA==
+  dependencies:
+    "@opentelemetry/core" "1.7.0"
+
 "@opentelemetry/[email protected]":
   version "1.7.0"
   resolved "https://registry.yarnpkg.com/@opentelemetry/resources/-/resources-1.7.0.tgz#90ccd3a6a86b4dfba4e833e73944bd64958d78c5"
@@ -3940,7 +3959,7 @@
     "@opentelemetry/api" "^0.12.0"
     "@opentelemetry/core" "^0.12.0"
 
-"@opentelemetry/sdk-trace-base@^1.7.0":
+"@opentelemetry/sdk-trace-base@1.7.0", "@opentelemetry/sdk-trace-base@^1.7.0":
   version "1.7.0"
   resolved "https://registry.yarnpkg.com/@opentelemetry/sdk-trace-base/-/sdk-trace-base-1.7.0.tgz#b498424e0c6340a9d80de63fd408c5c2130a60a5"
   integrity sha512-Iz84C+FVOskmauh9FNnj4+VrA+hG5o+tkMzXuoesvSfunVSioXib0syVFeNXwOm4+M5GdWCuW632LVjqEXStIg==
@@ -3949,6 +3968,18 @@
     "@opentelemetry/resources" "1.7.0"
     "@opentelemetry/semantic-conventions" "1.7.0"
 
+"@opentelemetry/sdk-trace-node@^1.7.0":
+  version "1.7.0"
+  resolved "https://registry.yarnpkg.com/@opentelemetry/sdk-trace-node/-/sdk-trace-node-1.7.0.tgz#83bf458c33db930144cebed72b524034135fce7b"
+  integrity sha512-DCAAbi0Zbb1pIofQcKzoAVy9/6bz24asFYeLb4fW/8QYAaawDnxumA++5Huw/RcYdJs8q8AIRBykwjYWWCm/5A==
+  dependencies:
+    "@opentelemetry/context-async-hooks" "1.7.0"
+    "@opentelemetry/core" "1.7.0"
+    "@opentelemetry/propagator-b3" "1.7.0"
+    "@opentelemetry/propagator-jaeger" "1.7.0"
+    "@opentelemetry/sdk-trace-base" "1.7.0"
+    semver "^7.3.5"
+
 "@opentelemetry/[email protected]":
   version "1.7.0"
   resolved "https://registry.yarnpkg.com/@opentelemetry/semantic-conventions/-/semantic-conventions-1.7.0.tgz#af80a1ef7cf110ea3a68242acd95648991bcd763"