Fix invalid timings in span events (#4486)

* fix: use reference value to avoid invalid timings in span * add comment, add to changelog * donot report invalid timing in span * lint fix * fix failing test * fix failing test 2 * Add tests * add removed test * suggested changes --------- Co-authored-by: Marc Pichler <marc.pichler@dynatrace.com>
open-telemetry · Apr 3, 2024 · e01f493 · e01f493
1 parent 5231aa2
commit e01f493
Show file tree

Hide file tree

Showing 3 changed files with 94 additions and 2 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -13,6 +13,8 @@ For experimental package changes, see the [experimental CHANGELOG](experimental/
 
 ### :bug: (Bug Fix)
 
+* fix(sdk-trace-web): fix invalid timings in span events [#4486](https://github.com/open-telemetry/opentelemetry-js/pull/4486) @Abinet18
+
 ### :books: (Refine Doc)
 
 ### :house: (Internal)

diff --git a/packages/opentelemetry-sdk-trace-web/src/utils.ts b/packages/opentelemetry-sdk-trace-web/src/utils.ts
@@ -56,17 +56,30 @@ export function hasKey<O extends object>(
  * @param span
  * @param performanceName name of performance entry for time start
  * @param entries
+ * @param refPerfName name of performance entry to use for reference
  */
 export function addSpanNetworkEvent(
   span: api.Span,
   performanceName: string,
-  entries: PerformanceEntries
+  entries: PerformanceEntries,
+  refPerfName?: string
 ): api.Span | undefined {
+  let perfTime = undefined;
+  let refTime = undefined;
   if (
     hasKey(entries, performanceName) &&
     typeof entries[performanceName] === 'number'
   ) {
-    span.addEvent(performanceName, entries[performanceName]);
+    perfTime = entries[performanceName];
+  }
+  const refName = refPerfName || PTN.FETCH_START;
+  // Use a reference time which is the earliest possible value so that the performance timings that are earlier should not be added
+  // using FETCH START time in case no reference is provided
+  if (hasKey(entries, refName) && typeof entries[refName] === 'number') {
+    refTime = entries[refName];
+  }
+  if (perfTime !== undefined && refTime !== undefined && perfTime >= refTime) {
+    span.addEvent(performanceName, perfTime);
     return span;
   }
   return undefined;

diff --git a/packages/opentelemetry-sdk-trace-web/test/utils.test.ts b/packages/opentelemetry-sdk-trace-web/test/utils.test.ts
@@ -213,7 +213,84 @@ describe('utils', () => {
         );
       });
     });
+    describe('when entries contain invalid performance timing', () => {
+      it('should only add events with time greater that or equal to reference value to span', () => {
+        const addEventSpy = sinon.spy();
+        const span = {
+          addEvent: addEventSpy,
+        } as unknown as tracing.Span;
+        const entries = {
+          [PTN.FETCH_START]: 123, // default reference time
+          [PTN.CONNECT_START]: 0,
+          [PTN.REQUEST_START]: 140,
+        } as PerformanceEntries;
+
+        assert.strictEqual(addEventSpy.callCount, 0);
+
+        addSpanNetworkEvent(span, PTN.CONNECT_START, entries);
+
+        assert.strictEqual(
+          addEventSpy.callCount,
+          0,
+          'should not call addEvent'
+        );
+
+        addSpanNetworkEvent(span, PTN.REQUEST_START, entries);
+
+        assert.strictEqual(
+          addEventSpy.callCount,
+          1,
+          'should call addEvent for valid value'
+        );
+      });
+    });
+
+    describe('when entries contain invalid performance timing and a reference event', () => {
+      it('should only add events with time greater that or equal to reference value to span', () => {
+        const addEventSpy = sinon.spy();
+        const span = {
+          addEvent: addEventSpy,
+        } as unknown as tracing.Span;
+        const entries = {
+          [PTN.FETCH_START]: 120,
+          [PTN.CONNECT_START]: 120, // this is used as reference time here
+          [PTN.REQUEST_START]: 10,
+        } as PerformanceEntries;
+
+        assert.strictEqual(addEventSpy.callCount, 0);
+
+        addSpanNetworkEvent(
+          span,
+          PTN.REQUEST_START,
+          entries,
+          PTN.CONNECT_START
+        );
+
+        assert.strictEqual(
+          addEventSpy.callCount,
+          0,
+          'should not call addEvent'
+        );
+
+        addSpanNetworkEvent(span, PTN.FETCH_START, entries, PTN.CONNECT_START);
+
+        assert.strictEqual(
+          addEventSpy.callCount,
+          1,
+          'should call addEvent for valid value'
+        );
+
+        addEventSpy.resetHistory();
+        addSpanNetworkEvent(span, PTN.CONNECT_START, entries, 'foo'); // invalid reference , not adding event to span
+        assert.strictEqual(
+          addEventSpy.callCount,
+          0,
+          'should not call addEvent for invalid reference(non-existent)'
+        );
+      });
+    });
   });
+
   describe('getResource', () => {
     const startTime = [0, 123123123] as HrTime;
     beforeEach(() => {