From 20734841c5d14c229487a29645932d942dfd4371 Mon Sep 17 00:00:00 2001 From: Dan Skinner Date: Fri, 18 Nov 2022 15:04:23 +0000 Subject: [PATCH] node improvements --- packages/node/package.json | 2 +- packages/node/src/notifier.js | 31 +++++++++------- packages/plugin-express/src/express.js | 23 +++--------- packages/plugin-koa/src/koa.js | 24 +++---------- .../uncaught-exception.js | 11 +++--- .../unhandled-rejection.js | 11 +++--- packages/plugin-restify/src/restify.js | 26 +++----------- test/node/features/connect.feature | 16 +++++++-- test/node/features/express.feature | 35 +++++++++++++++++-- .../fixtures/express/scenarios/app.js | 17 +++++++++ .../features/fixtures/koa/scenarios/app.js | 4 +-- .../fixtures/restify/scenarios/app.js | 8 +++++ test/node/features/koa.feature | 5 ++- test/node/features/restify.feature | 27 ++++++++++++++ 14 files changed, 153 insertions(+), 87 deletions(-) diff --git a/packages/node/package.json b/packages/node/package.json index 7250bdbb96..b36191425d 100644 --- a/packages/node/package.json +++ b/packages/node/package.json @@ -19,7 +19,7 @@ "scripts": { "clean": "rm -fr dist && mkdir dist", "build": "npm run clean && npm run build:dist", - "build:dist": "../../bin/bundle src/notifier.js --node --exclude=iserror,stack-generator,error-stack-parser,pump,byline --standalone=bugsnag | ../../bin/extract-source-map dist/bugsnag.js" + "build:dist": "../../bin/bundle src/notifier.js --node --exclude=iserror,stack-generator,error-stack-parser,pump,byline,async_hooks --standalone=bugsnag | ../../bin/extract-source-map dist/bugsnag.js" }, "author": "Bugsnag", "license": "MIT", diff --git a/packages/node/src/notifier.js b/packages/node/src/notifier.js index 0ef5cf32aa..37776dab52 100644 --- a/packages/node/src/notifier.js +++ b/packages/node/src/notifier.js @@ -2,6 +2,8 @@ const name = 'Bugsnag Node' const version = '__VERSION__' const url = 'https://github.com/bugsnag/bugsnag-js' +const { AsyncLocalStorage } = require('async_hooks') + const Client = require('@bugsnag/core/client') const Event = require('@bugsnag/core/event') const Session = require('@bugsnag/core/session') @@ -14,9 +16,6 @@ const delivery = require('@bugsnag/delivery-node') // extend the base config schema with some node-specific options const schema = { ...require('@bugsnag/core/config').schema, ...require('./config') } -// remove enabledBreadcrumbTypes from the config schema -delete schema.enabledBreadcrumbTypes - const pluginApp = require('@bugsnag/plugin-app-duration') const pluginSurroundingCode = require('@bugsnag/plugin-node-surrounding-code') const pluginInProject = require('@bugsnag/plugin-node-in-project') @@ -43,6 +42,11 @@ const internalPlugins = [ pluginStackframePathNormaliser ] +// Used to store and retrieve the request-scoped client which makes it easy to obtain the request-scoped client +// from anywhere in the codebase e.g. when calling Bugsnag.leaveBreadcrumb() or even within the global unhandled +// promise rejection handler. +const clientContext = new AsyncLocalStorage() + const Bugsnag = { _client: null, createClient: (opts) => { @@ -52,16 +56,12 @@ const Bugsnag = { const bugsnag = new Client(opts, schema, internalPlugins, { name, version, url }) + bugsnag._clientContext = clientContext + bugsnag._setDelivery(delivery) bugsnag._logger.debug('Loaded!') - bugsnag.leaveBreadcrumb = function () { - bugsnag._logger.warn('Breadcrumbs are not supported in Node.js yet') - } - - bugsnag._config.enabledBreadcrumbTypes = [] - return bugsnag }, start: (opts) => { @@ -80,10 +80,15 @@ const Bugsnag = { Object.keys(Client.prototype).forEach((m) => { if (/^_/.test(m)) return Bugsnag[m] = function () { - if (!Bugsnag._client) return console.error(`Bugsnag.${m}() was called before Bugsnag.start()`) - Bugsnag._client._depth += 1 - const ret = Bugsnag._client[m].apply(Bugsnag._client, arguments) - Bugsnag._client._depth -= 1 + // if we are in an async context, use the client from that context + const client = clientContext.getStore() || Bugsnag._client + + if (!client) return console.error(`Bugsnag.${m}() was called before Bugsnag.start()`) + + client._depth += 1 + const ret = client[m].apply(client, arguments) + client._depth -= 1 + return ret } }) diff --git a/packages/plugin-express/src/express.js b/packages/plugin-express/src/express.js index 4127b8213f..ac502a6faa 100644 --- a/packages/plugin-express/src/express.js +++ b/packages/plugin-express/src/express.js @@ -1,5 +1,3 @@ -/* eslint node/no-deprecated-api: [error, {ignoreModuleItems: ["domain"]}] */ -const domain = require('domain') const extractRequestInfo = require('./request-info') const clone = require('@bugsnag/core/lib/clone-client') const handledState = { @@ -15,8 +13,6 @@ module.exports = { name: 'express', load: client => { const requestHandler = (req, res, next) => { - const dom = domain.create() - // Get a client to be scoped to this request. If sessions are enabled, use the // resumeSession() call to get a session client, otherwise, clone the existing client. const requestClient = client._config.autoTrackSessions ? client.resumeSession() : clone(client) @@ -33,20 +29,11 @@ module.exports = { if (!client._config.autoDetectErrors) return next() - // unhandled errors caused by this request - dom.on('error', (err) => { - const event = client.Event.create(err, false, handledState, 'express middleware', 1) - req.bugsnag._notify(event, () => {}, (e, event) => { - if (e) client._logger.error('Failed to send event to Bugsnag') - req.bugsnag._config.onUncaughtException(err, event, client._logger) - }) - if (!res.headersSent) { - res.statusCode = 500 - res.end('Internal server error') - } - }) - - return dom.run(next) + if (client._clientContext) { + client._clientContext.run(requestClient, () => next()) + } else { + next() + } } const errorHandler = (err, req, res, next) => { diff --git a/packages/plugin-koa/src/koa.js b/packages/plugin-koa/src/koa.js index 66de221ebf..1565f5915e 100644 --- a/packages/plugin-koa/src/koa.js +++ b/packages/plugin-koa/src/koa.js @@ -1,5 +1,3 @@ -/* eslint node/no-deprecated-api: [error, {ignoreModuleItems: ["domain"]}] */ -const domain = require('domain') const clone = require('@bugsnag/core/lib/clone-client') const extractRequestInfo = require('./request-info') @@ -16,8 +14,6 @@ module.exports = { name: 'koa', load: client => { const requestHandler = async (ctx, next) => { - const dom = domain.create() - // Get a client to be scoped to this request. If sessions are enabled, use the // resumeSession() call to get a session client, otherwise, clone the existing client. const requestClient = client._config.autoTrackSessions ? client.resumeSession() : clone(client) @@ -31,21 +27,11 @@ module.exports = { event.addMetadata('request', metadata) }, true) - // unhandled errors caused by this request - dom.on('error', (err) => { - const event = client.Event.create(err, false, handledState, 'koa middleware', 1) - ctx.bugsnag._notify(event, () => {}, (e, event) => { - if (e) client._logger.error('Failed to send event to Bugsnag') - ctx.bugsnag._config.onUncaughtException(err, event, client._logger) - }) - if (!ctx.response.headersSent) { - ctx.response.status = 500 - } - }) - - dom.enter() - await next() - dom.exit() + if (client._clientContext) { + await client._clientContext.run(requestClient, () => next()) + } else { + await next() + } } requestHandler.v1 = function * (next) { diff --git a/packages/plugin-node-uncaught-exception/uncaught-exception.js b/packages/plugin-node-uncaught-exception/uncaught-exception.js index cf703a34bf..8cd80d596d 100644 --- a/packages/plugin-node-uncaught-exception/uncaught-exception.js +++ b/packages/plugin-node-uncaught-exception/uncaught-exception.js @@ -4,14 +4,17 @@ module.exports = { if (!client._config.autoDetectErrors) return if (!client._config.enabledErrorTypes.unhandledExceptions) return _handler = err => { - const event = client.Event.create(err, false, { + // if we are in an async context, use the client from that context + const c = (client._clientContext && client._clientContext.getStore()) ? client._clientContext.getStore() : client + + const event = c.Event.create(err, false, { severity: 'error', unhandled: true, severityReason: { type: 'unhandledException' } }, 'uncaughtException handler', 1) - client._notify(event, () => {}, (e, event) => { - if (e) client._logger.error('Failed to send event to Bugsnag') - client._config.onUncaughtException(err, event, client._logger) + c._notify(event, () => {}, (e, event) => { + if (e) c._logger.error('Failed to send event to Bugsnag') + c._config.onUncaughtException(err, event, c._logger) }) } process.on('uncaughtException', _handler) diff --git a/packages/plugin-node-unhandled-rejection/unhandled-rejection.js b/packages/plugin-node-unhandled-rejection/unhandled-rejection.js index 20ac5530d6..43e9340d8d 100644 --- a/packages/plugin-node-unhandled-rejection/unhandled-rejection.js +++ b/packages/plugin-node-unhandled-rejection/unhandled-rejection.js @@ -3,16 +3,19 @@ module.exports = { load: client => { if (!client._config.autoDetectErrors || !client._config.enabledErrorTypes.unhandledRejections) return _handler = err => { - const event = client.Event.create(err, false, { + // if we are in an async context, use the client from that context + const c = (client._clientContext && client._clientContext.getStore()) ? client._clientContext.getStore() : client + + const event = c.Event.create(err, false, { severity: 'error', unhandled: true, severityReason: { type: 'unhandledPromiseRejection' } }, 'unhandledRejection handler', 1) return new Promise(resolve => { - client._notify(event, () => {}, (e, event) => { - if (e) client._logger.error('Failed to send event to Bugsnag') - client._config.onUnhandledRejection(err, event, client._logger) + c._notify(event, () => {}, (e, event) => { + if (e) c._logger.error('Failed to send event to Bugsnag') + c._config.onUnhandledRejection(err, event, c._logger) resolve() }) }) diff --git a/packages/plugin-restify/src/restify.js b/packages/plugin-restify/src/restify.js index 71f6629e7f..4ba76f6061 100644 --- a/packages/plugin-restify/src/restify.js +++ b/packages/plugin-restify/src/restify.js @@ -1,4 +1,3 @@ -const domain = require('domain') // eslint-disable-line const extractRequestInfo = require('./request-info') const clone = require('@bugsnag/core/lib/clone-client') const handledState = { @@ -14,8 +13,6 @@ module.exports = { name: 'restify', load: client => { const requestHandler = (req, res, next) => { - const dom = domain.create() - // Get a client to be scoped to this request. If sessions are enabled, use the // resumeSession() call to get a session client, otherwise, clone the existing client. const requestClient = client._config.autoTrackSessions ? client.resumeSession() : clone(client) @@ -32,24 +29,11 @@ module.exports = { if (!client._config.autoDetectErrors) return next() - // unhandled errors caused by this request - dom.on('error', (err) => { - const event = client.Event.create(err, false, handledState, 'restify middleware', 1) - req.bugsnag._notify(event, () => {}, (e, event) => { - if (e) client._logger.error('Failed to send event to Bugsnag') - req.bugsnag._config.onUncaughtException(err, event, client._logger) - }) - if (!res.headersSent) { - const body = 'Internal server error' - res.writeHead(500, { - 'Content-Length': Buffer.byteLength(body), - 'Content-Type': 'text/plain' - }) - res.end(body) - } - }) - - return dom.run(next) + if (client._clientContext) { + client._clientContext.run(requestClient, () => next()) + } else { + next() + } } const errorHandler = (req, res, err, cb) => { diff --git a/test/node/features/connect.feature b/test/node/features/connect.feature index 3ff28ca3b3..851392be51 100644 --- a/test/node/features/connect.feature +++ b/test/node/features/connect.feature @@ -22,16 +22,18 @@ Scenario: a synchronous thrown error in a route And the event "request.httpMethod" equals "GET" Scenario: an asynchronous thrown error in a route - Then I open the URL "http://connect/async" + Then I open the URL "http://connect/async" tolerating any error And I wait to receive an error Then the error is valid for the error reporting API version "4" for the "Bugsnag Node" notifier And the event "unhandled" is true And the event "severity" equals "error" - And the event "severityReason.type" equals "unhandledErrorMiddleware" + And the event "severityReason.type" equals "unhandledException" And the exception "errorClass" equals "Error" And the exception "message" equals "async" And the exception "type" equals "nodejs" And the "file" of stack frame 0 equals "scenarios/app.js" + And the event "request.url" equals "http://connect/async" + And the event "request.httpMethod" equals "GET" Scenario: an error passed to next(err) Then I open the URL "http://connect/next" @@ -44,6 +46,8 @@ Scenario: an error passed to next(err) And the exception "message" equals "next" And the exception "type" equals "nodejs" And the "file" of stack frame 0 equals "scenarios/app.js" + And the event "request.url" equals "http://connect/next" + And the event "request.httpMethod" equals "GET" Scenario: a synchronous promise rejection in a route Then I open the URL "http://connect/rejection-sync" @@ -56,6 +60,8 @@ Scenario: a synchronous promise rejection in a route And the exception "message" equals "reject sync" And the exception "type" equals "nodejs" And the "file" of stack frame 0 equals "scenarios/app.js" + And the event "request.url" equals "http://connect/rejection-sync" + And the event "request.httpMethod" equals "GET" Scenario: an asynchronous promise rejection in a route Then I open the URL "http://connect/rejection-async" @@ -68,6 +74,8 @@ Scenario: an asynchronous promise rejection in a route And the exception "message" equals "reject async" And the exception "type" equals "nodejs" And the "file" of stack frame 0 equals "scenarios/app.js" + And the event "request.url" equals "http://connect/rejection-async" + And the event "request.httpMethod" equals "GET" Scenario: a string passed to next(err) Then I open the URL "http://connect/string-as-error" @@ -79,6 +87,8 @@ Scenario: a string passed to next(err) And the exception "errorClass" equals "InvalidError" And the exception "message" matches "^express middleware received a non-error\." And the exception "type" equals "nodejs" + And the event "request.url" equals "http://connect/string-as-error" + And the event "request.httpMethod" equals "GET" Scenario: throwing non-Error error Then I open the URL "http://connect/throw-non-error" @@ -90,3 +100,5 @@ Scenario: throwing non-Error error And the exception "errorClass" equals "InvalidError" And the exception "message" matches "^express middleware received a non-error\." And the exception "type" equals "nodejs" + And the event "request.url" equals "http://connect/throw-non-error" + And the event "request.httpMethod" equals "GET" \ No newline at end of file diff --git a/test/node/features/express.feature b/test/node/features/express.feature index f5732d0c3f..2127271d60 100644 --- a/test/node/features/express.feature +++ b/test/node/features/express.feature @@ -23,12 +23,12 @@ Scenario: a synchronous thrown error in a route And the event "request.clientIp" is not null Scenario: an asynchronous thrown error in a route - Then I open the URL "http://express/async" + Then I open the URL "http://express/async" tolerating any error And I wait to receive an error Then the error is valid for the error reporting API version "4" for the "Bugsnag Node" notifier And the event "unhandled" is true And the event "severity" equals "error" - And the event "severityReason.type" equals "unhandledErrorMiddleware" + And the event "severityReason.type" equals "unhandledException" And the exception "errorClass" equals "Error" And the exception "message" equals "async" And the exception "type" equals "nodejs" @@ -124,6 +124,18 @@ Scenario: a handled error passed to req.bugsnag.notify() And the event "request.httpMethod" equals "GET" And the event "request.clientIp" is not null +Scenario: an unhandled promise rejection in an async callback + Then I open the URL "http://express/unhandled-rejection-async-callback" and get a 200 response + And I wait to receive an error + Then the error is valid for the error reporting API version "4" for the "Bugsnag Node" notifier + And the event "unhandled" is true + And the event "severity" equals "error" + And the event "severityReason.type" equals "unhandledPromiseRejection" + And the exception "errorClass" equals "Error" + And the exception "message" equals "unhandled rejection in async callback" + And the event "request.url" equals "http://express/unhandled-rejection-async-callback" + And the event "request.httpMethod" equals "GET" + Scenario: adding body to request metadata When I POST the data "data=in_request_body" to the URL "http://express/bodytest" And I wait to receive an error @@ -136,3 +148,22 @@ Scenario: adding body to request metadata And the "file" of stack frame 0 equals "scenarios/app.js" And the event "request.body.data" equals "in_request_body" And the event "request.httpMethod" equals "POST" + +Scenario: Breadcrumbs from one request do not appear in another + When I open the URL "http://express/breadcrumbs_a" + And I wait to receive an error + Then the error is valid for the error reporting API version "4" for the "Bugsnag Node" notifier + And the event has a "manual" breadcrumb with message "For the first URL" + And the event "request.url" equals "http://express/breadcrumbs_a" + And the event "request.httpMethod" equals "GET" + And the event "request.clientIp" is not null + And I discard the oldest error + + And I open the URL "http://express/breadcrumbs_b" + And I wait to receive an error + Then the error is valid for the error reporting API version "4" for the "Bugsnag Node" notifier + And the event has a "manual" breadcrumb with message "For the second URL" + And the event does not have a "manual" breadcrumb with message "For the first URL" + And the event "request.url" equals "http://express/breadcrumbs_b" + And the event "request.httpMethod" equals "GET" + And the event "request.clientIp" is not null diff --git a/test/node/features/fixtures/express/scenarios/app.js b/test/node/features/fixtures/express/scenarios/app.js index 00e139864c..b61aead087 100644 --- a/test/node/features/fixtures/express/scenarios/app.js +++ b/test/node/features/fixtures/express/scenarios/app.js @@ -62,6 +62,13 @@ app.get('/rejection-async', function (req, res, next) { }, 100) }) +app.get('/unhandled-rejection-async-callback', function (req, res, next) { + setTimeout(function () { + Promise.reject(new Error('unhandled rejection in async callback')) + }, 100) + res.end('OK') +}) + app.get('/string-as-error', function (req, res, next) { next('errrr') }) @@ -108,6 +115,16 @@ app.post('/features/handled', bodyParser.urlencoded(), function (req, res, next) res.end('OK') }) +app.get('/breadcrumbs_a', function (req, res) { + Bugsnag.leaveBreadcrumb('For the first URL') + throw new Error('Error in /breadcrumbs_a') +}) + +app.get('/breadcrumbs_b', function (req, res) { + Bugsnag.leaveBreadcrumb('For the second URL') + throw new Error('Error in /breadcrumbs_b') +}) + app.use(middleware.errorHandler) app.listen(80) diff --git a/test/node/features/fixtures/koa/scenarios/app.js b/test/node/features/fixtures/koa/scenarios/app.js index 6f1d1eabfd..6daf0f0038 100644 --- a/test/node/features/fixtures/koa/scenarios/app.js +++ b/test/node/features/fixtures/koa/scenarios/app.js @@ -62,9 +62,9 @@ app.use(async (ctx, next) => { throw new Error('error in async callback') }, 100) ctx.body = 'ok' - } else if (ctx.path === '/unhandled-reject-async-callback') { + } else if (ctx.path === '/unhandled-rejection-async-callback') { setTimeout(function () { - Promise.reject(new Error('unhandled reject in async callback')) + Promise.reject(new Error('unhandled rejection in async callback')) }, 100) ctx.body = 'ok' } else { diff --git a/test/node/features/fixtures/restify/scenarios/app.js b/test/node/features/fixtures/restify/scenarios/app.js index caf90e1470..ce5af56117 100644 --- a/test/node/features/fixtures/restify/scenarios/app.js +++ b/test/node/features/fixtures/restify/scenarios/app.js @@ -57,6 +57,14 @@ server.get('/rejection-async', function (req, res, next) { Promise.reject(new Error('reject async')).catch(next) }, 100) }) + +server.get('/unhandled-rejection-async-callback', function (req, res, next) { + setTimeout(function () { + Promise.reject(new Error('reject async')) + }, 100) + res.end('OK') +}) + // // app.get('/string-as-error', function (req, res, next) { // next('errrr') diff --git a/test/node/features/koa.feature b/test/node/features/koa.feature index b0c90e876f..46ffe7c498 100644 --- a/test/node/features/koa.feature +++ b/test/node/features/koa.feature @@ -134,10 +134,13 @@ Scenario: a thrown error in an async callback And the event "request.httpMethod" equals "GET" Scenario: an unhandled promise rejection in an async callback - Then I open the URL "http://koa/unhandled-reject-async-callback" and get a 200 response + Then I open the URL "http://koa/unhandled-rejection-async-callback" and get a 200 response And I wait to receive an error Then the error is valid for the error reporting API version "4" for the "Bugsnag Node" notifier And the event "unhandled" is true And the event "severity" equals "error" And the event "severityReason.type" equals "unhandledPromiseRejection" And the exception "errorClass" equals "Error" + And the exception "message" equals "unhandled rejection in async callback" + And the event "request.url" equals "http://koa//unhandled-rejection-async-callback" + And the event "request.httpMethod" equals "GET" \ No newline at end of file diff --git a/test/node/features/restify.feature b/test/node/features/restify.feature index 5f19e58d91..09c495b79d 100644 --- a/test/node/features/restify.feature +++ b/test/node/features/restify.feature @@ -33,6 +33,9 @@ Scenario: an asynchronous thrown error in a route And the exception "message" equals "async" And the exception "type" equals "nodejs" And the "file" of stack frame 0 equals "scenarios/app.js" + And the event "request.url" equals "http://restify/async" + And the event "request.httpMethod" equals "GET" + And the event "request.clientIp" is not null Scenario: an error passed to next(err) Then I open the URL "http://restify/next" @@ -45,6 +48,9 @@ Scenario: an error passed to next(err) And the exception "message" equals "next" And the exception "type" equals "nodejs" And the "file" of stack frame 0 equals "scenarios/app.js" + And the event "request.url" equals "http://restify/next" + And the event "request.httpMethod" equals "GET" + And the event "request.clientIp" is not null Scenario: throwing non-Error error Then I open the URL "http://restify/throw-non-error" @@ -56,6 +62,9 @@ Scenario: throwing non-Error error And the exception "errorClass" equals "InvalidError" And the exception "message" matches "^restify middleware received a non-error\." And the exception "type" equals "nodejs" + And the event "request.url" equals "http://restify/throw-non-error" + And the event "request.httpMethod" equals "GET" + And the event "request.clientIp" is not null Scenario: an explicit 404 When I open the URL "http://restify/not-found" @@ -63,6 +72,9 @@ Scenario: an explicit 404 Then the session is valid for the session reporting API version "1" for the "Bugsnag Node" notifier And the session payload has a valid sessions array And the sessionCount "sessionsStarted" equals 1 + And the event "request.url" equals "http://restify/not-found" + And the event "request.httpMethod" equals "GET" + And the event "request.clientIp" is not null Scenario: an explicit internal server error Then I open the URL "http://restify/internal" @@ -75,6 +87,9 @@ Scenario: an explicit internal server error And the exception "message" equals "oh noes!" And the exception "type" equals "nodejs" And the "file" of stack frame 0 equals "scenarios/app.js" + And the event "request.url" equals "http://restify/internal" + And the event "request.httpMethod" equals "GET" + And the event "request.clientIp" is not null Scenario: a handled error passed to req.bugsnag.notify() Then I open the URL "http://restify/handled" @@ -90,6 +105,18 @@ Scenario: a handled error passed to req.bugsnag.notify() And the event "request.httpMethod" equals "GET" And the event "request.clientIp" is not null +Scenario: an unhandled promise rejection in an async callback + Then I open the URL "http://restify/unhandled-reject-async-callback" and get a 200 response + And I wait to receive an error + Then the error is valid for the error reporting API version "4" for the "Bugsnag Node" notifier + And the event "unhandled" is true + And the event "severity" equals "error" + And the event "severityReason.type" equals "unhandledPromiseRejection" + And the exception "errorClass" equals "Error" + And the exception "message" equals "unhandled reject in async callback" + And the event "request.url" equals "http://restify/unhandled-reject-async-callback" + And the event "request.httpMethod" equals "GET" + Scenario: adding body to request metadata When I POST the data "data=in_request_body" to the URL "http://restify/bodytest" And I wait to receive an error