diff --git a/packages/opentelemetry-node/package.json b/packages/opentelemetry-node/package.json index 1aaee273a2e4..4795ee1041fe 100644 --- a/packages/opentelemetry-node/package.json +++ b/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", diff --git a/packages/opentelemetry-node/src/spanprocessor.ts b/packages/opentelemetry-node/src/spanprocessor.ts index ef71c9cbef5b..35b52ea175ea 100644 --- a/packages/opentelemetry-node/src/spanprocessor.ts +++ b/packages/opentelemetry-node/src/spanprocessor.ts @@ -2,13 +2,15 @@ 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 = {}; + // public only for testing + public readonly _map: Map = new Map(); /** * @inheritDoc @@ -16,29 +18,34 @@ export class SentrySpanProcessor implements OtelSpanProcessor { 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({ @@ -46,12 +53,10 @@ export class SentrySpanProcessor implements OtelSpanProcessor { ...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); } } @@ -59,28 +64,23 @@ export class SentrySpanProcessor implements OtelSpanProcessor { * @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); } /** diff --git a/packages/opentelemetry-node/test/spanprocessor.test.ts b/packages/opentelemetry-node/test/spanprocessor.test.ts index fcd55e063c16..ec8947996c84 100644 --- a/packages/opentelemetry-node/test/spanprocessor.test.ts +++ b/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); + } - // 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]; +} diff --git a/packages/types/src/span.ts b/packages/types/src/span.ts index 44933ba8252b..d411e57f4f24 100644 --- a/packages/types/src/span.ts +++ b/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>, - ): Span; + startChild(spanContext?: Pick>): Span; /** * Determines whether span was successful (HTTP200) diff --git a/yarn.lock b/yarn.lock index a12d1b672215..e7732a741fdf 100644 --- a/yarn.lock +++ b/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/context-async-hooks@1.7.0": + 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/propagator-b3@1.7.0": + 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/propagator-jaeger@1.7.0": + 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/resources@1.7.0": 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/semantic-conventions@1.7.0": version "1.7.0" resolved "https://registry.yarnpkg.com/@opentelemetry/semantic-conventions/-/semantic-conventions-1.7.0.tgz#af80a1ef7cf110ea3a68242acd95648991bcd763"