diff --git a/packages/replay-internal/src/coreHandlers/performanceObserver.ts b/packages/replay-internal/src/coreHandlers/performanceObserver.ts index e57369ec7256..47367604085c 100644 --- a/packages/replay-internal/src/coreHandlers/performanceObserver.ts +++ b/packages/replay-internal/src/coreHandlers/performanceObserver.ts @@ -9,6 +9,7 @@ import { getCumulativeLayoutShift, getInteractionToNextPaint, getLargestContentfulPaint, + rememberEntryTimeOrigin, webVitalHandler, } from '../util/createPerformanceEntries'; @@ -20,6 +21,9 @@ export function setupPerformanceObserver(replay: ReplayContainer): () => void { function addPerformanceEntry(entry: PerformanceEntry): void { // It is possible for entries to come up multiple times if (!replay.performanceEntries.includes(entry)) { + // Entries are converted to wall clock time on flush, which can be long after this point, so the time origin that + // is currently in effect has to be captured now. + rememberEntryTimeOrigin(entry); replay.performanceEntries.push(entry); } } diff --git a/packages/replay-internal/src/util/createPerformanceEntries.ts b/packages/replay-internal/src/util/createPerformanceEntries.ts index 2f4e45e9b600..8841a02b1f64 100644 --- a/packages/replay-internal/src/util/createPerformanceEntries.ts +++ b/packages/replay-internal/src/util/createPerformanceEntries.ts @@ -16,7 +16,7 @@ import type { // Map entryType -> function to normalize data for event const ENTRY_TYPES: Record< string, - (entry: AllPerformanceEntry) => null | ReplayPerformanceEntry + (entry: AllPerformanceEntry, timeOrigin: number) => null | ReplayPerformanceEntry > = { // @ts-expect-error TODO: entry type does not fit the create* functions entry type resource: createResourceEntry, @@ -68,6 +68,26 @@ export function webVitalHandler( return ({ metric }) => void replay.replayPerformanceEntries.push(getter(metric)); } +/** + * The time origin that was in effect when an entry was observed. + * + * Entries are buffered raw and only converted to wall clock time on flush, which can be minutes later (and across a + * clock drift correction) for a long-running session. Converting them against the origin that was in effect when they + * were observed keeps their timestamps correct, whereas the origin at flush time would retroactively shift every + * buffered entry by the drift. + */ +const ENTRY_TIME_ORIGINS = new WeakMap(); + +/** + * Records the current time origin for an observed performance entry, so it can be converted to wall clock time later. + */ +export function rememberEntryTimeOrigin(entry: AllPerformanceEntry): void { + const timeOrigin = correctedPerformanceTimeOrigin(); + if (timeOrigin !== undefined) { + ENTRY_TIME_ORIGINS.set(entry, timeOrigin); + } +} + /** * Create replay performance entries from the browser performance entries. */ @@ -83,19 +103,24 @@ function createPerformanceEntry(entry: AllPerformanceEntry): ReplayPerformanceEn return null; } - return entryType(entry); + return entryType(entry, getEntryTimeOrigin(entry)); +} + +function getEntryTimeOrigin(entry: AllPerformanceEntry): number { + // The stamp is missing for entries that were not routed through `rememberEntryTimeOrigin` (e.g. web vitals, which + // convert eagerly). correctedPerformanceTimeOrigin can be undefined if `performance` or `performance.now` doesn't + // exist, but this is already checked by this integration. + return ENTRY_TIME_ORIGINS.get(entry) ?? correctedPerformanceTimeOrigin() ?? WINDOW.performance.timeOrigin; } -function getAbsoluteTime(time: number): number { - // correctedPerformanceTimeOrigin can be undefined if `performance` or - // `performance.now` doesn't exist, but this is already checked by this integration - return ((correctedPerformanceTimeOrigin() || WINDOW.performance.timeOrigin) + time) / 1000; +function getAbsoluteTime(time: number, timeOrigin: number): number { + return (timeOrigin + time) / 1000; } -function createPaintEntry(entry: PerformancePaintTiming): ReplayPerformanceEntry { +function createPaintEntry(entry: PerformancePaintTiming, timeOrigin: number): ReplayPerformanceEntry { const { duration, entryType, name, startTime } = entry; - const start = getAbsoluteTime(startTime); + const start = getAbsoluteTime(startTime, timeOrigin); return { type: entryType, name, @@ -105,7 +130,10 @@ function createPaintEntry(entry: PerformancePaintTiming): ReplayPerformanceEntry }; } -function createNavigationEntry(entry: PerformanceNavigationTiming): ReplayPerformanceEntry | null { +function createNavigationEntry( + entry: PerformanceNavigationTiming, + timeOrigin: number, +): ReplayPerformanceEntry | null { const { entryType, name, @@ -131,8 +159,8 @@ function createNavigationEntry(entry: PerformanceNavigationTiming): ReplayPerfor return { type: `${entryType}.${type}`, - start: getAbsoluteTime(startTime), - end: getAbsoluteTime(domComplete), + start: getAbsoluteTime(startTime, timeOrigin), + end: getAbsoluteTime(domComplete, timeOrigin), name, data: { size: transferSize, @@ -152,6 +180,7 @@ function createNavigationEntry(entry: PerformanceNavigationTiming): ReplayPerfor function createResourceEntry( entry: ExperimentalPerformanceResourceTiming, + timeOrigin: number, ): ReplayPerformanceEntry | null { const { entryType, @@ -172,8 +201,8 @@ function createResourceEntry( return { type: `${entryType}.${initiatorType}`, - start: getAbsoluteTime(startTime), - end: getAbsoluteTime(responseEnd), + start: getAbsoluteTime(startTime, timeOrigin), + end: getAbsoluteTime(responseEnd, timeOrigin), name, data: { size: transferSize, @@ -245,7 +274,8 @@ function getWebVital( const value = metric.value; const rating = metric.rating; - const end = getAbsoluteTime(value); + // Web vitals are converted as they are reported rather than buffered raw, so the current origin is the right one. + const end = getAbsoluteTime(value, correctedPerformanceTimeOrigin() ?? WINDOW.performance.timeOrigin); return { type: 'web-vital', diff --git a/packages/replay-internal/test/unit/util/createPerformanceEntry.test.ts b/packages/replay-internal/test/unit/util/createPerformanceEntry.test.ts index c87d18bff325..992fa99e79f4 100644 --- a/packages/replay-internal/test/unit/util/createPerformanceEntry.test.ts +++ b/packages/replay-internal/test/unit/util/createPerformanceEntry.test.ts @@ -1,4 +1,5 @@ import '../../utils/mock-internal-setTimeout'; +import { correctedPerformanceTimeOrigin } from '@sentry/core'; import { afterAll, beforeAll, beforeEach, describe, expect, it, vi } from 'vitest'; import { WINDOW } from '../../../src/constants'; import { @@ -6,12 +7,13 @@ import { getCumulativeLayoutShift, getInteractionToNextPaint, getLargestContentfulPaint, + rememberEntryTimeOrigin, } from '../../../src/util/createPerformanceEntries'; import { PerformanceEntryNavigation } from '../../fixtures/performanceEntry/navigation'; vi.mock('@sentry/core', async () => ({ ...(await vi.importActual('@sentry/core')), - browserPerformanceTimeOrigin: () => new Date('2023-01-01').getTime(), + correctedPerformanceTimeOrigin: vi.fn(() => new Date('2023-01-01').getTime()), })); describe('Unit | util | createPerformanceEntries', () => { @@ -21,6 +23,8 @@ describe('Unit | util | createPerformanceEntries', () => { }); beforeEach(function () { + vi.mocked(correctedPerformanceTimeOrigin).mockReturnValue(new Date('2023-01-01').getTime()); + if (!WINDOW.performance.getEntriesByType) { WINDOW.performance.getEntriesByType = vi.fn((type: string) => { if (type === 'navigation') { @@ -67,6 +71,64 @@ describe('Unit | util | createPerformanceEntries', () => { expect(createPerformanceEntries([data])).toEqual([]); }); + describe('time origin stamping', () => { + const TIME_ORIGIN = new Date('2023-01-01').getTime(); + // A sleep long enough for `timestampInSeconds` to re-derive its time origin. + const DRIFT_MS = 360_000; + + function resourceEntry(): PerformanceEntry { + return { + name: 'https://example.com/script.js', + entryType: 'resource', + startTime: 1_000, + duration: 100, + initiatorType: 'script', + responseEnd: 1_100, + transferSize: 0, + encodedBodySize: 0, + decodedBodySize: 0, + } as unknown as PerformanceEntry; + } + + it('converts a stamped entry against the origin from when it was observed', () => { + const entry = resourceEntry(); + + rememberEntryTimeOrigin(entry); + + // The origin is corrected after the entry was observed but before it is flushed. + vi.mocked(correctedPerformanceTimeOrigin).mockReturnValue(TIME_ORIGIN + DRIFT_MS); + + const [replayEntry] = createPerformanceEntries([entry]); + + expect(replayEntry?.start).toBe((TIME_ORIGIN + 1_000) / 1000); + expect(replayEntry?.end).toBe((TIME_ORIGIN + 1_100) / 1000); + }); + + it('falls back to the current origin for an entry that was never stamped', () => { + vi.mocked(correctedPerformanceTimeOrigin).mockReturnValue(TIME_ORIGIN + DRIFT_MS); + + const [replayEntry] = createPerformanceEntries([resourceEntry()]); + + expect(replayEntry?.start).toBe((TIME_ORIGIN + DRIFT_MS + 1_000) / 1000); + }); + + it('stamps each entry with the origin in effect when it was observed', () => { + const early = resourceEntry(); + rememberEntryTimeOrigin(early); + + vi.mocked(correctedPerformanceTimeOrigin).mockReturnValue(TIME_ORIGIN + DRIFT_MS); + const late = resourceEntry(); + rememberEntryTimeOrigin(late); + + const [earlyEntry, lateEntry] = createPerformanceEntries([early, late]); + + // Both entries carry the same monotonic `startTime`, so a shared origin would collapse them onto the same + // wall clock time even though they were observed on either side of a correction. + expect(earlyEntry?.start).toBe((TIME_ORIGIN + 1_000) / 1000); + expect(lateEntry?.start).toBe((TIME_ORIGIN + DRIFT_MS + 1_000) / 1000); + }); + }); + describe('getLargestContentfulPaint', () => { it('works with an LCP metric', async () => { const metric = {