🐛[RUMF-266] fix xhr incorrect status reported on late abortion (#283)

* feat(trackXhr): make xhr tracking work with Angular

* 🔧 allow fake backend with yarn dev

useful to debug requests behavior with unminified code

* ✅ add xhr tracker unit tests

* ✅ remove xhr scenario

Co-authored-by: Keito Aino <keitoaino@gmail.com>

packages/core/src/requestCollection.ts

@@ -72,7 +72,17 @@ export function trackXhr(observable: RequestObservable) {
       })
     }
 
-    this.addEventListener('loadend', monitor(reportXhr))
+    const originalOnreadystatechange = this.onreadystatechange
+
+    this.onreadystatechange = function() {
+      if (this.readyState === XMLHttpRequest.DONE) {
+        monitor(reportXhr)()
+      }
+
+      if (originalOnreadystatechange) {
+        originalOnreadystatechange.apply(this, arguments as any)
+      }
+    }
 
     return originalSend.apply(this, arguments as any)
   }

packages/core/test/requestCollection.spec.ts

@@ -6,6 +6,7 @@ import {
   RequestDetails,
   RequestType,
   trackFetch,
+  trackXhr,
 } from '../src/requestCollection'
 import { FetchStub, FetchStubBuilder, FetchStubPromise, isFirefox, isIE } from '../src/specHelper'
 
@@ -193,3 +194,152 @@ describe('normalize url', () => {
     expect(normalizeUrl('file://foo.com/my/path')).toEqual('file://foo.com/my/path')
   })
 })
+
+describe('xhr tracker', () => {
+  let originalOpen: typeof XMLHttpRequest.prototype.open
+  let originalSend: typeof XMLHttpRequest.prototype.send
+  let requestObservable: Observable<RequestDetails>
+  let notifySpy: jasmine.Spy
+
+  beforeEach(() => {
+    originalOpen = XMLHttpRequest.prototype.open
+    originalSend = XMLHttpRequest.prototype.send
+    requestObservable = new Observable<RequestDetails>()
+    notifySpy = spyOn(requestObservable, 'notify').and.callThrough()
+    trackXhr(requestObservable)
+  })
+
+  afterEach(() => {
+    XMLHttpRequest.prototype.open = originalOpen
+    XMLHttpRequest.prototype.send = originalSend
+  })
+
+  function xhrSpec(setup: (xhr: XMLHttpRequest) => void, expectations: (xhr: XMLHttpRequest) => void, done: DoneFn) {
+    const xhr = new XMLHttpRequest()
+    xhr.addEventListener('loadend', () => {
+      setTimeout(() => {
+        expect(notifySpy).toHaveBeenCalledWith(
+          jasmine.objectContaining({
+            duration: jasmine.any(Number),
+            startTime: jasmine.any(Number),
+            traceId: undefined,
+            type: 'xhr',
+          })
+        )
+        expectations(xhr)
+        done()
+      })
+    })
+    setup(xhr)
+    xhr.send()
+  }
+
+  it('should track successful request', (done) => {
+    xhrSpec(
+      (xhr) => xhr.open('GET', '/ok'),
+      () => {
+        expect(notifySpy).toHaveBeenCalledWith(
+          jasmine.objectContaining({
+            method: 'GET',
+            response: 'ok',
+            status: 200,
+            url: jasmine.stringMatching('/ok'),
+          })
+        )
+      },
+      done
+    )
+  })
+
+  it('should track client error', (done) => {
+    xhrSpec(
+      (xhr) => xhr.open('GET', '/expected-404'),
+      () => {
+        expect(notifySpy).toHaveBeenCalledWith(
+          jasmine.objectContaining({
+            method: 'GET',
+            response: 'NOT FOUND',
+            status: 404,
+            url: jasmine.stringMatching('/expected-404'),
+          })
+        )
+      },
+      done
+    )
+  })
+
+  it('should track server error', (done) => {
+    xhrSpec(
+      (xhr) => xhr.open('GET', '/throw'),
+      () => {
+        expect(notifySpy).toHaveBeenCalledWith(
+          jasmine.objectContaining({
+            method: 'GET',
+            response: jasmine.stringMatching('expected server error'),
+            status: 500,
+            url: jasmine.stringMatching('/throw'),
+          })
+        )
+      },
+      done
+    )
+  })
+
+  it('should track network error', (done) => {
+    xhrSpec(
+      (xhr) => xhr.open('GET', 'http://foo.bar/qux'),
+      () => {
+        expect(notifySpy).toHaveBeenCalledWith(
+          jasmine.objectContaining({
+            method: 'GET',
+            response: '',
+            status: 0,
+            url: 'http://foo.bar/qux',
+          })
+        )
+      },
+      done
+    )
+  })
+
+  it('should track successful request aborted', (done) => {
+    const onReadyStateChange = jasmine.createSpy()
+    xhrSpec(
+      (xhr) => {
+        xhr.onreadystatechange = onReadyStateChange
+        xhr.addEventListener('load', () => xhr.abort())
+        xhr.open('GET', '/ok')
+      },
+      (xhr) => {
+        expect(xhr.status).toBe(0)
+        expect(onReadyStateChange).toHaveBeenCalled()
+        expect(notifySpy).toHaveBeenCalledWith(
+          jasmine.objectContaining({
+            method: 'GET',
+            response: 'ok',
+            status: 200,
+            url: jasmine.stringMatching('/ok'),
+          })
+        )
+      },
+      done
+    )
+  })
+
+  it('should track successful sync request', (done) => {
+    xhrSpec(
+      (xhr) => xhr.open('GET', '/ok', false),
+      () => {
+        expect(notifySpy).toHaveBeenCalledWith(
+          jasmine.objectContaining({
+            method: 'GET',
+            response: 'ok',
+            status: 200,
+            url: jasmine.stringMatching('/ok'),
+          })
+        )
+      },
+      done
+    )
+  })
+})

