fix: filter out honeybadger source code from stack trace (#982)

.github/PULL_REQUEST_TEMPLATE.md

@@ -16,7 +16,6 @@ List related PRs against other branches:
 ## Todos
 - [ ] Tests
 - [ ] Documentation
-- [ ] Changelog Entry (unreleased)
 
 ## Steps to Test or Reproduce
 Outline the steps to test or reproduce the PR here.

packages/core/src/client.ts

@@ -312,13 +312,13 @@ export abstract class Client {
       tags: uniqueTags,
     })
 
-    let backtraceShift = 0
     if (typeof notice.stack !== 'string' || !notice.stack.trim()) {
       notice.stack = generateStackTrace()
-      backtraceShift = 2
+      notice.backtrace = makeBacktrace(notice.stack, true, this.logger)
+    }
+    else {
+      notice.backtrace = makeBacktrace(notice.stack, false, this.logger)
     }
-
-    notice.backtrace = makeBacktrace(notice.stack, backtraceShift)
 
     return notice as Notice
   }
@@ -376,7 +376,7 @@ export abstract class Client {
         backtrace: notice.backtrace,
         fingerprint: notice.fingerprint,
         tags: notice.tags,
-        causes: getCauses(notice),
+        causes: getCauses(notice, this.logger),
       },
       request: {
         url: filterUrl(notice.url, this.config.filters),

packages/core/src/util.ts

@@ -39,7 +39,7 @@ export function objectIsExtensible(obj): boolean {
   return Object.isExtensible(obj)
 }
 
-export function makeBacktrace(stack: string, shift = 0): BacktraceFrame[] {
+export function makeBacktrace(stack: string, filterHbSourceCode = false, logger: Logger = console): BacktraceFrame[] {
   try {
     const backtrace = stackTraceParser
       .parse(stack)
@@ -51,23 +51,81 @@ export function makeBacktrace(stack: string, shift = 0): BacktraceFrame[] {
           column: line.column
         }
       })
-    backtrace.splice(0, shift)
+    if (filterHbSourceCode) {
+      backtrace.splice(0, calculateBacktraceShift(backtrace))
+    }
+
     return backtrace
-  } catch (_err) {
-    // TODO: log error
+  } catch (err) {
+    logger.debug(err)
     return []
   }
 }
 
