diff --git a/CHANGELOG.md b/CHANGELOG.md index 99ee087da3..7fa0d9e3c3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -18,6 +18,7 @@ ### Fixes - Fix native frames measurements being dropped due to race condition ([#5813](https://github.com/getsentry/sentry-react-native/pull/5813)) +- Fix app start data lost when first navigation transaction is discarded ([#5833](https://github.com/getsentry/sentry-react-native/pull/5833)) ### Dependencies diff --git a/packages/core/src/js/tracing/integrations/appStart.ts b/packages/core/src/js/tracing/integrations/appStart.ts index 09b2263ceb..bad40bcaa4 100644 --- a/packages/core/src/js/tracing/integrations/appStart.ts +++ b/packages/core/src/js/tracing/integrations/appStart.ts @@ -83,22 +83,24 @@ export async function _captureAppStart({ isManual }: { isManual: boolean }): Pro isRecordedAppStartEndTimestampMsManual = isManual; const timestampMs = timestampInSeconds() * 1000; - let endFrames: NativeFramesResponse | null = null; + + // Set end timestamp immediately to avoid race with processEvent + // Frames data will be updated after the async fetch + _setAppStartEndData({ + timestampMs, + endFrames: null, + }); if (NATIVE.enableNative) { try { - endFrames = await NATIVE.fetchNativeFrames(); + const endFrames = await NATIVE.fetchNativeFrames(); debug.log('[AppStart] Captured end frames for app start.', endFrames); + _updateAppStartEndFrames(endFrames); } catch (error) { debug.log('[AppStart] Failed to capture end frames for app start.', error); } } - _setAppStartEndData({ - timestampMs, - endFrames, - }); - await client.getIntegrationByName(INTEGRATION_NAME)?.captureStandaloneAppStart(); } @@ -133,6 +135,19 @@ export const _setAppStartEndData = (data: AppStartEndData): void => { appStartEndData = data; }; +/** + * Updates only the endFrames on existing appStartEndData. + * Used after the async fetchNativeFrames completes to attach frame data + * without triggering the overwrite warning from _setAppStartEndData. + * + * @private + */ +export const _updateAppStartEndFrames = (endFrames: NativeFramesResponse | null): void => { + if (appStartEndData) { + appStartEndData.endFrames = endFrames; + } +}; + /** * For testing purposes only. * @@ -184,6 +199,7 @@ export const appStartIntegration = ({ let appStartDataFlushed = false; let afterAllSetupCalled = false; let firstStartedActiveRootSpanId: string | undefined = undefined; + let firstStartedActiveRootSpan: Span | undefined = undefined; const setup = (client: Client): void => { _client = client; @@ -210,6 +226,7 @@ export const appStartIntegration = ({ debug.log('[AppStartIntegration] Resetting app start data flushed flag based on runApplication call.'); appStartDataFlushed = false; firstStartedActiveRootSpanId = undefined; + firstStartedActiveRootSpan = undefined; } else { debug.log( '[AppStartIntegration] Waiting for initial app start was flush, before updating based on runApplication call.', @@ -235,7 +252,21 @@ export const appStartIntegration = ({ const recordFirstStartedActiveRootSpanId = (rootSpan: Span): void => { if (firstStartedActiveRootSpanId) { - return; + // Check if the previously locked span was dropped after it ended (e.g., by + // ignoreEmptyRouteChangeTransactions or ignoreEmptyBackNavigation setting + // _sampled = false during spanEnd). If so, reset and allow this new span. + // We check here (at the next spanStart) rather than at spanEnd because + // the discard listeners run after the app start listener in registration order, + // so _sampled is not yet false when our own spanEnd listener would fire. + if (firstStartedActiveRootSpan && !spanIsSampled(firstStartedActiveRootSpan)) { + debug.log( + '[AppStart] Previously locked root span was unsampled after ending. Resetting to allow next transaction.', + ); + resetFirstStartedActiveRootSpanId(); + // Fall through to lock to this new span + } else { + return; + } } if (!isRootSpan(rootSpan)) { @@ -246,9 +277,20 @@ export const appStartIntegration = ({ return; } + firstStartedActiveRootSpan = rootSpan; setFirstStartedActiveRootSpanId(rootSpan.spanContext().spanId); }; + /** + * Resets the first started active root span id and span reference to allow + * the next root span's transaction to attempt app start attachment. + */ + const resetFirstStartedActiveRootSpanId = (): void => { + debug.log('[AppStart] Resetting first started active root span id to allow retry on next transaction.'); + firstStartedActiveRootSpanId = undefined; + firstStartedActiveRootSpan = undefined; + }; + /** * For testing purposes only. * @private @@ -322,6 +364,7 @@ export const appStartIntegration = ({ async function attachAppStartToTransactionEvent(event: TransactionEvent): Promise { if (appStartDataFlushed) { // App start data is only relevant for the first transaction of the app run + debug.log('[AppStart] App start data already flushed. Skipping.'); return; } @@ -347,19 +390,24 @@ export const appStartIntegration = ({ } } + // All failure paths below set appStartDataFlushed = true to prevent + // wasteful retries — these conditions won't change within the same app start. const appStart = await NATIVE.fetchNativeAppStart(); if (!appStart) { debug.warn('[AppStart] Failed to retrieve the app start metrics from the native layer.'); + appStartDataFlushed = true; return; } if (appStart.has_fetched) { debug.warn('[AppStart] Measured app start metrics were already reported from the native layer.'); + appStartDataFlushed = true; return; } const appStartTimestampMs = appStart.app_start_timestamp_ms; if (!appStartTimestampMs) { debug.warn('[AppStart] App start timestamp could not be loaded from the native layer.'); + appStartDataFlushed = true; return; } @@ -368,6 +416,7 @@ export const appStartIntegration = ({ debug.warn( '[AppStart] Javascript failed to record app start end. `_setAppStartEndData` was not called nor could the bundle start be found.', ); + appStartDataFlushed = true; return; } @@ -375,6 +424,7 @@ export const appStartIntegration = ({ !!event.start_timestamp && appStartTimestampMs >= event.start_timestamp * 1_000 - MAX_APP_START_AGE_MS; if (!__DEV__ && !isAppStartWithinBounds) { debug.warn('[AppStart] App start timestamp is too far in the past to be used for app start span.'); + appStartDataFlushed = true; return; } @@ -382,6 +432,7 @@ export const appStartIntegration = ({ if (!__DEV__ && appStartDurationMs >= MAX_APP_START_DURATION_MS) { // Dev builds can have long app start waiting over minute for the first bundle to be produced debug.warn('[AppStart] App start duration is over a minute long, not adding app start span.'); + appStartDataFlushed = true; return; } @@ -393,6 +444,7 @@ export const appStartIntegration = ({ '[AppStart] Last recorded app start end timestamp is before the app start timestamp.', 'This is usually caused by missing `Sentry.wrap(RootComponent)` call.', ); + appStartDataFlushed = true; return; } diff --git a/packages/core/test/tracing/integrations/appStart.test.ts b/packages/core/test/tracing/integrations/appStart.test.ts index a15f931ba8..0f8ecc2a51 100644 --- a/packages/core/test/tracing/integrations/appStart.test.ts +++ b/packages/core/test/tracing/integrations/appStart.test.ts @@ -464,6 +464,59 @@ describe('App Start Integration', () => { }); }); + it('Attaches app start to next transaction when first root span was dropped', async () => { + mockAppStart({ cold: true }); + + const integration = appStartIntegration(); + const client = new TestClient({ + ...getDefaultTestClientOptions(), + enableAppStartTracking: true, + tracesSampleRate: 1.0, + }); + setCurrentClient(client); + integration.setup(client); + integration.afterAllSetup(client); + + // First root span starts — locks firstStartedActiveRootSpanId + const firstSpan = startInactiveSpan({ + name: 'First Navigation', + forceTransaction: true, + }); + + // Simulate the span being dropped (e.g., ignoreEmptyRouteChangeTransactions + // sets _sampled = false during spanEnd processing). + // Note: _sampled is a @sentry/core SentrySpan internal — this couples to the + // same mechanism used by onSpanEndUtils.ts (discardEmptyNavigationSpan). + (firstSpan as any)['_sampled'] = false; + + // Second root span starts — recordFirstStartedActiveRootSpanId detects + // the previously locked span is no longer sampled and resets the lock + const secondSpan = startInactiveSpan({ + name: 'Second Navigation', + forceTransaction: true, + }); + const secondSpanId = secondSpan.spanContext().spanId; + + // Process a transaction event matching the second span + const event = getMinimalTransactionEvent(); + event.contexts!.trace!.span_id = secondSpanId; + + const actualEvent = await processEventWithIntegration(integration, event); + + // App start should be attached to the second transaction + const appStartSpan = (actualEvent as TransactionEvent)?.spans?.find( + ({ description }) => description === 'Cold Start', + ); + expect(appStartSpan).toBeDefined(); + expect(appStartSpan).toEqual( + expect.objectContaining({ + description: 'Cold Start', + op: APP_START_COLD_OP, + }), + ); + expect((actualEvent as TransactionEvent)?.measurements?.[APP_START_COLD_MEASUREMENT]).toBeDefined(); + }); + it('Does not lock firstStartedActiveRootSpanId to unsampled root span', async () => { mockAppStart({ cold: true }); @@ -894,6 +947,77 @@ describe('App Start Integration', () => { expect(actualEvent).toStrictEqual(getMinimalTransactionEvent()); expect(NATIVE.fetchNativeAppStart).toHaveBeenCalledTimes(1); }); + + it('Sets appStartDataFlushed when native returns null to prevent wasteful retries', async () => { + mockFunction(NATIVE.fetchNativeAppStart).mockResolvedValue(null); + + const integration = appStartIntegration(); + const client = new TestClient(getDefaultTestClientOptions()); + + const firstEvent = getMinimalTransactionEvent(); + (integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(firstEvent.contexts?.trace?.span_id); + + await integration.processEvent(firstEvent, {}, client); + expect(firstEvent.measurements).toBeUndefined(); + + // Second transaction should be skipped (appStartDataFlushed = true) + mockAppStart({ cold: true }); + const secondEvent = getMinimalTransactionEvent(); + secondEvent.contexts!.trace!.span_id = '456'; + (integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(secondEvent.contexts?.trace?.span_id); + + const actualSecondEvent = await integration.processEvent(secondEvent, {}, client); + expect((actualSecondEvent as TransactionEvent).measurements).toBeUndefined(); + // fetchNativeAppStart should only be called once — the second event was skipped + expect(NATIVE.fetchNativeAppStart).toHaveBeenCalledTimes(1); + }); + + it('Sets appStartDataFlushed when has_fetched is true to prevent wasteful retries', async () => { + mockFunction(NATIVE.fetchNativeAppStart).mockResolvedValue({ + type: 'cold', + has_fetched: true, + spans: [], + }); + + const integration = appStartIntegration(); + const client = new TestClient(getDefaultTestClientOptions()); + + const firstEvent = getMinimalTransactionEvent(); + (integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(firstEvent.contexts?.trace?.span_id); + + await integration.processEvent(firstEvent, {}, client); + + // Second transaction should be skipped (appStartDataFlushed = true) + mockAppStart({ cold: true }); + const secondEvent = getMinimalTransactionEvent(); + secondEvent.contexts!.trace!.span_id = '456'; + (integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(secondEvent.contexts?.trace?.span_id); + + const actualSecondEvent = await integration.processEvent(secondEvent, {}, client); + expect((actualSecondEvent as TransactionEvent).measurements).toBeUndefined(); + }); + + it('Sets appStartDataFlushed when app start end timestamp is before app start timestamp', async () => { + mockAppStart({ cold: true, appStartEndTimestampMs: Date.now() - 1000 }); + + const integration = appStartIntegration(); + const client = new TestClient(getDefaultTestClientOptions()); + + const firstEvent = getMinimalTransactionEvent(); + (integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(firstEvent.contexts?.trace?.span_id); + + await integration.processEvent(firstEvent, {}, client); + expect(firstEvent.measurements).toBeUndefined(); + + // Second transaction should be skipped (appStartDataFlushed = true) + mockAppStart({ cold: true }); + const secondEvent = getMinimalTransactionEvent(); + secondEvent.contexts!.trace!.span_id = '456'; + (integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(secondEvent.contexts?.trace?.span_id); + + const actualSecondEvent = await integration.processEvent(secondEvent, {}, client); + expect((actualSecondEvent as TransactionEvent).measurements).toBeUndefined(); + }); }); });