diff --git a/dev-packages/e2e-tests/test-applications/react-create-hash-router/tests/transactions.test.ts b/dev-packages/e2e-tests/test-applications/react-create-hash-router/tests/transactions.test.ts index 971d4f31521b..24548324985a 100644 --- a/dev-packages/e2e-tests/test-applications/react-create-hash-router/tests/transactions.test.ts +++ b/dev-packages/e2e-tests/test-applications/react-create-hash-router/tests/transactions.test.ts @@ -10,7 +10,7 @@ test('Captures a pageload transaction', async ({ page }) => { const transactionEvent = await transactionEventPromise; expect(transactionEvent.contexts?.trace).toEqual({ - data: expect.objectContaining({ + data: { deviceMemory: expect.any(String), effectiveConnectionType: expect.any(String), hardwareConcurrency: expect.any(String), @@ -19,7 +19,7 @@ test('Captures a pageload transaction', async ({ page }) => { 'sentry.origin': 'auto.pageload.react.reactrouter_v6', 'sentry.sample_rate': 1, 'sentry.source': 'route', - }), + }, op: 'pageload', span_id: expect.any(String), trace_id: expect.any(String), diff --git a/packages/core/src/tracing/idleSpan.ts b/packages/core/src/tracing/idleSpan.ts index 2f9230b7dd4b..8f3ecb7e7d35 100644 --- a/packages/core/src/tracing/idleSpan.ts +++ b/packages/core/src/tracing/idleSpan.ts @@ -113,37 +113,48 @@ export function startIdleSpan(startSpanOptions: StartSpanOptions, options: Parti const previousActiveSpan = getActiveSpan(); const span = _startIdleSpan(startSpanOptions); - function _endSpan(timestamp: number = timestampInSeconds()): void { - // Ensure we end with the last span timestamp, if possible - const spans = getSpanDescendants(span).filter(child => child !== span); + // We patch span.end to ensure we can run some things before the span is ended + // eslint-disable-next-line @typescript-eslint/unbound-method + span.end = new Proxy(span.end, { + apply(target, thisArg, args: Parameters) { + if (beforeSpanEnd) { + beforeSpanEnd(span); + } - // If we have no spans, we just end, nothing else to do here - if (!spans.length) { - span.end(timestamp); - return; - } + const timestamp = args[0] || timestampInSeconds(); + const spanEndTimestamp = spanTimeInputToSeconds(timestamp); - const childEndTimestamps = spans - .map(span => spanToJSON(span).timestamp) - .filter(timestamp => !!timestamp) as number[]; - const latestSpanEndTimestamp = childEndTimestamps.length ? Math.max(...childEndTimestamps) : undefined; - - const spanEndTimestamp = spanTimeInputToSeconds(timestamp); - // In reality this should always exist here, but type-wise it may be undefined... - const spanStartTimestamp = spanToJSON(span).start_timestamp; - - // The final endTimestamp should: - // * Never be before the span start timestamp - // * Be the latestSpanEndTimestamp, if there is one, and it is smaller than the passed span end timestamp - // * Otherwise be the passed end timestamp - // Final timestamp can never be after finalTimeout - const endTimestamp = Math.min( - spanStartTimestamp ? spanStartTimestamp + finalTimeout / 1000 : Infinity, - Math.max(spanStartTimestamp || -Infinity, Math.min(spanEndTimestamp, latestSpanEndTimestamp || Infinity)), - ); - - span.end(endTimestamp); - } + // Ensure we end with the last span timestamp, if possible + const spans = getSpanDescendants(span).filter(child => child !== span); + + // If we have no spans, we just end, nothing else to do here + if (!spans.length) { + onIdleSpanEnded(spanEndTimestamp); + return Reflect.apply(target, thisArg, args); + } + + const childEndTimestamps = spans + .map(span => spanToJSON(span).timestamp) + .filter(timestamp => !!timestamp) as number[]; + const latestSpanEndTimestamp = childEndTimestamps.length ? Math.max(...childEndTimestamps) : undefined; + + // In reality this should always exist here, but type-wise it may be undefined... + const spanStartTimestamp = spanToJSON(span).start_timestamp; + + // The final endTimestamp should: + // * Never be before the span start timestamp + // * Be the latestSpanEndTimestamp, if there is one, and it is smaller than the passed span end timestamp + // * Otherwise be the passed end timestamp + // Final timestamp can never be after finalTimeout + const endTimestamp = Math.min( + spanStartTimestamp ? spanStartTimestamp + finalTimeout / 1000 : Infinity, + Math.max(spanStartTimestamp || -Infinity, Math.min(spanEndTimestamp, latestSpanEndTimestamp || Infinity)), + ); + + onIdleSpanEnded(endTimestamp); + return Reflect.apply(target, thisArg, [endTimestamp]); + }, + }); /** * Cancels the existing idle timeout, if there is one. @@ -173,7 +184,7 @@ export function startIdleSpan(startSpanOptions: StartSpanOptions, options: Parti _idleTimeoutID = setTimeout(() => { if (!_finished && activities.size === 0 && _autoFinishAllowed) { _finishReason = FINISH_REASON_IDLE_TIMEOUT; - _endSpan(endTimestamp); + span.end(endTimestamp); } }, idleTimeout); } @@ -186,7 +197,7 @@ export function startIdleSpan(startSpanOptions: StartSpanOptions, options: Parti _idleTimeoutID = setTimeout(() => { if (!_finished && _autoFinishAllowed) { _finishReason = FINISH_REASON_HEARTBEAT_FAILED; - _endSpan(endTimestamp); + span.end(endTimestamp); } }, childSpanTimeout); } @@ -223,21 +234,17 @@ export function startIdleSpan(startSpanOptions: StartSpanOptions, options: Parti } } - function onIdleSpanEnded(): void { + function onIdleSpanEnded(endTimestamp: number): void { _finished = true; activities.clear(); - if (beforeSpanEnd) { - beforeSpanEnd(span); - } - _setSpanForScope(scope, previousActiveSpan); const spanJSON = spanToJSON(span); - const { timestamp: endTimestamp, start_timestamp: startTimestamp } = spanJSON; + const { start_timestamp: startTimestamp } = spanJSON; // This should never happen, but to make TS happy... - if (!endTimestamp || !startTimestamp) { + if (!startTimestamp) { return; } @@ -267,7 +274,7 @@ export function startIdleSpan(startSpanOptions: StartSpanOptions, options: Parti // Add a delta with idle timeout so that we prevent false positives const timeoutWithMarginOfError = (finalTimeout + idleTimeout) / 1000; - const spanEndedBeforeFinalTimeout = childEndTimestamp - childStartTimestamp < timeoutWithMarginOfError; + const spanEndedBeforeFinalTimeout = childEndTimestamp - childStartTimestamp <= timeoutWithMarginOfError; if (DEBUG_BUILD) { const stringifiedSpan = JSON.stringify(childSpan, undefined, 2); @@ -312,10 +319,6 @@ export function startIdleSpan(startSpanOptions: StartSpanOptions, options: Parti } _popActivity(endedSpan.spanContext().spanId); - - if (endedSpan === span) { - onIdleSpanEnded(); - } }); client.on('idleSpanEnableAutoFinish', spanToAllowAutoFinish => { @@ -338,7 +341,7 @@ export function startIdleSpan(startSpanOptions: StartSpanOptions, options: Parti if (!_finished) { span.setStatus({ code: SPAN_STATUS_ERROR, message: 'deadline_exceeded' }); _finishReason = FINISH_REASON_FINAL_TIMEOUT; - _endSpan(); + span.end(); } }, finalTimeout); diff --git a/packages/core/src/tracing/sentrySpan.ts b/packages/core/src/tracing/sentrySpan.ts index 9d9706d4ebce..ad2bfeb7dc34 100644 --- a/packages/core/src/tracing/sentrySpan.ts +++ b/packages/core/src/tracing/sentrySpan.ts @@ -342,7 +342,10 @@ export class SentrySpan implements Span { if (hasMeasurements) { DEBUG_BUILD && - logger.log('[Measurements] Adding measurements to transaction', JSON.stringify(measurements, undefined, 2)); + logger.log( + '[Measurements] Adding measurements to transaction event', + JSON.stringify(measurements, undefined, 2), + ); transaction.measurements = measurements; } diff --git a/packages/core/test/lib/tracing/idleSpan.test.ts b/packages/core/test/lib/tracing/idleSpan.test.ts index 1624160736ea..86d032488229 100644 --- a/packages/core/test/lib/tracing/idleSpan.test.ts +++ b/packages/core/test/lib/tracing/idleSpan.test.ts @@ -122,9 +122,9 @@ describe('startIdleSpan', () => { span.setAttribute('foo', 'bar'); // Try adding a child here - we do this in browser tracing... const inner = startInactiveSpan({ name: 'from beforeSpanEnd', startTime: baseTimeInSeconds }); - inner?.end(baseTimeInSeconds); + inner.end(baseTimeInSeconds + 1); }); - const idleSpan = startIdleSpan({ name: 'idle span 2', startTime: baseTimeInSeconds }, { beforeSpanEnd }); + const idleSpan = startIdleSpan({ name: 'idle span', startTime: baseTimeInSeconds }, { beforeSpanEnd }); expect(idleSpan).toBeDefined(); expect(beforeSpanEnd).not.toHaveBeenCalled(); @@ -141,6 +141,10 @@ describe('startIdleSpan', () => { expect(beforeSendTransaction).toHaveBeenCalledTimes(1); const transaction = transactions[0]; + expect(transaction.start_timestamp).toBe(baseTimeInSeconds); + // It considers the end time of the span we added in beforeSpanEnd + expect(transaction.timestamp).toBe(baseTimeInSeconds + 1); + expect(transaction.contexts?.trace?.data).toEqual( expect.objectContaining({ foo: 'bar', @@ -178,9 +182,9 @@ describe('startIdleSpan', () => { }); // discardedSpan - startTimestamp is too large - const discardedSpan = startInactiveSpan({ name: 'discarded span', startTime: baseTimeInSeconds + 99 }); + const discardedSpan = startInactiveSpan({ name: 'discarded span 1', startTime: baseTimeInSeconds + 99 }); // discardedSpan2 - endTime is too large - const discardedSpan2 = startInactiveSpan({ name: 'discarded span', startTime: baseTimeInSeconds + 3 }); + const discardedSpan2 = startInactiveSpan({ name: 'discarded span 2', startTime: baseTimeInSeconds + 3 }); discardedSpan2.end(baseTimeInSeconds + 99)!; // Should be cancelled - will not finish