diff --git a/packages/opentelemetry-node/src/index.ts b/packages/opentelemetry-node/src/index.ts index 24c477a968fd..630acd960059 100644 --- a/packages/opentelemetry-node/src/index.ts +++ b/packages/opentelemetry-node/src/index.ts @@ -1,4 +1,4 @@ -import { getSentrySpan } from './spanprocessor'; +import { getSentrySpan } from './utils/spanMap'; export { SentrySpanProcessor } from './spanprocessor'; export { SentryPropagator } from './propagator'; diff --git a/packages/opentelemetry-node/src/propagator.ts b/packages/opentelemetry-node/src/propagator.ts index c032d776047f..63ca69c98fb7 100644 --- a/packages/opentelemetry-node/src/propagator.ts +++ b/packages/opentelemetry-node/src/propagator.ts @@ -13,7 +13,7 @@ import { SENTRY_TRACE_HEADER, SENTRY_TRACE_PARENT_CONTEXT_KEY, } from './constants'; -import { SENTRY_SPAN_PROCESSOR_MAP } from './spanprocessor'; +import { getSentrySpan } from './utils/spanMap'; /** * Injects and extracts `sentry-trace` and `baggage` headers from carriers. @@ -30,7 +30,7 @@ export class SentryPropagator extends W3CBaggagePropagator { let baggage = propagation.getBaggage(context) || propagation.createBaggage({}); - const span = SENTRY_SPAN_PROCESSOR_MAP.get(spanContext.spanId); + const span = getSentrySpan(spanContext.spanId); if (span) { setter.set(carrier, SENTRY_TRACE_HEADER, span.toTraceparent()); diff --git a/packages/opentelemetry-node/src/spanprocessor.ts b/packages/opentelemetry-node/src/spanprocessor.ts index 7c5873069dbe..7adc0ee31e5f 100644 --- a/packages/opentelemetry-node/src/spanprocessor.ts +++ b/packages/opentelemetry-node/src/spanprocessor.ts @@ -10,18 +10,7 @@ import { SENTRY_DYNAMIC_SAMPLING_CONTEXT_KEY, SENTRY_TRACE_PARENT_CONTEXT_KEY } import { isSentryRequestSpan } from './utils/isSentryRequest'; import { mapOtelStatus } from './utils/mapOtelStatus'; import { parseSpanDescription } from './utils/parseOtelSpanDescription'; - -export const SENTRY_SPAN_PROCESSOR_MAP: Map = new Map(); - -// make sure to remove references in maps, to ensure this can be GCed -function clearSpan(otelSpanId: string): void { - SENTRY_SPAN_PROCESSOR_MAP.delete(otelSpanId); -} - -/** Get a Sentry span for an otel span ID. */ -export function getSentrySpan(otelSpanId: string): SentrySpan | undefined { - return SENTRY_SPAN_PROCESSOR_MAP.get(otelSpanId); -} +import { clearSpan, getSentrySpan, setSentrySpan } from './utils/spanMap'; /** * Converts OpenTelemetry Spans to Sentry Spans and sends them to Sentry via @@ -62,7 +51,7 @@ export class SentrySpanProcessor implements OtelSpanProcessor { // 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 && SENTRY_SPAN_PROCESSOR_MAP.get(otelParentSpanId); + const sentryParentSpan = otelParentSpanId && getSentrySpan(otelParentSpanId); if (sentryParentSpan) { const sentryChildSpan = sentryParentSpan.startChild({ @@ -72,7 +61,7 @@ export class SentrySpanProcessor implements OtelSpanProcessor { spanId: otelSpanId, }); - SENTRY_SPAN_PROCESSOR_MAP.set(otelSpanId, sentryChildSpan); + setSentrySpan(otelSpanId, sentryChildSpan); } else { const traceCtx = getTraceData(otelSpan, parentContext); const transaction = getCurrentHub().startTransaction({ @@ -83,7 +72,7 @@ export class SentrySpanProcessor implements OtelSpanProcessor { spanId: otelSpanId, }); - SENTRY_SPAN_PROCESSOR_MAP.set(otelSpanId, transaction); + setSentrySpan(otelSpanId, transaction); } } @@ -97,6 +86,7 @@ export class SentrySpanProcessor implements OtelSpanProcessor { if (!sentrySpan) { __DEBUG_BUILD__ && logger.error(`SentrySpanProcessor could not find span with OTEL-spanId ${otelSpanId} to finish.`); + clearSpan(otelSpanId); return; } diff --git a/packages/opentelemetry-node/src/utils/spanData.ts b/packages/opentelemetry-node/src/utils/spanData.ts index d0e582d5763a..1cdbacf74955 100644 --- a/packages/opentelemetry-node/src/utils/spanData.ts +++ b/packages/opentelemetry-node/src/utils/spanData.ts @@ -2,7 +2,7 @@ import { Transaction } from '@sentry/core'; import type { Context, SpanOrigin } from '@sentry/types'; -import { getSentrySpan } from '../spanprocessor'; +import { getSentrySpan } from './spanMap'; type SentryTags = Record; type SentryData = Record; diff --git a/packages/opentelemetry-node/src/utils/spanMap.ts b/packages/opentelemetry-node/src/utils/spanMap.ts new file mode 100644 index 000000000000..8fe43222e93a --- /dev/null +++ b/packages/opentelemetry-node/src/utils/spanMap.ts @@ -0,0 +1,92 @@ +import type { Span as SentrySpan } from '@sentry/types'; + +interface SpanMapEntry { + sentrySpan: SentrySpan; + ref: SpanRefType; + // These are not direct children, but all spans under the tree of a root span. + subSpans: string[]; +} + +const SPAN_REF_ROOT = Symbol('root'); +const SPAN_REF_CHILD = Symbol('child'); +const SPAN_REF_CHILD_ENDED = Symbol('child_ended'); +type SpanRefType = typeof SPAN_REF_ROOT | typeof SPAN_REF_CHILD | typeof SPAN_REF_CHILD_ENDED; + +/** Exported only for tests. */ +export const SPAN_MAP = new Map(); + +/** + * Get a Sentry span for a given span ID. + */ +export function getSentrySpan(spanId: string): SentrySpan | undefined { + const entry = SPAN_MAP.get(spanId); + return entry ? entry.sentrySpan : undefined; +} + +/** + * Set a Sentry span for a given span ID. + * This is necessary so we can lookup parent spans later. + * We also keep a list of children for root spans only, in order to be able to clean them up together. + */ +export function setSentrySpan(spanId: string, sentrySpan: SentrySpan): void { + let ref: SpanRefType = SPAN_REF_ROOT; + + const rootSpanId = sentrySpan.transaction?.spanId; + + if (rootSpanId && rootSpanId !== spanId) { + const root = SPAN_MAP.get(rootSpanId); + if (root) { + root.subSpans.push(spanId); + ref = SPAN_REF_CHILD; + } + } + + SPAN_MAP.set(spanId, { + sentrySpan, + ref, + subSpans: [], + }); +} + +/** + * Clear references of the given span ID. + */ +export function clearSpan(spanId: string): void { + const entry = SPAN_MAP.get(spanId); + if (!entry) { + return; + } + + const { ref, subSpans } = entry; + + // If this is a child, mark it as ended. + if (ref === SPAN_REF_CHILD) { + entry.ref = SPAN_REF_CHILD_ENDED; + return; + } + + // If this is a root span, clear all (ended) children + if (ref === SPAN_REF_ROOT) { + for (const childId of subSpans) { + const child = SPAN_MAP.get(childId); + if (!child) { + continue; + } + + if (child.ref === SPAN_REF_CHILD_ENDED) { + // if the child has already ended, just clear it + SPAN_MAP.delete(childId); + } else if (child.ref === SPAN_REF_CHILD) { + // If the child has not ended yet, mark it as a root span so it is cleared when it ends. + child.ref = SPAN_REF_ROOT; + } + } + + SPAN_MAP.delete(spanId); + return; + } + + // Generally, `clearSpan` should never be called for ref === SPAN_REF_CHILD_ENDED + // But if it does, just clear the span + SPAN_MAP.delete(spanId); +} diff --git a/packages/opentelemetry-node/test/propagator.test.ts b/packages/opentelemetry-node/test/propagator.test.ts index 8136b81d9b9a..cee113e38e8b 100644 --- a/packages/opentelemetry-node/test/propagator.test.ts +++ b/packages/opentelemetry-node/test/propagator.test.ts @@ -17,7 +17,7 @@ import { SENTRY_TRACE_PARENT_CONTEXT_KEY, } from '../src/constants'; import { SentryPropagator } from '../src/propagator'; -import { SENTRY_SPAN_PROCESSOR_MAP } from '../src/spanprocessor'; +import { setSentrySpan, SPAN_MAP } from '../src/utils/spanMap'; beforeAll(() => { addTracingExtensions(); @@ -51,7 +51,7 @@ describe('SentryPropagator', () => { makeMain(hub); afterEach(() => { - SENTRY_SPAN_PROCESSOR_MAP.clear(); + SPAN_MAP.clear(); }); enum PerfType { @@ -61,12 +61,12 @@ describe('SentryPropagator', () => { function createTransactionAndMaybeSpan(type: PerfType, transactionContext: TransactionContext) { const transaction = new Transaction(transactionContext, hub); - SENTRY_SPAN_PROCESSOR_MAP.set(transaction.spanId, transaction); + setSentrySpan(transaction.spanId, transaction); if (type === PerfType.Span) { // eslint-disable-next-line @typescript-eslint/no-unused-vars const { spanId, ...ctx } = transactionContext; const span = transaction.startChild({ ...ctx, description: transaction.name }); - SENTRY_SPAN_PROCESSOR_MAP.set(span.spanId, span); + setSentrySpan(span.spanId, span); } } diff --git a/packages/opentelemetry-node/test/spanprocessor.test.ts b/packages/opentelemetry-node/test/spanprocessor.test.ts index 695086d9cce2..3b87068c76f7 100644 --- a/packages/opentelemetry-node/test/spanprocessor.test.ts +++ b/packages/opentelemetry-node/test/spanprocessor.test.ts @@ -17,7 +17,8 @@ import { import { NodeClient } from '@sentry/node'; import { resolvedSyncPromise } from '@sentry/utils'; -import { SENTRY_SPAN_PROCESSOR_MAP, SentrySpanProcessor } from '../src/spanprocessor'; +import { SentrySpanProcessor } from '../src/spanprocessor'; +import { clearSpan, getSentrySpan, SPAN_MAP } from '../src/utils/spanMap'; const SENTRY_DSN = 'https://0@0.ingest.sentry.io/0'; @@ -41,6 +42,9 @@ describe('SentrySpanProcessor', () => { let spanProcessor: SentrySpanProcessor; beforeEach(() => { + // To avoid test leakage, clear before each test + SPAN_MAP.clear(); + client = new NodeClient(DEFAULT_NODE_CLIENT_OPTIONS); hub = new Hub(client); makeMain(hub); @@ -56,12 +60,16 @@ describe('SentrySpanProcessor', () => { }); afterEach(async () => { + // Ensure test map is empty! + // Otherwise, we seem to have a leak somewhere... + expect(SPAN_MAP.size).toBe(0); + await provider.forceFlush(); await provider.shutdown(); }); function getSpanForOtelSpan(otelSpan: OtelSpan | OpenTelemetry.Span) { - return SENTRY_SPAN_PROCESSOR_MAP.get(otelSpan.spanContext().spanId); + return getSentrySpan(otelSpan.spanContext().spanId); } function getContext(transaction: Transaction) { @@ -125,6 +133,46 @@ describe('SentrySpanProcessor', () => { }); }); + it('handles a missing parent reference', () => { + const startTimestampMs = 1667381672309; + const endTimestampMs = 1667381672875; + const startTime = otelNumberToHrtime(startTimestampMs); + const endTime = otelNumberToHrtime(endTimestampMs); + + const tracer = provider.getTracer('default'); + + tracer.startActiveSpan('GET /users', parentOtelSpan => { + // We simulate the parent somehow not existing in our internal map + // this can happen if a race condition leads to spans being processed out of order + clearSpan(parentOtelSpan.spanContext().spanId); + + tracer.startActiveSpan('SELECT * FROM users;', { startTime }, child => { + const childOtelSpan = child as OtelSpan; + + // Parent span does not exist... + const sentrySpanTransaction = getSpanForOtelSpan(parentOtelSpan); + expect(sentrySpanTransaction).toBeUndefined(); + + // Span itself exists and is created as transaction + const sentrySpan = getSpanForOtelSpan(childOtelSpan); + expect(sentrySpan).toBeInstanceOf(SentrySpan); + expect(sentrySpan).toBeInstanceOf(Transaction); + expect(sentrySpan?.name).toBe('SELECT * FROM users;'); + expect(sentrySpan?.startTimestamp).toEqual(startTimestampMs / 1000); + expect(sentrySpan?.spanId).toEqual(childOtelSpan.spanContext().spanId); + expect(sentrySpan?.parentSpanId).toEqual(parentOtelSpan.spanContext().spanId); + + expect(hub.getScope().getSpan()).toBeUndefined(); + + child.end(endTime); + + expect(sentrySpan?.endTimestamp).toEqual(endTimestampMs / 1000); + }); + + parentOtelSpan.end(); + }); + }); + it('allows to create multiple child spans on same level', () => { const tracer = provider.getTracer('default'); @@ -159,6 +207,57 @@ describe('SentrySpanProcessor', () => { }); }); + it('handles child spans finished out of order', async () => { + const tracer = provider.getTracer('default'); + + tracer.startActiveSpan('GET /users', parent => { + tracer.startActiveSpan('SELECT * FROM users;', child => { + const grandchild = tracer.startSpan('child 1'); + + const parentSpan = getSpanForOtelSpan(parent); + const childSpan = getSpanForOtelSpan(child); + const grandchildSpan = getSpanForOtelSpan(grandchild); + + parent.end(); + child.end(); + grandchild.end(); + + expect(parentSpan).toBeDefined(); + expect(childSpan).toBeDefined(); + expect(grandchildSpan).toBeDefined(); + + expect(parentSpan?.endTimestamp).toBeDefined(); + expect(childSpan?.endTimestamp).toBeDefined(); + expect(grandchildSpan?.endTimestamp).toBeDefined(); + }); + }); + }); + + it('handles finished parent span before child span starts', async () => { + const tracer = provider.getTracer('default'); + + tracer.startActiveSpan('GET /users', parent => { + const parentSpan = getSpanForOtelSpan(parent); + + parent.end(); + + tracer.startActiveSpan('SELECT * FROM users;', child => { + const childSpan = getSpanForOtelSpan(child); + + child.end(); + + expect(parentSpan).toBeDefined(); + expect(childSpan).toBeDefined(); + expect(parentSpan).toBeInstanceOf(Transaction); + expect(childSpan).toBeInstanceOf(Transaction); + expect(parentSpan?.endTimestamp).toBeDefined(); + expect(childSpan?.endTimestamp).toBeDefined(); + expect(parentSpan?.parentSpanId).toBeUndefined(); + expect(childSpan?.parentSpanId).toEqual(parentSpan?.spanId); + }); + }); + }); + it('sets context for transaction', async () => { const otelSpan = provider.getTracer('default').startSpan('GET /users'); @@ -704,7 +803,7 @@ describe('SentrySpanProcessor', () => { it('does not finish spans for Sentry request', async () => { const tracer = provider.getTracer('default'); - tracer.startActiveSpan('GET /users', () => { + tracer.startActiveSpan('GET /users', parent => { tracer.startActiveSpan( 'SELECT * FROM users;', { @@ -720,6 +819,7 @@ describe('SentrySpanProcessor', () => { expect(sentrySpan).toBeDefined(); childOtelSpan.end(); + parent.end(); expect(sentrySpan?.endTimestamp).toBeUndefined(); @@ -733,7 +833,7 @@ describe('SentrySpanProcessor', () => { it('handles child spans of Sentry requests normally', async () => { const tracer = provider.getTracer('default'); - tracer.startActiveSpan('GET /users', () => { + tracer.startActiveSpan('GET /users', parent => { tracer.startActiveSpan( 'SELECT * FROM users;', { @@ -743,19 +843,17 @@ describe('SentrySpanProcessor', () => { }, }, child => { - const childOtelSpan = child as OtelSpan; - - const grandchildSpan = tracer.startSpan('child 1'); + const grandchild = tracer.startSpan('child 1'); - const sentrySpan = getSpanForOtelSpan(childOtelSpan); + const sentrySpan = getSpanForOtelSpan(child); expect(sentrySpan).toBeDefined(); - const sentryGrandchildSpan = getSpanForOtelSpan(grandchildSpan); + const sentryGrandchildSpan = getSpanForOtelSpan(grandchild); expect(sentryGrandchildSpan).toBeDefined(); - grandchildSpan.end(); - - childOtelSpan.end(); + grandchild.end(); + child.end(); + parent.end(); expect(sentryGrandchildSpan?.endTimestamp).toBeDefined(); expect(sentrySpan?.endTimestamp).toBeUndefined();