Skip to content

Commit cfd2d4f

Browse files
antonisclaude
antonis
and
claude
authored
fix(tracing): Recover app start data when first navigation transaction is discarded (#5833)
* fix(tracing): Recover app start data when first navigation transaction is discarded When the first navigation idle transaction is discarded at spanEnd (e.g., by ignoreEmptyRouteChangeTransactions because the navigation container was registered too late), firstStartedActiveRootSpanId remained permanently locked to the dead span. Since no transaction event was ever created for it, processEvent never ran, and all subsequent transactions failed the span ID check — silently losing app start data for the entire session. Add a spanEnd listener that resets the lock when the first root span is unsampled at end time. Also set appStartEndData timestamp before awaiting fetchNativeFrames to close a secondary timing race, and improve failure recovery in attachAppStartToTransactionEvent. Fixes #5831 Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com> * fix(tracing): Add changelog entry for app start recovery fix Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com> * fix(tracing): Address review feedback for app start recovery - Unsubscribe spanEnd listener after it fires to prevent listener leak - Add _updateAppStartEndFrames helper instead of direct module-level mutation - Make all processEvent failure paths set appStartDataFlushed = true (these conditions won't change within the same app start, retrying is wasteful) - Add comment about _sampled internal coupling in test - Fix unnecessary type assertions (lint) Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com> * fix(tracing): Check locked span sampled status at next spanStart instead of spanEnd The spanEnd listener approach had a listener ordering bug: the app start listener registered at spanStart time runs BEFORE the navigation discard listeners (ignoreEmptyRouteChangeTransactions, ignoreEmptyBackNavigation) that set _sampled = false. So our check always saw the span as sampled. Instead, store a reference to the locked root span and check its sampled status lazily at the next spanStart. By then, the old span has fully completed and _sampled has been set to false by the discard listeners. Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 4.6 (1M context) <noreply@anthropic.com>
1 parent 11f4bd9 commit cfd2d4f

3 files changed

Lines changed: 185 additions & 8 deletions

File tree

‎CHANGELOG.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818
### Fixes
1919

2020
- Fix native frames measurements being dropped due to race condition ([#5813](https://github.com/getsentry/sentry-react-native/pull/5813))
21+
- Fix app start data lost when first navigation transaction is discarded ([#5833](https://github.com/getsentry/sentry-react-native/pull/5833))
2122

2223
### Dependencies
2324

‎packages/core/src/js/tracing/integrations/appStart.ts‎

Lines changed: 60 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -83,22 +83,24 @@ export async function _captureAppStart({ isManual }: { isManual: boolean }): Pro
8383
isRecordedAppStartEndTimestampMsManual = isManual;
8484

8585
const timestampMs = timestampInSeconds() * 1000;
86-
let endFrames: NativeFramesResponse | null = null;
86+
87+
// Set end timestamp immediately to avoid race with processEvent
88+
// Frames data will be updated after the async fetch
89+
_setAppStartEndData({
90+
timestampMs,
91+
endFrames: null,
92+
});
8793

8894
if (NATIVE.enableNative) {
8995
try {
90-
endFrames = await NATIVE.fetchNativeFrames();
96+
const endFrames = await NATIVE.fetchNativeFrames();
9197
debug.log('[AppStart] Captured end frames for app start.', endFrames);
98+
_updateAppStartEndFrames(endFrames);
9299
} catch (error) {
93100
debug.log('[AppStart] Failed to capture end frames for app start.', error);
94101
}
95102
}
96103

97-
_setAppStartEndData({
98-
timestampMs,
99-
endFrames,
100-
});
101-
102104
await client.getIntegrationByName<AppStartIntegration>(INTEGRATION_NAME)?.captureStandaloneAppStart();
103105
}
104106

@@ -133,6 +135,19 @@ export const _setAppStartEndData = (data: AppStartEndData): void => {
133135
appStartEndData = data;
134136
};
135137

138+
/**
139+
* Updates only the endFrames on existing appStartEndData.
140+
* Used after the async fetchNativeFrames completes to attach frame data
141+
* without triggering the overwrite warning from _setAppStartEndData.
142+
*
143+
* @private
144+
*/
145+
export const _updateAppStartEndFrames = (endFrames: NativeFramesResponse | null): void => {
146+
if (appStartEndData) {
147+
appStartEndData.endFrames = endFrames;
148+
}
149+
};
150+
136151
/**
137152
* For testing purposes only.
138153
*
@@ -184,6 +199,7 @@ export const appStartIntegration = ({
184199
let appStartDataFlushed = false;
185200
let afterAllSetupCalled = false;
186201
let firstStartedActiveRootSpanId: string | undefined = undefined;
202+
let firstStartedActiveRootSpan: Span | undefined = undefined;
187203

188204
const setup = (client: Client): void => {
189205
_client = client;
@@ -210,6 +226,7 @@ export const appStartIntegration = ({
210226
debug.log('[AppStartIntegration] Resetting app start data flushed flag based on runApplication call.');
211227
appStartDataFlushed = false;
212228
firstStartedActiveRootSpanId = undefined;
229+
firstStartedActiveRootSpan = undefined;
213230
} else {
214231
debug.log(
215232
'[AppStartIntegration] Waiting for initial app start was flush, before updating based on runApplication call.',
@@ -235,7 +252,21 @@ export const appStartIntegration = ({
235252

236253
const recordFirstStartedActiveRootSpanId = (rootSpan: Span): void => {
237254
if (firstStartedActiveRootSpanId) {
238-
return;
255+
// Check if the previously locked span was dropped after it ended (e.g., by
256+
// ignoreEmptyRouteChangeTransactions or ignoreEmptyBackNavigation setting
257+
// _sampled = false during spanEnd). If so, reset and allow this new span.
258+
// We check here (at the next spanStart) rather than at spanEnd because
259+
// the discard listeners run after the app start listener in registration order,
260+
// so _sampled is not yet false when our own spanEnd listener would fire.
261+
if (firstStartedActiveRootSpan && !spanIsSampled(firstStartedActiveRootSpan)) {
262+
debug.log(
263+
'[AppStart] Previously locked root span was unsampled after ending. Resetting to allow next transaction.',
264+
);
265+
resetFirstStartedActiveRootSpanId();
266+
// Fall through to lock to this new span
267+
} else {
268+
return;
269+
}
239270
}
240271

241272
if (!isRootSpan(rootSpan)) {
@@ -246,9 +277,20 @@ export const appStartIntegration = ({
246277
return;
247278
}
248279

280+
firstStartedActiveRootSpan = rootSpan;
249281
setFirstStartedActiveRootSpanId(rootSpan.spanContext().spanId);
250282
};
251283

284+
/**
285+
* Resets the first started active root span id and span reference to allow
286+
* the next root span's transaction to attempt app start attachment.
287+
*/
288+
const resetFirstStartedActiveRootSpanId = (): void => {
289+
debug.log('[AppStart] Resetting first started active root span id to allow retry on next transaction.');
290+
firstStartedActiveRootSpanId = undefined;
291+
firstStartedActiveRootSpan = undefined;
292+
};
293+
252294
/**
253295
* For testing purposes only.
254296
* @private
@@ -322,6 +364,7 @@ export const appStartIntegration = ({
322364
async function attachAppStartToTransactionEvent(event: TransactionEvent): Promise<void> {
323365
if (appStartDataFlushed) {
324366
// App start data is only relevant for the first transaction of the app run
367+
debug.log('[AppStart] App start data already flushed. Skipping.');
325368
return;
326369
}
327370

@@ -347,19 +390,24 @@ export const appStartIntegration = ({
347390
}
348391
}
349392

393+
// All failure paths below set appStartDataFlushed = true to prevent
394+
// wasteful retries — these conditions won't change within the same app start.
350395
const appStart = await NATIVE.fetchNativeAppStart();
351396
if (!appStart) {
352397
debug.warn('[AppStart] Failed to retrieve the app start metrics from the native layer.');
398+
appStartDataFlushed = true;
353399
return;
354400
}
355401
if (appStart.has_fetched) {
356402
debug.warn('[AppStart] Measured app start metrics were already reported from the native layer.');
403+
appStartDataFlushed = true;
357404
return;
358405
}
359406

360407
const appStartTimestampMs = appStart.app_start_timestamp_ms;
361408
if (!appStartTimestampMs) {
362409
debug.warn('[AppStart] App start timestamp could not be loaded from the native layer.');
410+
appStartDataFlushed = true;
363411
return;
364412
}
365413

@@ -368,20 +416,23 @@ export const appStartIntegration = ({
368416
debug.warn(
369417
'[AppStart] Javascript failed to record app start end. `_setAppStartEndData` was not called nor could the bundle start be found.',
370418
);
419+
appStartDataFlushed = true;
371420
return;
372421
}
373422

374423
const isAppStartWithinBounds =
375424
!!event.start_timestamp && appStartTimestampMs >= event.start_timestamp * 1_000 - MAX_APP_START_AGE_MS;
376425
if (!__DEV__ && !isAppStartWithinBounds) {
377426
debug.warn('[AppStart] App start timestamp is too far in the past to be used for app start span.');
427+
appStartDataFlushed = true;
378428
return;
379429
}
380430

381431
const appStartDurationMs = appStartEndTimestampMs - appStartTimestampMs;
382432
if (!__DEV__ && appStartDurationMs >= MAX_APP_START_DURATION_MS) {
383433
// Dev builds can have long app start waiting over minute for the first bundle to be produced
384434
debug.warn('[AppStart] App start duration is over a minute long, not adding app start span.');
435+
appStartDataFlushed = true;
385436
return;
386437
}
387438

@@ -393,6 +444,7 @@ export const appStartIntegration = ({
393444
'[AppStart] Last recorded app start end timestamp is before the app start timestamp.',
394445
'This is usually caused by missing `Sentry.wrap(RootComponent)` call.',
395446
);
447+
appStartDataFlushed = true;
396448
return;
397449
}
398450

‎packages/core/test/tracing/integrations/appStart.test.ts‎

Lines changed: 124 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -464,6 +464,59 @@ describe('App Start Integration', () => {
464464
});
465465
});
466466

467+
it('Attaches app start to next transaction when first root span was dropped', async () => {
468+
mockAppStart({ cold: true });
469+
470+
const integration = appStartIntegration();
471+
const client = new TestClient({
472+
...getDefaultTestClientOptions(),
473+
enableAppStartTracking: true,
474+
tracesSampleRate: 1.0,
475+
});
476+
setCurrentClient(client);
477+
integration.setup(client);
478+
integration.afterAllSetup(client);
479+
480+
// First root span starts — locks firstStartedActiveRootSpanId
481+
const firstSpan = startInactiveSpan({
482+
name: 'First Navigation',
483+
forceTransaction: true,
484+
});
485+
486+
// Simulate the span being dropped (e.g., ignoreEmptyRouteChangeTransactions
487+
// sets _sampled = false during spanEnd processing).
488+
// Note: _sampled is a @sentry/core SentrySpan internal — this couples to the
489+
// same mechanism used by onSpanEndUtils.ts (discardEmptyNavigationSpan).
490+
(firstSpan as any)['_sampled'] = false;
491+
492+
// Second root span starts — recordFirstStartedActiveRootSpanId detects
493+
// the previously locked span is no longer sampled and resets the lock
494+
const secondSpan = startInactiveSpan({
495+
name: 'Second Navigation',
496+
forceTransaction: true,
497+
});
498+
const secondSpanId = secondSpan.spanContext().spanId;
499+
500+
// Process a transaction event matching the second span
501+
const event = getMinimalTransactionEvent();
502+
event.contexts!.trace!.span_id = secondSpanId;
503+
504+
const actualEvent = await processEventWithIntegration(integration, event);
505+
506+
// App start should be attached to the second transaction
507+
const appStartSpan = (actualEvent as TransactionEvent)?.spans?.find(
508+
({ description }) => description === 'Cold Start',
509+
);
510+
expect(appStartSpan).toBeDefined();
511+
expect(appStartSpan).toEqual(
512+
expect.objectContaining({
513+
description: 'Cold Start',
514+
op: APP_START_COLD_OP,
515+
}),
516+
);
517+
expect((actualEvent as TransactionEvent)?.measurements?.[APP_START_COLD_MEASUREMENT]).toBeDefined();
518+
});
519+
467520
it('Does not lock firstStartedActiveRootSpanId to unsampled root span', async () => {
468521
mockAppStart({ cold: true });
469522

@@ -894,6 +947,77 @@ describe('App Start Integration', () => {
894947
expect(actualEvent).toStrictEqual(getMinimalTransactionEvent());
895948
expect(NATIVE.fetchNativeAppStart).toHaveBeenCalledTimes(1);
896949
});
950+
951+
it('Sets appStartDataFlushed when native returns null to prevent wasteful retries', async () => {
952+
mockFunction(NATIVE.fetchNativeAppStart).mockResolvedValue(null);
953+
954+
const integration = appStartIntegration();
955+
const client = new TestClient(getDefaultTestClientOptions());
956+
957+
const firstEvent = getMinimalTransactionEvent();
958+
(integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(firstEvent.contexts?.trace?.span_id);
959+
960+
await integration.processEvent(firstEvent, {}, client);
961+
expect(firstEvent.measurements).toBeUndefined();
962+
963+
// Second transaction should be skipped (appStartDataFlushed = true)
964+
mockAppStart({ cold: true });
965+
const secondEvent = getMinimalTransactionEvent();
966+
secondEvent.contexts!.trace!.span_id = '456';
967+
(integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(secondEvent.contexts?.trace?.span_id);
968+
969+
const actualSecondEvent = await integration.processEvent(secondEvent, {}, client);
970+
expect((actualSecondEvent as TransactionEvent).measurements).toBeUndefined();
971+
// fetchNativeAppStart should only be called once — the second event was skipped
972+
expect(NATIVE.fetchNativeAppStart).toHaveBeenCalledTimes(1);
973+
});
974+
975+
it('Sets appStartDataFlushed when has_fetched is true to prevent wasteful retries', async () => {
976+
mockFunction(NATIVE.fetchNativeAppStart).mockResolvedValue({
977+
type: 'cold',
978+
has_fetched: true,
979+
spans: [],
980+
});
981+
982+
const integration = appStartIntegration();
983+
const client = new TestClient(getDefaultTestClientOptions());
984+
985+
const firstEvent = getMinimalTransactionEvent();
986+
(integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(firstEvent.contexts?.trace?.span_id);
987+
988+
await integration.processEvent(firstEvent, {}, client);
989+
990+
// Second transaction should be skipped (appStartDataFlushed = true)
991+
mockAppStart({ cold: true });
992+
const secondEvent = getMinimalTransactionEvent();
993+
secondEvent.contexts!.trace!.span_id = '456';
994+
(integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(secondEvent.contexts?.trace?.span_id);
995+
996+
const actualSecondEvent = await integration.processEvent(secondEvent, {}, client);
997+
expect((actualSecondEvent as TransactionEvent).measurements).toBeUndefined();
998+
});
999+
1000+
it('Sets appStartDataFlushed when app start end timestamp is before app start timestamp', async () => {
1001+
mockAppStart({ cold: true, appStartEndTimestampMs: Date.now() - 1000 });
1002+
1003+
const integration = appStartIntegration();
1004+
const client = new TestClient(getDefaultTestClientOptions());
1005+
1006+
const firstEvent = getMinimalTransactionEvent();
1007+
(integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(firstEvent.contexts?.trace?.span_id);
1008+
1009+
await integration.processEvent(firstEvent, {}, client);
1010+
expect(firstEvent.measurements).toBeUndefined();
1011+
1012+
// Second transaction should be skipped (appStartDataFlushed = true)
1013+
mockAppStart({ cold: true });
1014+
const secondEvent = getMinimalTransactionEvent();
1015+
secondEvent.contexts!.trace!.span_id = '456';
1016+
(integration as AppStartIntegrationTest).setFirstStartedActiveRootSpanId(secondEvent.contexts?.trace?.span_id);
1017+
1018+
const actualSecondEvent = await integration.processEvent(secondEvent, {}, client);
1019+
expect((actualSecondEvent as TransactionEvent).measurements).toBeUndefined();
1020+
});
8971021
});
8981022
});
8991023

0 commit comments

Comments
 (0)