From 40be8b3eb24653e017831c741114c0b833ae4525 Mon Sep 17 00:00:00 2001 From: Francesco Novy Date: Fri, 22 Dec 2023 10:57:55 +0100 Subject: [PATCH 1/2] feat(core): Replace idle transaction with idle span --- packages/core/src/baseclient.ts | 13 + packages/core/src/tracing/hubextensions.ts | 3 + packages/core/src/tracing/idlespan.ts | 318 ++++++++++++++++++ packages/core/src/tracing/idletransaction.ts | 26 +- packages/core/src/tracing/index.ts | 11 +- packages/core/src/tracing/span.ts | 11 + packages/core/test/lib/tracing/errors.test.ts | 22 +- .../src/browser/backgroundtab.ts | 4 +- .../src/browser/browsertracing.ts | 86 +++-- .../src/browser/metrics/index.ts | 6 +- .../tracing-internal/src/exports/index.ts | 2 + packages/tracing/src/index.ts | 3 + packages/tracing/test/idletransaction.test.ts | 1 + packages/types/src/client.ts | 25 ++ 14 files changed, 458 insertions(+), 73 deletions(-) create mode 100644 packages/core/src/tracing/idlespan.ts diff --git a/packages/core/src/baseclient.ts b/packages/core/src/baseclient.ts index 75b736bbf803..df48eee8e9d2 100644 --- a/packages/core/src/baseclient.ts +++ b/packages/core/src/baseclient.ts @@ -25,6 +25,7 @@ import type { SessionAggregates, Severity, SeverityLevel, + Span, Transaction, TransactionEvent, Transport, @@ -429,6 +430,12 @@ export abstract class BaseClient implements Client { /** @inheritdoc */ public on(hook: 'finishTransaction', callback: (transaction: Transaction) => void): void; + /** @inheritdoc */ + public on(hook: 'spanStart', callback: (span: Span) => void): void; + + /** @inheritdoc */ + public on(hook: 'spanEnd', callback: (span: Span) => void): void; + /** @inheritdoc */ public on(hook: 'beforeEnvelope', callback: (envelope: Envelope) => void): void; @@ -475,6 +482,12 @@ export abstract class BaseClient implements Client { /** @inheritdoc */ public emit(hook: 'finishTransaction', transaction: Transaction): void; + /** @inheritdoc */ + public emit(hook: 'spanStart', span: Span): void; + + /** @inheritdoc */ + public emit(hook: 'spanEnd', span: Span): void; + /** @inheritdoc */ public emit(hook: 'beforeEnvelope', envelope: Envelope): void; diff --git a/packages/core/src/tracing/hubextensions.ts b/packages/core/src/tracing/hubextensions.ts index 7cd8286860b2..f7e9a4bf01e1 100644 --- a/packages/core/src/tracing/hubextensions.ts +++ b/packages/core/src/tracing/hubextensions.ts @@ -74,6 +74,7 @@ The transaction will not be sampled. Please use the ${configInstrumenter} instru /** * Create new idle transaction. + * @deprecated Use `startIdleSpan` instead. */ export function startIdleTransaction( hub: Hub, @@ -83,10 +84,12 @@ export function startIdleTransaction( onScope?: boolean, customSamplingContext?: CustomSamplingContext, heartbeatInterval?: number, + // eslint-disable-next-line deprecation/deprecation ): IdleTransaction { const client = hub.getClient(); const options: Partial = (client && client.getOptions()) || {}; + // eslint-disable-next-line deprecation/deprecation let transaction = new IdleTransaction(transactionContext, hub, idleTimeout, finalTimeout, heartbeatInterval, onScope); transaction = sampleTransaction(transaction, options, { parentSampled: transactionContext.parentSampled, diff --git a/packages/core/src/tracing/idlespan.ts b/packages/core/src/tracing/idlespan.ts new file mode 100644 index 000000000000..d350e288b97e --- /dev/null +++ b/packages/core/src/tracing/idlespan.ts @@ -0,0 +1,318 @@ +/* eslint-disable max-lines */ +import type { TransactionContext } from '@sentry/types'; +import { logger, timestampInSeconds } from '@sentry/utils'; + +import { DEBUG_BUILD } from '../debug-build'; +import { getClient } from '../exports'; +import type { Span } from './span'; +import { startSpanManual } from './trace'; + +export const TRACING_DEFAULTS = { + idleTimeout: 1000, + finalTimeout: 30000, + heartbeatInterval: 5000, +}; + +const FINISH_REASON_TAG = 'finishReason'; + +const FINISH_REASON_HEARTBEAT_FAILED = 'heartbeatFailed'; +const FINISH_REASON_IDLE_TIMEOUT = 'idleTimeout'; +const FINISH_REASON_FINAL_TIMEOUT = 'finalTimeout'; +const FINISH_REASON_EXTERNAL_FINISH = 'externalFinish'; +const FINISH_REASON_CANCELLED = 'cancelled'; + +// unused +const FINISH_REASON_DOCUMENT_HIDDEN = 'documentHidden'; + +// unusued in this file, but used in BrowserTracing +const FINISH_REASON_INTERRUPTED = 'interactionInterrupted'; + +type IdleSpanFinishReason = + | typeof FINISH_REASON_CANCELLED + | typeof FINISH_REASON_DOCUMENT_HIDDEN + | typeof FINISH_REASON_EXTERNAL_FINISH + | typeof FINISH_REASON_FINAL_TIMEOUT + | typeof FINISH_REASON_HEARTBEAT_FAILED + | typeof FINISH_REASON_IDLE_TIMEOUT + | typeof FINISH_REASON_INTERRUPTED; + +interface IdleSpanOptions { + transactionContext: TransactionContext; + idleTimeout: number; + finalTimeout: number; + // TODO FN: Do we need this?? + // customSamplingContext?: CustomSamplingContext; + heartbeatInterval?: number; +} + +/** + * An idle span is a span that automatically finishes. It does this by tracking child spans as activities. + * An idle span is always the active span. + */ +export function startIdleSpan(options: IdleSpanOptions): Span | undefined { + // Activities store a list of active spans + const activities = new Map(); + + // Track state of activities in previous heartbeat + let _prevHeartbeatString: string | undefined; + + // Amount of times heartbeat has counted. Will cause span to finish after 3 beats. + let _heartbeatCounter = 0; + + // We should not use heartbeat if we finished a span + let _finished = false; + + // Idle timeout was canceled and we should finish the span with the last span end. + let _idleTimeoutCanceledPermanently = false; + + // Timer that tracks span idleTimeout + let _idleTimeoutID: ReturnType | undefined; + + // The reason why the span was finished + let _finishReason: IdleSpanFinishReason = FINISH_REASON_EXTERNAL_FINISH; + + const { + transactionContext, + idleTimeout, + finalTimeout, + heartbeatInterval = TRACING_DEFAULTS.heartbeatInterval, + } = options; + + const client = getClient(); + + if (!client || !client.on) { + return; + } + + const _span = _startIdleSpan(transactionContext); + + // Span _should_ always be defined here, but TS does not know that... + if (!_span) { + return; + } + + // For TS, so that we know everything below here has a span + const span = _span; + const spanId = span.spanId; + + // We keep all child spans (and children of children) here, + // so we can force end them when we end the idle span + const childSpans: Span[] = []; + + /** + * Cancels the existing idle timeout, if there is one. + * @param restartOnChildSpanChange If set to false the transaction will end with the last child span. + */ + function cancelIdleTimeout( + endTimestamp?: number, + { restartOnChildSpanChange } = { + restartOnChildSpanChange: true, + }, + ): void { + _idleTimeoutCanceledPermanently = restartOnChildSpanChange === false; + if (_idleTimeoutID) { + clearTimeout(_idleTimeoutID); + _idleTimeoutID = undefined; + + if (activities.size === 0 && _idleTimeoutCanceledPermanently) { + _finishReason = FINISH_REASON_CANCELLED; + span.end(endTimestamp); + } + } + } + + /** + * Restarts idle timeout, if there is no running idle timeout it will start one. + */ + function _restartIdleTimeout(endTimestamp?: number): void { + cancelIdleTimeout(); + _idleTimeoutID = setTimeout(() => { + if (!_finished && activities.size === 0) { + _finishReason = FINISH_REASON_IDLE_TIMEOUT; + span.end(endTimestamp); + } + }, idleTimeout); + } + + /** + * Start tracking a specific activity. + * @param spanId The span id that represents the activity + */ + function _pushActivity(spanId: string): void { + cancelIdleTimeout(undefined, { restartOnChildSpanChange: !_idleTimeoutCanceledPermanently }); + activities.set(spanId, true); + DEBUG_BUILD && logger.log(`[Tracing] pushActivity: ${spanId}`); + DEBUG_BUILD && logger.log('[Tracing] new activities count', activities.size); + } + + /** + * Remove an activity from usage + * @param spanId The span id that represents the activity + */ + function _popActivity(spanId: string): void { + if (activities.has(spanId)) { + DEBUG_BUILD && logger.log(`[Tracing] popActivity ${spanId}`); + activities.delete(spanId); + DEBUG_BUILD && logger.log('[Tracing] new activities count', activities.size); + } + + if (activities.size === 0) { + const endTimestamp = timestampInSeconds(); + if (_idleTimeoutCanceledPermanently) { + _finishReason = FINISH_REASON_CANCELLED; + span.end(endTimestamp); + } else { + // We need to add the timeout here to have the real endtimestamp of the transaction + // Remember timestampInSeconds is in seconds, timeout is in ms + _restartIdleTimeout(endTimestamp + idleTimeout / 1000); + } + } + } + + /** + * Checks when entries of activities are not changing for 3 beats. + * If this occurs we finish the transaction. + */ + function _beat(): void { + // We should not be running heartbeat if the idle transaction is finished. + if (_finished) { + return; + } + + const heartbeatString = Array.from(activities.keys()).join(''); + + if (heartbeatString === _prevHeartbeatString) { + _heartbeatCounter++; + } else { + _heartbeatCounter = 1; + } + + _prevHeartbeatString = heartbeatString; + + if (_heartbeatCounter >= 3) { + DEBUG_BUILD && logger.log('[Tracing] Transaction finished because of no change for 3 heart beats'); + span.setStatus('deadline_exceeded'); + _finishReason = FINISH_REASON_HEARTBEAT_FAILED; + span.end(); + } else { + _pingHeartbeat(); + } + } + + /** + * Pings the heartbeat + */ + function _pingHeartbeat(): void { + DEBUG_BUILD && logger.log(`pinging Heartbeat -> current counter: ${_heartbeatCounter}`); + setTimeout(() => { + _beat(); + }, heartbeatInterval); + } + + function endIdleSpan(): void { + const endTimestamp = span.endTimestamp; + + // This should never happen, but to make TS happy... + if (!endTimestamp) { + return; + } + + _finished = true; + activities.clear(); + + if (span.op === 'ui.action.click' && !span.tags[FINISH_REASON_TAG]) { + span.setTag(FINISH_REASON_TAG, _finishReason); + } + + DEBUG_BUILD && logger.log('[Tracing] finishing idle span', new Date(endTimestamp * 1000).toISOString(), span.op); + + childSpans.forEach(childSpan => { + // We cancel all pending spans with status "cancelled" to indicate the idle span was finished early + if (!childSpan.endTimestamp) { + childSpan.endTimestamp = endTimestamp; + childSpan.setStatus('cancelled'); + DEBUG_BUILD && + logger.log('[Tracing] cancelling span since span ended early', JSON.stringify(childSpan, undefined, 2)); + } + + const spanStartedBeforeIdleSpanEnd = childSpan.startTimestamp < endTimestamp; + + // Add a delta with idle timeout so that we prevent false positives + const timeoutWithMarginOfError = (finalTimeout + idleTimeout) / 1000; + const spanEndedBeforeFinalTimeout = childSpan.endTimestamp - span.startTimestamp < timeoutWithMarginOfError; + + if (DEBUG_BUILD) { + const stringifiedSpan = JSON.stringify(childSpan, undefined, 2); + if (!spanStartedBeforeIdleSpanEnd) { + logger.log('[Tracing] discarding Span since it happened after idle span was finished', stringifiedSpan); + } else if (!spanEndedBeforeFinalTimeout) { + logger.log('[Tracing] discarding Span since it finished after idle span final timeout', stringifiedSpan); + } + } + }); + + DEBUG_BUILD && logger.log('[Tracing] flushing idle span'); + + // Clear array of child spans + childSpans.splice(0, childSpans.length); + } + + client.on('spanStart', span => { + if (_finished) { + return; + } + + const { parentSpanId } = span; + // We only care about spans that are direct children of the idle span or its children + // and about spans that are not immediately closed + if (parentSpanId && (activities.has(parentSpanId) || parentSpanId === spanId) && span.endTimestamp === undefined) { + _pushActivity(span.spanId); + childSpans.push(span); + } + }); + + client.on('spanEnd', span => { + if (_finished) { + return; + } + + _popActivity(span.spanId); + + if (span.spanId === spanId) { + endIdleSpan(); + } + }); + + _restartIdleTimeout(); + + setTimeout(() => { + if (!_finished) { + span.setStatus('deadline_exceeded'); + _finishReason = FINISH_REASON_FINAL_TIMEOUT; + span.end(); + } + }, finalTimeout); + + // Start heartbeat so that spans do not run forever. + DEBUG_BUILD && logger.log('Starting heartbeat'); + _pingHeartbeat(); + + return span; +} + +function _startIdleSpan(transactionContext: TransactionContext): Span | undefined { + // Note: This is a bit hacky, and ONLY works in the browser + // because we do not actually have an execution context here anyhow, so the scope is not really forked + // Technically, this is incorrect, because the span is only active (spec-wise) inside of the `startSpanManual` callback + // But we rely on the incorrect browser behavior here that this is not actually the case + let span: Span | undefined; + startSpanManual(transactionContext, _span => { + span = _span; + }); + + if (span) { + DEBUG_BUILD && logger.log(`Setting idle span on scope. Span ID: ${span.spanId}`); + } + + return span; +} diff --git a/packages/core/src/tracing/idletransaction.ts b/packages/core/src/tracing/idletransaction.ts index 458bd9281627..cb6c0e015cac 100644 --- a/packages/core/src/tracing/idletransaction.ts +++ b/packages/core/src/tracing/idletransaction.ts @@ -4,17 +4,12 @@ import { logger, timestampInSeconds } from '@sentry/utils'; import { DEBUG_BUILD } from '../debug-build'; import type { Hub } from '../hub'; +import { TRACING_DEFAULTS } from './idlespan'; import type { Span } from './span'; import { SpanRecorder } from './span'; import { Transaction } from './transaction'; import { ensureTimestampInSeconds } from './utils'; -export const TRACING_DEFAULTS = { - idleTimeout: 1000, - finalTimeout: 30000, - heartbeatInterval: 5000, -}; - const FINISH_REASON_TAG = 'finishReason'; const IDLE_TRANSACTION_FINISH_REASONS = [ @@ -64,12 +59,19 @@ export class IdleTransactionSpanRecorder extends SpanRecorder { } } -export type BeforeFinishCallback = (transactionSpan: IdleTransaction, endTimestamp: number) => void; +/** @deprecated Use `startIdleSpan` instead */ +export type BeforeFinishCallback = ( + // eslint-disable-next-line deprecation/deprecation + transactionSpan: IdleTransaction, + endTimestamp: number, +) => void; /** * An IdleTransaction is a transaction that automatically finishes. It does this by tracking child spans as activities. * You can have multiple IdleTransactions active, but if the `onScope` option is specified, the idle transaction will * put itself on the scope on creation. + * + * @deprecated Use `startIdleSpan` instead. */ export class IdleTransaction extends Transaction { // Activities store a list of active spans @@ -86,6 +88,7 @@ export class IdleTransaction extends Transaction { // Idle timeout was canceled and we should finish the transaction with the last span end. private _idleTimeoutCanceledPermanently: boolean; + // eslint-disable-next-line deprecation/deprecation private readonly _beforeFinishCallbacks: BeforeFinishCallback[]; /** @@ -211,7 +214,10 @@ export class IdleTransaction extends Transaction { * This is exposed because users have no other way of running something before an idle transaction * finishes. */ - public registerBeforeFinishCallback(callback: BeforeFinishCallback): void { + public registerBeforeFinishCallback( + // eslint-disable-next-line deprecation/deprecation + callback: BeforeFinishCallback, + ): void { this._beforeFinishCallbacks.push(callback); } @@ -249,7 +255,7 @@ export class IdleTransaction extends Transaction { * with the last child span. */ public cancelIdleTimeout( - endTimestamp?: Parameters[0], + endTimestamp?: number, { restartOnChildSpanChange, }: { @@ -286,7 +292,7 @@ export class IdleTransaction extends Transaction { /** * Restarts idle timeout, if there is no running idle timeout it will start one. */ - private _restartIdleTimeout(endTimestamp?: Parameters[0]): void { + private _restartIdleTimeout(endTimestamp?: number): void { this.cancelIdleTimeout(); this._idleTimeoutID = setTimeout(() => { if (!this._finished && Object.keys(this.activities).length === 0) { diff --git a/packages/core/src/tracing/index.ts b/packages/core/src/tracing/index.ts index fcb208a797aa..111931865264 100644 --- a/packages/core/src/tracing/index.ts +++ b/packages/core/src/tracing/index.ts @@ -1,5 +1,12 @@ -export { startIdleTransaction, addTracingExtensions } from './hubextensions'; -export { IdleTransaction, TRACING_DEFAULTS } from './idletransaction'; +export { + // eslint-disable-next-line deprecation/deprecation + startIdleTransaction, + addTracingExtensions, +} from './hubextensions'; +export { startIdleSpan, TRACING_DEFAULTS } from './idlespan'; +// eslint-disable-next-line deprecation/deprecation +export { IdleTransaction } from './idletransaction'; +// eslint-disable-next-line deprecation/deprecation export type { BeforeFinishCallback } from './idletransaction'; export { Span, spanStatusfromHttpCode } from './span'; export { Transaction } from './transaction'; diff --git a/packages/core/src/tracing/span.ts b/packages/core/src/tracing/span.ts index 80704d44c9a7..f2034c3e3828 100644 --- a/packages/core/src/tracing/span.ts +++ b/packages/core/src/tracing/span.ts @@ -11,6 +11,7 @@ import type { import { dropUndefinedKeys, generateSentryTraceHeader, logger, timestampInSeconds, uuid4 } from '@sentry/utils'; import { DEBUG_BUILD } from '../debug-build'; +import { getClient } from '../exports'; import { ensureTimestampInSeconds } from './utils'; /** @@ -162,6 +163,11 @@ export class Span implements SpanInterface { if (spanContext.endTimestamp) { this.endTimestamp = spanContext.endTimestamp; } + + const client = getClient(); + if (client && client.emit) { + client.emit('spanStart', this); + } } /** An alias for `description` of the Span. */ @@ -283,6 +289,11 @@ export class Span implements SpanInterface { this.endTimestamp = typeof endTimestamp === 'number' ? ensureTimestampInSeconds(endTimestamp) : timestampInSeconds(); + + const client = getClient(); + if (client && client.emit) { + client.emit('spanEnd', this); + } } /** diff --git a/packages/core/test/lib/tracing/errors.test.ts b/packages/core/test/lib/tracing/errors.test.ts index 60b5db5c0c1d..f9d1a85818c0 100644 --- a/packages/core/test/lib/tracing/errors.test.ts +++ b/packages/core/test/lib/tracing/errors.test.ts @@ -1,5 +1,5 @@ import { BrowserClient } from '@sentry/browser'; -import { Hub, addTracingExtensions, makeMain } from '@sentry/core'; +import { Hub, addTracingExtensions, makeMain, startSpan } from '@sentry/core'; import type { HandlerDataError, HandlerDataUnhandledRejection } from '@sentry/types'; import { getDefaultBrowserClientOptions } from '../../../../tracing/test/testutils'; @@ -34,7 +34,7 @@ describe('registerErrorHandlers()', () => { beforeEach(() => { mockAddGlobalErrorInstrumentationHandler.mockClear(); mockAddGlobalUnhandledRejectionInstrumentationHandler.mockClear(); - const options = getDefaultBrowserClientOptions(); + const options = getDefaultBrowserClientOptions({ enableTracing: true }); hub = new Hub(new BrowserClient(options)); makeMain(hub); }); @@ -66,22 +66,20 @@ describe('registerErrorHandlers()', () => { it('sets status for transaction on scope on error', () => { registerErrorInstrumentation(); - const transaction = hub.startTransaction({ name: 'test' }); - hub.getScope().setSpan(transaction); - mockErrorCallback({} as HandlerDataError); - expect(transaction.status).toBe('internal_error'); + startSpan({ name: 'test' }, span => { + mockErrorCallback({} as HandlerDataError); - transaction.end(); + expect(span?.status).toBe('internal_error'); + }); }); it('sets status for transaction on scope on unhandledrejection', () => { registerErrorInstrumentation(); - const transaction = hub.startTransaction({ name: 'test' }); - hub.getScope().setSpan(transaction); - mockUnhandledRejectionCallback({}); - expect(transaction.status).toBe('internal_error'); - transaction.end(); + startSpan({ name: 'test' }, span => { + mockUnhandledRejectionCallback({}); + expect(span?.status).toBe('internal_error'); + }); }); }); diff --git a/packages/tracing-internal/src/browser/backgroundtab.ts b/packages/tracing-internal/src/browser/backgroundtab.ts index e13b997b16db..746c3c4e3d1d 100644 --- a/packages/tracing-internal/src/browser/backgroundtab.ts +++ b/packages/tracing-internal/src/browser/backgroundtab.ts @@ -1,4 +1,4 @@ -import type { IdleTransaction, SpanStatusType } from '@sentry/core'; +import type { SpanStatusType } from '@sentry/core'; import { getActiveTransaction } from '@sentry/core'; import { logger } from '@sentry/utils'; @@ -12,7 +12,7 @@ import { WINDOW } from './types'; export function registerBackgroundTabDetection(): void { if (WINDOW && WINDOW.document) { WINDOW.document.addEventListener('visibilitychange', () => { - const activeTransaction = getActiveTransaction() as IdleTransaction; + const activeTransaction = getActiveTransaction(); if (WINDOW.document.hidden && activeTransaction) { const statusType: SpanStatusType = 'cancelled'; diff --git a/packages/tracing-internal/src/browser/browsertracing.ts b/packages/tracing-internal/src/browser/browsertracing.ts index 3b99dd9603d6..4eed3d828af1 100644 --- a/packages/tracing-internal/src/browser/browsertracing.ts +++ b/packages/tracing-internal/src/browser/browsertracing.ts @@ -1,7 +1,8 @@ /* eslint-disable max-lines */ -import type { Hub, IdleTransaction } from '@sentry/core'; -import { TRACING_DEFAULTS, addTracingExtensions, getActiveTransaction, startIdleTransaction } from '@sentry/core'; -import type { EventProcessor, Integration, Transaction, TransactionContext, TransactionSource } from '@sentry/types'; +import type { Hub } from '@sentry/core'; +import { Transaction, getClient, startIdleSpan } from '@sentry/core'; +import { TRACING_DEFAULTS, addTracingExtensions, getActiveTransaction } from '@sentry/core'; +import type { EventProcessor, Integration, Span, TransactionContext, TransactionSource } from '@sentry/types'; import { getDomElement, logger, tracingContextFromHeaders } from '@sentry/utils'; import { DEBUG_BUILD } from '../common/debug-build'; @@ -259,12 +260,13 @@ export class BrowserTracing implements Integration { instrumentRouting( (context: TransactionContext) => { - const transaction = this._createRouteTransaction(context); + const span = this._createRouteSpan(context); + const transaction = span && span instanceof Transaction ? span : undefined; this.options._experiments.onStartRouteTransaction && this.options._experiments.onStartRouteTransaction(transaction, context, getCurrentHub); - return transaction; + return transaction as Transaction; }, startTransactionOnPageLoad, startTransactionOnLocationChange, @@ -288,10 +290,9 @@ export class BrowserTracing implements Integration { } /** Create routing idle transaction. */ - private _createRouteTransaction(context: TransactionContext): Transaction | undefined { + private _createRouteSpan(context: TransactionContext): Span | undefined { if (!this._getCurrentHub) { - DEBUG_BUILD && - logger.warn(`[Tracing] Did not create ${context.op} transaction because _getCurrentHub is invalid.`); + DEBUG_BUILD && logger.warn(`[Tracing] Did not create ${context.op} span because _getCurrentHub is invalid.`); return undefined; } @@ -334,22 +335,17 @@ export class BrowserTracing implements Integration { this._latestRouteSource = finalContext.metadata && finalContext.metadata.source; if (finalContext.sampled === false) { - DEBUG_BUILD && logger.log(`[Tracing] Will not send ${finalContext.op} transaction because of beforeNavigate.`); + DEBUG_BUILD && logger.log(`[Tracing] Will not send ${finalContext.op} span because of beforeNavigate.`); } - DEBUG_BUILD && logger.log(`[Tracing] Starting ${finalContext.op} transaction on scope`); + DEBUG_BUILD && logger.log(`[Tracing] Starting ${finalContext.op} span on scope`); - const { location } = WINDOW; - - const idleTransaction = startIdleTransaction( - hub, - finalContext, + const idleSpan = startIdleSpan({ + transactionContext: finalContext, idleTimeout, finalTimeout, - true, - { location }, // for use in the tracesSampler heartbeatInterval, - ); + }); const scope = hub.getScope(); @@ -357,29 +353,34 @@ export class BrowserTracing implements Integration { // use the traceparentData as the propagation context if (isPageloadTransaction && traceparentData) { scope.setPropagationContext(propagationContext); - } else { - // Navigation transactions should set a new propagation context based on the - // created idle transaction. + } else if (idleSpan) { + // Navigation spans should set a new propagation context based on the + // created idle span. scope.setPropagationContext({ - traceId: idleTransaction.traceId, - spanId: idleTransaction.spanId, - parentSpanId: idleTransaction.parentSpanId, - sampled: idleTransaction.sampled, + traceId: idleSpan.traceId, + spanId: idleSpan.spanId, + parentSpanId: idleSpan.parentSpanId, + sampled: idleSpan.sampled, }); } - idleTransaction.registerBeforeFinishCallback(transaction => { - this._collectWebVitals(); - addPerformanceEntries(transaction); - }); + const client = getClient(); + if (client && client.on) { + client.on('spanEnd', span => { + if (span === idleSpan && span instanceof Transaction) { + this._collectWebVitals(); + addPerformanceEntries(span); + } + }); + } - return idleTransaction as Transaction; + return idleSpan; } - /** Start listener for interaction transactions */ + /** Start listener for interaction span */ private _registerInteractionListener(): void { - let inflightInteractionTransaction: IdleTransaction | undefined; - const registerInteractionTransaction = (): void => { + let inflightInteractionSpan: Span | undefined; + const registerInteractionSpan = (): void => { const { idleTimeout, finalTimeout, heartbeatInterval } = this.options; const op = 'ui.action.click'; @@ -392,10 +393,10 @@ export class BrowserTracing implements Integration { return undefined; } - if (inflightInteractionTransaction) { - inflightInteractionTransaction.setFinishReason('interactionInterrupted'); - inflightInteractionTransaction.end(); - inflightInteractionTransaction = undefined; + if (inflightInteractionSpan) { + inflightInteractionSpan.setTag('finishReason', 'interactionInterrupted'); + inflightInteractionSpan.end(); + inflightInteractionSpan = undefined; } if (!this._getCurrentHub) { @@ -420,19 +421,16 @@ export class BrowserTracing implements Integration { }, }; - inflightInteractionTransaction = startIdleTransaction( - hub, - context, + inflightInteractionSpan = startIdleSpan({ + transactionContext: context, idleTimeout, finalTimeout, - true, - { location }, // for use in the tracesSampler heartbeatInterval, - ); + }); }; ['click'].forEach(type => { - addEventListener(type, registerInteractionTransaction, { once: false, capture: true }); + addEventListener(type, registerInteractionSpan, { once: false, capture: true }); }); } } diff --git a/packages/tracing-internal/src/browser/metrics/index.ts b/packages/tracing-internal/src/browser/metrics/index.ts index 651246dfb688..9351b8d4363d 100644 --- a/packages/tracing-internal/src/browser/metrics/index.ts +++ b/packages/tracing-internal/src/browser/metrics/index.ts @@ -1,5 +1,5 @@ /* eslint-disable max-lines */ -import type { IdleTransaction, Transaction } from '@sentry/core'; +import type { Transaction } from '@sentry/core'; import { getActiveTransaction } from '@sentry/core'; import type { Measurements, SpanContext } from '@sentry/types'; import { browserPerformanceTimeOrigin, getComponentName, htmlTreeAsString, logger } from '@sentry/utils'; @@ -69,7 +69,7 @@ export function startTrackingWebVitals(): () => void { export function startTrackingLongTasks(): void { addPerformanceInstrumentationHandler('longtask', ({ entries }) => { for (const entry of entries) { - const transaction = getActiveTransaction() as IdleTransaction | undefined; + const transaction = getActiveTransaction(); if (!transaction) { return; } @@ -93,7 +93,7 @@ export function startTrackingLongTasks(): void { export function startTrackingInteractions(): void { addPerformanceInstrumentationHandler('event', ({ entries }) => { for (const entry of entries) { - const transaction = getActiveTransaction() as IdleTransaction | undefined; + const transaction = getActiveTransaction(); if (!transaction) { return; } diff --git a/packages/tracing-internal/src/exports/index.ts b/packages/tracing-internal/src/exports/index.ts index 7b7f81a9caa1..46a814a73c5b 100644 --- a/packages/tracing-internal/src/exports/index.ts +++ b/packages/tracing-internal/src/exports/index.ts @@ -3,11 +3,13 @@ export { extractTraceparentData, getActiveTransaction, hasTracingEnabled, + // eslint-disable-next-line deprecation/deprecation IdleTransaction, Span, // eslint-disable-next-line deprecation/deprecation SpanStatus, spanStatusfromHttpCode, + // eslint-disable-next-line deprecation/deprecation startIdleTransaction, Transaction, } from '@sentry/core'; diff --git a/packages/tracing/src/index.ts b/packages/tracing/src/index.ts index a515db240117..6593437438c7 100644 --- a/packages/tracing/src/index.ts +++ b/packages/tracing/src/index.ts @@ -150,11 +150,13 @@ export const TRACEPARENT_REGEXP = TRACEPARENT_REGEXP_T; /** * @deprecated `@sentry/tracing` has been deprecated and will be moved to to `@sentry/node`, `@sentry/browser`, or your framework SDK in the next major version. */ +// eslint-disable-next-line deprecation/deprecation export const IdleTransaction = IdleTransactionT; /** * @deprecated `@sentry/tracing` has been deprecated and will be moved to to `@sentry/node`, `@sentry/browser`, or your framework SDK in the next major version. */ +// eslint-disable-next-line deprecation/deprecation export type IdleTransaction = IdleTransactionT; /** @@ -165,6 +167,7 @@ export const instrumentOutgoingRequests = instrumentOutgoingRequestsT; /** * @deprecated `@sentry/tracing` has been deprecated and will be moved to to `@sentry/node`, `@sentry/browser`, or your framework SDK in the next major version. */ +// eslint-disable-next-line deprecation/deprecation export const startIdleTransaction = startIdleTransactionT; /** diff --git a/packages/tracing/test/idletransaction.test.ts b/packages/tracing/test/idletransaction.test.ts index e0c5dd189cff..8f10349dcf8e 100644 --- a/packages/tracing/test/idletransaction.test.ts +++ b/packages/tracing/test/idletransaction.test.ts @@ -1,3 +1,4 @@ +/* eslint-disable deprecation/deprecation */ import { BrowserClient } from '@sentry/browser'; import { TRACING_DEFAULTS, Transaction } from '@sentry/core'; diff --git a/packages/types/src/client.ts b/packages/types/src/client.ts index bfb657d135fa..384b9ae3989b 100644 --- a/packages/types/src/client.ts +++ b/packages/types/src/client.ts @@ -14,6 +14,7 @@ import type { Scope } from './scope'; import type { SdkMetadata } from './sdkmetadata'; import type { Session, SessionAggregates } from './session'; import type { Severity, SeverityLevel } from './severity'; +import type { Span } from './span'; import type { Transaction } from './transaction'; import type { Transport, TransportMakeRequestResponse } from './transport'; @@ -203,6 +204,18 @@ export interface Client { */ on?(hook: 'finishTransaction', callback: (transaction: Transaction) => void): void; + /** + * Register a callback when a span (or transaction) starts. + * Receives the span as argument. + */ + on?(hook: 'spanStart', callback: (span: Span) => void): void; + + /** + * Register a callback when a span (or transaction) ends. + * Receives the span as argument. + */ + on?(hook: 'spanEnd', callback: (span: Span) => void): void; + /** * Register a callback for transaction start and finish. */ @@ -268,6 +281,18 @@ export interface Client { */ emit?(hook: 'finishTransaction', transaction: Transaction): void; + /** + * Fire a hook for span (or transaction) start. + * Expects to be given a span as the second argument. + */ + emit?(hook: 'spanStart', span: Span): void; + + /** + * Fire a hook for span (or transaction) ends. + * Expects to be given a span as the second argument. + */ + emit?(hook: 'spanEnd', span: Span): void; + /* * Fire a hook event for envelope creation and sending. Expects to be given an envelope as the * second argument. From 14d9c0b9e6ddf632511125322543b09ae89381e9 Mon Sep 17 00:00:00 2001 From: Francesco Novy Date: Fri, 22 Dec 2023 13:48:32 +0100 Subject: [PATCH 2/2] ref: Fix span scope setting --- packages/core/src/tracing/idlespan.ts | 14 ++--- .../test/browser/browsertracing.test.ts | 54 +++++++++++-------- 2 files changed, 39 insertions(+), 29 deletions(-) diff --git a/packages/core/src/tracing/idlespan.ts b/packages/core/src/tracing/idlespan.ts index d350e288b97e..cfa304288964 100644 --- a/packages/core/src/tracing/idlespan.ts +++ b/packages/core/src/tracing/idlespan.ts @@ -3,9 +3,9 @@ import type { TransactionContext } from '@sentry/types'; import { logger, timestampInSeconds } from '@sentry/utils'; import { DEBUG_BUILD } from '../debug-build'; -import { getClient } from '../exports'; +import { getClient, getCurrentScope } from '../exports'; import type { Span } from './span'; -import { startSpanManual } from './trace'; +import { getActiveSpan, startSpanManual } from './trace'; export const TRACING_DEFAULTS = { idleTimeout: 1000, @@ -84,6 +84,8 @@ export function startIdleSpan(options: IdleSpanOptions): Span | undefined { return; } + const scope = getCurrentScope(); + const previousActiveSpan = getActiveSpan(); const _span = _startIdleSpan(transactionContext); // Span _should_ always be defined here, but TS does not know that... @@ -210,6 +212,7 @@ export function startIdleSpan(options: IdleSpanOptions): Span | undefined { } function endIdleSpan(): void { + scope.setSpan(previousActiveSpan); const endTimestamp = span.endTimestamp; // This should never happen, but to make TS happy... @@ -301,15 +304,14 @@ export function startIdleSpan(options: IdleSpanOptions): Span | undefined { } function _startIdleSpan(transactionContext: TransactionContext): Span | undefined { - // Note: This is a bit hacky, and ONLY works in the browser - // because we do not actually have an execution context here anyhow, so the scope is not really forked - // Technically, this is incorrect, because the span is only active (spec-wise) inside of the `startSpanManual` callback - // But we rely on the incorrect browser behavior here that this is not actually the case + // We cannot use `startSpan()` here because that ends the current span when the callback finishes :() let span: Span | undefined; startSpanManual(transactionContext, _span => { span = _span; }); + getCurrentScope().setSpan(span); + if (span) { DEBUG_BUILD && logger.log(`Setting idle span on scope. Span ID: ${span.spanId}`); } diff --git a/packages/tracing-internal/test/browser/browsertracing.test.ts b/packages/tracing-internal/test/browser/browsertracing.test.ts index 3cbd6eb9f6b4..325448924f30 100644 --- a/packages/tracing-internal/test/browser/browsertracing.test.ts +++ b/packages/tracing-internal/test/browser/browsertracing.test.ts @@ -1,10 +1,15 @@ /* eslint-disable deprecation/deprecation */ import { Hub, TRACING_DEFAULTS, makeMain } from '@sentry/core'; import * as hubExtensions from '@sentry/core'; -import type { BaseTransportOptions, ClientOptions, DsnComponents, HandlerDataHistory } from '@sentry/types'; +import type { + BaseTransportOptions, + ClientOptions, + DsnComponents, + HandlerDataHistory, + Transaction, +} from '@sentry/types'; import { JSDOM } from 'jsdom'; -import type { IdleTransaction } from '../../../tracing/src'; import { getActiveTransaction } from '../../../tracing/src'; import { conditionalTest, getDefaultBrowserClientOptions } from '../../../tracing/test/testutils'; import type { BrowserTracingOptions } from '../../src/browser/browsertracing'; @@ -165,7 +170,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { routingInstrumentation: customInstrumentRouting, }); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; expect(transaction).toBeDefined(); expect(transaction.name).toBe('a/path'); expect(transaction.op).toBe('pageload'); @@ -176,7 +181,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { routingInstrumentation: customInstrumentRouting, }); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; const span = transaction.startChild(); span.end(); @@ -316,7 +321,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { beforeNavigate: mockBeforeNavigation, routingInstrumentation: customInstrumentRouting, }); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; expect(transaction).toBeDefined(); expect(mockBeforeNavigation).toHaveBeenCalledTimes(1); @@ -328,7 +333,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { beforeNavigate: mockBeforeNavigation, routingInstrumentation: customInstrumentRouting, }); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; expect(transaction.sampled).toBe(false); expect(mockBeforeNavigation).toHaveBeenCalledTimes(1); @@ -343,7 +348,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { beforeNavigate: mockBeforeNavigation, routingInstrumentation: customInstrumentRouting, }); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; expect(transaction).toBeDefined(); expect(transaction.op).toBe('not-pageload'); @@ -359,7 +364,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { beforeNavigate: mockBeforeNavigation, routingInstrumentation: customInstrumentRouting, }); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; expect(transaction).toBeDefined(); expect(transaction.name).toBe('newName'); expect(transaction.metadata.source).toBe('custom'); @@ -377,7 +382,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { customStartTransaction({ name: 'a/path', op: 'pageload', metadata: { source: 'url' } }); }, }); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; expect(transaction).toBeDefined(); expect(transaction.name).toBe('a/path'); expect(transaction.metadata.source).toBe('url'); @@ -417,7 +422,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { it('is created by default', () => { createBrowserTracing(true, { routingInstrumentation: customInstrumentRouting }); const mockFinish = jest.fn(); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; transaction.end = mockFinish; const span = transaction.startChild(); // activities = 1 @@ -429,9 +434,12 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { }); it('can be a custom value', () => { + hubExtensions.getCurrentScope().setTag('ahaha', 'ohoho'); + createBrowserTracing(true, { idleTimeout: 2000, routingInstrumentation: customInstrumentRouting }); + const mockFinish = jest.fn(); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; transaction.end = mockFinish; const span = transaction.startChild(); // activities = 1 @@ -444,7 +452,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { it('calls `_collectWebVitals` if enabled', () => { createBrowserTracing(true, { routingInstrumentation: customInstrumentRouting }); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; const span = transaction.startChild(); // activities = 1 span.end(); // activities = 0 @@ -459,7 +467,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { const interval = 200; createBrowserTracing(true, { heartbeatInterval: interval, routingInstrumentation: customInstrumentRouting }); const mockFinish = jest.fn(); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; transaction.end = mockFinish; const span = transaction.startChild(); // activities = 1 @@ -477,7 +485,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { describe('pageload transaction', () => { it('is created on setup on scope', () => { createBrowserTracing(true); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; expect(transaction).toBeDefined(); expect(transaction.op).toBe('pageload'); @@ -485,7 +493,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { it('is not created if the option is false', () => { createBrowserTracing(true, { startTransactionOnPageLoad: false }); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; expect(transaction).not.toBeDefined(); }); }); @@ -499,18 +507,18 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { createBrowserTracing(true); jest.runAllTimers(); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; expect(transaction).not.toBeDefined(); }); it('is created on location change', () => { createBrowserTracing(true); - const transaction1 = getActiveTransaction(hub) as IdleTransaction; + const transaction1 = getActiveTransaction(hub) as Transaction; expect(transaction1.op).toBe('pageload'); expect(transaction1.endTimestamp).not.toBeDefined(); mockChangeHistory({ to: 'here', from: 'there' }); - const transaction2 = getActiveTransaction(hub) as IdleTransaction; + const transaction2 = getActiveTransaction(hub) as Transaction; expect(transaction2.op).toBe('navigation'); expect(transaction1.endTimestamp).toBeDefined(); @@ -518,12 +526,12 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { it('is not created if startTransactionOnLocationChange is false', () => { createBrowserTracing(true, { startTransactionOnLocationChange: false }); - const transaction1 = getActiveTransaction(hub) as IdleTransaction; + const transaction1 = getActiveTransaction(hub) as Transaction; expect(transaction1.op).toBe('pageload'); expect(transaction1.endTimestamp).not.toBeDefined(); mockChangeHistory({ to: 'here', from: 'there' }); - const transaction2 = getActiveTransaction(hub) as IdleTransaction; + const transaction2 = getActiveTransaction(hub) as Transaction; expect(transaction2.op).toBe('pageload'); }); }); @@ -583,7 +591,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { // pageload transactions are created as part of the BrowserTracing integration's initialization createBrowserTracing(true); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; const dynamicSamplingContext = transaction.getDynamicSamplingContext()!; expect(transaction).toBeDefined(); @@ -603,7 +611,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { // pageload transactions are created as part of the BrowserTracing integration's initialization createBrowserTracing(true); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; const dynamicSamplingContext = transaction.getDynamicSamplingContext()!; expect(transaction).toBeDefined(); @@ -623,7 +631,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => { createBrowserTracing(true); mockChangeHistory({ to: 'here', from: 'there' }); - const transaction = getActiveTransaction(hub) as IdleTransaction; + const transaction = getActiveTransaction(hub) as Transaction; const dynamicSamplingContext = transaction.getDynamicSamplingContext()!; expect(transaction).toBeDefined();