🐛 [RUMF-71] do not report negative performance timing duration (#264)

* 🐛 [RUMF-71] do not report negative performance timing duration * 🔇 [RUM] remove logs for abnormal duration * 👌 [RUMF-71] discard the whole performance entry if it looks abnormal
DataDog · Feb 12, 2020 · 33178dc · 33178dc
1 parent 7e2a99d
commit 33178dc
Show file tree

Hide file tree

Showing 3 changed files with 74 additions and 48 deletions.
diff --git a/packages/rum/src/resourceUtils.ts b/packages/rum/src/resourceUtils.ts
@@ -39,57 +39,40 @@ export function computeResourceKind(timing: PerformanceResourceTiming) {
   return ResourceKind.OTHER
 }
 
-const durationPairs: Array<[keyof PerformanceResourceTiming, keyof PerformanceResourceTiming]> = [
-  ['connectStart', 'connectEnd'],
-  ['domainLookupStart', 'domainLookupEnd'],
-  ['responseStart', 'responseEnd'],
-  ['requestStart', 'responseStart'],
-  ['redirectStart', 'redirectEnd'],
-  ['secureConnectionStart', 'connectEnd'],
-]
-function reporteAbnormalEntry(entry: PerformanceResourceTiming) {
-  let error = ''
-  for (const [start, end] of durationPairs) {
-    if (entry[start] < 0) {
-      error += `${start} is negative\n`
-    } else if (entry[start] > entry[end]) {
-      error += `${start} is greater than ${end}\n`
-    }
-  }
-  if (error) {
-    addMonitoringMessage(`Got an abnormal PerformanceResourceTiming:
-${error}
-Entry: ${JSON.stringify(entry)}`)
-  }
+function formatTiming(start: number, end: number) {
+  return { duration: msToNs(end - start), start: msToNs(start) }
+}
+
+function isValidTiming(start: number, end: number) {
+  return start > 0 && end > 0 && end >= start
 }
 
 export function computePerformanceResourceDetails(
   entry?: PerformanceResourceTiming
 ): PerformanceResourceDetails | undefined {
-  if (entry && hasTimingAllowedAttributes(entry)) {
-    reporteAbnormalEntry(entry)
-    return {
-      connect: { duration: msToNs(entry.connectEnd - entry.connectStart), start: msToNs(entry.connectStart) },
-      dns: {
-        duration: msToNs(entry.domainLookupEnd - entry.domainLookupStart),
-        start: msToNs(entry.domainLookupStart),
-      },
-      download: { duration: msToNs(entry.responseEnd - entry.responseStart), start: msToNs(entry.responseStart) },
-      firstByte: { duration: msToNs(entry.responseStart - entry.requestStart), start: msToNs(entry.requestStart) },
-      redirect:
-        entry.redirectStart > 0
-          ? { duration: msToNs(entry.redirectEnd - entry.redirectStart), start: msToNs(entry.redirectStart) }
-          : undefined,
-      ssl:
-        entry.secureConnectionStart > 0
-          ? {
-              duration: msToNs(entry.connectEnd - entry.secureConnectionStart),
-              start: msToNs(entry.secureConnectionStart),
-            }
-          : undefined,
-    }
+  if (!entry || !hasTimingAllowedAttributes(entry)) {
+    return undefined
+  }
+  if (
+    !isValidTiming(entry.connectStart, entry.connectEnd) ||
+    !isValidTiming(entry.domainLookupStart, entry.domainLookupEnd) ||
+    !isValidTiming(entry.responseStart, entry.responseEnd) ||
+    !isValidTiming(entry.requestStart, entry.responseStart)
+  ) {
+    return undefined
+  }
+  return {
+    connect: formatTiming(entry.connectStart, entry.connectEnd),
+    dns: formatTiming(entry.domainLookupStart, entry.domainLookupEnd),
+    download: formatTiming(entry.responseStart, entry.responseEnd),
+    firstByte: formatTiming(entry.requestStart, entry.responseStart),
+    redirect: isValidTiming(entry.redirectStart, entry.redirectEnd)
+      ? formatTiming(entry.redirectStart, entry.redirectEnd)
+      : undefined,
+    ssl: isValidTiming(entry.secureConnectionStart, entry.connectEnd)
+      ? formatTiming(entry.secureConnectionStart, entry.connectEnd)
+      : undefined,
   }
-  return undefined
 }
 
 export function computeSize(entry?: PerformanceResourceTiming) {

diff --git a/packages/rum/test/rum.spec.ts b/packages/rum/test/rum.spec.ts
@@ -150,8 +150,11 @@ describe('rum handle performance entry', () => {
     const entry: Partial<PerformanceResourceTiming> = {
       connectEnd: 10,
       connectStart: 3,
+      domainLookupEnd: 3,
+      domainLookupStart: 3,
       entryType: 'resource',
       name: 'http://localhost/test',
+      requestStart: 20,
       responseEnd: 100,
       responseStart: 25,
     }
@@ -163,8 +166,48 @@ describe('rum handle performance entry', () => {
       new LifeCycle()
     )
     const resourceEvent = getEntry(addRumEvent, 0) as RumResourceEvent
-    expect(resourceEvent.http.performance!.connect.duration).toEqual(7 * 1e6)
-    expect(resourceEvent.http.performance!.download.duration).toEqual(75 * 1e6)
+    expect(resourceEvent.http.performance!.connect!.duration).toEqual(7 * 1e6)
+    expect(resourceEvent.http.performance!.download!.duration).toEqual(75 * 1e6)
+  })
+
+  describe('ignore invalid performance entry', () => {
+    it('when it has a negative timing start', () => {
+      const entry: Partial<PerformanceResourceTiming> = {
+        connectEnd: 10,
+        connectStart: -3,
+        entryType: 'resource',
+        name: 'http://localhost/test',
+        responseEnd: 100,
+        responseStart: 25,
+      }
+
+      handleResourceEntry(
+        configuration as Configuration,
+        entry as PerformanceResourceTiming,
+        addRumEvent,
+        new LifeCycle()
+      )
+      const resourceEvent = getEntry(addRumEvent, 0) as RumResourceEvent
+      expect(resourceEvent.http.performance).toBe(undefined)
+    })
+
+    it('when it has timing start after its end', () => {
+      const entry: Partial<PerformanceResourceTiming> = {
+        entryType: 'resource',
+        name: 'http://localhost/test',
+        responseEnd: 25,
+        responseStart: 100,
+      }
+
+      handleResourceEntry(
+        configuration as Configuration,
+        entry as PerformanceResourceTiming,
+        addRumEvent,
+        new LifeCycle()
+      )
+      const resourceEvent = getEntry(addRumEvent, 0) as RumResourceEvent
+      expect(resourceEvent.http.performance).toBe(undefined)
+    })
   })
 })
 

diff --git a/test/e2e/scenario/agents.scenario.ts b/test/e2e/scenario/agents.scenario.ts
@@ -96,7 +96,7 @@ describe('rum', () => {
     expect(timing.http.method).toEqual('GET')
     expect((timing.http as any).status_code).toEqual(200)
     expect(timing.duration).toBeGreaterThan(0)
-    expect(timing.http.performance!.download.start).toBeGreaterThan(0)
+    expect(timing.http.performance!.download!.start).toBeGreaterThan(0)
   })
 
   it('should send performance timings along the view events', async () => {