diff --git a/CHANGELOG.md b/CHANGELOG.md index 078d6bb6a0..dbc0687e12 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,10 @@ - Copy `app.vitals.start.screen` and `app.vitals.start.type` onto standalone `app.start` children, including user spans under `app.start.extended` ([#6631](https://github.com/getsentry/sentry-react-native/pull/6631)) - `featureFlagsIntegration` now forwards flag evaluations to the native SDKs, so flags are attached to native crashes too ([#6613](https://github.com/getsentry/sentry-react-native/pull/6613)) +### Fixes + +- `time_to_initial_display`/`time_to_full_display` now measure the actual screen render for apps whose first navigation happens well after app start ([#6626](https://github.com/getsentry/sentry-react-native/pull/6626)) + ### Dependencies - Bump Android SDK from v8.53.0 to v8.54.0 ([#6624](https://github.com/getsentry/sentry-react-native/pull/6624)) diff --git a/packages/core/src/js/tracing/integrations/appStart.ts b/packages/core/src/js/tracing/integrations/appStart.ts index 0bd5446c2a..53ac6a0c37 100644 --- a/packages/core/src/js/tracing/integrations/appStart.ts +++ b/packages/core/src/js/tracing/integrations/appStart.ts @@ -45,6 +45,7 @@ import { } from '../semanticAttributes'; import { setMainThreadInfo } from '../span'; import { + addMeasurement, createChildSpanJSON, createSpanJSON, getBundleStartTimestampMs, @@ -74,6 +75,16 @@ const MAX_APP_START_DURATION_MS = 60_000; /** We filter out App starts which timestamp is 60s and more before the transaction start */ const MAX_APP_START_AGE_MS = 60_000; +/** + * When the first navigation transaction starts more than this long after the app finished starting, + * it is a normal (delayed) screen load — e.g. after a splash / auth / loading screen — not the + * cold-start's initial display. App start is decoupled from JS navigation in React Native, so we still + * report the `app_start_*` measurement, but we do NOT re-anchor the screen's TTID/TTFD to process init. + * Re-anchoring would make TTID/TTFD absorb the uninstrumented gap between app start end and the first + * navigation, inflating them well beyond the actual screen render time. + */ +const MAX_APP_START_TO_FIRST_DISPLAY_GAP_MS = 5_000; + /** App Start transaction name */ const APP_START_TX_NAME = 'App Start'; @@ -722,6 +733,28 @@ export const appStartIntegration = ({ event.contexts.trace.data[SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN] = origin; event.contexts.trace.origin = origin; + // If the first navigation transaction starts well after the app finished starting, it is a normal + // (delayed) screen load, not the cold-start's initial display. In React Native the JS navigation is + // decoupled from the native app start, so this gap is uninstrumented time (splash / auth / loading) + // that belongs to neither the app start nor the screen render. Report the app start measurement, but + // leave `event.start_timestamp` (and therefore TTID/TTFD, which are derived from it) anchored to the + // navigation start so they measure the actual screen render. Re-anchoring to process init here — and + // adding the process-init-anchored breakdown spans — would make TTID/TTFD absorb the whole gap. + // Skipped for standalone (the transaction *is* the app start) and in dev builds (long dev app starts). + const appReadyToFirstDisplayGapMs = event.start_timestamp + ? event.start_timestamp * 1000 - originalAppStartEndTimestampMs + : 0; + if (!standalone && !__DEV__ && appReadyToFirstDisplayGapMs > MAX_APP_START_TO_FIRST_DISPLAY_GAP_MS) { + debug.log(`[AppStart] First navigation is delayed past the app start end. +Reporting the app start measurement only and leaving the screen TTID/TTFD anchored to the navigation start.`); + const measurementKey = appStart.type === 'cold' ? APP_START_COLD_MEASUREMENT : APP_START_WARM_MEASUREMENT; + addMeasurement(event, measurementKey, { + value: appStartDurationMs, + unit: 'millisecond', + }); + return true; + } + const appStartTimestampSeconds = appStartTimestampMs / 1000; const appStartEndTimestampSeconds = appStartEndTimestampMs / 1000; event.start_timestamp = appStartTimestampSeconds; @@ -843,8 +876,7 @@ export const appStartIntegration = ({ value: appStartDurationMs, unit: 'millisecond', }; - event.measurements = event.measurements || {}; - event.measurements[measurementKey] = measurementValue; + addMeasurement(event, measurementKey, measurementValue); debug.log( '[AppStart] Added app start measurement to transaction event.', JSON.stringify(measurementValue, undefined, 2), @@ -1097,11 +1129,10 @@ function setSpanDurationAsMeasurementOnTransactionEvent(event: TransactionEvent, return; } - event.measurements = event.measurements || {}; - event.measurements[label] = { + addMeasurement(event, label, { value: (span.timestamp - span.start_timestamp) * 1000, unit: 'millisecond', - }; + }); } /** diff --git a/packages/core/src/js/tracing/integrations/timeToDisplayIntegration.ts b/packages/core/src/js/tracing/integrations/timeToDisplayIntegration.ts index a5dec8513d..e1f9450ecc 100644 --- a/packages/core/src/js/tracing/integrations/timeToDisplayIntegration.ts +++ b/packages/core/src/js/tracing/integrations/timeToDisplayIntegration.ts @@ -11,7 +11,7 @@ import { SPAN_THREAD_NAME, SPAN_THREAD_NAME_JAVASCRIPT } from '../span'; import { _popImperativeTtfdTimestamp } from '../timetodisplay'; import { clearSpan as clearTimeToDisplayCoordinatorSpan } from '../timeToDisplayCoordinator'; import { getTimeToInitialDisplayFallback } from '../timeToDisplayFallback'; -import { createSpanJSON } from '../utils'; +import { addMeasurement, createSpanJSON } from '../utils'; export const INTEGRATION_NAME = 'TimeToDisplay'; @@ -56,7 +56,6 @@ export const timeToDisplayIntegration = (): Integration => { } event.spans = event.spans || []; - event.measurements = event.measurements || {}; const ttidSpan = await addTimeToInitialDisplay({ event, @@ -80,10 +79,10 @@ export const timeToDisplayIntegration = (): Integration => { const ttidDeadlineExceeded = ttidDurationMs !== undefined && isDeadlineExceeded(ttidDurationMs); if (ttidDurationMs !== undefined && !ttidDeadlineExceeded) { - event.measurements['time_to_initial_display'] = { + addMeasurement(event, 'time_to_initial_display', { value: ttidDurationMs, unit: 'millisecond', - }; + }); } const ttfdDurationMs = @@ -94,14 +93,15 @@ export const timeToDisplayIntegration = (): Integration => { if (ttfdDurationMs !== undefined) { if (ttfdDeadlineExceeded) { - if (event.measurements['time_to_initial_display']) { - event.measurements['time_to_full_display'] = event.measurements['time_to_initial_display']; + const ttidMeasurement = event.measurements?.['time_to_initial_display']; + if (ttidMeasurement) { + addMeasurement(event, 'time_to_full_display', ttidMeasurement); } } else { - event.measurements['time_to_full_display'] = { + addMeasurement(event, 'time_to_full_display', { value: ttfdDurationMs, unit: 'millisecond', - }; + }); } } diff --git a/packages/core/src/js/tracing/utils.ts b/packages/core/src/js/tracing/utils.ts index 47a38cb18b..57f63cf336 100644 --- a/packages/core/src/js/tracing/utils.ts +++ b/packages/core/src/js/tracing/utils.ts @@ -1,4 +1,12 @@ -import type { MeasurementUnit, Span, SpanJSON, StartSpanOptions, TransactionSource } from '@sentry/core'; +import type { + Event, + MeasurementUnit, + Measurements, + Span, + SpanJSON, + StartSpanOptions, + TransactionSource, +} from '@sentry/core'; import { debug, @@ -73,6 +81,14 @@ export function setSpanDurationAsMeasurementOnSpan(name: string, span: Span, on: setSpanMeasurement(on, name, (spanEnd - spanStart) * 1000, 'millisecond'); } +/** + * Sets a measurement on the event, initializing the measurements object if needed. + */ +export function addMeasurement(event: Event, key: string, measurement: Measurements[string]): void { + event.measurements = event.measurements || {}; + event.measurements[key] = measurement; +} + /** * Sets measurement on the give span. */ diff --git a/packages/core/test/tracing/integrations/appStart.test.ts b/packages/core/test/tracing/integrations/appStart.test.ts index 497c68fe2f..86b5122344 100644 --- a/packages/core/test/tracing/integrations/appStart.test.ts +++ b/packages/core/test/tracing/integrations/appStart.test.ts @@ -776,6 +776,101 @@ describe('App Start Integration', () => { ); }); + it('Reports app start measurement but keeps TTID anchored to navigation when first navigation is delayed', async () => { + set__DEV__(false); + const { appStartTimeMilliseconds, appStartDurationMilliseconds, navigationStartTimestampSeconds } = + mockAppStartWithFirstNavigationGap({ cold: true, gapMilliseconds: 16000 }); + + const actualEvent = (await processEvent( + getMinimalTransactionEvent({ startTimestampSeconds: navigationStartTimestampSeconds }), + )) as TransactionEvent; + + // Start timestamp is NOT rewritten to process init — it stays at the navigation start so + // TTID/TTFD (derived from it by the timeToDisplay integration) measure the real screen render. + expect(actualEvent.start_timestamp).toBe(navigationStartTimestampSeconds); + expect(actualEvent.start_timestamp).not.toBe(appStartTimeMilliseconds / 1000); + + // The app start vital is still reported. + expect(actualEvent.measurements?.[APP_START_COLD_MEASUREMENT]).toEqual({ + value: appStartDurationMilliseconds, + unit: 'millisecond', + }); + + // The carrier transaction is marked as a screen load. + expect(actualEvent.contexts?.trace?.op).toBe(UI_LOAD); + expect(actualEvent.contexts?.trace?.origin).toBe(SPAN_ORIGIN_AUTO_APP_START); + + // No process-init-anchored breakdown span is added (it would be out of the transaction bounds). + expect(actualEvent.spans?.find(({ description }) => description === 'Cold Start')).toBeUndefined(); + // The original span is left untouched, and no span starts before the (navigation) transaction start. + expect(actualEvent.spans).toEqual([ + { + start_timestamp: 100, + timestamp: 200, + op: 'test', + description: 'Test', + span_id: '123', + trace_id: '456', + data: {}, + }, + ]); + }); + + it('Keeps app-start-anchored behavior when the first navigation follows app start promptly', async () => { + set__DEV__(false); + const { appStartTimeMilliseconds, appStartEndTimestampMilliseconds, navigationStartTimestampSeconds } = + mockAppStartWithFirstNavigationGap({ cold: true, gapMilliseconds: 4000 }); + + const actualEvent = (await processEvent( + getMinimalTransactionEvent({ startTimestampSeconds: navigationStartTimestampSeconds }), + )) as TransactionEvent; + + // Gap is under the threshold, so this is treated as the cold start's initial display: the + // transaction start is re-anchored to process init and the Cold Start breakdown span is added. + expect(actualEvent.start_timestamp).toBe(appStartTimeMilliseconds / 1000); + expect(actualEvent).toEqual( + expectEventWithAttachedColdAppStart({ + timeOriginMilliseconds: appStartEndTimestampMilliseconds, + appStartTimeMilliseconds, + }), + ); + }); + + it('Reports warm app start measurement while keeping TTID anchored on a delayed first navigation', async () => { + set__DEV__(false); + const { appStartDurationMilliseconds, navigationStartTimestampSeconds } = mockAppStartWithFirstNavigationGap({ + cold: false, + gapMilliseconds: 16000, + }); + + const actualEvent = (await processEvent( + getMinimalTransactionEvent({ startTimestampSeconds: navigationStartTimestampSeconds }), + )) as TransactionEvent; + + expect(actualEvent.start_timestamp).toBe(navigationStartTimestampSeconds); + expect(actualEvent.measurements?.[APP_START_WARM_MEASUREMENT]).toEqual({ + value: appStartDurationMilliseconds, + unit: 'millisecond', + }); + expect(actualEvent.spans?.find(({ description }) => description === 'Warm Start')).toBeUndefined(); + }); + + it('Does not apply the delayed-first-navigation branch in development builds', async () => { + set__DEV__(true); + const { appStartTimeMilliseconds, navigationStartTimestampSeconds } = mockAppStartWithFirstNavigationGap({ + cold: true, + gapMilliseconds: 16000, + }); + + const actualEvent = (await processEvent( + getMinimalTransactionEvent({ startTimestampSeconds: navigationStartTimestampSeconds }), + )) as TransactionEvent; + + // Dev builds keep the existing behavior (start re-anchored, breakdown span added). + expect(actualEvent.start_timestamp).toBe(appStartTimeMilliseconds / 1000); + expect(actualEvent.spans?.find(({ description }) => description === 'Cold Start')).toBeDefined(); + }); + it('Does not create app start transaction if has_fetched == true', async () => { mockAppStart({ has_fetched: true }); @@ -2663,6 +2758,47 @@ function mockTooOldAppStart() { return [timeOriginMilliseconds, appStartTimeMilliseconds, appStartDurationMilliseconds]; } +/** + * Mocks an app start followed by a first navigation that begins `gapMilliseconds` after the app + * finished starting. Used to exercise the delayed-first-navigation branch, where the app start + * measurement is still reported but the screen TTID/TTFD stays anchored to the navigation start. + * + * The app start itself is short (2s) and recent, so the existing age (60s) and duration (60s) guards + * do not fire — the only discriminator is the gap between app start end and the navigation start. + */ +function mockAppStartWithFirstNavigationGap({ + cold = true, + gapMilliseconds, +}: { + cold?: boolean; + gapMilliseconds: number; +}) { + const appStartTimeMilliseconds = Date.now(); + const appStartEndTimestampMilliseconds = appStartTimeMilliseconds + 2000; + const appStartDurationMilliseconds = appStartEndTimestampMilliseconds - appStartTimeMilliseconds; + const navigationStartTimestampSeconds = (appStartEndTimestampMilliseconds + gapMilliseconds) / 1000; + const mockAppStartResponse: NativeAppStartResponse = { + type: cold ? 'cold' : 'warm', + app_start_timestamp_ms: appStartTimeMilliseconds, + has_fetched: false, + spans: [], + }; + + _setAppStartEndData({ + timestampMs: appStartEndTimestampMilliseconds, + endFrames: null, + }); + mockFunction(getTimeOriginMilliseconds).mockReturnValue(appStartEndTimestampMilliseconds); + mockFunction(NATIVE.fetchNativeAppStart).mockResolvedValue(mockAppStartResponse); + + return { + appStartTimeMilliseconds, + appStartEndTimestampMilliseconds, + appStartDurationMilliseconds, + navigationStartTimestampSeconds, + }; +} + /** * Mocks RN Bundle Start Module * `var __BUNDLE_START_TIME__=this.nativePerformanceNow?nativePerformanceNow():Date.now()`