-
-
Notifications
You must be signed in to change notification settings - Fork 367
fix(core): Guard against unreliable performance.timeOrigin #6654
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. Weโll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
ef6f559
9077785
d19e896
32317f7
e39e3d8
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,64 @@ | ||
| import { RN_GLOBAL_OBJ } from './worldwide'; | ||
|
|
||
| /** | ||
| * Divergence (ms) beyond which `performance.timeOrigin` is considered unreliable. | ||
| * Mirrors the 5-minute guard `@sentry/core`'s `getBrowserTimeOrigin` already | ||
| * applies to the browser time origin, but which is not wired into the span/log | ||
| * timestamp path (`createUnixTimestampInSecondsFunc`). | ||
| */ | ||
| const TIME_ORIGIN_DRIFT_THRESHOLD_MS = 3e5; | ||
|
|
||
| interface PerformanceLike { | ||
| now?: () => number; | ||
| timeOrigin?: number; | ||
| } | ||
|
|
||
| /** | ||
| * Neutralizes an unreliable `performance.timeOrigin` so `@sentry/core` timestamps | ||
| * spans and logs with `Date.now()` instead of `timeOrigin + performance.now()`. | ||
| * | ||
| * Background (#6630): on iOS with React Native >= 0.86, `performance.now()` is | ||
| * backed by `mach_absolute_time()` while `performance.timeOrigin` is derived from | ||
| * a different clock reference (`std::chrono::steady_clock`) and cached once. The | ||
| * two can diverge by ~device uptime, so `timeOrigin + performance.now()` โ which | ||
| * `@sentry/core` uses for span and log timestamps โ drifts hours or days into the | ||
| * past. Such payloads are silently dropped during ingestion (the transport still | ||
| * reports HTTP 200), while error events (which use `Date.now()`) are unaffected. | ||
| * Before RN 0.86 the modules exposed no truthy `timeOrigin`, so `@sentry/core` | ||
| * already fell back to `Date.now()`; this restores that behavior when the clock | ||
| * is broken. | ||
| * | ||
| * Must run before the first `@sentry/core` timestamp (it caches the origin on | ||
| * first use), i.e. before `initAndBind`. Because `initAndBind` is also where the | ||
| * debug logger is enabled, this returns the corrected drift instead of logging in | ||
| * place, so the caller can warn once logging is live. | ||
| * | ||
| * Self-gating: only acts when the drift exceeds the threshold, so healthy runtimes | ||
| * (and platforms where the pair is consistent) keep the high-resolution clock. | ||
| * | ||
| * @returns the corrected drift in milliseconds when `timeOrigin` was neutralized, | ||
| * or `undefined` when the clock was left untouched. | ||
| */ | ||
| export function ensureReliablePerformanceTimeOrigin(): number | undefined { | ||
| const performance = (RN_GLOBAL_OBJ as { performance?: PerformanceLike }).performance; | ||
| if (!performance || typeof performance.now !== 'function' || typeof performance.timeOrigin !== 'number') { | ||
| return undefined; | ||
| } | ||
|
|
||
| const drift = Math.abs(performance.timeOrigin + performance.now() - Date.now()); | ||
| if (drift <= TIME_ORIGIN_DRIFT_THRESHOLD_MS) { | ||
| return undefined; | ||
| } | ||
|
|
||
| try { | ||
| // Falsy timeOrigin makes `@sentry/core`'s createUnixTimestampInSecondsFunc gate | ||
| // (`!performance.timeOrigin`) fall back to `dateTimestampInSeconds` (Date.now). | ||
| Object.defineProperty(performance, 'timeOrigin', { | ||
| configurable: true, | ||
| value: 0, | ||
| }); | ||
| return drift; | ||
| } catch (_e) { | ||
| return undefined; | ||
| } | ||
| } | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,163 @@ | ||
| import { ensureReliablePerformanceTimeOrigin } from '../../src/js/utils/performanceclock'; | ||
|
|
||
| describe('ensureReliablePerformanceTimeOrigin', () => { | ||
| const originalPerformance = (globalThis as { performance?: unknown }).performance; | ||
| const NOW = 1_700_000_000_000; | ||
|
|
||
| beforeEach(() => { | ||
| jest.spyOn(Date, 'now').mockReturnValue(NOW); | ||
| }); | ||
|
|
||
| afterEach(() => { | ||
| if (originalPerformance !== undefined) { | ||
| (globalThis as { performance?: unknown }).performance = originalPerformance; | ||
| } else { | ||
| delete (globalThis as { performance?: unknown }).performance; | ||
| } | ||
| jest.restoreAllMocks(); | ||
| }); | ||
|
|
||
| const setPerformance = (value: unknown): void => { | ||
| (globalThis as { performance?: unknown }).performance = value; | ||
| }; | ||
|
|
||
| it('neutralizes timeOrigin and returns the drift when timeOrigin + now() drifts far from Date.now()', () => { | ||
| // timeOrigin + now() = 100 + 1000 = 1100, ~1.7e12 ms behind Date.now(): far past the threshold. | ||
| setPerformance({ now: () => 1000, timeOrigin: 100 }); | ||
|
|
||
| const drift = ensureReliablePerformanceTimeOrigin(); | ||
|
|
||
| expect((globalThis as { performance: { timeOrigin: number } }).performance.timeOrigin).toBe(0); | ||
| expect(drift).toBe(NOW - 1100); | ||
| }); | ||
|
|
||
| it('leaves a healthy timeOrigin untouched and returns undefined', () => { | ||
| // timeOrigin + now() === Date.now(): no drift. | ||
| const timeOrigin = NOW - 5000; | ||
| setPerformance({ now: () => 5000, timeOrigin }); | ||
|
|
||
| const drift = ensureReliablePerformanceTimeOrigin(); | ||
|
|
||
| expect((globalThis as { performance: { timeOrigin: number } }).performance.timeOrigin).toBe(timeOrigin); | ||
| expect(drift).toBeUndefined(); | ||
| }); | ||
|
|
||
| it('leaves timeOrigin untouched when drift is within the threshold', () => { | ||
| // 60s of drift, under the 5-minute threshold. | ||
| const timeOrigin = NOW - 5000 - 60_000; | ||
| setPerformance({ now: () => 5000, timeOrigin }); | ||
|
|
||
| const drift = ensureReliablePerformanceTimeOrigin(); | ||
|
|
||
| expect((globalThis as { performance: { timeOrigin: number } }).performance.timeOrigin).toBe(timeOrigin); | ||
| expect(drift).toBeUndefined(); | ||
| }); | ||
|
|
||
| it('does nothing when performance is missing', () => { | ||
| delete (globalThis as { performance?: unknown }).performance; | ||
|
|
||
| expect(ensureReliablePerformanceTimeOrigin()).toBeUndefined(); | ||
| expect((globalThis as { performance?: unknown }).performance).toBeUndefined(); | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Could you check the CI comment
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This should be covered with the above and warden seem to be happy :) |
||
| }); | ||
|
|
||
| it('does nothing when timeOrigin is not a number', () => { | ||
| setPerformance({ now: () => 1000 }); | ||
|
|
||
| expect(ensureReliablePerformanceTimeOrigin()).toBeUndefined(); | ||
| expect((globalThis as { performance: { timeOrigin?: number } }).performance.timeOrigin).toBeUndefined(); | ||
| }); | ||
|
|
||
| it('does nothing when now is not a function', () => { | ||
| setPerformance({ timeOrigin: 100 }); | ||
|
|
||
| expect(ensureReliablePerformanceTimeOrigin()).toBeUndefined(); | ||
| expect((globalThis as { performance: { timeOrigin: number } }).performance.timeOrigin).toBe(100); | ||
| }); | ||
|
|
||
| it('returns undefined without throwing when timeOrigin cannot be redefined', () => { | ||
| // A non-configurable `timeOrigin` makes `Object.defineProperty` throw; the guard must swallow it. | ||
| const performance = { now: () => 1000 }; | ||
| Object.defineProperty(performance, 'timeOrigin', { configurable: false, value: 100 }); | ||
| setPerformance(performance); | ||
|
|
||
| expect(() => ensureReliablePerformanceTimeOrigin()).not.toThrow(); | ||
| expect(ensureReliablePerformanceTimeOrigin()).toBeUndefined(); | ||
| expect((globalThis as { performance: { timeOrigin: number } }).performance.timeOrigin).toBe(100); | ||
| }); | ||
| }); | ||
|
|
||
| // Integration coverage against the real `@sentry/core` timestamp function, not a stub. | ||
| // This exercises the property the fix actually relies on: `@sentry/core` builds its | ||
| // timestamp closure lazily on the FIRST `timestampInSeconds()` call and reads the same | ||
| // global `performance` object the guard mutates. `jest.isolateModules` gives each case a | ||
| // fresh module registry so `@sentry/core` re-derives its lazily-cached timestamp function. | ||
| describe('ensureReliablePerformanceTimeOrigin against the real @sentry/core timestampInSeconds', () => { | ||
| const originalPerformance = (globalThis as { performance?: unknown }).performance; | ||
| const NOW = 1_700_000_000_000; | ||
|
|
||
| const requireFreshTimestampInSeconds = (): (() => number) => { | ||
| let timestampInSeconds!: () => number; | ||
| jest.isolateModules(() => { | ||
| timestampInSeconds = require('@sentry/core').timestampInSeconds; | ||
| }); | ||
| return timestampInSeconds; | ||
| }; | ||
|
|
||
| beforeEach(() => { | ||
| jest.spyOn(Date, 'now').mockReturnValue(NOW); | ||
| // Stale clock: timeOrigin + now() = 1100ms, ~1.7e12ms behind Date.now() โ the #6630 shape. | ||
| (globalThis as { performance?: unknown }).performance = { now: () => 1000, timeOrigin: 100 }; | ||
| }); | ||
|
|
||
| afterEach(() => { | ||
| if (originalPerformance !== undefined) { | ||
| (globalThis as { performance?: unknown }).performance = originalPerformance; | ||
| } else { | ||
| delete (globalThis as { performance?: unknown }).performance; | ||
| } | ||
| jest.restoreAllMocks(); | ||
| }); | ||
|
|
||
| it('reproduces the bug: a stale timeOrigin drifts @sentry/core span/log timestamps', () => { | ||
| const timestampInSeconds = requireFreshTimestampInSeconds(); | ||
|
|
||
| // (100 + 1000) / 1000 = 1.1s โ the high-resolution path, wildly behind Date.now()/1000. | ||
| expect(timestampInSeconds()).toBeCloseTo(1.1, 5); | ||
| expect(timestampInSeconds()).not.toBeCloseTo(NOW / 1000, 0); | ||
| }); | ||
|
|
||
| it('running the guard before the first timestamp makes @sentry/core fall back to Date.now()', () => { | ||
| ensureReliablePerformanceTimeOrigin(); | ||
|
|
||
| // Guard ran first, so @sentry/core captures a zeroed (falsy) timeOrigin on first use and | ||
| // gates onto the `dateTimestampInSeconds` (Date.now) path โ the same path errors already use. | ||
| const timestampInSeconds = requireFreshTimestampInSeconds(); | ||
|
|
||
| expect(timestampInSeconds()).toBeCloseTo(NOW / 1000, 5); | ||
| }); | ||
|
|
||
| it('importing @sentry/core before the guard does not pre-cache the origin, so the guard still forces the Date.now() fallback', () => { | ||
| jest.isolateModules(() => { | ||
| // Realistic startup order: @sentry/core is imported at app boot, before init() runs the | ||
| // guard. Importing it must NOT capture the origin โ only the first timestampInSeconds() does. | ||
| const { timestampInSeconds } = require('@sentry/core'); | ||
|
|
||
| ensureReliablePerformanceTimeOrigin(); | ||
|
|
||
| // First call happens after the guard, so the closure captures the zeroed origin. | ||
| expect(timestampInSeconds()).toBeCloseTo(NOW / 1000, 5); | ||
| }); | ||
| }); | ||
|
|
||
| it('is order-dependent: running after the first timestamp cannot repair the cached closure', () => { | ||
| // @sentry/core caches the drifted closure on first use, before the guard runs. | ||
| const timestampInSeconds = requireFreshTimestampInSeconds(); | ||
| expect(timestampInSeconds()).toBeCloseTo(1.1, 5); | ||
|
|
||
| ensureReliablePerformanceTimeOrigin(); | ||
|
|
||
| // The closure captured the original timeOrigin as a local const, so zeroing the property | ||
| // afterwards is a no-op. This is why the guard must run before `initAndBind`. | ||
| expect(timestampInSeconds()).toBeCloseTo(1.1, 5); | ||
| }); | ||
| }); | ||
Uh oh!
There was an error while loading. Please reload this page.