fix(tracing): make spans resilient to performance clock drift

[dyladan]

trafficstars

Relates to #3279 particularly https://github.com/open-telemetry/opentelemetry-js/issues/3279#issuecomment-1302575571

Fixes #3355

[codecov[bot]]

Codecov Report

Merging #3384 (eb4c2ae) into main (bd56547) will decrease coverage by 0.70%. The diff coverage is 91.07%.

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #3384      +/-   ##
==========================================
- Coverage   93.27%   92.57%   -0.71%     
==========================================
  Files         247      132     -115     
  Lines        7348     3152    -4196     
  Branches     1512      656     -856     
==========================================
- Hits         6854     2918    -3936     
+ Misses        494      234     -260     

Impacted Files	Coverage Δ
packages/opentelemetry-core/src/common/time.ts	95.45% <75.00%> (+0.06%)	:arrow_up:
packages/opentelemetry-sdk-trace-base/src/Span.ts	97.87% <93.75%> (-2.13%)	:arrow_down:
api/src/platform/node/globalThis.ts	0.00% <0.00%> (-100.00%)	:arrow_down:
...s/opentelemetry-core/src/platform/node/sdk-info.ts	0.00% <0.00%> (-100.00%)	:arrow_down:
...opentelemetry-core/src/platform/node/globalThis.ts	0.00% <0.00%> (-100.00%)	:arrow_down:
...pentelemetry-core/src/platform/node/performance.ts	0.00% <0.00%> (-100.00%)	:arrow_down:
.../packages/api-logs/src/platform/node/globalThis.ts	0.00% <0.00%> (-100.00%)	:arrow_down:
...lemetry-resources/src/detectors/ProcessDetector.ts	31.81% <0.00%> (-68.19%)	:arrow_down:
...perimental/packages/otlp-exporter-base/src/util.ts	78.94% <0.00%> (-15.79%)	:arrow_down:
...ckages/opentelemetry-exporter-zipkin/src/zipkin.ts	84.48% <0.00%> (-15.52%)	:arrow_down:
... and 119 more

[t2t2]

Made a sandbox with this patch, most frequently used otel web instrumentations (document-load, user-interaction, xhr and fetch) and an artificial time drift simulator:

https://codesandbox.io/s/modest-fermat-4eu09e?file=/src/otel-fixes.ts

It doesn't improve this test case a lot (user interaction's in right time scale, as it's auto + auto), pretty much all cases of performance timestamps are still affected by drift

1. document load: performance time start + performance time end:

2. fetch: auto start + performance time end (duration becomes negative -> set to 0)

[dyladan]

It doesn't improve this test case a lot (user interaction's in right time scale, as it's auto + auto), pretty much all cases of performance timestamps are still affected by drift

These instrumentations all use auto start and manual end times.

duration becomes negative -> set to 0

If the duration is negative it should be getting the drift offset correction applied, not just set to 0. If you look at the diagram in the linked comment there is no situation where it should be set to 0, so there must be some bad code path.

[t2t2]

Updated codesandbox with pr changes as of now

This was the root of the 0-duration spans in your example too

Yep fixed on auto start + perf end, however span events (input: perf timestamp) also need correcting (now they end up outside the span w/ drift)

These instrumentations all use auto start and manual end times.

document-load spans don't, as they use manual (performance API) times for both start and end, and these still get drifted:

[dyladan]

document-load spans don't, as they use manual (performance API) times for both start and end, and these still get drifted

I'm not sure what we can do there. If the user provides manual start and end times we can't correct drift because they may be intentionally describing a span that happened in the past.

[t2t2]

If the user provides manual start and end times we can't correct drift because they may be intentionally describing a span that happened in the past.

There is currently an assumption that any numeric value lower than timeOrigin is a performance timestamp:

https://github.com/open-telemetry/opentelemetry-js/blob/1b7246abb49164ec5c2cff7b66956c454f230fed/packages/opentelemetry-core/src/common/time.ts#L88

So it's actually impossible to create spans in the past (w/ accounting for drift) anyway:

[Flarna]

I'm not sure what we can do there. If the user provides manual start and end times we can't correct drift because they may be intentionally describing a span that happened in the past.

We can document how we create timestamps to allow users to keep in sync. Maybe provide some helper APIs. And use this mechanism at least in the instrumentations hosted here.

[dyladan]

If the user provides manual start and end times we can't correct drift because they may be intentionally describing a span that happened in the past.

There is currently an assumption that any numeric value lower than timeOrigin is a performance timestamp:

https://github.com/open-telemetry/opentelemetry-js/blob/1b7246abb49164ec5c2cff7b66956c454f230fed/packages/opentelemetry-core/src/common/time.ts#L88

So it's actually impossible to create spans in the past (w/ accounting for drift) anyway:

Hmm so there is. That is disappointing and actually strikes me as a bug. The time code in core attempts to do way too much magic IMO and really limits us. That specific one can probably be fixed by changing it so that the heuristic is < performance.now() instead of < performance.timeOrigin. It would at least limit impossible times to epoch + time the page has been open.

I'm not sure what we can do there. If the user provides manual start and end times we can't correct drift because they may be intentionally describing a span that happened in the past.

We can document how we create timestamps to allow users to keep in sync. Maybe provide some helper APIs. And use this mechanism at least in the instrumentations hosted here.

I agree here documentation is a bare minimum and providing a helper API of some kind to correct drift would be a good idea

[github-actions[bot]]

This PR is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days.

[legendecas]

Superseded by https://github.com/open-telemetry/opentelemetry-js/pull/3434.