Skip to content

Commit a699d13

Browse files
antonislucas-zimerman
antonis
and
lucas-zimerman
authored
fix(ttid/ttfd): Add frame data to ttid/ttfd spans (#5419)
* fix(ttid/ttfd): Add frame data to ttid/ttfd spans * Update changelog * Fix lint issues * Prevent memory leak * Fix test feedback * Seer review feedback * fix potential race condition * Imrove log readability Co-authored-by: LucasZF <lucas-zimerman1@hotmail.com> * Update log for redability Co-authored-by: LucasZF <lucas-zimerman1@hotmail.com> --------- Co-authored-by: LucasZF <lucas-zimerman1@hotmail.com>
1 parent 6416d6c commit a699d13

File tree

3 files changed

+468
-22
lines changed

3 files changed

+468
-22
lines changed

‎CHANGELOG.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@
1212

1313
- Adds Metrics Beta ([#5402](https://github.com/getsentry/sentry-react-native/pull/5402))
1414
- Improves Expo Router integration to optionally include full paths to components instead of just component names ([#5414](https://github.com/getsentry/sentry-react-native/pull/5414))
15+
- Report slow and frozen frames as TTID/TTFD span data ([#5419](https://github.com/getsentry/sentry-react-native/pull/5419))
1516

1617
### Fixes
1718

‎packages/core/src/js/tracing/timetodisplay.tsx‎

Lines changed: 229 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,25 @@
1-
import type { Span,StartSpanOptions } from '@sentry/core';
1+
/* eslint-disable max-lines */
2+
import type { Span, StartSpanOptions } from '@sentry/core';
23
import { debug, fill, getActiveSpan, getSpanDescendants, SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN, SPAN_STATUS_ERROR, SPAN_STATUS_OK, spanToJSON, startInactiveSpan } from '@sentry/core';
34
import * as React from 'react';
45
import { useState } from 'react';
6+
import type { NativeFramesResponse } from '../NativeRNSentry';
7+
import { NATIVE } from '../wrapper';
58
import { SPAN_ORIGIN_AUTO_UI_TIME_TO_DISPLAY, SPAN_ORIGIN_MANUAL_UI_TIME_TO_DISPLAY } from './origin';
69
import { getRNSentryOnDrawReporter } from './timetodisplaynative';
710
import { setSpanDurationAsMeasurement, setSpanDurationAsMeasurementOnSpan } from './utils';
811

12+
/**
13+
* Timeout for fetching native frames
14+
*/
15+
const FETCH_FRAMES_TIMEOUT_MS = 2_000;
16+
17+
/**
18+
* Maximum time to keep frame data in memory before cleaning up.
19+
* Prevents memory leaks for spans that never complete.
20+
*/
21+
const FRAME_DATA_CLEANUP_TIMEOUT_MS = 60_000;
22+
923
/**
1024
* Flags of active spans with manual initial display.
1125
*/
@@ -16,6 +30,20 @@ export const manualInitialDisplaySpans = new WeakMap<Span, true>();
1630
*/
1731
const fullDisplayBeforeInitialDisplay = new WeakMap<Span, true>();
1832

33+
interface FrameDataForSpan {
34+
startFrames: NativeFramesResponse | null;
35+
endFrames: NativeFramesResponse | null;
36+
cleanupTimeout?: ReturnType<typeof setTimeout>;
37+
}
38+
39+
/**
40+
* Stores frame data for in-flight TTID/TTFD spans.
41+
* Entries are automatically cleaned up when spans end (in captureEndFramesAndAttachToSpan finally block).
42+
* As a safety mechanism, entries are also cleaned up after FRAME_DATA_CLEANUP_TIMEOUT_MS
43+
* to prevent memory leaks for spans that never complete.
44+
*/
45+
const spanFrameDataMap = new Map<string, FrameDataForSpan>();
46+
1947
export type TimeToDisplayProps = {
2048
children?: React.ReactNode;
2149
record?: boolean;
@@ -105,6 +133,10 @@ export function startTimeToInitialDisplaySpan(
105133
return undefined;
106134
}
107135

136+
captureStartFramesForSpan(initialDisplaySpan.spanContext().spanId).catch((error) => {
137+
debug.log(`[TimeToDisplay] Failed to capture start frames for initial display span (${initialDisplaySpan.spanContext().spanId}).`, error);
138+
});
139+
108140
if (options?.isAutoInstrumented) {
109141
initialDisplaySpan.setAttribute(SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN, SPAN_ORIGIN_AUTO_UI_TIME_TO_DISPLAY);
110142
} else {
@@ -161,13 +193,26 @@ export function startTimeToFullDisplaySpan(
161193
return undefined;
162194
}
163195

196+
captureStartFramesForSpan(fullDisplaySpan.spanContext().spanId).catch((error) => {
197+
debug.log(`[TimeToDisplay] Failed to capture start frames for full display span (${fullDisplaySpan.spanContext().spanId}).`, error);
198+
});
199+
164200
const timeout = setTimeout(() => {
165201
if (spanToJSON(fullDisplaySpan).timestamp) {
166202
return;
167203
}
168204
fullDisplaySpan.setStatus({ code: SPAN_STATUS_ERROR, message: 'deadline_exceeded' });
169-
fullDisplaySpan.end(spanToJSON(initialDisplaySpan).timestamp);
170-
setSpanDurationAsMeasurement('time_to_full_display', fullDisplaySpan);
205+
206+
captureEndFramesAndAttachToSpan(fullDisplaySpan).then(() => {
207+
debug.log(`[TimeToDisplay] span ${fullDisplaySpan.spanContext().spanId} updated with frame data.`);
208+
fullDisplaySpan.end(spanToJSON(initialDisplaySpan).timestamp);
209+
setSpanDurationAsMeasurement('time_to_full_display', fullDisplaySpan);
210+
}).catch(() => {
211+
debug.warn(`[TimeToDisplay] Failed to capture end frames for full display span (${fullDisplaySpan.spanContext().spanId}).`);
212+
fullDisplaySpan.end(spanToJSON(initialDisplaySpan).timestamp);
213+
setSpanDurationAsMeasurement('time_to_full_display', fullDisplaySpan);
214+
});
215+
171216
debug.warn('[TimeToDisplay] Full display span deadline_exceeded.');
172217
}, options.timeoutMs);
173218

@@ -220,17 +265,31 @@ export function updateInitialDisplaySpan(
220265
return;
221266
}
222267

223-
span.end(frameTimestampSeconds);
224-
span.setStatus({ code: SPAN_STATUS_OK });
225-
debug.log(`[TimeToDisplay] ${spanToJSON(span).description} span updated with end timestamp.`);
268+
captureEndFramesAndAttachToSpan(span).then(() => {
269+
span.end(frameTimestampSeconds);
270+
span.setStatus({ code: SPAN_STATUS_OK });
271+
debug.log(`[TimeToDisplay] ${spanToJSON(span).description} span updated with end timestamp and frame data.`);
272+
273+
if (fullDisplayBeforeInitialDisplay.has(activeSpan)) {
274+
fullDisplayBeforeInitialDisplay.delete(activeSpan);
275+
debug.log(`[TimeToDisplay] Updating full display with initial display (${span.spanContext().spanId}) end.`);
276+
updateFullDisplaySpan(frameTimestampSeconds, span);
277+
}
226278

227-
if (fullDisplayBeforeInitialDisplay.has(activeSpan)) {
228-
fullDisplayBeforeInitialDisplay.delete(activeSpan);
229-
debug.log(`[TimeToDisplay] Updating full display with initial display (${span.spanContext().spanId}) end.`);
230-
updateFullDisplaySpan(frameTimestampSeconds, span);
231-
}
279+
setSpanDurationAsMeasurementOnSpan('time_to_initial_display', span, activeSpan);
280+
}).catch((error) => {
281+
debug.log('[TimeToDisplay] Failed to capture frame data for initial display span.', error);
282+
span.end(frameTimestampSeconds);
283+
span.setStatus({ code: SPAN_STATUS_OK });
284+
285+
if (fullDisplayBeforeInitialDisplay.has(activeSpan)) {
286+
fullDisplayBeforeInitialDisplay.delete(activeSpan);
287+
debug.log(`[TimeToDisplay] Updating full display with initial display (${span.spanContext().spanId}) end.`);
288+
updateFullDisplaySpan(frameTimestampSeconds, span);
289+
}
232290

233-
setSpanDurationAsMeasurementOnSpan('time_to_initial_display', span, activeSpan);
291+
setSpanDurationAsMeasurementOnSpan('time_to_initial_display', span, activeSpan);
292+
});
234293
}
235294

236295
function updateFullDisplaySpan(frameTimestampSeconds: number, passedInitialDisplaySpan?: Span): void {
@@ -263,17 +322,26 @@ function updateFullDisplaySpan(frameTimestampSeconds: number, passedInitialDispl
263322
return;
264323
}
265324

266-
if (initialDisplayEndTimestamp > frameTimestampSeconds) {
267-
debug.warn('[TimeToDisplay] Using initial display end. Full display end frame timestamp is before initial display end.');
268-
span.end(initialDisplayEndTimestamp);
269-
} else {
270-
span.end(frameTimestampSeconds);
271-
}
325+
captureEndFramesAndAttachToSpan(span).then(() => {
326+
const endTimestamp = initialDisplayEndTimestamp > frameTimestampSeconds ? initialDisplayEndTimestamp : frameTimestampSeconds;
272327

273-
span.setStatus({ code: SPAN_STATUS_OK });
274-
debug.log(`[TimeToDisplay] ${spanJSON.description} (${spanJSON.span_id}) span updated with end timestamp.`);
328+
if (initialDisplayEndTimestamp > frameTimestampSeconds) {
329+
debug.warn('[TimeToDisplay] Using initial display end. Full display end frame timestamp is before initial display end.');
330+
}
331+
332+
span.end(endTimestamp);
333+
span.setStatus({ code: SPAN_STATUS_OK });
334+
debug.log(`[TimeToDisplay] span ${spanJSON.description} (${spanJSON.span_id}) updated with end timestamp and frame data.`);
335+
336+
setSpanDurationAsMeasurement('time_to_full_display', span);
337+
}).catch((error) => {
338+
debug.log('[TimeToDisplay] Failed to capture frame data for full display span.', error);
339+
const endTimestamp = initialDisplayEndTimestamp > frameTimestampSeconds ? initialDisplayEndTimestamp : frameTimestampSeconds;
275340

276-
setSpanDurationAsMeasurement('time_to_full_display', span);
341+
span.end(endTimestamp);
342+
span.setStatus({ code: SPAN_STATUS_OK });
343+
setSpanDurationAsMeasurement('time_to_full_display', span);
344+
});
277345
}
278346

279347
/**
@@ -327,3 +395,143 @@ function createTimeToDisplay({
327395
TimeToDisplayWrapper.displayName = 'TimeToDisplayWrapper';
328396
return TimeToDisplayWrapper;
329397
}
398+
399+
/**
400+
* Attaches frame data to a span's data object.
401+
*/
402+
function attachFrameDataToSpan(span: Span, startFrames: NativeFramesResponse, endFrames: NativeFramesResponse): void {
403+
const totalFrames = endFrames.totalFrames - startFrames.totalFrames;
404+
const slowFrames = endFrames.slowFrames - startFrames.slowFrames;
405+
const frozenFrames = endFrames.frozenFrames - startFrames.frozenFrames;
406+
407+
if (totalFrames <= 0 && slowFrames <= 0 && frozenFrames <= 0) {
408+
debug.warn(`[TimeToDisplay] Detected zero slow or frozen frames. Not adding measurements to span (${span.spanContext().spanId}).`);
409+
return;
410+
}
411+
span.setAttribute('frames.total', totalFrames);
412+
span.setAttribute('frames.slow', slowFrames);
413+
span.setAttribute('frames.frozen', frozenFrames);
414+
415+
debug.log('[TimeToDisplay] Attached frame data to span.', {
416+
spanId: span.spanContext().spanId,
417+
frameData: {
418+
total: totalFrames,
419+
slow: slowFrames,
420+
frozen: frozenFrames,
421+
},
422+
});
423+
}
424+
425+
/**
426+
* Captures start frames for a time-to-display span
427+
*/
428+
async function captureStartFramesForSpan(spanId: string): Promise<void> {
429+
if (!NATIVE.enableNative) {
430+
return;
431+
}
432+
433+
try {
434+
const startFrames = await fetchNativeFramesWithTimeout();
435+
436+
// Set up automatic cleanup as a safety mechanism for spans that never complete
437+
const cleanupTimeout = setTimeout(() => {
438+
const entry = spanFrameDataMap.get(spanId);
439+
if (entry) {
440+
spanFrameDataMap.delete(spanId);
441+
debug.log(`[TimeToDisplay] Cleaned up stale frame data for span ${spanId} after timeout.`);
442+
}
443+
}, FRAME_DATA_CLEANUP_TIMEOUT_MS);
444+
445+
if (!spanFrameDataMap.has(spanId)) {
446+
spanFrameDataMap.set(spanId, { startFrames: null, endFrames: null, cleanupTimeout });
447+
}
448+
449+
// Re-check after async operations - entry might have been deleted by captureEndFramesAndAttachToSpan
450+
const frameData = spanFrameDataMap.get(spanId);
451+
if (!frameData) {
452+
// Span already ended and cleaned up, cancel the cleanup timeout
453+
clearTimeout(cleanupTimeout);
454+
debug.log(`[TimeToDisplay] Span ${spanId} already ended, discarding start frames.`);
455+
return;
456+
}
457+
458+
frameData.startFrames = startFrames;
459+
frameData.cleanupTimeout = cleanupTimeout;
460+
debug.log(`[TimeToDisplay] Captured start frames for span ${spanId}.`, startFrames);
461+
} catch (error) {
462+
debug.log(`[TimeToDisplay] Failed to capture start frames for span ${spanId}.`, error);
463+
}
464+
}
465+
466+
/**
467+
* Captures end frames and attaches frame data to span
468+
*/
469+
async function captureEndFramesAndAttachToSpan(span: Span): Promise<void> {
470+
if (!NATIVE.enableNative) {
471+
return;
472+
}
473+
474+
const spanId = span.spanContext().spanId;
475+
const frameData = spanFrameDataMap.get(spanId);
476+
477+
if (!frameData?.startFrames) {
478+
debug.log(`[TimeToDisplay] No start frames found for span ${spanId}, skipping frame data collection.`);
479+
return;
480+
}
481+
482+
try {
483+
const endFrames = await fetchNativeFramesWithTimeout();
484+
frameData.endFrames = endFrames;
485+
486+
attachFrameDataToSpan(span, frameData.startFrames, endFrames);
487+
488+
debug.log(`[TimeToDisplay] Captured and attached end frames for span ${spanId}.`, endFrames);
489+
} catch (error) {
490+
debug.log(`[TimeToDisplay] Failed to capture end frames for span ${spanId}.`, error);
491+
} finally {
492+
// Clear the cleanup timeout since we're cleaning up now
493+
if (frameData.cleanupTimeout) {
494+
clearTimeout(frameData.cleanupTimeout);
495+
}
496+
spanFrameDataMap.delete(spanId);
497+
}
498+
}
499+
500+
/**
501+
* Fetches native frames with a timeout
502+
*/
503+
function fetchNativeFramesWithTimeout(): Promise<NativeFramesResponse> {
504+
return new Promise<NativeFramesResponse>((resolve, reject) => {
505+
let settled = false;
506+
507+
const timeoutId = setTimeout(() => {
508+
if (!settled) {
509+
settled = true;
510+
reject('Fetching native frames took too long. Dropping frames.');
511+
}
512+
}, FETCH_FRAMES_TIMEOUT_MS);
513+
514+
NATIVE.fetchNativeFrames()
515+
.then(value => {
516+
if (settled) {
517+
return;
518+
}
519+
clearTimeout(timeoutId);
520+
settled = true;
521+
522+
if (!value) {
523+
reject('Native frames response is null.');
524+
return;
525+
}
526+
resolve(value);
527+
})
528+
.then(undefined, (error: unknown) => {
529+
if (settled) {
530+
return;
531+
}
532+
clearTimeout(timeoutId);
533+
settled = true;
534+
reject(error);
535+
});
536+
});
537+
}

0 commit comments

Comments
 (0)