From 53f76984e5b52b9952ee9e17396c77404f7ac81c Mon Sep 17 00:00:00 2001 From: Krystof Woldrich <31292499+krystofwoldrich@users.noreply.github.com> Date: Tue, 13 Aug 2024 13:21:40 +0200 Subject: [PATCH] fix(ttid): End and measure TTID regardless current active span (#4019) --- CHANGELOG.md | 5 ++ src/js/tracing/reactnavigation.ts | 47 +++++--------- src/js/tracing/utils.ts | 31 ++++++--- test/tracing/reactnavigation.ttid.test.tsx | 73 ++++++++++++++++++++++ 4 files changed, 113 insertions(+), 43 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4714b151a..8b0ba8612 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,11 @@ ## Unreleased +### Fixed + +- fix(ttid): End and measure TTID regardless current active span ([#4019](https://github.com/getsentry/sentry-react-native/pull/4019)) + - Fixes possible missing TTID measurements and spans + ### Dependencies - Bump JavaScript SDK from v7.117.0 to v7.118.0 ([#4018](https://github.com/getsentry/sentry-react-native/pull/4018)) diff --git a/src/js/tracing/reactnavigation.ts b/src/js/tracing/reactnavigation.ts index a25abaa79..f4225d902 100644 --- a/src/js/tracing/reactnavigation.ts +++ b/src/js/tracing/reactnavigation.ts @@ -1,5 +1,5 @@ /* eslint-disable max-lines */ -import { getActiveSpan, setMeasurement, spanToJSON, startInactiveSpan } from '@sentry/core'; +import { getActiveSpan, startInactiveSpan } from '@sentry/core'; import type { Span, Transaction as TransactionType, TransactionContext } from '@sentry/types'; import { logger, timestampInSeconds } from '@sentry/utils'; @@ -11,7 +11,12 @@ import type { OnConfirmRoute, TransactionCreator } from './routingInstrumentatio import { InternalRoutingInstrumentation } from './routingInstrumentation'; import { manualInitialDisplaySpans, startTimeToInitialDisplaySpan } from './timetodisplay'; import type { BeforeNavigate, ReactNavigationTransactionContext, RouteChangeContextData } from './types'; -import { customTransactionSource, defaultTransactionSource, getBlankTransactionContext } from './utils'; +import { + customTransactionSource, + defaultTransactionSource, + getBlankTransactionContext, + setSpanDurationAsMeasurementOnTransaction, +} from './utils'; export interface NavigationRoute { name: string; @@ -224,6 +229,7 @@ export class ReactNavigationInstrumentation extends InternalRoutingInstrumentati if (this._latestTransaction) { if (!previousRoute || previousRoute.key !== route.key) { const routeHasBeenSeen = this._recentRouteKeys.includes(route.key); + const latestTransaction = this._latestTransaction; const latestTtidSpan = !routeHasBeenSeen && this._options.enableTimeToInitialDisplay && @@ -233,46 +239,21 @@ export class ReactNavigationInstrumentation extends InternalRoutingInstrumentati }); !routeHasBeenSeen && + latestTtidSpan && this._newScreenFrameEventEmitter?.once( NewFrameEventName, ({ newFrameTimestampInSeconds }: NewFrameEvent) => { const activeSpan = getActiveSpan(); - if (!activeSpan) { - logger.warn( - '[ReactNavigationInstrumentation] No active span found to attach ui.load.initial_display to.', - ); - return; - } - - if (manualInitialDisplaySpans.has(activeSpan)) { + if (activeSpan && manualInitialDisplaySpans.has(activeSpan)) { logger.warn( '[ReactNavigationInstrumentation] Detected manual instrumentation for the current active span.', ); return; } - if (!latestTtidSpan) { - return; - } - - if (spanToJSON(latestTtidSpan).parent_span_id !== getActiveSpan()?.spanContext().spanId) { - logger.warn( - '[ReactNavigationInstrumentation] Currently Active Span changed before the new frame was rendered, _latestTtidSpan is not a child of the currently active span.', - ); - return; - } - latestTtidSpan.setStatus('ok'); latestTtidSpan.end(newFrameTimestampInSeconds); - const ttidSpan = spanToJSON(latestTtidSpan); - - const ttidSpanEnd = ttidSpan.timestamp; - const ttidSpanStart = ttidSpan.start_timestamp; - if (!ttidSpanEnd || !ttidSpanStart) { - return; - } - - setMeasurement('time_to_initial_display', (ttidSpanEnd - ttidSpanStart) * 1000, 'millisecond'); + setSpanDurationAsMeasurementOnTransaction(latestTransaction, 'time_to_initial_display', latestTtidSpan); }, ); @@ -281,7 +262,7 @@ export class ReactNavigationInstrumentation extends InternalRoutingInstrumentati this._navigationProcessingSpan?.end(stateChangedTimestamp); this._navigationProcessingSpan = undefined; - const originalContext = this._latestTransaction.toContext() as typeof BLANK_TRANSACTION_CONTEXT; + const originalContext = latestTransaction.toContext() as typeof BLANK_TRANSACTION_CONTEXT; const data: RouteChangeContextData = { ...originalContext.data, @@ -313,10 +294,10 @@ export class ReactNavigationInstrumentation extends InternalRoutingInstrumentati }; const finalContext = this._prepareFinalContext(updatedContext); - this._latestTransaction.updateWithContext(finalContext); + latestTransaction.updateWithContext(finalContext); const isCustomName = updatedContext.name !== finalContext.name; - this._latestTransaction.setName( + latestTransaction.setName( finalContext.name, isCustomName ? customTransactionSource : defaultTransactionSource, ); diff --git a/src/js/tracing/utils.ts b/src/js/tracing/utils.ts index f154322d1..c426c186e 100644 --- a/src/js/tracing/utils.ts +++ b/src/js/tracing/utils.ts @@ -1,11 +1,6 @@ -import { - type IdleTransaction, - type Span as SpanClass, - type Transaction, - setMeasurement, - spanToJSON, -} from '@sentry/core'; -import type { Span, TransactionContext, TransactionSource } from '@sentry/types'; +import type { Transaction } from '@sentry/core'; +import { type IdleTransaction, type Span as SpanClass, setMeasurement, spanToJSON } from '@sentry/core'; +import type { Span, Transaction as TransactionType, TransactionContext, TransactionSource } from '@sentry/types'; import { logger, timestampInSeconds } from '@sentry/utils'; import { RN_GLOBAL_OBJ } from '../utils/worldwide'; @@ -105,8 +100,7 @@ export function isNearToNow(timestamp: number): boolean { * Uses `setMeasurement` function from @sentry/core. */ export function setSpanDurationAsMeasurement(name: string, span: Span): void { - const spanEnd = spanToJSON(span).timestamp; - const spanStart = spanToJSON(span).start_timestamp; + const { timestamp: spanEnd, start_timestamp: spanStart } = spanToJSON(span); if (!spanEnd || !spanStart) { return; } @@ -114,6 +108,23 @@ export function setSpanDurationAsMeasurement(name: string, span: Span): void { setMeasurement(name, (spanEnd - spanStart) * 1000, 'millisecond'); } +/** + * Sets the duration of the span as a measurement. + * Uses `setMeasurement` function from @sentry/core. + */ +export function setSpanDurationAsMeasurementOnTransaction( + transaction: TransactionType, + name: string, + span: Span, +): void { + const { timestamp: spanEnd, start_timestamp: spanStart } = spanToJSON(span); + if (!spanEnd || !spanStart) { + return; + } + + transaction.setMeasurement(name, (spanEnd - spanStart) * 1000, 'millisecond'); +} + /** * Returns unix timestamp in ms of the bundle start time. * diff --git a/test/tracing/reactnavigation.ttid.test.tsx b/test/tracing/reactnavigation.ttid.test.tsx index df840a3e1..b1357dcdd 100644 --- a/test/tracing/reactnavigation.ttid.test.tsx +++ b/test/tracing/reactnavigation.ttid.test.tsx @@ -6,6 +6,7 @@ jest.mock('../../src/js/utils/environment'); jest.mock('../../src/js/utils/sentryeventemitter', () => mockedSentryEventEmitter); jest.mock('../../src/js/tracing/timetodisplaynative', () => mockedtimetodisplaynative); +import { Span } from '@sentry/core'; import type { SpanJSON, TransactionEvent, Transport } from '@sentry/types'; import { timestampInSeconds } from '@sentry/utils'; import React from "react"; @@ -84,6 +85,78 @@ describe('React Navigation - TTID', () => { ); }); + test('should end ttid with measurements even when active span was removed from the scope', () => { + jest.runOnlyPendingTimers(); // Flush app start transaction + + mockedNavigation.navigateToNewScreen(); + Sentry.getCurrentScope().setSpan(undefined); + mockedEventEmitter.emitNewFrameEvent(); + jest.runOnlyPendingTimers(); // Flush transaction + + const transaction = getLastTransaction(transportSendMock); + expect(transaction).toEqual( + expect.objectContaining({ + type: 'transaction', + spans: expect.arrayContaining([ + expect.objectContaining>({ + data: { + 'sentry.op': 'ui.load.initial_display', + 'sentry.origin': 'manual', + }, + description: 'New Screen initial display', + op: 'ui.load.initial_display', + origin: 'manual', + status: 'ok', + start_timestamp: transaction.start_timestamp, + timestamp: expect.any(Number), + }), + ]), + measurements: expect.objectContaining['measurements']>({ + time_to_initial_display: { + value: expect.any(Number), + unit: 'millisecond', + }, + }), + }), + ); + }); + + test('should end ttid with measurements even when active span on the scope changed', () => { + jest.runOnlyPendingTimers(); // Flush app start transaction + + mockedNavigation.navigateToNewScreen(); + Sentry.getCurrentScope().setSpan(new Span()); + mockedEventEmitter.emitNewFrameEvent(); + jest.runOnlyPendingTimers(); // Flush transaction + + const transaction = getLastTransaction(transportSendMock); + expect(transaction).toEqual( + expect.objectContaining({ + type: 'transaction', + spans: expect.arrayContaining([ + expect.objectContaining>({ + data: { + 'sentry.op': 'ui.load.initial_display', + 'sentry.origin': 'manual', + }, + description: 'New Screen initial display', + op: 'ui.load.initial_display', + origin: 'manual', + status: 'ok', + start_timestamp: transaction.start_timestamp, + timestamp: expect.any(Number), + }), + ]), + measurements: expect.objectContaining['measurements']>({ + time_to_initial_display: { + value: expect.any(Number), + unit: 'millisecond', + }, + }), + }), + ); + }); + test('should add ttid measurement', () => { jest.runOnlyPendingTimers(); // Flush app start transaction