fix(sdk-trace-base): make span start times resistant to hrtime clock …

…drift

packages/opentelemetry-context-async-hooks/src/AbstractAsyncHooksContextManager.ts

@@ -19,15 +19,6 @@ import { EventEmitter } from 'events';
 
 type Func<T> = (...args: unknown[]) => T;
 
-/**
- * Store a map for each event of all original listeners and their "patched"
- * version. So when a listener is removed by the user, the corresponding
- * patched function will be also removed.
- */
-interface PatchMap {
-  [name: string]: WeakMap<Func<void>, Func<void>>;
-}
-
 const ADD_LISTENER_METHODS = [
   'addListener' as const,
   'on' as const,
@@ -37,7 +28,7 @@ const ADD_LISTENER_METHODS = [
 ];
 
 export abstract class AbstractAsyncHooksContextManager
-implements ContextManager {
+  implements ContextManager {
   abstract active(): Context;
 
   abstract with<A extends unknown[], F extends (...args: A) => ReturnType<F>>(
@@ -79,6 +70,10 @@ implements ContextManager {
       writable: false,
       value: target.length,
     });
+
+    // eslint-disable-next-line @typescript-eslint/no-explicit-any
+    (target as any)[this._kOtWrapper] = contextWrapper;
+
     /**
      * It isn't possible to tell Typescript that contextWrapper is the same as T
      * so we forced to cast as any here.
@@ -109,10 +104,10 @@ implements ContextManager {
     });
     // patch methods that remove a listener
     if (typeof ee.removeListener === 'function') {
-      ee.removeListener = this._patchRemoveListener(ee, ee.removeListener);
+      ee.removeListener = this._patchRemoveListener(ee.removeListener);
     }
     if (typeof ee.off === 'function') {
-      ee.off = this._patchRemoveListener(ee, ee.off);
+      ee.off = this._patchRemoveListener(ee.off);
     }
     // patch method that remove all listeners
     if (typeof ee.removeAllListeners === 'function') {
@@ -130,14 +125,11 @@ implements ContextManager {
    * @param ee EventEmitter instance
    * @param original reference to the patched method
    */
-  private _patchRemoveListener(ee: EventEmitter, original: Function) {
+  private _patchRemoveListener(original: Function) {
     const contextManager = this;
     return function (this: never, event: string, listener: Func<void>) {
-      const events = contextManager._getPatchMap(ee)?.[event];
-      if (events === undefined) {
-        return original.call(this, event, listener);
-      }
-      const patchedListener = events.get(listener);
+      // eslint-disable-next-line @typescript-eslint/no-explicit-any
+      const patchedListener = (listener as any)[contextManager._kOtWrapper];
       return original.call(this, event, patchedListener || listener);
     };
   }
@@ -204,4 +196,5 @@ implements ContextManager {
   }
 
   private readonly _kOtListeners = Symbol('OtListeners');
+  private readonly _kOtWrapper = Symbol('OpenTelemetry wrapper function');
 }

packages/opentelemetry-core/src/common/time.ts

@@ -121,6 +121,18 @@ export function hrTimeDuration(
   return [seconds, nanos];
 }
 
+/**
+ * Add an HrTime duration to an HrTime
+ */
+export function addHrTime(time: api.HrTime, duration: api.HrTime): api.HrTime {
+  const out: api.HrTime = [time[0] + duration[0], time[1] + duration[1]];
+  if (out[1] > 1e9) {
+    out[1] -= 1e9;
+    out[0] += 1;
+  }
+  return out;
+}
+
 /**
  * Convert hrTime to timestamp, for example "2019-05-14T17:00:00.000123456Z"
  * @param time

packages/opentelemetry-sdk-trace-base/src/Span.ts

@@ -23,6 +23,7 @@ import {
   isTimeInput,
   timeInputToHrTime,
   sanitizeAttributes,
+  addHrTime,
 } from '@opentelemetry/core';
 import { Resource } from '@opentelemetry/resources';
 import { SemanticAttributes } from '@opentelemetry/semantic-conventions';
@@ -59,6 +60,7 @@ export class Span implements api.Span, ReadableSpan {
   private readonly _spanProcessor: SpanProcessor;
   private readonly _spanLimits: SpanLimits;
   private readonly _attributeValueLengthLimit: number;
+  private readonly _hrStartTime: api.HrTime;
 
   /** Constructs a new Span instance. */
   constructor(
@@ -69,14 +71,15 @@ export class Span implements api.Span, ReadableSpan {
     kind: api.SpanKind,
     parentSpanId?: string,
     links: api.Link[] = [],
-    startTime: api.TimeInput = hrTime()
+    startTime?: api.TimeInput
   ) {
     this.name = spanName;
     this._spanContext = spanContext;
     this.parentSpanId = parentSpanId;
     this.kind = kind;
     this.links = links;
-    this.startTime = timeInputToHrTime(startTime);
+    this._hrStartTime = hrTime();
+    this.startTime = timeInputToHrTime(startTime ?? Date.now());
     this.resource = parentTracer.resource;
     this.instrumentationLibrary = parentTracer.instrumentationLibrary;
     this._spanLimits = parentTracer.getSpanLimits();
@@ -103,7 +106,7 @@ export class Span implements api.Span, ReadableSpan {
 
     if (
       Object.keys(this.attributes).length >=
-        this._spanLimits.attributeCountLimit! &&
+      this._spanLimits.attributeCountLimit! &&
       !Object.prototype.hasOwnProperty.call(this.attributes, key)
     ) {
       return this;
@@ -171,15 +174,22 @@ export class Span implements api.Span, ReadableSpan {
     return this;
   }
 
-  end(endTime: api.TimeInput = hrTime()): void {
+  end(endTime?: api.TimeInput): void {
     if (this._isSpanEnded()) {
       api.diag.error('You can only call end() on a span once.');
       return;
     }
     this._ended = true;
-    this.endTime = timeInputToHrTime(endTime);
 
-    this._duration = hrTimeDuration(this.startTime, this.endTime);
+
+    if (endTime != null) {
+      this.endTime = timeInputToHrTime(endTime);
+      this._duration = hrTimeDuration(this._hrStartTime, this.endTime);
+    } else {
+      this._duration = hrTimeDuration(this._hrStartTime, hrTime());
+      this.endTime = addHrTime(this.startTime, this._duration);
+    }
+
     if (this._duration[0] < 0) {
       api.diag.warn(
         'Inconsistent start and end time, startTime > endTime',