From 9fe67aaed54bd6989b8856f9832d1affe369bbdc Mon Sep 17 00:00:00 2001 From: Luca Forstner Date: Tue, 30 Jan 2024 13:23:26 +0100 Subject: [PATCH] fix: Fork scope and keep async context within `startSpan` and `startSpanManual` (#10413) --- packages/core/src/tracing/trace.ts | 99 ++++++++-------- packages/node/test/performance.test.ts | 150 +++++++++++++++++++++++++ 2 files changed, 202 insertions(+), 47 deletions(-) create mode 100644 packages/node/test/performance.test.ts diff --git a/packages/core/src/tracing/trace.ts b/packages/core/src/tracing/trace.ts index 308e68a9738c..dc822a2bab7d 100644 --- a/packages/core/src/tracing/trace.ts +++ b/packages/core/src/tracing/trace.ts @@ -5,6 +5,7 @@ import { dropUndefinedKeys, logger, tracingContextFromHeaders } from '@sentry/ut import { DEBUG_BUILD } from '../debug-build'; import { getCurrentScope, withScope } from '../exports'; import type { Hub } from '../hub'; +import { runWithAsyncContext } from '../hub'; import { getIsolationScope } from '../hub'; import { getCurrentHub } from '../hub'; import { handleCallbackErrors } from '../utils/handleCallbackErrors'; @@ -74,31 +75,33 @@ export function trace( export function startSpan(context: StartSpanOptions, callback: (span: Span | undefined) => T): T { const ctx = normalizeContext(context); - return withScope(context.scope, scope => { - // eslint-disable-next-line deprecation/deprecation - const hub = getCurrentHub(); - // eslint-disable-next-line deprecation/deprecation - const parentSpan = scope.getSpan(); + return runWithAsyncContext(() => { + return withScope(context.scope, scope => { + // eslint-disable-next-line deprecation/deprecation + const hub = getCurrentHub(); + // eslint-disable-next-line deprecation/deprecation + const parentSpan = scope.getSpan(); - const shouldSkipSpan = context.onlyIfParent && !parentSpan; - const activeSpan = shouldSkipSpan ? undefined : createChildSpanOrTransaction(hub, parentSpan, ctx); + const shouldSkipSpan = context.onlyIfParent && !parentSpan; + const activeSpan = shouldSkipSpan ? undefined : createChildSpanOrTransaction(hub, parentSpan, ctx); - // eslint-disable-next-line deprecation/deprecation - scope.setSpan(activeSpan); - - return handleCallbackErrors( - () => callback(activeSpan), - () => { - // Only update the span status if it hasn't been changed yet - if (activeSpan) { - const { status } = spanToJSON(activeSpan); - if (!status || status === 'ok') { - activeSpan.setStatus('internal_error'); + // eslint-disable-next-line deprecation/deprecation + scope.setSpan(activeSpan); + + return handleCallbackErrors( + () => callback(activeSpan), + () => { + // Only update the span status if it hasn't been changed yet + if (activeSpan) { + const { status } = spanToJSON(activeSpan); + if (!status || status === 'ok') { + activeSpan.setStatus('internal_error'); + } } - } - }, - () => activeSpan && activeSpan.end(), - ); + }, + () => activeSpan && activeSpan.end(), + ); + }); }); } @@ -124,34 +127,36 @@ export function startSpanManual( ): T { const ctx = normalizeContext(context); - return withScope(context.scope, scope => { - // eslint-disable-next-line deprecation/deprecation - const hub = getCurrentHub(); - // eslint-disable-next-line deprecation/deprecation - const parentSpan = scope.getSpan(); - - const shouldSkipSpan = context.onlyIfParent && !parentSpan; - const activeSpan = shouldSkipSpan ? undefined : createChildSpanOrTransaction(hub, parentSpan, ctx); + return runWithAsyncContext(() => { + return withScope(context.scope, scope => { + // eslint-disable-next-line deprecation/deprecation + const hub = getCurrentHub(); + // eslint-disable-next-line deprecation/deprecation + const parentSpan = scope.getSpan(); - // eslint-disable-next-line deprecation/deprecation - scope.setSpan(activeSpan); + const shouldSkipSpan = context.onlyIfParent && !parentSpan; + const activeSpan = shouldSkipSpan ? undefined : createChildSpanOrTransaction(hub, parentSpan, ctx); - function finishAndSetSpan(): void { - activeSpan && activeSpan.end(); - } - - return handleCallbackErrors( - () => callback(activeSpan, finishAndSetSpan), - () => { - // Only update the span status if it hasn't been changed yet, and the span is not yet finished - if (activeSpan && activeSpan.isRecording()) { - const { status } = spanToJSON(activeSpan); - if (!status || status === 'ok') { - activeSpan.setStatus('internal_error'); + // eslint-disable-next-line deprecation/deprecation + scope.setSpan(activeSpan); + + function finishAndSetSpan(): void { + activeSpan && activeSpan.end(); + } + + return handleCallbackErrors( + () => callback(activeSpan, finishAndSetSpan), + () => { + // Only update the span status if it hasn't been changed yet, and the span is not yet finished + if (activeSpan && activeSpan.isRecording()) { + const { status } = spanToJSON(activeSpan); + if (!status || status === 'ok') { + activeSpan.setStatus('internal_error'); + } } - } - }, - ); + }, + ); + }); }); } diff --git a/packages/node/test/performance.test.ts b/packages/node/test/performance.test.ts new file mode 100644 index 000000000000..0f57dd4166e6 --- /dev/null +++ b/packages/node/test/performance.test.ts @@ -0,0 +1,150 @@ +import { setAsyncContextStrategy, setCurrentClient, startSpan, startSpanManual } from '@sentry/core'; +import type { TransactionEvent } from '@sentry/types'; +import { NodeClient, defaultStackParser } from '../src'; +import { setNodeAsyncContextStrategy } from '../src/async'; +import { getDefaultNodeClientOptions } from './helper/node-client-options'; + +const dsn = 'https://53039209a22b4ec1bcc296a3c9fdecd6@sentry.io/4291'; + +beforeAll(() => { + setNodeAsyncContextStrategy(); +}); + +afterAll(() => { + setAsyncContextStrategy(undefined); +}); + +describe('startSpan()', () => { + it('should correctly separate spans when called after one another with interwoven timings', async () => { + const transactionEventPromise = new Promise(resolve => { + setCurrentClient( + new NodeClient( + getDefaultNodeClientOptions({ + stackParser: defaultStackParser, + tracesSampleRate: 1, + beforeSendTransaction: event => { + resolve(event); + return null; + }, + dsn, + }), + ), + ); + }); + + startSpan({ name: 'first' }, () => { + return new Promise(resolve => { + setTimeout(resolve, 500); + }); + }); + + startSpan({ name: 'second' }, () => { + return new Promise(resolve => { + setTimeout(resolve, 250); + }); + }); + + const transactionEvent = await transactionEventPromise; + + // Any transaction events happening shouldn't have any child spans + expect(transactionEvent.spans).toStrictEqual([]); + }); + + it('should correctly nest spans when called within one another', async () => { + const transactionEventPromise = new Promise(resolve => { + setCurrentClient( + new NodeClient( + getDefaultNodeClientOptions({ + stackParser: defaultStackParser, + tracesSampleRate: 1, + beforeSendTransaction: event => { + resolve(event); + return null; + }, + dsn, + }), + ), + ); + }); + + startSpan({ name: 'first' }, () => { + startSpan({ name: 'second' }, () => undefined); + }); + + const transactionEvent = await transactionEventPromise; + + expect(transactionEvent.spans).toContainEqual(expect.objectContaining({ description: 'second' })); + }); +}); + +describe('startSpanManual()', () => { + it('should correctly separate spans when called after one another with interwoven timings', async () => { + const transactionEventPromise = new Promise(resolve => { + setCurrentClient( + new NodeClient( + getDefaultNodeClientOptions({ + stackParser: defaultStackParser, + tracesSampleRate: 1, + beforeSendTransaction: event => { + resolve(event); + return null; + }, + dsn, + }), + ), + ); + }); + + startSpanManual({ name: 'first' }, span => { + return new Promise(resolve => { + setTimeout(() => { + span?.end(); + resolve(); + }, 500); + }); + }); + + startSpanManual({ name: 'second' }, span => { + return new Promise(resolve => { + setTimeout(() => { + span?.end(); + resolve(); + }, 500); + }); + }); + + const transactionEvent = await transactionEventPromise; + + // Any transaction events happening shouldn't have any child spans + expect(transactionEvent.spans).toStrictEqual([]); + }); + + it('should correctly nest spans when called within one another', async () => { + const transactionEventPromise = new Promise(resolve => { + setCurrentClient( + new NodeClient( + getDefaultNodeClientOptions({ + stackParser: defaultStackParser, + tracesSampleRate: 1, + beforeSendTransaction: event => { + resolve(event); + return null; + }, + dsn, + }), + ), + ); + }); + + startSpanManual({ name: 'first' }, span1 => { + startSpanManual({ name: 'second' }, span2 => { + span2?.end(); + }); + span1?.end(); + }); + + const transactionEvent = await transactionEventPromise; + + expect(transactionEvent.spans).toContainEqual(expect.objectContaining({ description: 'second' })); + }); +});