From 3c07adbd58532cccfb451703dcb28c38cc0690cf Mon Sep 17 00:00:00 2001 From: Antonis Lilis Date: Fri, 13 Mar 2026 15:31:02 +0100 Subject: [PATCH 1/3] fix(tracing): Fix native frames measurements dropped for idle transactions The NativeFrames integration was dropping transaction-level frame measurements (frames_total, frames_slow, frames_frozen) for all idle transactions because the fallback child span end frames were either unavailable or had mismatched timestamps when processEvent ran. Three issues fixed: - Race condition: child span end frames stored after async awaits, so processEvent could run before data was available. Now stores a Promise immediately before any awaits. - Timestamp mismatch: used wall-clock time (timestampInSeconds) instead of actual span timestamp (spanToJSON), causing isClose check to fail when comparing against the trimmed event.timestamp. - Concurrent transaction interference: single global variable overwritten by any transaction's child spans. Now scoped per root span using AsyncExpiringMap. Co-Authored-By: Claude Opus 4.6 --- .../js/tracing/integrations/nativeFrames.ts | 56 ++++++++++------ .../tracing/integrations/nativeframes.test.ts | 65 +++++++++++++++++++ 2 files changed, 102 insertions(+), 19 deletions(-) diff --git a/packages/core/src/js/tracing/integrations/nativeFrames.ts b/packages/core/src/js/tracing/integrations/nativeFrames.ts index d46b350954..e8f266e929 100644 --- a/packages/core/src/js/tracing/integrations/nativeFrames.ts +++ b/packages/core/src/js/tracing/integrations/nativeFrames.ts @@ -1,5 +1,5 @@ import type { Client, Event, Integration, Measurements, MeasurementUnit, Span } from '@sentry/core'; -import { debug, timestampInSeconds } from '@sentry/core'; +import { debug, getRootSpan, spanToJSON, timestampInSeconds } from '@sentry/core'; import type { NativeFramesResponse } from '../../NativeRNSentry'; import { AsyncExpiringMap } from '../../utils/AsyncExpiringMap'; import { isRootSpan } from '../../utils/span'; @@ -58,8 +58,11 @@ export const createNativeFramesIntegrations = (enable: boolean | undefined): Int * and frame data (frames.total, frames.slow, frames.frozen) onto all spans. */ export const nativeFramesIntegration = (): Integration => { - /** The native frames at the finish time of the most recent span. */ - let _lastChildSpanEndFrames: NativeFramesResponseWithTimestamp | null = null; + /** The native frames at the finish time of the most recent child span, keyed by root span ID. + * Stores promises so the data is available for processEvent to await even before + * the async native bridge call completes. */ + const _lastChildSpanEndFramesByRootSpan: AsyncExpiringMap = + new AsyncExpiringMap({ ttl: START_FRAMES_TIMEOUT_MS }); const _spanToNativeFramesAtStartMap: AsyncExpiringMap = new AsyncExpiringMap({ ttl: START_FRAMES_TIMEOUT_MS, }); @@ -109,7 +112,6 @@ export const nativeFramesIntegration = (): Integration => { * produce incorrect deltas. The native bridge calls are async and non-blocking. */ const fetchEndFramesForSpan = async (span: Span): Promise => { - const timestamp = timestampInSeconds(); const spanId = span.spanContext().spanId; const hasStartFrames = _spanToNativeFramesAtStartMap.has(spanId); @@ -118,8 +120,31 @@ export const nativeFramesIntegration = (): Integration => { return; } + // For child spans: immediately store a promise for fallback end frames before any awaits, + // so processEvent can find and await it even if this async function hasn't completed yet. + // Uses the actual span timestamp (not wall-clock time) so it matches the trimmed event.timestamp + // for idle transactions. Scoped per root span to avoid concurrent transaction interference. + let childEndFramesPromise: Promise | undefined; + if (!isRootSpan(span)) { + const rootSpanId = getRootSpan(span).spanContext().spanId; + const spanTimestamp = spanToJSON(span).timestamp; + if (spanTimestamp) { + childEndFramesPromise = fetchNativeFrames(); + _lastChildSpanEndFramesByRootSpan.set( + rootSpanId, + childEndFramesPromise + .then(frames => ({ timestamp: spanTimestamp, nativeFrames: frames })) + .then(undefined, error => { + debug.log(`[${INTEGRATION_NAME}] Error while fetching child span end frames.`, error); + return null; + }), + ); + } + } + if (isRootSpan(span)) { // Root spans: Store end frames for transaction measurements (backward compatibility) + const timestamp = timestampInSeconds(); debug.log(`[${INTEGRATION_NAME}] Fetch frames for root span end (${spanId}).`); _spanToNativeFramesAtEndMap.set( spanId, @@ -147,10 +172,10 @@ export const nativeFramesIntegration = (): Integration => { return; } - // NOTE: For root spans, this is the second call to fetchNativeFrames() for the same span. + // For child spans, reuse the already-kicked-off promise to avoid a redundant native bridge call. + // For root spans, this is the second call to fetchNativeFrames() for the same span. // The calls are very close together (microseconds apart), so inconsistency is minimal. - // Future optimization: reuse the first call's promise to avoid redundant native bridge call. - const endFrames = await fetchNativeFrames(); + const endFrames = childEndFramesPromise ? await childEndFramesPromise : await fetchNativeFrames(); // Calculate deltas const totalFrames = endFrames.totalFrames - startFrames.totalFrames; @@ -166,14 +191,6 @@ export const nativeFramesIntegration = (): Integration => { `[${INTEGRATION_NAME}] Attached frame data to span ${spanId}: total=${totalFrames}, slow=${slowFrames}, frozen=${frozenFrames}`, ); } - - // Update last child span end frames for root span fallback logic - if (!isRootSpan(span)) { - _lastChildSpanEndFrames = { - timestamp, - nativeFrames: endFrames, - }; - } } catch (error) { debug.log(`[${INTEGRATION_NAME}] Error while capturing end frames for span ${spanId}.`, error); } @@ -202,17 +219,18 @@ export const nativeFramesIntegration = (): Integration => { } const endFrames = await _spanToNativeFramesAtEndMap.pop(spanId); + const lastChildFrames = await _lastChildSpanEndFramesByRootSpan.pop(spanId); let finalEndFrames: NativeFramesResponse | undefined; if (endFrames && isClose(endFrames.timestamp, event.timestamp)) { // Must be in the margin of error of the actual transaction finish time (finalEndTimestamp) debug.log(`[${INTEGRATION_NAME}] Using frames from root span end (spanId, ${spanId}).`); finalEndFrames = endFrames.nativeFrames; - } else if (_lastChildSpanEndFrames && isClose(_lastChildSpanEndFrames.timestamp, event.timestamp)) { - // Fallback to the last span finish if it is within the margin of error of the actual finish timestamp. - // This should be the case for trimEnd. + } else if (lastChildFrames && isClose(lastChildFrames.timestamp, event.timestamp)) { + // Fallback to the last child span finish if it is within the margin of error of the actual finish timestamp. + // This handles idle transactions where event.timestamp is trimmed to the last child span's end time. debug.log(`[${INTEGRATION_NAME}] Using native frames from last child span end (spanId, ${spanId}).`); - finalEndFrames = _lastChildSpanEndFrames.nativeFrames; + finalEndFrames = lastChildFrames.nativeFrames; } else { debug.warn( `[${INTEGRATION_NAME}] Frames were collected within larger than margin of error delay for spanId (${spanId}). Dropping the inaccurate values.`, diff --git a/packages/core/test/tracing/integrations/nativeframes.test.ts b/packages/core/test/tracing/integrations/nativeframes.test.ts index 28c257b010..db92174399 100644 --- a/packages/core/test/tracing/integrations/nativeframes.test.ts +++ b/packages/core/test/tracing/integrations/nativeframes.test.ts @@ -332,6 +332,71 @@ describe('NativeFramesInstrumentation', () => { expect(childSpan!.data).not.toHaveProperty('frames.frozen'); }); + it('falls back to last child span end frames when root span end timestamp does not match event timestamp (idle transaction trim)', async () => { + // Simulate idle transaction trimming: an event processor before NativeFrames shifts + // event.timestamp back to the child span's end time. This makes the root span's end frames + // timestamp (captured at idle timeout) no longer match within the 50ms margin of error, + // forcing processEvent to fall back to the child span's end frames. + let childEndTimestamp: number | undefined; + asyncProcessorBeforeNativeFrames = async (event: Event) => { + if (event.timestamp && childEndTimestamp) { + event.timestamp = childEndTimestamp; // Trim to child span end time (simulates idle trimEnd) + } + return event; + }; + + const rootStartFrames = { totalFrames: 100, slowFrames: 10, frozenFrames: 5 }; + const childStartFrames = { totalFrames: 110, slowFrames: 11, frozenFrames: 6 }; + const childEndFrames = { totalFrames: 160, slowFrames: 16, frozenFrames: 8 }; + const rootEndFrames = { totalFrames: 200, slowFrames: 20, frozenFrames: 10 }; + + mockFunction(NATIVE.fetchNativeFrames) + .mockResolvedValueOnce(rootStartFrames) // root span start + .mockResolvedValueOnce(childStartFrames) // child span start + .mockResolvedValueOnce(childEndFrames) // child span end (fallback + span attributes) + .mockResolvedValueOnce(rootEndFrames) // root span end (stored in endMap) + .mockResolvedValueOnce(rootEndFrames); // root span end (for span attributes) + + await startSpan({ name: 'idle-transaction' }, async () => { + startSpan({ name: 'child-activity' }, childSpan => { + // Child span ends here at current mock time + childEndTimestamp = Date.now() / 1000; + }); + await Promise.resolve(); // Flush frame captures + await Promise.resolve(); + await Promise.resolve(); + + // Advance time to simulate idle timeout gap (1 second > 50ms margin) + global.Date.now = jest.fn(() => mockDate.getTime() + 1000); + // Root span ends here at the advanced time + }); + + await jest.runOnlyPendingTimersAsync(); + await client.flush(); + + // The root span end frames timestamp won't match event.timestamp (off by 1s > 50ms margin), + // so processEvent falls back to the child span end frames. + // measurements = childEndFrames - rootStartFrames + expect(client.event!).toEqual( + expect.objectContaining>({ + measurements: expect.objectContaining({ + frames_total: { + value: 60, // 160 - 100 + unit: 'none', + }, + frames_slow: { + value: 6, // 16 - 10 + unit: 'none', + }, + frames_frozen: { + value: 3, // 8 - 5 + unit: 'none', + }, + }), + }), + ); + }); + it('attaches frame data to multiple child spans', async () => { const rootStartFrames = { totalFrames: 100, slowFrames: 10, frozenFrames: 5 }; const child1StartFrames = { totalFrames: 100, slowFrames: 10, frozenFrames: 5 }; From 32f98500740ccbb5464ae2fda0fd3e5e5431e5d6 Mon Sep 17 00:00:00 2001 From: Antonis Lilis Date: Fri, 13 Mar 2026 15:36:13 +0100 Subject: [PATCH 2/3] docs: Add changelog entry for native frames race condition fix Co-Authored-By: Claude Opus 4.6 --- CHANGELOG.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index add9b2b74e..bc2b4cc5ee 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,12 @@ > make sure you follow our [migration guide](https://docs.sentry.io/platforms/react-native/migration/) first. +## Unreleased + +### Fixes + +- Fix native frames measurements being dropped due to race condition ([#5813](https://github.com/getsentry/sentry-react-native/pull/5813)) + ## 8.4.0 ### Fixes From ff103c38f21853d9378941efee15abb64be469c5 Mon Sep 17 00:00:00 2001 From: Antonis Lilis Date: Fri, 13 Mar 2026 15:52:12 +0100 Subject: [PATCH 3/3] fix(lint): Remove unused childSpan parameter in test Co-Authored-By: Claude Opus 4.6 --- packages/core/test/tracing/integrations/nativeframes.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/core/test/tracing/integrations/nativeframes.test.ts b/packages/core/test/tracing/integrations/nativeframes.test.ts index db92174399..b1336251ad 100644 --- a/packages/core/test/tracing/integrations/nativeframes.test.ts +++ b/packages/core/test/tracing/integrations/nativeframes.test.ts @@ -358,7 +358,7 @@ describe('NativeFramesInstrumentation', () => { .mockResolvedValueOnce(rootEndFrames); // root span end (for span attributes) await startSpan({ name: 'idle-transaction' }, async () => { - startSpan({ name: 'child-activity' }, childSpan => { + startSpan({ name: 'child-activity' }, () => { // Child span ends here at current mock time childEndTimestamp = Date.now() / 1000; });