diff --git a/dev-packages/e2e-tests/test-applications/node-connect/tests/transactions.test.ts b/dev-packages/e2e-tests/test-applications/node-connect/tests/transactions.test.ts index aa868ceab291..a0836d8569f6 100644 --- a/dev-packages/e2e-tests/test-applications/node-connect/tests/transactions.test.ts +++ b/dev-packages/e2e-tests/test-applications/node-connect/tests/transactions.test.ts @@ -7,7 +7,7 @@ const sentryTestProject = process.env.E2E_TEST_SENTRY_PROJECT; const EVENT_POLLING_TIMEOUT = 90_000; test('Sends an API route transaction', async ({ baseURL }) => { - const pageloadTransactionEventPromise = waitForTransaction('node-connect', transactionEvent => { + const transactionEventPromise = waitForTransaction('node-connect', transactionEvent => { return ( transactionEvent?.contexts?.trace?.op === 'http.server' && transactionEvent?.transaction === 'GET /test-transaction' @@ -16,8 +16,7 @@ test('Sends an API route transaction', async ({ baseURL }) => { await fetch(`${baseURL}/test-transaction`); - const transactionEvent = await pageloadTransactionEventPromise; - const transactionEventId = transactionEvent.event_id; + const transactionEvent = await transactionEventPromise; expect(transactionEvent.contexts?.trace).toEqual({ data: { @@ -54,7 +53,7 @@ test('Sends an API route transaction', async ({ baseURL }) => { expect(transactionEvent).toEqual( expect.objectContaining({ - spans: [ + spans: expect.arrayContaining([ { data: { 'sentry.origin': 'manual', @@ -88,7 +87,7 @@ test('Sends an API route transaction', async ({ baseURL }) => { trace_id: expect.any(String), origin: 'auto.http.otel.connect', }, - ], + ]), transaction: 'GET /test-transaction', type: 'transaction', transaction_info: { diff --git a/dev-packages/node-integration-tests/suites/public-api/startSpan/with-nested-spans/test.ts b/dev-packages/node-integration-tests/suites/public-api/startSpan/with-nested-spans/test.ts index f7a1678e1eb6..c550a0d8337e 100644 --- a/dev-packages/node-integration-tests/suites/public-api/startSpan/with-nested-spans/test.ts +++ b/dev-packages/node-integration-tests/suites/public-api/startSpan/with-nested-spans/test.ts @@ -10,31 +10,31 @@ test('should report finished spans as children of the root transaction.', done = .expect({ transaction: transaction => { const rootSpanId = transaction.contexts?.trace?.span_id; - const span3Id = transaction.spans?.[1]?.span_id; + const span3Id = transaction.spans?.find(span => span.description === 'span_3')?.span_id; expect(rootSpanId).toEqual(expect.any(String)); expect(span3Id).toEqual(expect.any(String)); assertSentryTransaction(transaction, { transaction: 'root_span', - spans: [ - { + spans: expect.arrayContaining([ + expect.objectContaining({ description: 'span_1', - data: { + data: expect.objectContaining({ foo: 'bar', baz: [1, 2, 3], - }, + }), parent_span_id: rootSpanId, - }, - { + }), + expect.objectContaining({ description: 'span_3', parent_span_id: rootSpanId, - }, - { + }), + expect.objectContaining({ description: 'span_5', parent_span_id: span3Id, - }, - ] as SpanJSON[], + }), + ]) as SpanJSON[], }); }, }) diff --git a/packages/node/test/integration/transactions.test.ts b/packages/node/test/integration/transactions.test.ts index 75f5ef85a519..a479eeacf9d9 100644 --- a/packages/node/test/integration/transactions.test.ts +++ b/packages/node/test/integration/transactions.test.ts @@ -1,12 +1,9 @@ import { TraceFlags, context, trace } from '@opentelemetry/api'; -import type { SpanProcessor } from '@opentelemetry/sdk-trace-base'; import { SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN, SEMANTIC_ATTRIBUTE_SENTRY_SOURCE } from '@sentry/core'; -import { SentrySpanProcessor } from '@sentry/opentelemetry'; import type { TransactionEvent } from '@sentry/types'; -import { logger } from '@sentry/utils'; import * as Sentry from '../../src'; -import { cleanupOtel, getProvider, mockSdkInit } from '../helpers/mockSdkInit'; +import { cleanupOtel, mockSdkInit } from '../helpers/mockSdkInit'; describe('Integration | Transactions', () => { afterEach(() => { @@ -560,77 +557,4 @@ describe('Integration | Transactions', () => { }, ]); }); - - it('cleans up spans that are not flushed for over 5 mins', async () => { - const beforeSendTransaction = jest.fn(() => null); - - const now = Date.now(); - jest.useFakeTimers(); - jest.setSystemTime(now); - - const logs: unknown[] = []; - jest.spyOn(logger, 'log').mockImplementation(msg => logs.push(msg)); - - mockSdkInit({ enableTracing: true, beforeSendTransaction }); - - const provider = getProvider(); - const multiSpanProcessor = provider?.activeSpanProcessor as - | (SpanProcessor & { _spanProcessors?: SpanProcessor[] }) - | undefined; - const spanProcessor = multiSpanProcessor?.['_spanProcessors']?.find( - spanProcessor => spanProcessor instanceof SentrySpanProcessor, - ) as SentrySpanProcessor | undefined; - - const exporter = spanProcessor ? spanProcessor['_exporter'] : undefined; - - if (!exporter) { - throw new Error('No exporter found, aborting test...'); - } - - let innerSpan1Id: string | undefined; - let innerSpan2Id: string | undefined; - - void Sentry.startSpan({ name: 'test name' }, async () => { - const subSpan = Sentry.startInactiveSpan({ name: 'inner span 1' }); - innerSpan1Id = subSpan.spanContext().spanId; - subSpan.end(); - - Sentry.startSpan({ name: 'inner span 2' }, innerSpan => { - innerSpan2Id = innerSpan.spanContext().spanId; - }); - - // Pretend this is pending for 10 minutes - await new Promise(resolve => setTimeout(resolve, 10 * 60 * 1000)); - }); - - jest.advanceTimersByTime(1); - - // Child-spans have been added to the exporter, but they are pending since they are waiting for their parant - expect(exporter['_finishedSpans'].length).toBe(2); - expect(beforeSendTransaction).toHaveBeenCalledTimes(0); - - // Now wait for 5 mins - jest.advanceTimersByTime(5 * 60 * 1_000 + 1); - - // Adding another span will trigger the cleanup - Sentry.startSpan({ name: 'other span' }, () => {}); - - jest.advanceTimersByTime(1); - - // Old spans have been cleared away - expect(exporter['_finishedSpans'].length).toBe(0); - - // Called once for the 'other span' - expect(beforeSendTransaction).toHaveBeenCalledTimes(1); - - expect(logs).toEqual( - expect.arrayContaining([ - 'SpanExporter has 1 unsent spans remaining', - 'SpanExporter has 2 unsent spans remaining', - 'SpanExporter exported 1 spans, 2 unsent spans remaining', - `SpanExporter dropping span inner span 1 (${innerSpan1Id}) because it is pending for more than 5 minutes.`, - `SpanExporter dropping span inner span 2 (${innerSpan2Id}) because it is pending for more than 5 minutes.`, - ]), - ); - }); }); diff --git a/packages/node/test/sdk/api.test.ts b/packages/node/test/sdk/api.test.ts index e2699b4496f2..a8a556880df4 100644 --- a/packages/node/test/sdk/api.test.ts +++ b/packages/node/test/sdk/api.test.ts @@ -7,6 +7,11 @@ afterEach(() => { cleanupOtel(); }); +// Prevent leakage between tests +afterEach(async () => { + await getClient()?.flush(); +}); + describe('withActiveSpan()', () => { it('should set the active span within the callback', () => { mockSdkInit(); diff --git a/packages/opentelemetry/src/spanExporter.ts b/packages/opentelemetry/src/spanExporter.ts deleted file mode 100644 index 94e12bc019a8..000000000000 --- a/packages/opentelemetry/src/spanExporter.ts +++ /dev/null @@ -1,375 +0,0 @@ -import type { Span } from '@opentelemetry/api'; -import { SpanKind } from '@opentelemetry/api'; -import type { ReadableSpan } from '@opentelemetry/sdk-trace-base'; -import { SEMATTRS_HTTP_STATUS_CODE } from '@opentelemetry/semantic-conventions'; -import { - captureEvent, - getCapturedScopesOnSpan, - getDynamicSamplingContextFromSpan, - getMetricSummaryJsonForSpan, - timedEventsToMeasurements, -} from '@sentry/core'; -import { - SEMANTIC_ATTRIBUTE_SENTRY_OP, - SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN, - SEMANTIC_ATTRIBUTE_SENTRY_SAMPLE_RATE, - SEMANTIC_ATTRIBUTE_SENTRY_SOURCE, - getStatusMessage, -} from '@sentry/core'; -import type { SpanJSON, SpanOrigin, TraceContext, TransactionEvent, TransactionSource } from '@sentry/types'; -import { dropUndefinedKeys, logger } from '@sentry/utils'; -import { SENTRY_TRACE_STATE_PARENT_SPAN_ID } from './constants'; - -import { DEBUG_BUILD } from './debug-build'; -import { SEMANTIC_ATTRIBUTE_SENTRY_PARENT_IS_REMOTE } from './semanticAttributes'; -import { convertOtelTimeToSeconds } from './utils/convertOtelTimeToSeconds'; -import { getRequestSpanData } from './utils/getRequestSpanData'; -import type { SpanNode } from './utils/groupSpansWithParents'; -import { getLocalParentId } from './utils/groupSpansWithParents'; -import { groupSpansWithParents } from './utils/groupSpansWithParents'; -import { mapStatus } from './utils/mapStatus'; -import { parseSpanDescription } from './utils/parseSpanDescription'; - -type SpanNodeCompleted = SpanNode & { span: ReadableSpan }; - -const MAX_SPAN_COUNT = 1000; - -/** - * A Sentry-specific exporter that converts OpenTelemetry Spans to Sentry Spans & Transactions. - */ -export class SentrySpanExporter { - private _flushTimeout: ReturnType | undefined; - private _finishedSpans: ReadableSpan[]; - - public constructor() { - this._finishedSpans = []; - } - - /** Export a single span. */ - public export(span: ReadableSpan): void { - this._finishedSpans.push(span); - - // If the span has a local parent ID, we don't need to export anything just yet - if (getLocalParentId(span)) { - const openSpanCount = this._finishedSpans.length; - DEBUG_BUILD && logger.log(`SpanExporter has ${openSpanCount} unsent spans remaining`); - this._cleanupOldSpans(); - return; - } - - this._clearTimeout(); - - // If we got a parent span, we try to send the span tree - // Wait a tick for this, to ensure we avoid race conditions - this._flushTimeout = setTimeout(() => { - this.flush(); - }, 1); - } - - /** Try to flush any pending spans immediately. */ - public flush(): void { - this._clearTimeout(); - - const openSpanCount = this._finishedSpans.length; - - const remainingSpans = maybeSend(this._finishedSpans); - - const remainingOpenSpanCount = remainingSpans.length; - const sentSpanCount = openSpanCount - remainingOpenSpanCount; - - DEBUG_BUILD && - logger.log(`SpanExporter exported ${sentSpanCount} spans, ${remainingOpenSpanCount} unsent spans remaining`); - - this._cleanupOldSpans(remainingSpans); - } - - /** Clear the exporter. */ - public clear(): void { - this._finishedSpans = []; - this._clearTimeout(); - } - - /** Clear the flush timeout. */ - private _clearTimeout(): void { - if (this._flushTimeout) { - clearTimeout(this._flushTimeout); - this._flushTimeout = undefined; - } - } - - /** - * Remove any span that is older than 5min. - * We do this to avoid leaking memory. - */ - private _cleanupOldSpans(spans = this._finishedSpans): void { - this._finishedSpans = spans.filter(span => { - const shouldDrop = shouldCleanupSpan(span, 5 * 60); - DEBUG_BUILD && - shouldDrop && - logger.log( - `SpanExporter dropping span ${span.name} (${ - span.spanContext().spanId - }) because it is pending for more than 5 minutes.`, - ); - return !shouldDrop; - }); - } -} - -/** - * Send the given spans, but only if they are part of a finished transaction. - * - * Returns the unsent spans. - * Spans remain unsent when their parent span is not yet finished. - * This will happen regularly, as child spans are generally finished before their parents. - * But it _could_ also happen because, for whatever reason, a parent span was lost. - * In this case, we'll eventually need to clean this up. - */ -function maybeSend(spans: ReadableSpan[]): ReadableSpan[] { - const grouped = groupSpansWithParents(spans); - const remaining = new Set(grouped); - - const rootNodes = getCompletedRootNodes(grouped); - - rootNodes.forEach(root => { - remaining.delete(root); - const span = root.span; - const transactionEvent = createTransactionForOtelSpan(span); - - // We'll recursively add all the child spans to this array - const spans = transactionEvent.spans || []; - - root.children.forEach(child => { - createAndFinishSpanForOtelSpan(child, spans, remaining); - }); - - // spans.sort() mutates the array, but we do not use this anymore after this point - // so we can safely mutate it here - transactionEvent.spans = - spans.length > MAX_SPAN_COUNT - ? spans.sort((a, b) => a.start_timestamp - b.start_timestamp).slice(0, MAX_SPAN_COUNT) - : spans; - - const measurements = timedEventsToMeasurements(span.events); - if (measurements) { - transactionEvent.measurements = measurements; - } - - captureEvent(transactionEvent); - }); - - return Array.from(remaining) - .map(node => node.span) - .filter((span): span is ReadableSpan => !!span); -} - -function nodeIsCompletedRootNode(node: SpanNode): node is SpanNodeCompleted { - return !!node.span && !node.parentNode; -} - -function getCompletedRootNodes(nodes: SpanNode[]): SpanNodeCompleted[] { - return nodes.filter(nodeIsCompletedRootNode); -} - -function shouldCleanupSpan(span: ReadableSpan, maxStartTimeOffsetSeconds: number): boolean { - const cutoff = Date.now() / 1000 - maxStartTimeOffsetSeconds; - return convertOtelTimeToSeconds(span.startTime) < cutoff; -} - -function parseSpan(span: ReadableSpan): { op?: string; origin?: SpanOrigin; source?: TransactionSource } { - const attributes = span.attributes; - - const origin = attributes[SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN] as SpanOrigin | undefined; - const op = attributes[SEMANTIC_ATTRIBUTE_SENTRY_OP] as string | undefined; - const source = attributes[SEMANTIC_ATTRIBUTE_SENTRY_SOURCE] as TransactionSource | undefined; - - return { origin, op, source }; -} - -function createTransactionForOtelSpan(span: ReadableSpan): TransactionEvent { - const { op, description, data, origin = 'manual', source } = getSpanData(span); - const capturedSpanScopes = getCapturedScopesOnSpan(span as unknown as Span); - - const sampleRate = span.attributes[SEMANTIC_ATTRIBUTE_SENTRY_SAMPLE_RATE] as number | undefined; - - const attributes = dropUndefinedKeys({ - [SEMANTIC_ATTRIBUTE_SENTRY_SOURCE]: source, - [SEMANTIC_ATTRIBUTE_SENTRY_SAMPLE_RATE]: sampleRate, - [SEMANTIC_ATTRIBUTE_SENTRY_OP]: op, - [SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN]: origin, - ...data, - ...removeSentryAttributes(span.attributes), - }); - - const { traceId: trace_id, spanId: span_id } = span.spanContext(); - - const parentSpanIdFromTraceState = span.spanContext().traceState?.get(SENTRY_TRACE_STATE_PARENT_SPAN_ID); - - // If parentSpanIdFromTraceState is defined at all, we want it to take presedence - // In that case, an empty string should be interpreted as "no parent span id", - // even if `span.parentSpanId` is set - // this is the case when we are starting a new trace, where we have a virtual span based on the propagationContext - // We only want to continue the traceId in this case, but ignore the parent span - const parent_span_id = - typeof parentSpanIdFromTraceState === 'string' ? parentSpanIdFromTraceState || undefined : span.parentSpanId; - - const status = mapStatus(span); - - const traceContext: TraceContext = dropUndefinedKeys({ - parent_span_id, - span_id, - trace_id, - data: attributes, - origin, - op, - status: getStatusMessage(status), // As per protocol, span status is allowed to be undefined - }); - - const transactionEvent: TransactionEvent = { - contexts: { - trace: traceContext, - otel: { - resource: span.resource.attributes, - }, - }, - spans: [], - start_timestamp: convertOtelTimeToSeconds(span.startTime), - timestamp: convertOtelTimeToSeconds(span.endTime), - transaction: description, - type: 'transaction', - sdkProcessingMetadata: { - ...dropUndefinedKeys({ - capturedSpanScope: capturedSpanScopes.scope, - capturedSpanIsolationScope: capturedSpanScopes.isolationScope, - sampleRate, - dynamicSamplingContext: getDynamicSamplingContextFromSpan(span as unknown as Span), - }), - }, - ...(source && { - transaction_info: { - source, - }, - }), - _metrics_summary: getMetricSummaryJsonForSpan(span as unknown as Span), - }; - - return transactionEvent; -} - -function createAndFinishSpanForOtelSpan(node: SpanNode, spans: SpanJSON[], remaining: Set): void { - remaining.delete(node); - const span = node.span; - - const shouldDrop = !span; - - // If this span should be dropped, we still want to create spans for the children of this - if (shouldDrop) { - node.children.forEach(child => { - createAndFinishSpanForOtelSpan(child, spans, remaining); - }); - return; - } - - const span_id = span.spanContext().spanId; - const trace_id = span.spanContext().traceId; - - const { attributes, startTime, endTime, parentSpanId } = span; - - const { op, description, data, origin = 'manual' } = getSpanData(span); - const allData = dropUndefinedKeys({ - [SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN]: origin, - [SEMANTIC_ATTRIBUTE_SENTRY_OP]: op, - ...removeSentryAttributes(attributes), - ...data, - }); - - const status = mapStatus(span); - - const spanJSON: SpanJSON = dropUndefinedKeys({ - span_id, - trace_id, - data: allData, - description, - parent_span_id: parentSpanId, - start_timestamp: convertOtelTimeToSeconds(startTime), - // This is [0,0] by default in OTEL, in which case we want to interpret this as no end time - timestamp: convertOtelTimeToSeconds(endTime) || undefined, - status: getStatusMessage(status), // As per protocol, span status is allowed to be undefined - op, - origin, - _metrics_summary: getMetricSummaryJsonForSpan(span as unknown as Span), - measurements: timedEventsToMeasurements(span.events), - }); - - spans.push(spanJSON); - - node.children.forEach(child => { - createAndFinishSpanForOtelSpan(child, spans, remaining); - }); -} - -function getSpanData(span: ReadableSpan): { - data: Record; - op?: string; - description: string; - source?: TransactionSource; - origin?: SpanOrigin; -} { - const { op: definedOp, source: definedSource, origin } = parseSpan(span); - const { op: inferredOp, description, source: inferredSource, data: inferredData } = parseSpanDescription(span); - - const op = definedOp || inferredOp; - const source = definedSource || inferredSource; - - const data = { ...inferredData, ...getData(span) }; - - return { - op, - description, - source, - origin, - data, - }; -} - -/** - * Remove custom `sentry.` attribtues we do not need to send. - * These are more carrier attributes we use inside of the SDK, we do not need to send them to the API. - */ -function removeSentryAttributes(data: Record): Record { - const cleanedData = { ...data }; - - /* eslint-disable @typescript-eslint/no-dynamic-delete */ - delete cleanedData[SEMANTIC_ATTRIBUTE_SENTRY_SAMPLE_RATE]; - delete cleanedData[SEMANTIC_ATTRIBUTE_SENTRY_PARENT_IS_REMOTE]; - /* eslint-enable @typescript-eslint/no-dynamic-delete */ - - return cleanedData; -} - -function getData(span: ReadableSpan): Record { - const attributes = span.attributes; - const data: Record = { - 'otel.kind': SpanKind[span.kind], - }; - - if (attributes[SEMATTRS_HTTP_STATUS_CODE]) { - const statusCode = attributes[SEMATTRS_HTTP_STATUS_CODE] as string; - data['http.response.status_code'] = statusCode; - } - - const requestData = getRequestSpanData(span); - - if (requestData.url) { - data.url = requestData.url; - } - - if (requestData['http.query']) { - data['http.query'] = requestData['http.query'].slice(1); - } - if (requestData['http.fragment']) { - data['http.fragment'] = requestData['http.fragment'].slice(1); - } - - return data; -} diff --git a/packages/opentelemetry/src/spanProcessor.ts b/packages/opentelemetry/src/spanProcessor.ts index e3f604cab64b..6a30d6891f73 100644 --- a/packages/opentelemetry/src/spanProcessor.ts +++ b/packages/opentelemetry/src/spanProcessor.ts @@ -1,20 +1,41 @@ import type { Context } from '@opentelemetry/api'; -import { ROOT_CONTEXT, trace } from '@opentelemetry/api'; +import { ROOT_CONTEXT, SpanKind, trace } from '@opentelemetry/api'; import type { ReadableSpan, Span, SpanProcessor as SpanProcessorInterface } from '@opentelemetry/sdk-trace-base'; +import { SEMATTRS_HTTP_STATUS_CODE } from '@opentelemetry/semantic-conventions'; import { + SEMANTIC_ATTRIBUTE_SENTRY_OP, + SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN, + SEMANTIC_ATTRIBUTE_SENTRY_SAMPLE_RATE, + SEMANTIC_ATTRIBUTE_SENTRY_SOURCE, addChildSpanToSpan, + captureEvent, + getCapturedScopesOnSpan, getClient, getDefaultCurrentScope, getDefaultIsolationScope, + getDynamicSamplingContextFromSpan, + getMetricSummaryJsonForSpan, + getSpanDescendants, + getStatusMessage, logSpanEnd, logSpanStart, setCapturedScopesOnSpan, + timedEventsToMeasurements, } from '@sentry/core'; +import type { SpanJSON, SpanOrigin, TraceContext, TransactionEvent, TransactionSource } from '@sentry/types'; +import { dropUndefinedKeys } from '@sentry/utils'; +import { SENTRY_TRACE_STATE_PARENT_SPAN_ID } from './constants'; import { SEMANTIC_ATTRIBUTE_SENTRY_PARENT_IS_REMOTE } from './semanticAttributes'; -import { SentrySpanExporter } from './spanExporter'; import { getScopesFromContext } from './utils/contextData'; +import { convertOtelTimeToSeconds } from './utils/convertOtelTimeToSeconds'; +import { getRequestSpanData } from './utils/getRequestSpanData'; +import { getLocalParentId } from './utils/groupSpansWithParents'; +import { mapStatus } from './utils/mapStatus'; +import { parseSpanDescription } from './utils/parseSpanDescription'; import { setIsSetup } from './utils/setupCheck'; +const MAX_SPAN_COUNT = 1000; + function onSpanStart(span: Span, parentContext: Context): void { // This is a reliable way to get the parent span - because this is exactly how the parent is identified in the OTEL SDK const parentSpan = trace.getSpan(parentContext); @@ -63,25 +84,22 @@ function onSpanEnd(span: Span): void { * the Sentry SDK. */ export class SentrySpanProcessor implements SpanProcessorInterface { - private _exporter: SentrySpanExporter; - public constructor() { setIsSetup('SentrySpanProcessor'); - this._exporter = new SentrySpanExporter(); } /** * @inheritDoc */ public async forceFlush(): Promise { - this._exporter.flush(); + // noop } /** * @inheritDoc */ public async shutdown(): Promise { - this._exporter.clear(); + // noop } /** @@ -95,6 +113,213 @@ export class SentrySpanProcessor implements SpanProcessorInterface { public onEnd(span: Span & ReadableSpan): void { onSpanEnd(span); - this._exporter.export(span); + // TODO: Explain this check + if (!getLocalParentId(span)) { + // TODO: Explain this timeout + setTimeout(() => { + sendRootSpan(span); + }, 1); + } + } +} + +function sendRootSpan(span: Span & ReadableSpan): void { + const transactionEvent = createTransactionForOtelSpan(span); + let childSpans = (getSpanDescendants(span) as Span[]) + .filter(descendant => descendant !== span) + .map(span => createSpanForOtelSpan(span)); + + if (childSpans.length > MAX_SPAN_COUNT) { + // TODO: Explain why we sort + childSpans.sort((a, b) => a.start_timestamp - b.start_timestamp); + childSpans = childSpans.slice(0, MAX_SPAN_COUNT); + } + + transactionEvent.spans = childSpans; + + const measurements = timedEventsToMeasurements(span.events); + if (measurements) { + transactionEvent.measurements = measurements; } + + captureEvent(transactionEvent); +} + +function createSpanForOtelSpan(span: Span): SpanJSON { + const span_id = span.spanContext().spanId; + const trace_id = span.spanContext().traceId; + + const { attributes, startTime, endTime, parentSpanId } = span; + + const { op, description, data, origin = 'manual' } = getSpanData(span); + const allData = dropUndefinedKeys({ + [SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN]: origin, + [SEMANTIC_ATTRIBUTE_SENTRY_OP]: op, + ...removeSentryAttributes(attributes), + ...data, + }); + + const status = mapStatus(span); + + return dropUndefinedKeys({ + span_id, + trace_id, + data: allData, + description, + parent_span_id: parentSpanId, + start_timestamp: convertOtelTimeToSeconds(startTime), + // This is [0,0] by default in OTEL, in which case we want to interpret this as no end time + timestamp: convertOtelTimeToSeconds(endTime) || undefined, + status: getStatusMessage(status), // As per protocol, span status is allowed to be undefined + op, + origin, + _metrics_summary: getMetricSummaryJsonForSpan(span as unknown as Span), + measurements: timedEventsToMeasurements(span.events), + }); +} + +function parseSpan(span: ReadableSpan): { op?: string; origin?: SpanOrigin; source?: TransactionSource } { + const attributes = span.attributes; + + const origin = attributes[SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN] as SpanOrigin | undefined; + const op = attributes[SEMANTIC_ATTRIBUTE_SENTRY_OP] as string | undefined; + const source = attributes[SEMANTIC_ATTRIBUTE_SENTRY_SOURCE] as TransactionSource | undefined; + + return { origin, op, source }; +} + +function getSpanData(span: ReadableSpan): { + data: Record; + op?: string; + description: string; + source?: TransactionSource; + origin?: SpanOrigin; +} { + const { op: definedOp, source: definedSource, origin } = parseSpan(span); + const { op: inferredOp, description, source: inferredSource, data: inferredData } = parseSpanDescription(span); + + const op = definedOp || inferredOp; + const source = definedSource || inferredSource; + + const data = { ...inferredData, ...getData(span) }; + + return { + op, + description, + source, + origin, + data, + }; +} + +function getData(span: ReadableSpan): Record { + const attributes = span.attributes; + const data: Record = { + 'otel.kind': SpanKind[span.kind], + }; + + if (attributes[SEMATTRS_HTTP_STATUS_CODE]) { + const statusCode = attributes[SEMATTRS_HTTP_STATUS_CODE] as string; + data['http.response.status_code'] = statusCode; + } + + const requestData = getRequestSpanData(span); + + if (requestData.url) { + data.url = requestData.url; + } + + if (requestData['http.query']) { + data['http.query'] = requestData['http.query'].slice(1); + } + if (requestData['http.fragment']) { + data['http.fragment'] = requestData['http.fragment'].slice(1); + } + + return data; +} + +/** + * Remove custom `sentry.` attribtues we do not need to send. + * These are more carrier attributes we use inside of the SDK, we do not need to send them to the API. + */ +function removeSentryAttributes(data: Record): Record { + const cleanedData = { ...data }; + + /* eslint-disable @typescript-eslint/no-dynamic-delete */ + delete cleanedData[SEMANTIC_ATTRIBUTE_SENTRY_SAMPLE_RATE]; + delete cleanedData[SEMANTIC_ATTRIBUTE_SENTRY_PARENT_IS_REMOTE]; + /* eslint-enable @typescript-eslint/no-dynamic-delete */ + + return cleanedData; +} + +function createTransactionForOtelSpan(span: ReadableSpan): TransactionEvent { + const { op, description, data, origin = 'manual', source } = getSpanData(span); + const capturedSpanScopes = getCapturedScopesOnSpan(span as unknown as Span); + + const sampleRate = span.attributes[SEMANTIC_ATTRIBUTE_SENTRY_SAMPLE_RATE] as number | undefined; + + const attributes = dropUndefinedKeys({ + [SEMANTIC_ATTRIBUTE_SENTRY_SOURCE]: source, + [SEMANTIC_ATTRIBUTE_SENTRY_SAMPLE_RATE]: sampleRate, + [SEMANTIC_ATTRIBUTE_SENTRY_OP]: op, + [SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN]: origin, + ...data, + ...removeSentryAttributes(span.attributes), + }); + + const { traceId: trace_id, spanId: span_id } = span.spanContext(); + + const parentSpanIdFromTraceState = span.spanContext().traceState?.get(SENTRY_TRACE_STATE_PARENT_SPAN_ID); + + // If parentSpanIdFromTraceState is defined at all, we want it to take presedence + // In that case, an empty string should be interpreted as "no parent span id", + // even if `span.parentSpanId` is set + // this is the case when we are starting a new trace, where we have a virtual span based on the propagationContext + // We only want to continue the traceId in this case, but ignore the parent span + const parent_span_id = + typeof parentSpanIdFromTraceState === 'string' ? parentSpanIdFromTraceState || undefined : span.parentSpanId; + + const status = mapStatus(span); + + const traceContext = dropUndefinedKeys({ + parent_span_id, + span_id, + trace_id, + data: attributes, + origin, + op, + status: getStatusMessage(status), // As per protocol, span status is allowed to be undefined + }) satisfies TraceContext; + + const transactionEvent = { + contexts: { + trace: traceContext, + otel: { + resource: span.resource.attributes, + }, + }, + spans: [], + start_timestamp: convertOtelTimeToSeconds(span.startTime), + timestamp: convertOtelTimeToSeconds(span.endTime), + transaction: description, + type: 'transaction', + sdkProcessingMetadata: { + ...dropUndefinedKeys({ + capturedSpanScope: capturedSpanScopes.scope, + capturedSpanIsolationScope: capturedSpanScopes.isolationScope, + sampleRate, + dynamicSamplingContext: getDynamicSamplingContextFromSpan(span as unknown as Span), + }), + }, + ...(source && { + transaction_info: { + source, + }, + }), + _metrics_summary: getMetricSummaryJsonForSpan(span as unknown as Span), + } satisfies TransactionEvent; + + return transactionEvent; } diff --git a/packages/opentelemetry/test/integration/transactions.test.ts b/packages/opentelemetry/test/integration/transactions.test.ts index 13f8c91af7b7..5d4e11a83813 100644 --- a/packages/opentelemetry/test/integration/transactions.test.ts +++ b/packages/opentelemetry/test/integration/transactions.test.ts @@ -1,7 +1,6 @@ import type { SpanContext } from '@opentelemetry/api'; import { ROOT_CONTEXT } from '@opentelemetry/api'; import { TraceFlags, context, trace } from '@opentelemetry/api'; -import type { SpanProcessor } from '@opentelemetry/sdk-trace-base'; import { SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN, SEMANTIC_ATTRIBUTE_SENTRY_SOURCE, @@ -17,10 +16,9 @@ import { logger } from '@sentry/utils'; import { TraceState } from '@opentelemetry/core'; import { SENTRY_TRACE_STATE_DSC } from '../../src/constants'; import { makeTraceState } from '../../src/propagator'; -import { SentrySpanProcessor } from '../../src/spanProcessor'; import { startInactiveSpan, startSpan } from '../../src/trace'; import type { TestClientInterface } from '../helpers/TestClient'; -import { cleanupOtel, getProvider, mockSdkInit } from '../helpers/mockSdkInit'; +import { cleanupOtel, mockSdkInit } from '../helpers/mockSdkInit'; describe('Integration | Transactions', () => { afterEach(() => { @@ -442,77 +440,6 @@ describe('Integration | Transactions', () => { ]); }); - it('cleans up spans that are not flushed for over 5 mins', async () => { - const beforeSendTransaction = jest.fn(() => null); - - const now = Date.now(); - jest.useFakeTimers(); - jest.setSystemTime(now); - - const logs: unknown[] = []; - jest.spyOn(logger, 'log').mockImplementation(msg => logs.push(msg)); - - mockSdkInit({ enableTracing: true, beforeSendTransaction }); - - const provider = getProvider(); - const multiSpanProcessor = provider?.activeSpanProcessor as - | (SpanProcessor & { _spanProcessors?: SpanProcessor[] }) - | undefined; - const spanProcessor = multiSpanProcessor?.['_spanProcessors']?.find( - spanProcessor => spanProcessor instanceof SentrySpanProcessor, - ) as SentrySpanProcessor | undefined; - - const exporter = spanProcessor ? spanProcessor['_exporter'] : undefined; - - if (!exporter) { - throw new Error('No exporter found, aborting test...'); - } - - let innerSpan1Id: string | undefined; - let innerSpan2Id: string | undefined; - - void startSpan({ name: 'test name' }, async () => { - const subSpan = startInactiveSpan({ name: 'inner span 1' }); - innerSpan1Id = subSpan.spanContext().spanId; - subSpan.end(); - - startSpan({ name: 'inner span 2' }, innerSpan => { - innerSpan2Id = innerSpan.spanContext().spanId; - }); - - // Pretend this is pending for 10 minutes - await new Promise(resolve => setTimeout(resolve, 10 * 60 * 1000)); - }); - - // Child-spans have been added to the exporter, but they are pending since they are waiting for their parant - expect(exporter['_finishedSpans'].length).toBe(2); - expect(beforeSendTransaction).toHaveBeenCalledTimes(0); - - // Now wait for 5 mins - jest.advanceTimersByTime(5 * 60 * 1_000 + 1); - - // Adding another span will trigger the cleanup - startSpan({ name: 'other span' }, () => {}); - - jest.advanceTimersByTime(1); - - // Old spans have been cleared away - expect(exporter['_finishedSpans'].length).toBe(0); - - // Called once for the 'other span' - expect(beforeSendTransaction).toHaveBeenCalledTimes(1); - - expect(logs).toEqual( - expect.arrayContaining([ - 'SpanExporter has 1 unsent spans remaining', - 'SpanExporter has 2 unsent spans remaining', - 'SpanExporter exported 1 spans, 2 unsent spans remaining', - `SpanExporter dropping span inner span 1 (${innerSpan1Id}) because it is pending for more than 5 minutes.`, - `SpanExporter dropping span inner span 2 (${innerSpan2Id}) because it is pending for more than 5 minutes.`, - ]), - ); - }); - it('includes child spans that are finished in the same tick but after their parent span', async () => { const now = Date.now(); jest.useFakeTimers(); @@ -531,20 +458,6 @@ describe('Integration | Transactions', () => { }, }); - const provider = getProvider(); - const multiSpanProcessor = provider?.activeSpanProcessor as - | (SpanProcessor & { _spanProcessors?: SpanProcessor[] }) - | undefined; - const spanProcessor = multiSpanProcessor?.['_spanProcessors']?.find( - spanProcessor => spanProcessor instanceof SentrySpanProcessor, - ) as SentrySpanProcessor | undefined; - - const exporter = spanProcessor ? spanProcessor['_exporter'] : undefined; - - if (!exporter) { - throw new Error('No exporter found, aborting test...'); - } - startSpanManual({ name: 'test name' }, async span => { const subSpan = startInactiveSpan({ name: 'inner span 1' }); subSpan.end(); @@ -559,64 +472,6 @@ describe('Integration | Transactions', () => { expect(transactions).toHaveLength(1); expect(transactions[0]?.spans).toHaveLength(2); - - // No spans are pending - expect(exporter['_finishedSpans'].length).toBe(0); - }); - - it('discards child spans that are finished after their parent span', async () => { - const now = Date.now(); - jest.useFakeTimers(); - jest.setSystemTime(now); - - const logs: unknown[] = []; - jest.spyOn(logger, 'log').mockImplementation(msg => logs.push(msg)); - - const transactions: Event[] = []; - - mockSdkInit({ - enableTracing: true, - beforeSendTransaction: event => { - transactions.push(event); - return null; - }, - }); - - const provider = getProvider(); - const multiSpanProcessor = provider?.activeSpanProcessor as - | (SpanProcessor & { _spanProcessors?: SpanProcessor[] }) - | undefined; - const spanProcessor = multiSpanProcessor?.['_spanProcessors']?.find( - spanProcessor => spanProcessor instanceof SentrySpanProcessor, - ) as SentrySpanProcessor | undefined; - - const exporter = spanProcessor ? spanProcessor['_exporter'] : undefined; - - if (!exporter) { - throw new Error('No exporter found, aborting test...'); - } - - startSpanManual({ name: 'test name' }, async span => { - const subSpan = startInactiveSpan({ name: 'inner span 1' }); - subSpan.end(); - - const subSpan2 = startInactiveSpan({ name: 'inner span 2' }); - - span.end(); - - setTimeout(() => { - subSpan2.end(); - }, 1); - }); - - jest.advanceTimersByTime(2); - - expect(transactions).toHaveLength(1); - expect(transactions[0]?.spans).toHaveLength(1); - - // subSpan2 is pending (and will eventually be cleaned up) - expect(exporter['_finishedSpans'].length).toBe(1); - expect(exporter['_finishedSpans'][0]?.name).toBe('inner span 2'); }); it('uses & inherits DSC on span trace state', async () => { diff --git a/packages/opentelemetry/test/trace.test.ts b/packages/opentelemetry/test/trace.test.ts index 2da8c7a8b511..c73ec7f96148 100644 --- a/packages/opentelemetry/test/trace.test.ts +++ b/packages/opentelemetry/test/trace.test.ts @@ -31,6 +31,11 @@ import { getSpanKind } from '../src/utils/getSpanKind'; import { spanHasAttributes, spanHasName } from '../src/utils/spanTypes'; import { cleanupOtel, mockSdkInit } from './helpers/mockSdkInit'; +// Prevent leakage between tests +afterEach(async () => { + await getClient()?.flush(); +}); + describe('trace', () => { beforeEach(() => { mockSdkInit({ enableTracing: true });