test/e2e/scenario/agents.scenario.ts

@@ -175,55 +175,6 @@ describe('rum', () => {
 })
 
 describe('error collection', () => {
-  it('should track xhr error', async () => {
-    await browserExecuteAsync(
-      (baseUrl, unreachableUrl, done) => {
-        let count = 0
-        let xhr = new XMLHttpRequest()
-        xhr.addEventListener('load', () => (count += 1))
-        xhr.open('GET', `${baseUrl}/throw`)
-        xhr.send()
-
-        xhr = new XMLHttpRequest()
-        xhr.addEventListener('load', () => (count += 1))
-        xhr.open('GET', `${baseUrl}/unknown`)
-        xhr.send()
-
-        xhr = new XMLHttpRequest()
-        xhr.addEventListener('error', () => (count += 1))
-        xhr.open('GET', unreachableUrl)
-        xhr.send()
-
-        xhr = new XMLHttpRequest()
-        xhr.addEventListener('load', () => (count += 1))
-        xhr.open('GET', `${baseUrl}/ok`)
-        xhr.send()
-
-        const interval = setInterval(() => {
-          if (count === 4) {
-            clearInterval(interval)
-            done(undefined)
-          }
-        }, 500)
-      },
-      browser.options.baseUrl!,
-      UNREACHABLE_URL
-    )
-    await flushBrowserLogs()
-    await flushEvents()
-    const logs = (await waitServerLogs()).sort(sortByMessage)
-
-    expect(logs.length).toEqual(2)
-
-    expect(logs[0].message).toEqual(`XHR error GET ${browser.options.baseUrl}/throw`)
-    expect(logs[0].http.status_code).toEqual(500)
-    expect(logs[0].error.stack).toMatch(/Server error/)
-
-    expect(logs[1].message).toEqual(`XHR error GET ${UNREACHABLE_URL}`)
-    expect(logs[1].http.status_code).toEqual(0)
-    expect(logs[1].error.stack).toEqual('Failed to load')
-  })
-
   it('should track fetch error', async () => {
     await browserExecuteAsync(
       (baseUrl, unreachableUrl, done) => {

test/server/server.js

@@ -31,9 +31,9 @@ if (process.env.ENV === 'development') {
   // e2e tests
   app.use(express.static(path.join(__dirname, '../../packages/logs/bundle')))
   app.use(express.static(path.join(__dirname, '../../packages/rum/bundle')))
-  app.use(bodyParser.text())
-  fakeBackend(app)
 }
+app.use(bodyParser.text())
+fakeBackend(app)
 
 app.listen(port, () => console.log(`server listening on port ${port}.`))
 

test/unit/karma.base.conf.js

@@ -30,4 +30,19 @@ module.exports = {
     stats: 'errors-only',
     logLevel: 'warn',
   },
+  beforeMiddleware: ['custom'],
+  plugins: ['karma-*', { 'middleware:custom': ['factory', CustomMiddlewareFactory] }],
+}
+
+function CustomMiddlewareFactory() {
+  return function(request, response, next) {
+    if (request.url === '/ok') {
+      response.writeHead(200)
+      return response.end('ok')
+    }
+    if (request.url === '/throw') {
+      throw 'expected server error'
+    }
+    return next()
+  }
 }

test/unit/karma.cbt.conf.js

@@ -11,7 +11,7 @@ const ONE_MINUTE = 60000
 module.exports = function(config) {
   config.set({
     ...karmaBaseConf,
-    plugins: ['karma-*', 'karma-cbt-launcher'],
+    plugins: [...karmaBaseConf.plugins, 'karma-cbt-launcher'],
     reporters: [...karmaBaseConf.reporters, 'CrossBrowserTesting'],
     browsers: Object.keys(browsers),
     concurrency: 1,