diff --git a/CHANGELOG.md b/CHANGELOG.md index 8a9293b954..1586d2f24b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,6 +15,7 @@ ### Fixes +- Prevent silently dropped logs and spans on iOS with React Native >= 0.86 caused by an unreliable `performance.timeOrigin` ([#6654](https://github.com/getsentry/sentry-react-native/pull/6654)) - Fix Metro bundler crash on Expo static/EAS Update exports ([#6652](https://github.com/getsentry/sentry-react-native/pull/6652)) - No longer logs `NSNull cannot be converted` warnings on iOS with the New Architecture when clearing a scope context ([#6651](https://github.com/getsentry/sentry-react-native/pull/6651)) - `time_to_initial_display`/`time_to_full_display` now measure the actual screen render for apps whose first navigation happens well after app start ([#6626](https://github.com/getsentry/sentry-react-native/pull/6626)) diff --git a/packages/core/src/js/sdk.tsx b/packages/core/src/js/sdk.tsx index 8778d516f7..a5f00c4f05 100644 --- a/packages/core/src/js/sdk.tsx +++ b/packages/core/src/js/sdk.tsx @@ -37,6 +37,7 @@ import { useEncodePolyfill } from './transports/encodePolyfill'; import { DEFAULT_BUFFER_SIZE, makeNativeTransportFactory } from './transports/native'; import { getDefaultEnvironment, isExpoGo, isRunningInMetroDevServer, isWeb } from './utils/environment'; import { registerFeatureMarker } from './utils/featureMarkers'; +import { ensureReliablePerformanceTimeOrigin } from './utils/performanceclock'; import { getDefaultRelease } from './utils/release'; import { safeFactory, safeTracesSampler } from './utils/safe'; import { checkSentryJsSdkVersionMismatch } from './utils/sdkVersionCheck'; @@ -72,6 +73,12 @@ export function init(passedOptions: ReactNativeOptions): void { return; } + // Guard against an unreliable `performance.timeOrigin` before any span or log is + // timestamped by `@sentry/core` (it caches the origin on first use). See #6630 and + // `ensureReliablePerformanceTimeOrigin`. The warning is deferred until after + // `initAndBind` enables the debug logger. + const timeOriginDriftMs = ensureReliablePerformanceTimeOrigin(); + const userOptions = { ...RN_GLOBAL_OBJ.__SENTRY_OPTIONS__, ...passedOptions, @@ -183,8 +190,14 @@ export function init(passedOptions: ReactNativeOptions): void { defaultIntegrations, }); initAndBind(ReactNativeClient, options); - // Must run after `initAndBind`: that is where `@sentry/core` enables the debug logger - // (`debug.enable()` when `debug: true`), so `debug.warn` is a no-op before it. + // The following must run after `initAndBind`: that is where `@sentry/core` enables the debug + // logger (`debug.enable()` when `debug: true`), so `debug.warn` is a no-op before it. + if (timeOriginDriftMs !== undefined) { + debug.warn( + `[ReactNative] performance.timeOrigin diverged from Date.now() by ${Math.round(timeOriginDriftMs)}ms; ` + + 'falling back to Date.now() for span and log timestamps (see #6630).', + ); + } warnIfReplayIntegrationMissing(options); if (__DEV__) { checkSentryJsSdkVersionMismatch(); diff --git a/packages/core/src/js/utils/performanceclock.ts b/packages/core/src/js/utils/performanceclock.ts new file mode 100644 index 0000000000..5640d32a01 --- /dev/null +++ b/packages/core/src/js/utils/performanceclock.ts @@ -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; + } +} diff --git a/packages/core/test/utils/performanceclock.test.ts b/packages/core/test/utils/performanceclock.test.ts new file mode 100644 index 0000000000..264b9afe18 --- /dev/null +++ b/packages/core/test/utils/performanceclock.test.ts @@ -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(); + }); + + 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); + }); +});