Skip to content

Commit

Permalink
fix: Reimplement timestamp computation (#2947)
Browse files Browse the repository at this point in the history
This is a partial improvement to address inconsistencies in browsers and
how they implement performance.now().

It mitigates observing timestamps in the past for pageload transactions,
but gives no guarantees to navigation transactions.

Depending on the platform, the clock used in performance.now() may stop
when the computer goes to sleep, creating an ever increasing skew. This
skew is more likely to manifest in navigation transactions.

Notable Changes

- Do not polyfill/patch performance.timeOrigin to avoid changing
behavior of third parties that may depend on it. Instead, use an
explicit browserPerformanceTimeOrigin where needed.

- Use a timestamp based on the Date API for error events,
breadcrumbs and envelope header. This should fully resolve the problem
of ingesting events with timestamps in the past, as long as the client
wall clock is reasonably in sync.

- Apply an equivalent workaround that we used for React Native to all
JavaScript environments, essentially resetting the timeOrigin used to
compute monotonic timestamps when execution starts.
  • Loading branch information
rhcarvalho authored Oct 5, 2020
1 parent 2c51883 commit 6c33bfc
Show file tree
Hide file tree
Showing 8 changed files with 134 additions and 81 deletions.
5 changes: 3 additions & 2 deletions packages/apm/src/integrations/tracing.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import { Hub } from '@sentry/hub';
import { Event, EventProcessor, Integration, Severity, Span, SpanContext, TransactionContext } from '@sentry/types';
import {
addInstrumentationHandler,
browserPerformanceTimeOrigin,
getGlobalObject,
isInstanceOf,
isMatchingPattern,
Expand Down Expand Up @@ -570,7 +571,7 @@ export class Tracing implements Integration {
* @param transactionSpan The transaction span
*/
private static _addPerformanceEntries(transactionSpan: SpanClass): void {
if (!global.performance || !global.performance.getEntries) {
if (!global.performance || !global.performance.getEntries || !browserPerformanceTimeOrigin) {
// Gatekeeper if performance API not available
return;
}
Expand All @@ -587,7 +588,7 @@ export class Tracing implements Integration {
}
}

const timeOrigin = Tracing._msToSec(performance.timeOrigin);
const timeOrigin = Tracing._msToSec(browserPerformanceTimeOrigin);

// eslint-disable-next-line jsdoc/require-jsdoc
function addPerformanceNavigationTiming(parent: Span, entry: { [key: string]: number }, event: string): void {
Expand Down
4 changes: 2 additions & 2 deletions packages/core/src/baseclient.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,13 +2,13 @@
import { Scope } from '@sentry/hub';
import { Client, Event, EventHint, Integration, IntegrationClass, Options, Severity } from '@sentry/types';
import {
dateTimestampInSeconds,
Dsn,
isPrimitive,
isThenable,
logger,
normalize,
SyncPromise,
timestampWithMs,
truncate,
uuid4,
} from '@sentry/utils';
Expand Down Expand Up @@ -256,7 +256,7 @@ export abstract class BaseClient<B extends Backend, O extends Options> implement
const prepared: Event = {
...event,
event_id: event.event_id || (hint && hint.event_id ? hint.event_id : uuid4()),
timestamp: event.timestamp || timestampWithMs(),
timestamp: event.timestamp || dateTimestampInSeconds(),
};

this._applyClientOptions(prepared);
Expand Down
3 changes: 1 addition & 2 deletions packages/core/src/request.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,4 @@
import { Event } from '@sentry/types';
import { timestampWithMs } from '@sentry/utils';

import { API } from './api';

Expand Down Expand Up @@ -34,7 +33,7 @@ export function eventToSentryRequest(event: Event, api: API): SentryRequest {
event_id: event.event_id,
// We need to add * 1000 since we divide it by 1000 by default but JS works with ms precision
// The reason we use timestampWithMs here is that all clocks across the SDK use the same clock
sent_at: new Date(timestampWithMs() * 1000).toISOString(),
sent_at: new Date().toISOString(),
});
const itemHeaders = JSON.stringify({
type: event.type,
Expand Down
3 changes: 3 additions & 0 deletions packages/core/test/lib/base.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -43,6 +43,9 @@ jest.mock('@sentry/utils', () => {
timestampWithMs(): number {
return 2020;
},
dateTimestampInSeconds(): number {
return 2020;
},
};
});

Expand Down
4 changes: 2 additions & 2 deletions packages/hub/src/hub.ts
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@ import {
TransactionContext,
User,
} from '@sentry/types';
import { consoleSandbox, getGlobalObject, isNodeEnv, logger, timestampWithMs, uuid4 } from '@sentry/utils';
import { consoleSandbox, dateTimestampInSeconds, getGlobalObject, isNodeEnv, logger, uuid4 } from '@sentry/utils';

import { Carrier, DomainAsCarrier, Layer } from './interfaces';
import { Scope } from './scope';
Expand Down Expand Up @@ -242,7 +242,7 @@ export class Hub implements HubInterface {
return;
}

const timestamp = timestampWithMs();
const timestamp = dateTimestampInSeconds();
const mergedBreadcrumb = { timestamp, ...breadcrumb };
const finalBreadcrumb = beforeBreadcrumb
? (consoleSandbox(() => beforeBreadcrumb(mergedBreadcrumb, hint)) as Breadcrumb | null)
Expand Down
4 changes: 2 additions & 2 deletions packages/hub/src/scope.ts
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ import {
Transaction,
User,
} from '@sentry/types';
import { getGlobalObject, isPlainObject, isThenable, SyncPromise, timestampWithMs } from '@sentry/utils';
import { dateTimestampInSeconds, getGlobalObject, isPlainObject, isThenable, SyncPromise } from '@sentry/utils';

/**
* Holds additional event information. {@link Scope.applyToEvent} will be
Expand Down Expand Up @@ -302,7 +302,7 @@ export class Scope implements ScopeInterface {
*/
public addBreadcrumb(breadcrumb: Breadcrumb, maxBreadcrumbs?: number): this {
const mergedBreadcrumb = {
timestamp: timestampWithMs(),
timestamp: dateTimestampInSeconds(),
...breadcrumb,
};

Expand Down
6 changes: 3 additions & 3 deletions packages/tracing/src/browser/metrics.ts
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
/* eslint-disable max-lines */
/* eslint-disable @typescript-eslint/no-explicit-any */
import { SpanContext } from '@sentry/types';
import { getGlobalObject, logger } from '@sentry/utils';
import { browserPerformanceTimeOrigin, getGlobalObject, logger } from '@sentry/utils';

import { Span } from '../span';
import { Transaction } from '../transaction';
Expand All @@ -27,7 +27,7 @@ export class MetricsInstrumentation {

/** Add performance related spans to a transaction */
public addPerformanceEntries(transaction: Transaction): void {
if (!global || !global.performance || !global.performance.getEntries) {
if (!global || !global.performance || !global.performance.getEntries || !browserPerformanceTimeOrigin) {
// Gatekeeper if performance API not available
return;
}
Expand All @@ -44,7 +44,7 @@ export class MetricsInstrumentation {
}
}

const timeOrigin = msToSec(performance.timeOrigin);
const timeOrigin = msToSec(browserPerformanceTimeOrigin);
let entryScriptSrc: string | undefined;

if (global.document) {
Expand Down
186 changes: 118 additions & 68 deletions packages/utils/src/time.ts
Original file line number Diff line number Diff line change
@@ -1,98 +1,148 @@
import { getGlobalObject } from './misc';
import { dynamicRequire, isNodeEnv } from './node';

const INITIAL_TIME = Date.now();
/**
* An object that can return the current timestamp in seconds since the UNIX epoch.
*/
interface TimestampSource {
nowSeconds(): number;
}

/**
* A TimestampSource implementation for environments that do not support the Performance Web API natively.
*
* Note that this TimestampSource does not use a monotonic clock. A call to `nowSeconds` may return a timestamp earlier
* than a previously returned value. We do not try to emulate a monotonic behavior in order to facilitate debugging. It
* is more obvious to explain "why does my span have negative duration" than "why my spans have zero duration".
*/
const dateTimestampSource: TimestampSource = {
nowSeconds: () => Date.now() / 1000,
};

/**
* Cross platform compatible partial performance implementation
* A partial definition of the [Performance Web API]{@link https://developer.mozilla.org/en-US/docs/Web/API/Performance}
* for accessing a high resolution monotonic clock.
*/
interface CrossPlatformPerformance {
interface Performance {
/**
* The millisecond timestamp at which measurement began, measured in Unix time.
*/
timeOrigin: number;
/**
* Returns the current timestamp in ms
* Returns the current millisecond timestamp, where 0 represents the start of measurement.
*/
now(): number;
}

let prevNow = 0;

const performanceFallback: CrossPlatformPerformance = {
now(): number {
let now = Date.now() - INITIAL_TIME;
if (now < prevNow) {
now = prevNow;
}
prevNow = now;
return now;
},
timeOrigin: INITIAL_TIME,
};

const crossPlatformPerformance: CrossPlatformPerformance = ((): CrossPlatformPerformance => {
// React Native's performance.now() starts with a gigantic offset, so we need to wrap it.
if (isReactNative()) {
return getReactNativePerformanceWrapper();
}

if (isNodeEnv()) {
try {
const perfHooks = dynamicRequire(module, 'perf_hooks') as { performance: CrossPlatformPerformance };
return perfHooks.performance;
} catch (_) {
return performanceFallback;
}
}

/**
* Returns a wrapper around the native Performance API browser implementation, or undefined for browsers that do not
* support the API.
*
* Wrapping the native API works around differences in behavior from different browsers.
*/
function getBrowserPerformance(): Performance | undefined {
const { performance } = getGlobalObject<Window>();

if (!performance || !performance.now) {
return performanceFallback;
return undefined;
}

// Polyfill for performance.timeOrigin.
// Replace performance.timeOrigin with our own timeOrigin based on Date.now().
//
// While performance.timing.navigationStart is deprecated in favor of performance.timeOrigin, performance.timeOrigin
// is not as widely supported. Namely, performance.timeOrigin is undefined in Safari as of writing.
if (performance.timeOrigin === undefined) {
// As of writing, performance.timing is not available in Web Workers in mainstream browsers, so it is not always a
// valid fallback. In the absence of a initial time provided by the browser, fallback to INITIAL_TIME.
// @ts-ignore ignored because timeOrigin is a readonly property but we want to override
// eslint-disable-next-line deprecation/deprecation
performance.timeOrigin = (performance.timing && performance.timing.navigationStart) || INITIAL_TIME;
}
// This is a partial workaround for browsers reporting performance.timeOrigin such that performance.timeOrigin +
// performance.now() gives a date arbitrarily in the past.
//
// Additionally, computing timeOrigin in this way fills the gap for browsers where performance.timeOrigin is
// undefined.
//
// The assumption that performance.timeOrigin + performance.now() ~= Date.now() is flawed, but we depend on it to
// interact with data coming out of performance entries.
//
// Note that despite recommendations against it in the spec, browsers implement the Performance API with a clock that
// might stop when the computer is asleep (and perhaps under other circumstances). Such behavior causes
// performance.timeOrigin + performance.now() to have an arbitrary skew over Date.now(). In laptop computers, we have
// observed skews that can be as long as days, weeks or months.
//
// See https://github.com/getsentry/sentry-javascript/issues/2590.
//
// BUG: despite our best intentions, this workaround has its limitations. It mostly addresses timings of pageload
// transactions, but ignores the skew built up over time that can aversely affect timestamps of navigation
// transactions of long-lived web pages.
const timeOrigin = Date.now() - performance.now();

return performance;
})();
return {
now: () => performance.now(),
timeOrigin,
};
}

/**
* Returns a timestamp in seconds with milliseconds precision since the UNIX epoch calculated with the monotonic clock.
* Returns the native Performance API implementation from Node.js. Returns undefined in old Node.js versions that don't
* implement the API.
*/
export function timestampWithMs(): number {
return (crossPlatformPerformance.timeOrigin + crossPlatformPerformance.now()) / 1000;
function getNodePerformance(): Performance | undefined {
try {
const perfHooks = dynamicRequire(module, 'perf_hooks') as { performance: Performance };
return perfHooks.performance;
} catch (_) {
return undefined;
}
}

/**
* Determines if running in react native
* The Performance API implementation for the current platform, if available.
*/
function isReactNative(): boolean {
return getGlobalObject<Window>().navigator?.product === 'ReactNative';
}
const platformPerformance: Performance | undefined = isNodeEnv() ? getNodePerformance() : getBrowserPerformance();

const timestampSource: TimestampSource =
platformPerformance === undefined
? dateTimestampSource
: {
nowSeconds: () => (platformPerformance.timeOrigin + platformPerformance.now()) / 1000,
};

/**
* Performance wrapper for react native as performance.now() has been found to start off with an unusual offset.
* Returns a timestamp in seconds since the UNIX epoch using the Date API.
*/
function getReactNativePerformanceWrapper(): CrossPlatformPerformance {
// Performance only available >= RN 0.63
const { performance } = getGlobalObject<Window>();
if (performance && typeof performance.now === 'function') {
const INITIAL_OFFSET = performance.now();
export const dateTimestampInSeconds = dateTimestampSource.nowSeconds.bind(dateTimestampSource);

/**
* Returns a timestamp in seconds since the UNIX epoch using either the Performance or Date APIs, depending on the
* availability of the Performance API.
*
* See `usingPerformanceAPI` to test whether the Performance API is used.
*
* BUG: Note that because of how browsers implement the Performance API, the clock might stop when the computer is
* asleep. This creates a skew between `dateTimestampInSeconds` and `timestampInSeconds`. The
* skew can grow to arbitrary amounts like days, weeks or months.
* See https://github.com/getsentry/sentry-javascript/issues/2590.
*/
export const timestampInSeconds = timestampSource.nowSeconds.bind(timestampSource);

return {
now(): number {
return performance.now() - INITIAL_OFFSET;
},
timeOrigin: INITIAL_TIME,
};
// Re-exported with an old name for backwards-compatibility.
export const timestampWithMs = timestampInSeconds;

/**
* A boolean that is true when timestampInSeconds uses the Performance API to produce monotonic timestamps.
*/
export const usingPerformanceAPI = platformPerformance !== undefined;

/**
* The number of milliseconds since the UNIX epoch. This value is only usable in a browser, and only when the
* performance API is available.
*/
export const browserPerformanceTimeOrigin = ((): number | undefined => {
const { performance } = getGlobalObject<Window>();
if (!performance) {
return undefined;
}
return performanceFallback;
}
if (performance.timeOrigin) {
return performance.timeOrigin;
}
// While performance.timing.navigationStart is deprecated in favor of performance.timeOrigin, performance.timeOrigin
// is not as widely supported. Namely, performance.timeOrigin is undefined in Safari as of writing.
// Also as of writing, performance.timing is not available in Web Workers in mainstream browsers, so it is not always
// a valid fallback. In the absence of an initial time provided by the browser, fallback to the current time from the
// Date API.
// eslint-disable-next-line deprecation/deprecation
return (performance.timing && performance.timing.navigationStart) || Date.now();
})();

0 comments on commit 6c33bfc

Please sign in to comment.