Skip to content

Commit 3d745b1

Browse files
krystofwoldrichkrystofwoldrich
committed
add time to initial display tests
1 parent 7c2dad9 commit 3d745b1

File tree

7 files changed

+298
-267
lines changed

7 files changed

+298
-267
lines changed

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

Lines changed: 122 additions & 47 deletions
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,16 @@
1-
import type { Integration, SpanJSON } from '@sentry/core';
1+
import type { Event, Integration, SpanJSON } from '@sentry/core';
22
import { logger } from '@sentry/core';
3+
34
import { NATIVE } from '../../wrapper';
4-
import { createSpanJSON } from '../utils';
5+
import { UI_LOAD_FULL_DISPLAY, UI_LOAD_INITIAL_DISPLAY } from '../ops';
56
import { SPAN_ORIGIN_MANUAL_UI_TIME_TO_DISPLAY } from '../origin';
6-
import { UI_LOAD_INITIAL_DISPLAY, UI_LOAD_FULL_DISPLAY } from '../ops';
7+
import { SPAN_THREAD_NAME, SPAN_THREAD_NAME_JAVASCRIPT } from '../span';
8+
import { createSpanJSON } from '../utils';
79
export const INTEGRATION_NAME = 'TimeToDisplay';
810

11+
const TIME_TO_DISPLAY_TIMEOUT_MS = 30_000;
12+
const isDeadlineExceeded = (durationMs: number): boolean => durationMs > TIME_TO_DISPLAY_TIMEOUT_MS;
13+
914
export const timeToDisplayIntegration = (): Integration => {
1015
return {
1116
name: INTEGRATION_NAME,
@@ -29,54 +34,27 @@ export const timeToDisplayIntegration = (): Integration => {
2934
}
3035

3136
event.spans = event.spans || [];
37+
event.measurements = event.measurements || {};
3238

33-
const ttidEndTimestampSeconds = await NATIVE.popTimeToDisplayFor(`ttid-${rootSpanId}`);
34-
let ttidSpan: SpanJSON | undefined = event.spans?.find(span => span.op === UI_LOAD_INITIAL_DISPLAY);
35-
if (ttidEndTimestampSeconds) {
36-
if (ttidSpan && ttidSpan.status && ttidSpan.status !== 'ok') {
37-
ttidSpan.status = 'ok';
38-
ttidSpan.timestamp = ttidEndTimestampSeconds;
39-
logger.debug(`[${INTEGRATION_NAME}] Updated existing ttid span.`, ttidSpan);
40-
} else {
41-
ttidSpan = createSpanJSON({
42-
op: UI_LOAD_INITIAL_DISPLAY,
43-
description: 'NEW Time To Initial Display',
44-
start_timestamp: transactionStartTimestampSeconds,
45-
timestamp: ttidEndTimestampSeconds,
46-
origin: SPAN_ORIGIN_MANUAL_UI_TIME_TO_DISPLAY,
47-
parent_span_id: rootSpanId,
48-
// TODO: Add data
49-
});
50-
logger.debug(`[${INTEGRATION_NAME}] Added ttid span to transaction.`, ttidSpan);
51-
event.spans?.push(ttidSpan);
52-
}
39+
const ttidSpan = await addTimeToInitialDisplay({ event, rootSpanId, transactionStartTimestampSeconds });
40+
const ttfdSpan = await addTimeToFullDisplay({ event, rootSpanId, transactionStartTimestampSeconds, ttidSpan });
41+
42+
if (ttidSpan && ttidSpan.start_timestamp && ttidSpan.timestamp) {
43+
event.measurements['time_to_initial_display'] = {
44+
value: (ttidSpan.timestamp - ttidSpan.start_timestamp) * 1000,
45+
unit: 'millisecond',
46+
};
5347
}
5448

55-
// TODO: Should we trim it to 30s a.k.a max timeout?
56-
const ttfdEndTimestampSeconds = await NATIVE.popTimeToDisplayFor(`ttfd-${rootSpanId}`);
57-
let ttfdSpan: SpanJSON | undefined;
58-
if (ttfdEndTimestampSeconds && ttidSpan) {
59-
ttfdSpan = event.spans?.find(span => span.op === UI_LOAD_FULL_DISPLAY);
60-
const ttfdAdjustedEndTimestampSeconds =
61-
ttidSpan?.timestamp && ttfdEndTimestampSeconds < ttidSpan.timestamp
62-
? ttidSpan.timestamp
63-
: ttfdEndTimestampSeconds;
64-
if (ttfdSpan && ttfdSpan.status && ttfdSpan.status !== 'ok') {
65-
ttfdSpan.status = 'ok';
66-
ttfdSpan.timestamp = ttfdAdjustedEndTimestampSeconds;
67-
logger.debug(`[${INTEGRATION_NAME}] Updated existing ttfd span.`, ttfdSpan);
49+
if (ttfdSpan && ttfdSpan.start_timestamp && ttfdSpan.timestamp) {
50+
const durationMs = (ttfdSpan.timestamp - ttfdSpan.start_timestamp) * 1000;
51+
if (isDeadlineExceeded(durationMs)) {
52+
event.measurements['time_to_full_display'] = event.measurements['time_to_initial_display'];
6853
} else {
69-
ttfdSpan = createSpanJSON({
70-
op: UI_LOAD_FULL_DISPLAY,
71-
description: 'Time To Full Display',
72-
start_timestamp: transactionStartTimestampSeconds,
73-
timestamp: ttfdAdjustedEndTimestampSeconds,
74-
origin: SPAN_ORIGIN_MANUAL_UI_TIME_TO_DISPLAY,
75-
parent_span_id: rootSpanId,
76-
// TODO: Add data
77-
});
78-
logger.debug(`[${INTEGRATION_NAME}] Added ttfd span to transaction.`, ttfdSpan);
79-
event.spans?.push(ttfdSpan);
54+
event.measurements['time_to_full_display'] = {
55+
value: durationMs,
56+
unit: 'millisecond',
57+
};
8058
}
8159
}
8260

@@ -93,3 +71,100 @@ export const timeToDisplayIntegration = (): Integration => {
9371
},
9472
};
9573
};
74+
75+
async function addTimeToInitialDisplay({
76+
event,
77+
rootSpanId,
78+
transactionStartTimestampSeconds,
79+
}: {
80+
event: Event;
81+
rootSpanId: string;
82+
transactionStartTimestampSeconds: number;
83+
}): Promise<SpanJSON | undefined> {
84+
const ttidEndTimestampSeconds = await NATIVE.popTimeToDisplayFor(`ttid-${rootSpanId}`);
85+
86+
let ttidSpan: SpanJSON | undefined = event.spans?.find(span => span.op === UI_LOAD_INITIAL_DISPLAY);
87+
88+
if (ttidSpan && (ttidSpan.status === undefined || ttidSpan.status === 'ok') && !ttidEndTimestampSeconds) {
89+
logger.debug(`[${INTEGRATION_NAME}] Ttid span already exists and is ok.`, ttidSpan);
90+
return ttidSpan;
91+
}
92+
93+
if (!ttidEndTimestampSeconds) {
94+
logger.debug(`[${INTEGRATION_NAME}] No ttid end timestamp found for span ${rootSpanId}.`);
95+
return undefined;
96+
}
97+
98+
if (ttidSpan && ttidSpan.status && ttidSpan.status !== 'ok') {
99+
ttidSpan.status = 'ok';
100+
ttidSpan.timestamp = ttidEndTimestampSeconds;
101+
logger.debug(`[${INTEGRATION_NAME}] Updated existing ttid span.`, ttidSpan);
102+
return ttidSpan;
103+
}
104+
105+
ttidSpan = createSpanJSON({
106+
op: UI_LOAD_INITIAL_DISPLAY,
107+
description: 'Time To Initial Display',
108+
start_timestamp: transactionStartTimestampSeconds,
109+
timestamp: ttidEndTimestampSeconds,
110+
origin: SPAN_ORIGIN_MANUAL_UI_TIME_TO_DISPLAY,
111+
parent_span_id: rootSpanId,
112+
data: {
113+
[SPAN_THREAD_NAME]: SPAN_THREAD_NAME_JAVASCRIPT,
114+
},
115+
});
116+
logger.debug(`[${INTEGRATION_NAME}] Added ttid span to transaction.`, ttidSpan);
117+
event.spans.push(ttidSpan);
118+
return ttidSpan;
119+
}
120+
121+
async function addTimeToFullDisplay({
122+
event,
123+
rootSpanId,
124+
transactionStartTimestampSeconds,
125+
ttidSpan,
126+
}: {
127+
event: Event;
128+
rootSpanId: string;
129+
transactionStartTimestampSeconds: number;
130+
ttidSpan: SpanJSON | undefined;
131+
}): Promise<SpanJSON | undefined> {
132+
const ttfdEndTimestampSeconds = await NATIVE.popTimeToDisplayFor(`ttfd-${rootSpanId}`);
133+
134+
if (!ttidSpan || !ttfdEndTimestampSeconds) {
135+
return undefined;
136+
}
137+
138+
let ttfdSpan = event.spans?.find(span => span.op === UI_LOAD_FULL_DISPLAY);
139+
140+
let ttfdAdjustedEndTimestampSeconds = ttfdEndTimestampSeconds;
141+
const ttfdIsBeforeTtid = ttidSpan?.timestamp && ttfdEndTimestampSeconds < ttidSpan.timestamp;
142+
if (ttfdIsBeforeTtid) {
143+
ttfdAdjustedEndTimestampSeconds = ttidSpan.timestamp;
144+
}
145+
146+
const durationMs = (ttfdAdjustedEndTimestampSeconds - transactionStartTimestampSeconds) * 1000;
147+
148+
if (ttfdSpan && ttfdSpan.status && ttfdSpan.status !== 'ok') {
149+
ttfdSpan.status = 'ok';
150+
ttfdSpan.timestamp = ttfdAdjustedEndTimestampSeconds;
151+
logger.debug(`[${INTEGRATION_NAME}] Updated existing ttfd span.`, ttfdSpan);
152+
return ttfdSpan;
153+
}
154+
155+
ttfdSpan = createSpanJSON({
156+
status: isDeadlineExceeded(durationMs) ? 'deadline_exceeded' : 'ok',
157+
op: UI_LOAD_FULL_DISPLAY,
158+
description: 'Time To Full Display',
159+
start_timestamp: transactionStartTimestampSeconds,
160+
timestamp: ttfdAdjustedEndTimestampSeconds,
161+
origin: SPAN_ORIGIN_MANUAL_UI_TIME_TO_DISPLAY,
162+
parent_span_id: rootSpanId,
163+
data: {
164+
[SPAN_THREAD_NAME]: SPAN_THREAD_NAME_JAVASCRIPT,
165+
},
166+
});
167+
logger.debug(`[${INTEGRATION_NAME}] Added ttfd span to transaction.`, ttfdSpan);
168+
event.spans.push(ttfdSpan);
169+
return ttfdSpan;
170+
}

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

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -88,6 +88,8 @@ function TimeToDisplay(props: {
8888
* Starts a new span for the initial display.
8989
*
9090
* Returns current span if already exists in the currently active span.
91+
*
92+
* @deprecated Use `<TimeToInitialDisplay record={boolean}/>` component instead.
9193
*/
9294
export function startTimeToInitialDisplaySpan(
9395
options?: Omit<StartSpanOptions, 'op' | 'name'> & {
@@ -132,6 +134,8 @@ export function startTimeToInitialDisplaySpan(
132134
* Starts a new span for the full display.
133135
*
134136
* Returns current span if already exists in the currently active span.
137+
*
138+
* @deprecated Use `<TimeToFullDisplay record={boolean}/>` component instead.
135139
*/
136140
export function startTimeToFullDisplaySpan(
137141
options: Omit<StartSpanOptions, 'op' | 'name'> & {

‎packages/core/test/mockWrapper.ts‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -60,7 +60,7 @@ const NATIVE: MockInterface<NativeType> = {
6060
crashedLastRun: jest.fn(),
6161
getNewScreenTimeToDisplay: jest.fn().mockResolvedValue(42),
6262
getDataFromUri: jest.fn(),
63-
popTimeToDisplayFor: jest.fn().mockResolvedValue(42),
63+
popTimeToDisplayFor: jest.fn(),
6464
};
6565

6666
NATIVE.isNativeAvailable.mockReturnValue(true);
@@ -85,6 +85,7 @@ NATIVE.initNativeReactNavigationNewFrameTracking.mockReturnValue(Promise.resolve
8585
NATIVE.captureReplay.mockResolvedValue(null);
8686
NATIVE.getCurrentReplayId.mockReturnValue(null);
8787
NATIVE.crashedLastRun.mockResolvedValue(false);
88+
NATIVE.popTimeToDisplayFor.mockResolvedValue(null);
8889

8990
export const getRNSentryModule = jest.fn();
9091

‎packages/core/test/testutils.ts‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -62,6 +62,10 @@ export const createMockTransport = (): MockInterface<Transport> => {
6262
};
6363
};
6464

65+
export const nowInSeconds = (): number => {
66+
return Date.now() / 1000;
67+
};
68+
6569
export const secondAgoTimestampMs = (): number => {
6670
return new Date(Date.now() - 1000).getTime();
6771
};

‎packages/core/test/tracing/mockedtimetodisplaynative.tsx‎

Lines changed: 24 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,26 +1,43 @@
11
import * as React from 'react';
22
import { View } from 'react-native';
33

4-
import type { RNSentryOnDrawNextFrameEvent, RNSentryOnDrawReporterProps } from '../../src/js/tracing/timetodisplaynative.types';
4+
import type { RNSentryOnDrawReporterProps } from '../../src/js/tracing/timetodisplaynative.types';
5+
import { NATIVE } from '../mockWrapper';
56

67
export let nativeComponentExists = true;
78

89
export function setMockedNativeComponentExists(value: boolean): void {
910
nativeComponentExists = value;
1011
}
1112

12-
export let mockedOnDrawNextFrame: (event: { nativeEvent: RNSentryOnDrawNextFrameEvent }) => void;
13+
/**
14+
* {
15+
* [spanId]: timestampInSeconds,
16+
* }
17+
*/
18+
export function mockRecordedTimeToDisplay({ ttid = {}, ttfd = {} }: { ttid?: Record<string, number>, ttfd?: Record<string, number> }): void {
19+
NATIVE.popTimeToDisplayFor.mockImplementation((key: string) => {
20+
if (key.startsWith('ttid-')) {
21+
return Promise.resolve(ttid[key.substring(5)]);
22+
} else if (key.startsWith('ttfd-')) {
23+
return Promise.resolve(ttfd[key.substring(5)]);
24+
}
25+
return Promise.resolve(undefined);
26+
});
27+
}
28+
29+
let mockedProps: RNSentryOnDrawReporterProps[] = [];
1330

14-
export function emitNativeInitialDisplayEvent(frameTimestampMs?: number): void {
15-
mockedOnDrawNextFrame({ nativeEvent: { type: 'initialDisplay', newFrameTimestampInSeconds: (frameTimestampMs || Date.now()) / 1_000 } });
31+
export function getMockedOnDrawReportedProps(): RNSentryOnDrawReporterProps[] {
32+
return mockedProps;
1633
}
1734

18-
export function emitNativeFullDisplayEvent(frameTimestampMs?: number): void {
19-
mockedOnDrawNextFrame({ nativeEvent: { type: 'fullDisplay', newFrameTimestampInSeconds: (frameTimestampMs || Date.now()) / 1_000 } });
35+
export function clearMockedOnDrawReportedProps(): void {
36+
mockedProps = [];
2037
}
2138

2239
function RNSentryOnDrawReporterMock(props: RNSentryOnDrawReporterProps): React.ReactElement {
23-
mockedOnDrawNextFrame = props.onDrawNextFrame;
40+
mockedProps.push(props);
2441
return <View />;
2542
}
2643

‎packages/core/test/tracing/reactnavigation.ttid.test.tsx‎

Lines changed: 26 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
import type { Scope, Span, SpanJSON, TransactionEvent, Transport } from '@sentry/core';
2-
import { timestampInSeconds } from '@sentry/core';
2+
import { getActiveSpan, spanToJSON, timestampInSeconds } from '@sentry/core';
33
import * as TestRenderer from '@testing-library/react-native'
44
import * as React from "react";
55

@@ -21,9 +21,10 @@ import { isHermesEnabled, notWeb } from '../../src/js/utils/environment';
2121
import { createSentryFallbackEventEmitter } from '../../src/js/utils/sentryeventemitterfallback';
2222
import { RN_GLOBAL_OBJ } from '../../src/js/utils/worldwide';
2323
import { MOCK_DSN } from '../mockDsn';
24-
import { secondInFutureTimestampMs } from '../testutils';
24+
import { nowInSeconds, secondInFutureTimestampMs } from '../testutils';
2525
import type { MockedSentryEventEmitterFallback } from '../utils/mockedSentryeventemitterfallback';
26-
import { emitNativeFullDisplayEvent, emitNativeInitialDisplayEvent } from './mockedtimetodisplaynative';
26+
import { mockRecordedTimeToDisplay } from './mockedtimetodisplaynative';
27+
// import { // mockRecordedFullDisplayAt, // mockRecordedInitialDisplayAt } from './mockedtimetodisplaynative';
2728
import { createMockNavigationAndAttachTo } from './reactnavigationutils';
2829

2930
const SCOPE_SPAN_FIELD = '_sentrySpan';
@@ -286,7 +287,11 @@ describe('React Navigation - TTID', () => {
286287
mockedEventEmitter.emitNewFrameEvent();
287288

288289
TestRenderer.render(<TimeToFullDisplay record />);
289-
emitNativeFullDisplayEvent();
290+
mockRecordedTimeToDisplay({
291+
ttfd: {
292+
[spanToJSON(getActiveSpan()!).span_id!]: nowInSeconds(),
293+
},
294+
});
290295

291296
jest.runOnlyPendingTimers(); // Flush ttid transaction
292297

@@ -356,7 +361,11 @@ describe('React Navigation - TTID', () => {
356361

357362
mockedNavigation.navigateToNewScreen();
358363
TestRenderer.render(<TimeToFullDisplay record />);
359-
emitNativeFullDisplayEvent();
364+
mockRecordedTimeToDisplay({
365+
ttfd: {
366+
[spanToJSON(getActiveSpan()!).span_id!]: timestampInSeconds() - 1,
367+
},
368+
});
360369
mockedEventEmitter.emitNewFrameEvent();
361370

362371
jest.runOnlyPendingTimers(); // Flush navigation transaction
@@ -378,7 +387,11 @@ describe('React Navigation - TTID', () => {
378387
mockedEventEmitter.emitNewFrameEvent();
379388

380389
TestRenderer.render(<TimeToFullDisplay record />);
381-
emitNativeFullDisplayEvent();
390+
mockRecordedTimeToDisplay({
391+
ttfd: {
392+
[spanToJSON(getActiveSpan()!).span_id!]: timestampInSeconds(),
393+
},
394+
});
382395

383396
jest.runOnlyPendingTimers(); // Flush ttid transaction
384397

@@ -481,7 +494,11 @@ describe('React Navigation - TTID', () => {
481494

482495
mockedEventEmitter.emitNewFrameEvent();
483496
timeToDisplayComponent.update(<TimeToInitialDisplay record />);
484-
emitNativeInitialDisplayEvent(manualInitialDisplayEndTimestampMs);
497+
mockRecordedTimeToDisplay({
498+
ttid: {
499+
[spanToJSON(getActiveSpan()!).span_id!]: manualInitialDisplayEndTimestampMs / 1_000,
500+
},
501+
});
485502

486503
jest.runOnlyPendingTimers(); // Flush transaction
487504

@@ -515,7 +532,7 @@ describe('React Navigation - TTID', () => {
515532

516533
// Initialized too late auto instrumentation finished before manual
517534
TestRenderer.render(<TimeToInitialDisplay record />);
518-
emitNativeInitialDisplayEvent(secondInFutureTimestampMs());
535+
// mockRecordedInitialDisplayAt(secondInFutureTimestampMs());
519536

520537
jest.runOnlyPendingTimers(); // Flush transaction
521538

@@ -703,6 +720,7 @@ function initSentry(sut: ReturnType<typeof Sentry.reactNavigationIntegration>):
703720
integrations: [
704721
sut,
705722
Sentry.reactNativeTracingIntegration(),
723+
Sentry.timeToDisplayIntegration(),
706724
],
707725
transport: () => ({
708726
send: transportSendMock.mockResolvedValue({}),

0 commit comments

Comments
 (0)