-export function getCauses(notice: Partial<Notice>) {
+function isFrameFromHbSourceCode(frame: BacktraceFrame) {
+  let hasHbFile = false
+  let hasHbMethod = false
+  if (frame.file) {
+    hasHbFile = frame.file.toLowerCase().indexOf('@honeybadger-io') > -1
+  }
+  if (frame.method) {
+    hasHbMethod = frame.method.toLowerCase().indexOf('@honeybadger-io') > -1
+  }
+
+  return hasHbFile || hasHbMethod
+}
+
+export const DEFAULT_BACKTRACE_SHIFT = 3
+
+/**
+ * If {@link generateStackTrace} is used, we want to exclude frames that come from
+ * Honeybadger's source code.
+ *
+ * Logic:
+ * - For each frame, increment the shift if source code is from Honeybadger
+ * - If a frame from an <anonymous> file is encountered increment the shift ONLY if between Honeybadger source code
+ *   (i.e. previous and next frames are from Honeybadger)
+ * - Exit when frame encountered is not from Honeybadger source code
+ *
+ * Note: this will not always work, especially in browser versions where code
+ *       is minified, uglified and bundled.
+ *       For those cases we default to 3:
+ *       - generateStackTrace
+ *       - makeNotice
+ *       - notify
+ */
+export function calculateBacktraceShift(backtrace: BacktraceFrame[]) {
+  let shift = 0
+  for (let i = 0; i < backtrace.length; i++) {
+    const frame = backtrace[i]
+    if (isFrameFromHbSourceCode(frame)) {
+      shift++
+      continue
+    }
+
+    if (!frame.file || frame.file === '<anonymous>') {
+      const nextFrame = backtrace[i + 1]
+      if (nextFrame && isFrameFromHbSourceCode(nextFrame)) {
+        shift++
+        continue
+      }
+    }
+
+    break
+  }
+
+  return shift || DEFAULT_BACKTRACE_SHIFT
+}
+
+export function getCauses(notice: Partial<Notice>, logger: Logger) {
   if (notice.cause) {
     const causes =[]
     let cause = notice as Error
     while (causes.length < 3 && (cause = cause.cause) as Error) {
       causes.push({
         class: cause.name,
         message: cause.message,
-        backtrace: typeof cause.stack == 'string' ? makeBacktrace(cause.stack) : null
+        backtrace: typeof cause.stack == 'string' ? makeBacktrace(cause.stack, false, logger) : null
       })
     }
     return causes

packages/core/test/client.test.ts

@@ -1,5 +1,7 @@
+import * as stackTraceParser from 'stacktrace-parser'
 import { nullLogger, TestClient, TestTransport } from './helpers'
 import { Notice } from '../src/types'
+import { makeBacktrace, DEFAULT_BACKTRACE_SHIFT } from '../src/util'
 
 class MyError extends Error {
   context = null
@@ -19,7 +21,8 @@ describe('client', function () {
   beforeEach(function () {
     client = new TestClient({
       logger: nullLogger(),
-      environment: null
+      environment: null,
+      projectRoot: process.cwd()
     }, new TestTransport())
     client.configure()
   })
@@ -309,18 +312,6 @@ describe('client', function () {
       expect(payload.error.backtrace.length).toBeGreaterThan(0)
     })
 
-    it('generates a backtrace when there isn\'t one', function () {
-      client.configure({
-        apiKey: 'testing'
-      })
-
-      const payload = client.getPayload('expected message')
-
-      expect(payload.error.message).toEqual('expected message')
-      expect((payload.error.backtrace).length).toBeGreaterThan(0)
-      expect(payload.error.backtrace[0].file).toMatch('helpers.ts')
-    })
-
     it('sends details', function () {
       client.configure({
         apiKey: 'testing'
@@ -338,6 +329,93 @@ describe('client', function () {
     })
   })
 
+  describe('backtrace', function () {
+    it('generates a backtrace when there isn\'t one', function () {
+      client.configure({
+        apiKey: 'testing'
+      })
+
+      const payload = client.getPayload('expected message')
+
+      expect(payload.error.message).toEqual('expected message')
+      expect((payload.error.backtrace).length).toBeGreaterThan(0)
+      expect(payload.error.backtrace[0].file).toMatch('client.test.ts')
+    })
+
+    it('returns an empty array when no stack is undefined', function () {
+      const backtrace = makeBacktrace(undefined)
+      expect(backtrace).toEqual([])
+    })
+
+    it('filters out top frames that come from @honeybadger-io (nodejs)', function () {
+      const error = new Error('ENOENT: no such file or directory, open \'\'/tmp/file-123456\'\'')
+      error.stack = `Error: ENOENT: no such file or directory, open ''/tmp/file-67efc3cb2da4'' 
+            at generateStackTrace (/var/www/somebody/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:563:15)
+            at Honeybadger.Client.makeNotice (/var/www/somebody/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:985:60)
+            at Honeybadger.Client.notify (/var/www/somebody/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:827:27)
+            at /var/www/somebody/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:946:19
+            at new Promise (<anonymous>)
+            at Honeybadger.Client.notifyAsync (/var/www/somebody/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:914:16)
+            at HoneybadgerTransport.log (/var/www/somebody/node_modules/@somebody/logger/HoneybadgerTransport.js:18:19)
+            at HoneybadgerTransport._write (/var/www/somebody/node_modules/winston-transport/index.js:82:19)
+            at doWrite (/var/www/somebody/node_modules/winston-transport/node_modules/readable-stream/lib/_stream_writable.js:409:139)
+            at writeOrBuffer (/var/www/somebody/node_modules/winston-transport/node_modules/readable-stream/lib/_stream_writable.js:398:5)
+            at HoneybadgerTransport.Writable.write (/var/www/somebody/node_modules/winston-transport/node_modules/readable-stream/lib/_stream_writable.js:307:11)
+            at DerivedLogger.ondata (/var/www/somebody/node_modules/winston/node_modules/readable-stream/lib/_stream_readable.js:681:20)
+            at DerivedLogger.emit (node:events:525:35)
+            at DerivedLogger.emit (node:domain:489:12)
+            at addChunk (/var/www/somebody/node_modules/winston/node_modules/readable-stream/lib/_stream_readable.js:298:12)
+            at readableAddChunk (/var/www/somebody/node_modules/winston/node_modules/readable-stream/lib/_stream_readable.js:280:11)
+            at DerivedLogger.Readable.push (/var/www/somebody/node_modules/winston/node_modules/readable-stream/lib/_stream_readable.js:241:10)
+            at DerivedLogger.Transform.push (/var/www/somebody/node_modules/winston/node_modules/readable-stream/lib/_stream_transform.js:139:32)
+            at DerivedLogger._transform (/var/www/somebody/node_modules/winston/lib/winston/logger.js:313:12)
+            at DerivedLogger.Transform._read (/var/www/somebody/node_modules/winston/node_modules/readable-stream/lib/_stream_transform.js:177:10)
+            at DerivedLogger.Transform._write (/var/www/somebody/node_modules/winston/node_modules/readable-stream/lib/_stream_transform.js:164:83)
+            at doWrite (/var/www/somebody/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:409:139)
+            at writeOrBuffer (/var/www/somebody/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:398:5)
+            at DerivedLogger.Writable.write (/var/www/somebody/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:307:11)
+            at DerivedLogger.log (/var/www/somebody/node_modules/winston/lib/winston/logger.js:252:14)
+            at DerivedLogger.<computed> [as error] (/var/www/somebody/node_modules/winston/lib/winston/create-logger.js:95:19)
+            at console.hideMe [as error] (/var/www/somebody/node_modules/@somebody/logger/index.js:83:45)
+            at Function.logerror (/var/www/somebody/node_modules/express/lib/application.js:647:43)`
+      const backtrace = makeBacktrace(error.stack, true)
+      expect(backtrace[0]).toEqual({
+        file: '/var/www/somebody/node_modules/@somebody/logger/HoneybadgerTransport.js',
+        method: 'HoneybadgerTransport.log',
+        number: 18,
+        column: 19
+      })
+    })
+
+    it('filters out top frames that come from @honeybadger-io (browser)', function () {
+      const error = new Error('This is a test message reported from an addEventListener callback.')
+      error.stack = `Error: This is a test message reported from an addEventListener callback.
+            at __webpack_modules__../node_modules/@honeybadger-io/js/dist/browser/honeybadger.js.Client.notify (http://localhost:63342/honeybadger-js/packages/js/examples/webpack/bundle.js:821:28)
+            at HTMLButtonElement.<anonymous> (http://localhost:63342/honeybadger-js/packages/js/examples/webpack/bundle.js:2139:10)
+            at func.___hb (http://localhost:63342/honeybadger-js/packages/js/examples/webpack/bundle.js:2030:39)`
+      const backtrace = makeBacktrace(error.stack, true)
+      expect(backtrace[0]).toEqual({
+        file: 'http://localhost:63342/honeybadger-js/packages/js/examples/webpack/bundle.js',
+        method: 'HTMLButtonElement.<anonymous>',
+        number: 2139,
+        column: 10
+      })
+    })
+
+    it('filters out default number of frames if no honeybadger source code is found', function () {
+      const error = new Error('This is an error from the test file. Tests are not under @honeybadger-io node_modules so the default backtrace shift will be applied.')
+      const originalBacktrace = stackTraceParser.parse(error.stack)
+      const shiftedBacktrace = makeBacktrace(error.stack, true)
+      expect(originalBacktrace.length).toEqual(shiftedBacktrace.length + DEFAULT_BACKTRACE_SHIFT)
+      expect(originalBacktrace[DEFAULT_BACKTRACE_SHIFT]).toMatchObject({
+        file: shiftedBacktrace[0].file,
+        methodName: shiftedBacktrace[0].method,
+        lineNumber: shiftedBacktrace[0].number,
+        column: shiftedBacktrace[0].column
+      })
+    })
+  })
+
   describe('notifyAsync', function () {
     beforeEach(() => {
       client.configure({

packages/js/test/unit/server.test.ts

@@ -1,4 +1,3 @@
-import { join } from 'path'
 import { Client as BaseClient } from '@honeybadger-io/core'
 import nock from 'nock'
 import Singleton from '../../src/server'
@@ -8,11 +7,9 @@ describe('server client', function () {
   let client: typeof Singleton
 
   beforeEach(function () {
-    const MONOREPO_ROOT = join(__dirname, '../../../..')
     client = Singleton.factory({
       logger: nullLogger(),
       environment: null,
-      projectRoot: MONOREPO_ROOT
     })
   })
 

packages/js/test/unit/server/backtrace.test.ts → packages/js/test/unit/server/backtrace.server.test.ts

@@ -4,11 +4,11 @@ import { getSourceFile } from '../../../src/server/util'
 const { getSourceForBacktrace, makeBacktrace, makeNotice } = Util
 
 // this is in a separate file, because we are actually testing the line number of the code
-describe('makeBacktrace', function () {
+describe('getSourceForBacktrace', function () {
   it('returns a parsed stacktrace in Honeybadger format', async function notAnonymous() {
     const error = new Error('this is an error from tests')
     const notice = makeNotice(error)
-    notice.backtrace = makeBacktrace(notice.stack, 0)
+    notice.backtrace = makeBacktrace(notice.stack)
     expect(notice.backtrace[0]).toEqual({
       file: __filename,
       method: 'Object.<anonymous>',
@@ -18,16 +18,11 @@ describe('makeBacktrace', function () {
 
     const backtrace = await getSourceForBacktrace(notice.backtrace, getSourceFile)
     expect(backtrace[0]).toEqual({
-      '7': 'describe(\'makeBacktrace\', function () {',
+      '7': 'describe(\'getSourceForBacktrace\', function () {',
       '8': '  it(\'returns a parsed stacktrace in Honeybadger format\', async function notAnonymous() {',
       '9': '    const error = new Error(\'this is an error from tests\')',
       '10': '    const notice = makeNotice(error)',
-      '11': '    notice.backtrace = makeBacktrace(notice.stack, 0)'
+      '11': '    notice.backtrace = makeBacktrace(notice.stack)'
     })
   })
-
-  it('returns an empty array when no stack is undefined', function () {
-    const backtrace = makeBacktrace(undefined, 0)
-    expect(backtrace).toEqual([])
-  })
 })

packages/js/test/unit/server/middleware.server.test.ts

@@ -100,7 +100,7 @@ describe('Express Middleware', function () {
       const initialContext = client.__getContext();
       client.setContext({ reqId: req.params.reqId });
       setTimeout(() => {
-        res.json({
+        res.status(200).json({
           initial: initialContext,
           final: client.__getContext()
         });
@@ -137,7 +137,7 @@ describe('Express Middleware', function () {
     app.use(client.errorHandler)
 
     app.use(function(_err, _req, res, _next) {
-      res.json(client.__getContext(), 500);
+      res.status(500).json(client.__getContext());
     })
 
     return Promise.all([80, 90].map((i) => {