From 95e23ba94bb8be508b92c73555ec15ea59fea528 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Tue, 14 Apr 2026 15:16:48 -0400 Subject: [PATCH 01/24] feat: add TracingChannel support for express:request Add a single `express:request` TracingChannel that emits structured lifecycle events (start, end, asyncStart, asyncEnd, error) for every middleware, route handler, and error handler execution. Context shape: { req, res, layer } where layer is the Layer instance, giving subscribers access to layer.name, layer.handle.length (for error handler detection), and layer.route. Consumers decide how to classify and name spans based on these properties. Route dispatch wrapper layers (internal glue that calls route.dispatch) are excluded from tracing to avoid duplicate events. The actual user handlers inside the route are traced individually. Zero overhead when no subscribers are registered. The hasSubscribers check gates all context allocation and tracePromise wrapping. Refs: https://github.com/pillarjs/router/pull/96 Refs: https://github.com/expressjs/express/issues/6353 --- lib/layer.js | 86 ++++++++--- test/tracing.js | 402 ++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 468 insertions(+), 20 deletions(-) create mode 100644 test/tracing.js diff --git a/lib/layer.js b/lib/layer.js index 6a4408ff..98d2ad21 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -12,6 +12,7 @@ * @private */ +const dc = require('diagnostics_channel') const isPromise = require('is-promise') const pathRegexp = require('path-to-regexp') const debug = require('debug')('router:layer') @@ -25,6 +26,20 @@ const deprecate = require('depd')('router') const TRAILING_SLASH_REGEXP = /\/+$/ const MATCHING_GROUP_REGEXP = /\((?:\?<(.*?)>)?(?!\?)/g +/** + * TracingChannel setup. + * @private + */ + +const requestChannel = dc.tracingChannel('express:request') + +/** + * Check if the channel has subscribers. + */ +function shouldTrace (ch) { + return ch && ch.start.hasSubscribers !== false +} + /** * Expose `Layer`. */ @@ -111,23 +126,12 @@ Layer.prototype.handleError = function handleError (error, req, res, next) { return next(error) } - try { - // invoke function - const ret = fn(error, req, res, next) - - // wait for returned promise - if (isPromise(ret)) { - if (!(ret instanceof Promise)) { - deprecate('handlers that are Promise-like are deprecated, use a native Promise instead') - } - - ret.then(null, function (error) { - next(error || new Error('Rejected promise')) - }) - } - } catch (err) { - next(err) - } + const layer = this + invokeWithTrace(function () { + return fn(error, req, res, next) + }, function () { + return { req, res, layer } + }, next) } /** @@ -147,11 +151,53 @@ Layer.prototype.handleRequest = function handleRequest (req, res, next) { return next() } + // Skip tracing for route dispatch wrappers (this.route is only set on + // the internal layer that calls route.dispatch). The actual user handlers + // inside the route are traced individually. + if (this.route) { + return invokeWithTrace(function () { + return fn(req, res, next) + }, null, next) + } + + const layer = this + invokeWithTrace(function () { + return fn(req, res, next) + }, function () { + return { req, res, layer } + }, next) +} + +/** + * Invoke a handler function, optionally wrapping it in TracingChannel. + * The ctxFactory is only called when tracing is active, ensuring zero + * allocation overhead when no subscribers are registered. + * @private + */ + +function invokeWithTrace (exec, ctxFactory, next) { + if (ctxFactory && shouldTrace(requestChannel)) { + try { + requestChannel.tracePromise(function () { + const ret = exec() + if (isPromise(ret)) { + if (!(ret instanceof Promise)) { + deprecate('handlers that are Promise-like are deprecated, use a native Promise instead') + } + return ret + } + }, ctxFactory()).then(null, function (error) { + next(error || new Error('Rejected promise')) + }) + } catch (err) { + next(err) + } + return + } + try { - // invoke function - const ret = fn(req, res, next) + const ret = exec() - // wait for returned promise if (isPromise(ret)) { if (!(ret instanceof Promise)) { deprecate('handlers that are Promise-like are deprecated, use a native Promise instead') diff --git a/test/tracing.js b/test/tracing.js new file mode 100644 index 00000000..c817d04b --- /dev/null +++ b/test/tracing.js @@ -0,0 +1,402 @@ +const { it, describe, beforeEach, afterEach } = require('mocha') +const Router = require('..') +const utils = require('./support/utils') + +const assert = utils.assert +const createServer = utils.createServer +const request = utils.request + +let dc +let tracingChannel + +try { + dc = require('node:diagnostics_channel') + if (dc.tracingChannel) { + tracingChannel = dc.tracingChannel + } +} catch {} + +const describeTracing = tracingChannel ? describe : describe.skip + +describeTracing('TracingChannel', function () { + let handlers + let events + + beforeEach(function () { + events = [] + handlers = { + start (ctx) { events.push({ phase: 'start', ctx }) }, + end (ctx) { events.push({ phase: 'end', ctx }) }, + asyncStart (ctx) { events.push({ phase: 'asyncStart', ctx }) }, + asyncEnd (ctx) { events.push({ phase: 'asyncEnd', ctx }) }, + error (ctx) { events.push({ phase: 'error', ctx }) } + } + }) + + afterEach(function () { + dc.tracingChannel('express:request').unsubscribe(handlers) + }) + + describe('when no subscribers', function () { + it('should not affect normal behavior', function (done) { + const router = new Router() + const server = createServer(router) + + router.get('/foo', function (req, res) { + res.statusCode = 200 + res.end('hello') + }) + + request(server) + .get('/foo') + .expect(200, 'hello', done) + }) + }) + + describe('context shape', function () { + it('should provide req, res, and layer in context', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.use(function myMiddleware (req, res, next) { + next() + }) + + router.get('/foo', function (req, res) { + res.statusCode = 200 + res.end('hello') + }) + + request(server) + .get('/foo') + .expect(200, function (err) { + if (err) return done(err) + + const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const middlewareStart = startEvents.find(function (e) { + return e.ctx.layer && e.ctx.layer.name === 'myMiddleware' + }) + + assert.ok(middlewareStart, 'should have start event for myMiddleware') + assert.ok(middlewareStart.ctx.req, 'should have req') + assert.ok(middlewareStart.ctx.res, 'should have res') + assert.ok(middlewareStart.ctx.layer, 'should have layer') + assert.equal(middlewareStart.ctx.layer.name, 'myMiddleware') + + done() + }) + }) + + it('should have layer.name as for unnamed middleware', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.use(function (req, res, next) { + next() + }) + + router.get('/foo', function (req, res) { + res.statusCode = 200 + res.end('hello') + }) + + request(server) + .get('/foo') + .expect(200, function (err) { + if (err) return done(err) + + const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const anonMiddleware = startEvents.find(function (e) { + return e.ctx.layer && e.ctx.layer.name === '' + }) + + assert.ok(anonMiddleware, 'should have anonymous middleware event') + + done() + }) + }) + }) + + describe('route handler tracing', function () { + it('should have req.route set for route handlers', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/users/:id', function getUser (req, res) { + res.statusCode = 200 + res.end('user') + }) + + request(server) + .get('/users/123') + .expect(200, function (err) { + if (err) return done(err) + + const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const handlerStart = startEvents.find(function (e) { + return e.ctx.layer && e.ctx.layer.name === 'getUser' + }) + + assert.ok(handlerStart, 'should have start event for getUser') + assert.ok(handlerStart.ctx.req.route, 'should have req.route') + assert.equal(handlerStart.ctx.req.route.path, '/users/:id') + + done() + }) + }) + + it('should not trace the route dispatch wrapper', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/foo', function myHandler (req, res) { + res.statusCode = 200 + res.end('ok') + }) + + request(server) + .get('/foo') + .expect(200, function (err) { + if (err) return done(err) + + const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const dispatchWrapper = startEvents.find(function (e) { + return e.ctx.layer && e.ctx.layer.name === 'handle' + }) + + assert.ok(!dispatchWrapper, 'should not have dispatch wrapper event') + + done() + }) + }) + }) + + describe('error handler tracing', function () { + it('should trace error handlers (fn.length === 4)', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/fail', function (req, res, next) { + next(new Error('boom')) + }) + + router.use(function myErrorHandler (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/fail') + .expect(500, 'boom', function (err) { + if (err) return done(err) + + const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const errorHandlerStart = startEvents.find(function (e) { + return e.ctx.layer && e.ctx.layer.name === 'myErrorHandler' + }) + + assert.ok(errorHandlerStart, 'should have start event for error handler') + assert.equal(errorHandlerStart.ctx.layer.handle.length, 4) + + done() + }) + }) + }) + + describe('error channel', function () { + it('should emit error when handler throws synchronously', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/throw', function (req, res) { + throw new Error('sync boom') + }) + + request(server) + .get('/throw') + .expect(500, function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.ok(errorEvents.length > 0, 'should have error events') + + const errorEvent = errorEvents.find(function (e) { + return e.ctx.error && e.ctx.error.message === 'sync boom' + }) + assert.ok(errorEvent, 'should have error event with the thrown error') + + done() + }) + }) + + it('should emit error when async handler rejects', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/reject', async function (req, res) { + throw new Error('async boom') + }) + + request(server) + .get('/reject') + .expect(500, function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.ok(errorEvents.length > 0, 'should have error events') + + const errorEvent = errorEvents.find(function (e) { + return e.ctx.error && e.ctx.error.message === 'async boom' + }) + assert.ok(errorEvent, 'should have error event with the rejected error') + + done() + }) + }) + }) + + describe('async handlers', function () { + it('should trace async handlers that return promises', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/async', function asyncHandler (req, res) { + return new Promise(function (resolve) { + setTimeout(function () { + res.statusCode = 200 + res.end('async hello') + resolve() + }, 10) + }) + }) + + request(server) + .get('/async') + .expect(200, 'async hello', function (err) { + if (err) return done(err) + + const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const asyncEndEvents = events.filter(function (e) { return e.phase === 'asyncEnd' }) + + assert.ok(startEvents.length > 0, 'should have start events') + assert.ok(asyncEndEvents.length > 0, 'should have asyncEnd events') + + done() + }) + }) + }) + + describe('nested routers', function () { + it('should trace middleware in nested routers', function (done) { + const router = new Router() + const nested = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + nested.get('/bar', function nestedHandler (req, res) { + res.statusCode = 200 + res.end('nested') + }) + + router.use('/foo', nested) + + request(server) + .get('/foo/bar') + .expect(200, 'nested', function (err) { + if (err) return done(err) + + const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const handlerEvent = startEvents.find(function (e) { + return e.ctx.layer && e.ctx.layer.name === 'nestedHandler' + }) + assert.ok(handlerEvent, 'should have event from nested route handler') + assert.ok(handlerEvent.ctx.req.route, 'should have req.route') + + done() + }) + }) + }) + + describe('event ordering', function () { + it('should emit start before asyncEnd', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/order', function (req, res) { + res.statusCode = 200 + res.end('ok') + }) + + request(server) + .get('/order') + .expect(200, function (err) { + if (err) return done(err) + + const phases = events.map(function (e) { return e.phase }) + const firstStart = phases.indexOf('start') + const lastAsyncEnd = phases.lastIndexOf('asyncEnd') + + assert.ok(firstStart >= 0, 'should have start') + assert.ok(lastAsyncEnd >= 0, 'should have asyncEnd') + assert.ok(firstStart < lastAsyncEnd, 'start should come before asyncEnd') + + done() + }) + }) + }) + + describe('multiple middleware', function () { + it('should emit events for each middleware in the chain', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.use(function first (req, res, next) { + next() + }) + + router.use(function second (req, res, next) { + next() + }) + + router.get('/multi', function handler (req, res) { + res.statusCode = 200 + res.end('multi') + }) + + request(server) + .get('/multi') + .expect(200, function (err) { + if (err) return done(err) + + const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const names = startEvents.map(function (e) { return e.ctx.layer.name }) + + assert.ok(names.indexOf('first') >= 0, 'should trace first middleware') + assert.ok(names.indexOf('second') >= 0, 'should trace second middleware') + + done() + }) + }) + }) +}) From 858399cee8b90aadf4396bb7900ce01d78632f86 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Tue, 14 Apr 2026 16:21:38 -0400 Subject: [PATCH 02/24] refactor: reduce duplication in invokeWithTrace Extract handlePromise and unify the traced/untraced paths into a single try/catch and .then handler. --- lib/layer.js | 43 ++++++++++++++++++------------------------- 1 file changed, 18 insertions(+), 25 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index 98d2ad21..f2beffdf 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -176,33 +176,12 @@ Layer.prototype.handleRequest = function handleRequest (req, res, next) { */ function invokeWithTrace (exec, ctxFactory, next) { - if (ctxFactory && shouldTrace(requestChannel)) { - try { - requestChannel.tracePromise(function () { - const ret = exec() - if (isPromise(ret)) { - if (!(ret instanceof Promise)) { - deprecate('handlers that are Promise-like are deprecated, use a native Promise instead') - } - return ret - } - }, ctxFactory()).then(null, function (error) { - next(error || new Error('Rejected promise')) - }) - } catch (err) { - next(err) - } - return - } - try { - const ret = exec() - - if (isPromise(ret)) { - if (!(ret instanceof Promise)) { - deprecate('handlers that are Promise-like are deprecated, use a native Promise instead') - } + const ret = (ctxFactory && shouldTrace(requestChannel)) + ? requestChannel.tracePromise(function () { return handlePromise(exec()) }, ctxFactory()) + : handlePromise(exec()) + if (ret) { ret.then(null, function (error) { next(error || new Error('Rejected promise')) }) @@ -212,6 +191,20 @@ function invokeWithTrace (exec, ctxFactory, next) { } } +/** + * If the return value is a promise, validate it and return it. + * @private + */ + +function handlePromise (ret) { + if (isPromise(ret)) { + if (!(ret instanceof Promise)) { + deprecate('handlers that are Promise-like are deprecated, use a native Promise instead') + } + return ret + } +} + /** * Check if this route matches `path`, if so * populate `.params`. From 9f1aea7764b7590d6d4998f6482e2586863e2287 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Apr 2026 08:27:40 -0400 Subject: [PATCH 03/24] fix: guard against missing dc.tracingChannel on older Node versions --- lib/layer.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/layer.js b/lib/layer.js index f2beffdf..d617d33f 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -31,7 +31,7 @@ const MATCHING_GROUP_REGEXP = /\((?:\?<(.*?)>)?(?!\?)/g * @private */ -const requestChannel = dc.tracingChannel('express:request') +const requestChannel = dc.tracingChannel && dc.tracingChannel('express:request') /** * Check if the channel has subscribers. From dea81ae99d5d7870eb1d9dbf66912be4c61cd91c Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Apr 2026 09:23:19 -0400 Subject: [PATCH 04/24] ref: use node: prefix --- lib/layer.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/layer.js b/lib/layer.js index d617d33f..bdded7c5 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -12,7 +12,7 @@ * @private */ -const dc = require('diagnostics_channel') +const dc = require('node:diagnostics_channel') const isPromise = require('is-promise') const pathRegexp = require('path-to-regexp') const debug = require('debug')('router:layer') From 1f6bc25db30bf377845e87179ec01edfbef5a655 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Apr 2026 09:26:14 -0400 Subject: [PATCH 05/24] fix: use the top-level hasSubscribers flag --- lib/layer.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/layer.js b/lib/layer.js index bdded7c5..220fa4d2 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -37,7 +37,7 @@ const requestChannel = dc.tracingChannel && dc.tracingChannel('express:request') * Check if the channel has subscribers. */ function shouldTrace (ch) { - return ch && ch.start.hasSubscribers !== false + return ch && ch.hasSubscribers !== false } /** From 1ad1b9c31aceca2b696f40da7b7b5857c8316310 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Mon, 20 Apr 2026 12:41:21 -0400 Subject: [PATCH 06/24] test: pin down error event semantics for next(err) flows --- test/tracing.js | 244 ++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 244 insertions(+) diff --git a/test/tracing.js b/test/tracing.js index c817d04b..4a454520 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -211,6 +211,132 @@ describeTracing('TracingChannel', function () { done() }) }) + + it('should not emit error on the originating layer when next(err) is recovered downstream', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/fail', function failingHandler (req, res, next) { + next(new Error('boom')) + }) + + router.use(function myErrorHandler (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/fail') + .expect(500, 'boom', function (err) { + if (err) return done(err) + + const byLayer = function (name) { + return function (e) { return e.ctx.layer && e.ctx.layer.name === name } + } + + const failingEvents = events.filter(byLayer('failingHandler')) + const errorHandlerEvents = events.filter(byLayer('myErrorHandler')) + + assert.ok(failingEvents.some(function (e) { return e.phase === 'start' }), + 'originating layer should have a start event') + assert.ok(!failingEvents.some(function (e) { return e.phase === 'error' }), + 'originating layer should not emit error — next(err) is normal control flow, not an exception') + + assert.ok(errorHandlerEvents.some(function (e) { return e.phase === 'start' }), + 'recovering error handler should have a start event') + assert.ok(!errorHandlerEvents.some(function (e) { return e.phase === 'error' }), + 'recovering error handler should not emit error — it handled the error successfully') + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 0, + 'no error event should fire anywhere when an error is forwarded via next() and recovered downstream') + + done() + }) + }) + + it('should nest the error handler span inside the originating layer span', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.use(function firstMiddleware (req, res, next) { + next() + }) + + router.get('/fail', function failingHandler (req, res, next) { + next(new Error('boom')) + }) + + router.use(function myErrorHandler (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/fail') + .expect(500, 'boom', function (err) { + if (err) return done(err) + + const syncEvents = events.filter(function (e) { + return e.phase === 'start' || e.phase === 'end' + }).map(function (e) { + return e.phase + ':' + (e.ctx.layer && e.ctx.layer.name) + }) + + const failingStart = syncEvents.indexOf('start:failingHandler') + const failingEnd = syncEvents.indexOf('end:failingHandler') + const errorHandlerStart = syncEvents.indexOf('start:myErrorHandler') + const errorHandlerEnd = syncEvents.indexOf('end:myErrorHandler') + + assert.notEqual(failingStart, -1, 'failingHandler should have start') + assert.notEqual(errorHandlerStart, -1, 'myErrorHandler should have start') + + assert.ok(failingStart < errorHandlerStart, + 'failing layer start should come before error handler start') + assert.ok(errorHandlerStart < errorHandlerEnd, + 'error handler start should come before its own end') + assert.ok(errorHandlerEnd < failingEnd, + 'error handler end should come before failing layer end — nesting contract: the error handler that runs via next(err) is nested inside the layer that triggered it, letting APMs attribute the error to the correct parent span') + + done() + }) + }) + + it('should not emit error on the originating layer when next(err) is unhandled', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/fail', function failingHandler (req, res, next) { + next(new Error('unhandled boom')) + }) + + request(server) + .get('/fail') + .expect(500, function (err) { + if (err) return done(err) + + const failingEvents = events.filter(function (e) { + return e.ctx.layer && e.ctx.layer.name === 'failingHandler' + }) + + assert.ok(failingEvents.some(function (e) { return e.phase === 'start' }), + 'originating layer should have a start event') + assert.ok(!failingEvents.some(function (e) { return e.phase === 'error' }), + 'originating layer should not emit error even when no error handler exists — next(err) is not an exception from tracePromise\'s perspective') + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 0, + 'no error event fires on the channel when errors are forwarded via next(); APMs relying on this channel cannot detect next(err) errors') + + done() + }) + }) }) describe('error channel', function () { @@ -267,6 +393,124 @@ describeTracing('TracingChannel', function () { done() }) }) + + it('should emit error on route only when sync throw is recovered by a clean error handler', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/throw', function throwingHandler (req, res) { + throw new Error('sync boom') + }) + + router.use(function cleanErrorHandler (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/throw') + .expect(500, 'sync boom', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 1, 'exactly one error event should fire') + assert.equal(errorEvents[0].ctx.layer.name, 'throwingHandler', + 'error event should belong to the throwing route layer') + + done() + }) + }) + + it('should emit error on route only when async reject is recovered by a clean error handler', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/reject', async function rejectingHandler (req, res) { + throw new Error('async boom') + }) + + router.use(function cleanErrorHandler (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/reject') + .expect(500, 'async boom', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 1, 'exactly one error event should fire') + assert.equal(errorEvents[0].ctx.layer.name, 'rejectingHandler', + 'error event should belong to the rejecting route layer') + + done() + }) + }) + + it('should emit error on both layers when sync throw is followed by a throwing error handler', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/throw', function throwingHandler (req, res) { + throw new Error('sync boom') + }) + + router.use(function throwingErrorHandler (err, req, res, next) { // eslint-disable-line no-unused-vars + throw new Error('handler boom') + }) + + request(server) + .get('/throw') + .expect(500, function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const layerNames = errorEvents.map(function (e) { return e.ctx.layer.name }) + + assert.equal(errorEvents.length, 2, 'error should fire on both layers') + assert.ok(layerNames.includes('throwingHandler'), 'route layer should emit error') + assert.ok(layerNames.includes('throwingErrorHandler'), 'error handler should emit its own error') + + done() + }) + }) + + it('should emit error on both layers when async reject is followed by a throwing error handler', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/reject', async function rejectingHandler (req, res) { + throw new Error('async boom') + }) + + router.use(function throwingErrorHandler (err, req, res, next) { // eslint-disable-line no-unused-vars + throw new Error('handler boom') + }) + + request(server) + .get('/reject') + .expect(500, function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const layerNames = errorEvents.map(function (e) { return e.ctx.layer.name }) + + assert.equal(errorEvents.length, 2, 'error should fire on both layers') + assert.ok(layerNames.includes('rejectingHandler'), 'route layer should emit error') + assert.ok(layerNames.includes('throwingErrorHandler'), 'error handler should emit its own error') + + done() + }) + }) }) describe('async handlers', function () { From 28b32134587d68028aeda7b548a2df86b967956e Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Mon, 20 Apr 2026 16:21:08 -0400 Subject: [PATCH 07/24] fix: always publish error events before calling next --- lib/layer.js | 33 +++++++++++++++++-------- test/tracing.js | 64 +++++++++++++++++++++++++++++++------------------ 2 files changed, 64 insertions(+), 33 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index 220fa4d2..ab3ecf5c 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -127,10 +127,10 @@ Layer.prototype.handleError = function handleError (error, req, res, next) { } const layer = this - invokeWithTrace(function () { - return fn(error, req, res, next) + invokeWithTrace(function (wrappedNext) { + return fn(error, req, res, wrappedNext) }, function () { - return { req, res, layer } + return { req, res, layer, error, handled: true } }, next) } @@ -155,14 +155,14 @@ Layer.prototype.handleRequest = function handleRequest (req, res, next) { // the internal layer that calls route.dispatch). The actual user handlers // inside the route are traced individually. if (this.route) { - return invokeWithTrace(function () { - return fn(req, res, next) + return invokeWithTrace(function (wrappedNext) { + return fn(req, res, wrappedNext) }, null, next) } const layer = this - invokeWithTrace(function () { - return fn(req, res, next) + invokeWithTrace(function (wrappedNext) { + return fn(req, res, wrappedNext) }, function () { return { req, res, layer } }, next) @@ -176,10 +176,23 @@ Layer.prototype.handleRequest = function handleRequest (req, res, next) { */ function invokeWithTrace (exec, ctxFactory, next) { + const tracing = ctxFactory && shouldTrace(requestChannel) + const ctx = tracing ? ctxFactory() : null + const wrappedNext = tracing + ? function (err) { + if (err) { + ctx.error = err + // Explicitly publish the error to the error channel + requestChannel.error.publish(ctx) + } + next(err) + } + : next + try { - const ret = (ctxFactory && shouldTrace(requestChannel)) - ? requestChannel.tracePromise(function () { return handlePromise(exec()) }, ctxFactory()) - : handlePromise(exec()) + const ret = tracing + ? requestChannel.tracePromise(function () { return handlePromise(exec(wrappedNext)) }, ctx) + : handlePromise(exec(wrappedNext)) if (ret) { ret.then(null, function (error) { diff --git a/test/tracing.js b/test/tracing.js index 4a454520..13ce8c07 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -180,13 +180,13 @@ describeTracing('TracingChannel', function () { }) describe('error handler tracing', function () { - it('should trace error handlers (fn.length === 4)', function (done) { + it('should trace error handlers (fn.length === 4) and mark their ctx as handled', function (done) { const router = new Router() const server = createServer(router) dc.tracingChannel('express:request').subscribe(handlers) - router.get('/fail', function (req, res, next) { + router.get('/fail', function failingHandler (req, res, next) { next(new Error('boom')) }) @@ -200,19 +200,35 @@ describeTracing('TracingChannel', function () { .expect(500, 'boom', function (err) { if (err) return done(err) - const startEvents = events.filter(function (e) { return e.phase === 'start' }) - const errorHandlerStart = startEvents.find(function (e) { - return e.ctx.layer && e.ctx.layer.name === 'myErrorHandler' - }) + const byLayer = function (name) { + return function (e) { return e.ctx.layer && e.ctx.layer.name === name } + } + const failingEvents = events.filter(byLayer('failingHandler')) + const errorHandlerEvents = events.filter(byLayer('myErrorHandler')) + + const errorHandlerStart = errorHandlerEvents.find(function (e) { return e.phase === 'start' }) assert.ok(errorHandlerStart, 'should have start event for error handler') assert.equal(errorHandlerStart.ctx.layer.handle.length, 4) + assert.equal(errorHandlerStart.ctx.handled, true, + 'error handler ctx should be marked handled so APMs can dedup the origin error') + assert.ok(errorHandlerStart.ctx.error, + 'error handler ctx should expose the error it received') + + assert.ok(!errorHandlerEvents.some(function (e) { return e.phase === 'error' }), + 'error handler itself did not throw, so it should not emit error') + + const failingError = failingEvents.find(function (e) { return e.phase === 'error' }) + assert.ok(failingError, 'origin layer should emit error for next(err)') + assert.equal(failingError.ctx.error.message, 'boom') + assert.ok(!failingError.ctx.handled, + 'origin layer ctx is not the handler — should not be marked handled') done() }) }) - it('should not emit error on the originating layer when next(err) is recovered downstream', function (done) { + it('should emit error on originating layer when next(err) is recovered downstream', function (done) { const router = new Router() const server = createServer(router) @@ -239,19 +255,21 @@ describeTracing('TracingChannel', function () { const failingEvents = events.filter(byLayer('failingHandler')) const errorHandlerEvents = events.filter(byLayer('myErrorHandler')) - assert.ok(failingEvents.some(function (e) { return e.phase === 'start' }), - 'originating layer should have a start event') - assert.ok(!failingEvents.some(function (e) { return e.phase === 'error' }), - 'originating layer should not emit error — next(err) is normal control flow, not an exception') + const failingError = failingEvents.find(function (e) { return e.phase === 'error' }) + assert.ok(failingError, + 'originating layer should emit error — unhandled-at-origin is always observable') + assert.equal(failingError.ctx.error.message, 'boom') - assert.ok(errorHandlerEvents.some(function (e) { return e.phase === 'start' }), - 'recovering error handler should have a start event') assert.ok(!errorHandlerEvents.some(function (e) { return e.phase === 'error' }), - 'recovering error handler should not emit error — it handled the error successfully') + 'recovering error handler itself did not throw — should not emit error') + + const errorHandlerStart = errorHandlerEvents.find(function (e) { return e.phase === 'start' }) + assert.equal(errorHandlerStart.ctx.handled, true, + 'error handler ctx is marked handled so APMs can dedup against the origin error') const errorEvents = events.filter(function (e) { return e.phase === 'error' }) - assert.equal(errorEvents.length, 0, - 'no error event should fire anywhere when an error is forwarded via next() and recovered downstream') + assert.equal(errorEvents.length, 1, + 'exactly one error event fires — on the origin layer that called next(err)') done() }) @@ -306,7 +324,7 @@ describeTracing('TracingChannel', function () { }) }) - it('should not emit error on the originating layer when next(err) is unhandled', function (done) { + it('should emit error on originating layer when next(err) is unhandled', function (done) { const router = new Router() const server = createServer(router) @@ -325,14 +343,14 @@ describeTracing('TracingChannel', function () { return e.ctx.layer && e.ctx.layer.name === 'failingHandler' }) - assert.ok(failingEvents.some(function (e) { return e.phase === 'start' }), - 'originating layer should have a start event') - assert.ok(!failingEvents.some(function (e) { return e.phase === 'error' }), - 'originating layer should not emit error even when no error handler exists — next(err) is not an exception from tracePromise\'s perspective') + const failingError = failingEvents.find(function (e) { return e.phase === 'error' }) + assert.ok(failingError, + 'unhandled next(err) must be observable on the origin layer') + assert.equal(failingError.ctx.error.message, 'unhandled boom') const errorEvents = events.filter(function (e) { return e.phase === 'error' }) - assert.equal(errorEvents.length, 0, - 'no error event fires on the channel when errors are forwarded via next(); APMs relying on this channel cannot detect next(err) errors') + assert.equal(errorEvents.length, 1, + 'exactly one error event fires — on the origin layer that called next(err)') done() }) From 90ed7e2cf75e8da027d9a47763c96471457aa34e Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Mon, 20 Apr 2026 16:29:56 -0400 Subject: [PATCH 08/24] fix: refine error handling for control-flow sentinels in invokeWithTrace --- lib/layer.js | 4 +++- test/tracing.js | 34 ++++++++++++++++++++++++++++++++-- 2 files changed, 35 insertions(+), 3 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index ab3ecf5c..ca571ec9 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -180,7 +180,9 @@ function invokeWithTrace (exec, ctxFactory, next) { const ctx = tracing ? ctxFactory() : null const wrappedNext = tracing ? function (err) { - if (err) { + // 'route' and 'router' are control-flow sentinels (skip route / exit router), + // not real errors — don't pollute the error channel with them. + if (err && err !== 'route' && err !== 'router') { ctx.error = err // Explicitly publish the error to the error channel requestChannel.error.publish(ctx) diff --git a/test/tracing.js b/test/tracing.js index 13ce8c07..eda59670 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -324,6 +324,34 @@ describeTracing('TracingChannel', function () { }) }) + it('should not emit error for next("route") or next("router") control-flow sentinels', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.get('/skip', function skipToNextRoute (req, res, next) { + next('route') + }) + + router.get('/skip', function nextRouteHandler (req, res) { + res.statusCode = 200 + res.end('skipped') + }) + + request(server) + .get('/skip') + .expect(200, 'skipped', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 0, + 'next("route") is a control-flow sentinel, not an error — nothing should publish') + + done() + }) + }) + it('should emit error on originating layer when next(err) is unhandled', function (done) { const router = new Router() const server = createServer(router) @@ -480,7 +508,8 @@ describeTracing('TracingChannel', function () { throw new Error('sync boom') }) - router.use(function throwingErrorHandler (err, req, res, next) { // eslint-disable-line no-unused-vars + // eslint-disable-next-line no-unused-vars, n/handle-callback-err + router.use(function throwingErrorHandler (err, req, res, next) { throw new Error('handler boom') }) @@ -510,7 +539,8 @@ describeTracing('TracingChannel', function () { throw new Error('async boom') }) - router.use(function throwingErrorHandler (err, req, res, next) { // eslint-disable-line no-unused-vars + // eslint-disable-next-line no-unused-vars, n/handle-callback-err + router.use(function throwingErrorHandler (err, req, res, next) { throw new Error('handler boom') }) From 758030ee576d84053167cf4412e155f000393260 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Mon, 20 Apr 2026 16:31:31 -0400 Subject: [PATCH 09/24] test: added case for router control flow error --- test/tracing.js | 30 +++++++++++++++++++++++++++++- 1 file changed, 29 insertions(+), 1 deletion(-) diff --git a/test/tracing.js b/test/tracing.js index eda59670..98627b24 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -324,7 +324,7 @@ describeTracing('TracingChannel', function () { }) }) - it('should not emit error for next("route") or next("router") control-flow sentinels', function (done) { + it('should not emit error for next("route") control-flow sentinel', function (done) { const router = new Router() const server = createServer(router) @@ -352,6 +352,34 @@ describeTracing('TracingChannel', function () { }) }) + it('should not emit error for next("router") control-flow sentinel', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express:request').subscribe(handlers) + + router.use(function ejectFromRouter (req, res, next) { + next('router') + }) + + router.get('/foo', function shouldNotRun (req, res) { + res.statusCode = 200 + res.end('should not reach') + }) + + request(server) + .get('/foo') + .expect(404, function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 0, + 'next("router") is a control-flow sentinel, not an error — nothing should publish') + + done() + }) + }) + it('should emit error on originating layer when next(err) is unhandled', function (done) { const router = new Router() const server = createServer(router) From 9c9b4a77eed2ec01a7e6c804ccd70ed89c67b66b Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Mon, 20 Apr 2026 16:46:27 -0400 Subject: [PATCH 10/24] test: assert handled flag on error events in both-layers error tests --- test/tracing.js | 32 ++++++++++++++++++++++++++------ 1 file changed, 26 insertions(+), 6 deletions(-) diff --git a/test/tracing.js b/test/tracing.js index 98627b24..16ddd045 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -547,11 +547,21 @@ describeTracing('TracingChannel', function () { if (err) return done(err) const errorEvents = events.filter(function (e) { return e.phase === 'error' }) - const layerNames = errorEvents.map(function (e) { return e.ctx.layer.name }) + const byName = function (name) { + return errorEvents.find(function (e) { return e.ctx.layer.name === name }) + } assert.equal(errorEvents.length, 2, 'error should fire on both layers') - assert.ok(layerNames.includes('throwingHandler'), 'route layer should emit error') - assert.ok(layerNames.includes('throwingErrorHandler'), 'error handler should emit its own error') + + const routeError = byName('throwingHandler') + assert.ok(routeError, 'route layer should emit error') + assert.ok(!routeError.ctx.handled, + 'route layer is not an error handler — handled flag must be absent') + + const handlerError = byName('throwingErrorHandler') + assert.ok(handlerError, 'error handler should emit its own error') + assert.equal(handlerError.ctx.handled, true, + 'error handler\'s own error event must carry handled:true so APMs can classify the span correctly') done() }) @@ -578,11 +588,21 @@ describeTracing('TracingChannel', function () { if (err) return done(err) const errorEvents = events.filter(function (e) { return e.phase === 'error' }) - const layerNames = errorEvents.map(function (e) { return e.ctx.layer.name }) + const byName = function (name) { + return errorEvents.find(function (e) { return e.ctx.layer.name === name }) + } assert.equal(errorEvents.length, 2, 'error should fire on both layers') - assert.ok(layerNames.includes('rejectingHandler'), 'route layer should emit error') - assert.ok(layerNames.includes('throwingErrorHandler'), 'error handler should emit its own error') + + const routeError = byName('rejectingHandler') + assert.ok(routeError, 'route layer should emit error') + assert.ok(!routeError.ctx.handled, + 'route layer is not an error handler — handled flag must be absent') + + const handlerError = byName('throwingErrorHandler') + assert.ok(handlerError, 'error handler should emit its own error') + assert.equal(handlerError.ctx.handled, true, + 'error handler\'s own error event must carry handled:true so APMs can classify the span correctly') done() }) From 67c3851c28e8f0b43a41a5fe62c27d1a1a4da4cd Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Tue, 21 Apr 2026 11:19:13 -0400 Subject: [PATCH 11/24] refactor: rename tracing channel to pillarjs.router.request Follows the Node.js TracingChannel naming guideline (dot-separated, module-scoped) and avoids the express-specific prefix since router is usable outside express. --- lib/layer.js | 2 +- test/tracing.js | 42 +++++++++++++++++++++--------------------- 2 files changed, 22 insertions(+), 22 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index ca571ec9..e243b9a0 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -31,7 +31,7 @@ const MATCHING_GROUP_REGEXP = /\((?:\?<(.*?)>)?(?!\?)/g * @private */ -const requestChannel = dc.tracingChannel && dc.tracingChannel('express:request') +const requestChannel = dc.tracingChannel && dc.tracingChannel('pillarjs.router.request') /** * Check if the channel has subscribers. diff --git a/test/tracing.js b/test/tracing.js index 16ddd045..8d9fecc8 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -34,7 +34,7 @@ describeTracing('TracingChannel', function () { }) afterEach(function () { - dc.tracingChannel('express:request').unsubscribe(handlers) + dc.tracingChannel('pillarjs.router.request').unsubscribe(handlers) }) describe('when no subscribers', function () { @@ -58,7 +58,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.use(function myMiddleware (req, res, next) { next() @@ -93,7 +93,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.use(function (req, res, next) { next() @@ -126,7 +126,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/users/:id', function getUser (req, res) { res.statusCode = 200 @@ -155,7 +155,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/foo', function myHandler (req, res) { res.statusCode = 200 @@ -184,7 +184,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/fail', function failingHandler (req, res, next) { next(new Error('boom')) @@ -232,7 +232,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/fail', function failingHandler (req, res, next) { next(new Error('boom')) @@ -279,7 +279,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.use(function firstMiddleware (req, res, next) { next() @@ -328,7 +328,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/skip', function skipToNextRoute (req, res, next) { next('route') @@ -356,7 +356,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.use(function ejectFromRouter (req, res, next) { next('router') @@ -384,7 +384,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/fail', function failingHandler (req, res, next) { next(new Error('unhandled boom')) @@ -418,7 +418,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/throw', function (req, res) { throw new Error('sync boom') @@ -445,7 +445,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/reject', async function (req, res) { throw new Error('async boom') @@ -472,7 +472,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/throw', function throwingHandler (req, res) { throw new Error('sync boom') @@ -501,7 +501,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/reject', async function rejectingHandler (req, res) { throw new Error('async boom') @@ -530,7 +530,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/throw', function throwingHandler (req, res) { throw new Error('sync boom') @@ -571,7 +571,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/reject', async function rejectingHandler (req, res) { throw new Error('async boom') @@ -614,7 +614,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/async', function asyncHandler (req, res) { return new Promise(function (resolve) { @@ -648,7 +648,7 @@ describeTracing('TracingChannel', function () { const nested = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) nested.get('/bar', function nestedHandler (req, res) { res.statusCode = 200 @@ -679,7 +679,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.get('/order', function (req, res) { res.statusCode = 200 @@ -709,7 +709,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express:request').subscribe(handlers) + dc.tracingChannel('pillarjs.router.request').subscribe(handlers) router.use(function first (req, res, next) { next() From 6aa0575a2c8132ca55db4179a9eff51d4a8d9ebd Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Sun, 26 Apr 2026 20:02:02 -0400 Subject: [PATCH 12/24] docs: document pillarjs.router.request tracing channel --- README.md | 50 ++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 50 insertions(+) diff --git a/README.md b/README.md index 156c380c..991a522d 100644 --- a/README.md +++ b/README.md @@ -400,6 +400,56 @@ router.route('/pet/:id') server.listen(8080) ``` +## Diagnostics + +`router` integrates with Node.js [`diagnostics_channel`](https://nodejs.org/api/diagnostics_channel.html) +via a [`TracingChannel`](https://nodejs.org/api/diagnostics_channel.html#class-tracingchannel) +named `pillarjs.router.request`. This lets observability tools (APMs, tracers, +loggers) hook into middleware and route handler execution without monkey-patching. + +Each layer's handler invocation publishes the standard tracing channel sub-events +(`start`, `end`, `asyncStart`, `asyncEnd`, `error`). The published context object +contains: + +- `req`: the incoming `http.IncomingMessage` +- `res`: the `http.ServerResponse` +- `layer`: the internal `Layer` instance being invoked (exposes `.name`, `.path`, `.handle`, etc.). Note that `Layer` is an internal implementation detail and its shape may change between releases. +- `error`: the error passed to `next(err)`, when applicable +- `handled`: `true` when the layer is an error-handling middleware (4-arg signature) + +The `error` event is also published when a handler calls `next(err)` with a real +error. The control-flow sentinels `'route'` and `'router'` are not treated as +errors and will not publish to the `error` channel. + +When no subscribers are attached, tracing is bypassed entirely, so there is no +context allocation or channel publishing overhead on the hot path. + +```js +const dc = require('node:diagnostics_channel') + +const channel = dc.tracingChannel('pillarjs.router.request') + +channel.subscribe({ + start (ctx) { + ctx.startTime = process.hrtime.bigint() + }, + end (ctx) { + // do whatever you need on synchronous completion + }, + asyncStart (ctx) { + // do whatever you need when the async portion begins + }, + asyncEnd (ctx) { + const durationNs = process.hrtime.bigint() - ctx.startTime + console.log('%s %s -> %s (%dns)', + ctx.req.method, ctx.req.url, ctx.layer.name, durationNs) + }, + error (ctx) { + console.error('handler error in %s:', ctx.layer.name, ctx.error) + } +}) +``` + ## License [MIT](LICENSE) From 5e800782aebb82a2e87014656e3810abb06a0fce Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Mon, 27 Apr 2026 11:01:47 -0400 Subject: [PATCH 13/24] refactor: rename tracing channel to express.router.request --- README.md | 4 ++-- lib/layer.js | 2 +- test/tracing.js | 42 +++++++++++++++++++++--------------------- 3 files changed, 24 insertions(+), 24 deletions(-) diff --git a/README.md b/README.md index 991a522d..a15dac2a 100644 --- a/README.md +++ b/README.md @@ -404,7 +404,7 @@ server.listen(8080) `router` integrates with Node.js [`diagnostics_channel`](https://nodejs.org/api/diagnostics_channel.html) via a [`TracingChannel`](https://nodejs.org/api/diagnostics_channel.html#class-tracingchannel) -named `pillarjs.router.request`. This lets observability tools (APMs, tracers, +named `express.router.request`. This lets observability tools (APMs, tracers, loggers) hook into middleware and route handler execution without monkey-patching. Each layer's handler invocation publishes the standard tracing channel sub-events @@ -427,7 +427,7 @@ context allocation or channel publishing overhead on the hot path. ```js const dc = require('node:diagnostics_channel') -const channel = dc.tracingChannel('pillarjs.router.request') +const channel = dc.tracingChannel('express.router.request') channel.subscribe({ start (ctx) { diff --git a/lib/layer.js b/lib/layer.js index e243b9a0..6744db4e 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -31,7 +31,7 @@ const MATCHING_GROUP_REGEXP = /\((?:\?<(.*?)>)?(?!\?)/g * @private */ -const requestChannel = dc.tracingChannel && dc.tracingChannel('pillarjs.router.request') +const requestChannel = dc.tracingChannel && dc.tracingChannel('express.router.request') /** * Check if the channel has subscribers. diff --git a/test/tracing.js b/test/tracing.js index 8d9fecc8..c1e1d968 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -34,7 +34,7 @@ describeTracing('TracingChannel', function () { }) afterEach(function () { - dc.tracingChannel('pillarjs.router.request').unsubscribe(handlers) + dc.tracingChannel('express.router.request').unsubscribe(handlers) }) describe('when no subscribers', function () { @@ -58,7 +58,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.use(function myMiddleware (req, res, next) { next() @@ -93,7 +93,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.use(function (req, res, next) { next() @@ -126,7 +126,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/users/:id', function getUser (req, res) { res.statusCode = 200 @@ -155,7 +155,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/foo', function myHandler (req, res) { res.statusCode = 200 @@ -184,7 +184,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/fail', function failingHandler (req, res, next) { next(new Error('boom')) @@ -232,7 +232,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/fail', function failingHandler (req, res, next) { next(new Error('boom')) @@ -279,7 +279,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.use(function firstMiddleware (req, res, next) { next() @@ -328,7 +328,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/skip', function skipToNextRoute (req, res, next) { next('route') @@ -356,7 +356,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.use(function ejectFromRouter (req, res, next) { next('router') @@ -384,7 +384,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/fail', function failingHandler (req, res, next) { next(new Error('unhandled boom')) @@ -418,7 +418,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/throw', function (req, res) { throw new Error('sync boom') @@ -445,7 +445,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/reject', async function (req, res) { throw new Error('async boom') @@ -472,7 +472,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/throw', function throwingHandler (req, res) { throw new Error('sync boom') @@ -501,7 +501,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/reject', async function rejectingHandler (req, res) { throw new Error('async boom') @@ -530,7 +530,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/throw', function throwingHandler (req, res) { throw new Error('sync boom') @@ -571,7 +571,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/reject', async function rejectingHandler (req, res) { throw new Error('async boom') @@ -614,7 +614,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/async', function asyncHandler (req, res) { return new Promise(function (resolve) { @@ -648,7 +648,7 @@ describeTracing('TracingChannel', function () { const nested = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) nested.get('/bar', function nestedHandler (req, res) { res.statusCode = 200 @@ -679,7 +679,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.get('/order', function (req, res) { res.statusCode = 200 @@ -709,7 +709,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('pillarjs.router.request').subscribe(handlers) + dc.tracingChannel('express.router.request').subscribe(handlers) router.use(function first (req, res, next) { next() From da0da144fb5a174c17e2a73ea170f8f1c7cab594 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 00:40:09 -0400 Subject: [PATCH 14/24] fix: detect tracing subscribers on Node versions without TracingChannel#hasSubscribers TracingChannel#hasSubscribers was added in Node 20.13/22 and is undefined on older supported versions, where `hasSubscribers !== false` is always true and forces tracing on every request. Check the sub-channels instead, which expose hasSubscribers on all supported versions. --- lib/layer.js | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index 6744db4e..e36db7ca 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -33,11 +33,15 @@ const MATCHING_GROUP_REGEXP = /\((?:\?<(.*?)>)?(?!\?)/g const requestChannel = dc.tracingChannel && dc.tracingChannel('express.router.request') -/** - * Check if the channel has subscribers. - */ +// TracingChannel#hasSubscribers is undefined before Node 20.13/22, so check the sub-channels. function shouldTrace (ch) { - return ch && ch.hasSubscribers !== false + return Boolean(ch) && ( + ch.start.hasSubscribers || + ch.end.hasSubscribers || + ch.asyncStart.hasSubscribers || + ch.asyncEnd.hasSubscribers || + ch.error.hasSubscribers + ) } /** From 8fd857f40badb27a4f4114729f9b374dc897a05b Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 00:41:03 -0400 Subject: [PATCH 15/24] refactor: gate tracing on subscribers in callers and pass ctx directly Move the no-subscriber decision into handleRequest/handleError so the untraced path allocates no context object per request, matching the behavior on master. invokeWithTrace now receives the context object directly instead of a factory, since it only runs when tracing is active. --- lib/layer.js | 84 +++++++++++++++++++++++++++++++--------------------- 1 file changed, 51 insertions(+), 33 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index e36db7ca..93785b34 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -130,12 +130,27 @@ Layer.prototype.handleError = function handleError (error, req, res, next) { return next(error) } + if (!shouldTrace(requestChannel)) { + try { + // invoke function + const ret = handlePromise(fn(error, req, res, next)) + + // wait for returned promise + if (ret) { + ret.then(null, function (error) { + next(error || new Error('Rejected promise')) + }) + } + } catch (err) { + next(err) + } + return + } + const layer = this invokeWithTrace(function (wrappedNext) { return fn(error, req, res, wrappedNext) - }, function () { - return { req, res, layer, error, handled: true } - }, next) + }, { req, res, layer, error, handled: true }, next) } /** @@ -155,50 +170,53 @@ Layer.prototype.handleRequest = function handleRequest (req, res, next) { return next() } - // Skip tracing for route dispatch wrappers (this.route is only set on - // the internal layer that calls route.dispatch). The actual user handlers - // inside the route are traced individually. - if (this.route) { - return invokeWithTrace(function (wrappedNext) { - return fn(req, res, wrappedNext) - }, null, next) + // Skip tracing for route dispatch wrappers (this.route is only set on the + // internal layer that calls route.dispatch); the user handlers inside the + // route are traced individually. Also skip when there are no subscribers, + // to avoid allocating a context object on every request. + if (this.route || !shouldTrace(requestChannel)) { + try { + // invoke function + const ret = handlePromise(fn(req, res, next)) + + // wait for returned promise + if (ret) { + ret.then(null, function (error) { + next(error || new Error('Rejected promise')) + }) + } + } catch (err) { + next(err) + } + return } const layer = this invokeWithTrace(function (wrappedNext) { return fn(req, res, wrappedNext) - }, function () { - return { req, res, layer } - }, next) + }, { req, res, layer }, next) } /** - * Invoke a handler function, optionally wrapping it in TracingChannel. - * The ctxFactory is only called when tracing is active, ensuring zero - * allocation overhead when no subscribers are registered. + * Invoke a handler wrapped in the request TracingChannel. Only called when the + * channel has subscribers, so ctx is always present. * @private */ -function invokeWithTrace (exec, ctxFactory, next) { - const tracing = ctxFactory && shouldTrace(requestChannel) - const ctx = tracing ? ctxFactory() : null - const wrappedNext = tracing - ? function (err) { - // 'route' and 'router' are control-flow sentinels (skip route / exit router), - // not real errors — don't pollute the error channel with them. - if (err && err !== 'route' && err !== 'router') { - ctx.error = err - // Explicitly publish the error to the error channel - requestChannel.error.publish(ctx) - } - next(err) +function invokeWithTrace (exec, ctx, next) { + const wrappedNext = function (err) { + // 'route' and 'router' are control-flow sentinels (skip route / exit router), + // not real errors — don't pollute the error channel with them. + if (err && err !== 'route' && err !== 'router') { + ctx.error = err + // Explicitly publish the error to the error channel + requestChannel.error.publish(ctx) } - : next + next(err) + } try { - const ret = tracing - ? requestChannel.tracePromise(function () { return handlePromise(exec(wrappedNext)) }, ctx) - : handlePromise(exec(wrappedNext)) + const ret = requestChannel.tracePromise(function () { return handlePromise(exec(wrappedNext)) }, ctx) if (ret) { ret.then(null, function (error) { From 337e212127cf0f2088213226e5545979ff290b43 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 00:47:30 -0400 Subject: [PATCH 16/24] fix: report each request error once, at its origin layer An error propagating through mounted sub-routers or forwarding error handlers was published on the error channel once per layer it passed through, so a single failure produced duplicate error events. Track the errors already reported for a request and publish each only at the layer where it originated. --- lib/layer.js | 33 +++++++++- test/tracing.js | 156 ++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 186 insertions(+), 3 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index 93785b34..e4a18961 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -33,6 +33,10 @@ const MATCHING_GROUP_REGEXP = /\((?:\?<(.*?)>)?(?!\?)/g const requestChannel = dc.tracingChannel && dc.tracingChannel('express.router.request') +// Tracks errors already reported for a request so the same error bubbling up +// through mounted routers or forwarding error handlers is only reported once. +const publishedErrors = Symbol('router.tracing.publishedErrors') + // TracingChannel#hasSubscribers is undefined before Node 20.13/22, so check the sub-channels. function shouldTrace (ch) { return Boolean(ch) && ( @@ -197,6 +201,23 @@ Layer.prototype.handleRequest = function handleRequest (req, res, next) { }, { req, res, layer }, next) } +/** + * Record an error as reported for this request. Returns false when the same + * error was already reported, so it isn't published again as it bubbles up. + * @private + */ + +function recordError (req, err) { + let seen = req[publishedErrors] + if (!seen) { + seen = req[publishedErrors] = new Set() + } else if (seen.has(err)) { + return false + } + seen.add(err) + return true +} + /** * Invoke a handler wrapped in the request TracingChannel. Only called when the * channel has subscribers, so ctx is always present. @@ -206,10 +227,10 @@ Layer.prototype.handleRequest = function handleRequest (req, res, next) { function invokeWithTrace (exec, ctx, next) { const wrappedNext = function (err) { // 'route' and 'router' are control-flow sentinels (skip route / exit router), - // not real errors — don't pollute the error channel with them. - if (err && err !== 'route' && err !== 'router') { + // not real errors — don't pollute the error channel with them. An error that + // already bubbled up from an inner layer is only reported at its origin. + if (err && err !== 'route' && err !== 'router' && recordError(ctx.req, err)) { ctx.error = err - // Explicitly publish the error to the error channel requestChannel.error.publish(ctx) } next(err) @@ -220,10 +241,16 @@ function invokeWithTrace (exec, ctx, next) { if (ret) { ret.then(null, function (error) { + // tracePromise already reported the rejection on this layer; record it + // so outer layers don't report it again. + recordError(ctx.req, error) next(error || new Error('Rejected promise')) }) } } catch (err) { + // tracePromise already reported the sync throw on this layer; record it so + // outer layers don't report it again. + recordError(ctx.req, err) next(err) } } diff --git a/test/tracing.js b/test/tracing.js index c1e1d968..b6d93f05 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -674,6 +674,162 @@ describeTracing('TracingChannel', function () { }) }) + describe('error deduplication', function () { + it('should report a next(err) error once, on the origin layer, across mounted routers', function (done) { + const outer = new Router() + const nested = new Router() + const server = createServer(outer) + + dc.tracingChannel('express.router.request').subscribe(handlers) + + nested.get('/bar', function innerHandler (req, res, next) { + next(new Error('boom')) + }) + outer.use('/foo', nested) + outer.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/foo/bar') + .expect(500, 'boom', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 1, + 'the same error bubbling through the mounted router must be reported once') + assert.equal(errorEvents[0].ctx.layer.name, 'innerHandler', + 'the single error event belongs to the origin layer') + + done() + }) + }) + + it('should report a next(err) error once across two mount levels', function (done) { + const outer = new Router() + const mid = new Router() + const deep = new Router() + const server = createServer(outer) + + dc.tracingChannel('express.router.request').subscribe(handlers) + + deep.get('/baz', function deepHandler (req, res, next) { + next(new Error('boom')) + }) + mid.use('/bar', deep) + outer.use('/foo', mid) + outer.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/foo/bar/baz') + .expect(500, 'boom', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 1, + 'the error must not be re-reported at each ancestor router') + assert.equal(errorEvents[0].ctx.layer.name, 'deepHandler') + + done() + }) + }) + + it('should report a thrown error once across mounted routers', function (done) { + const outer = new Router() + const nested = new Router() + const server = createServer(outer) + + dc.tracingChannel('express.router.request').subscribe(handlers) + + nested.get('/bar', function innerThrow (req, res) { + throw new Error('boom') + }) + outer.use('/foo', nested) + outer.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/foo/bar') + .expect(500, 'boom', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 1, + 'a thrown error must be reported once, at its origin') + assert.equal(errorEvents[0].ctx.layer.name, 'innerThrow') + + done() + }) + }) + + it('should report a rejected error once across mounted routers', function (done) { + const outer = new Router() + const nested = new Router() + const server = createServer(outer) + + dc.tracingChannel('express.router.request').subscribe(handlers) + + nested.get('/bar', async function innerReject (req, res) { + throw new Error('boom') + }) + outer.use('/foo', nested) + outer.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/foo/bar') + .expect(500, 'boom', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 1, + 'a rejected error must be reported once, at its origin') + assert.equal(errorEvents[0].ctx.layer.name, 'innerReject') + + done() + }) + }) + + it('should report next(err) once when an error handler forwards it', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express.router.request').subscribe(handlers) + + router.get('/fail', function origin (req, res, next) { + next(new Error('boom')) + }) + router.use(function forwarding (err, req, res, next) { + next(err) + }) + router.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/fail') + .expect(500, 'boom', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 1, + 'forwarding the same error with next(err) must not re-report it') + assert.equal(errorEvents[0].ctx.layer.name, 'origin') + + done() + }) + }) + }) + describe('event ordering', function () { it('should emit start before asyncEnd', function (done) { const router = new Router() From 232143bc47c7599cdfe6602f4ddd0983f6c021b9 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 00:58:27 -0400 Subject: [PATCH 17/24] fix: don't report thrown 'route'/'router' signals as errors A handler that throws 'route' or 'router' uses the same routing signals as next('route')/next('router') to skip the route or exit the router. Those were reaching the error channel because tracePromise reports any thrown value; catch them before tracePromise sees them so they aren't published as errors, matching how the signals are handled via next(). --- lib/layer.js | 38 +++++++++++++++++++---- test/tracing.js | 80 +++++++++++++++++++++++++++++++++++++++++-------- 2 files changed, 101 insertions(+), 17 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index e4a18961..b8b7f69b 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -218,6 +218,12 @@ function recordError (req, err) { return true } +// 'route' and 'router' signal to exit the route / router (see route.js), not +// real errors. +function isRoutingSignal (err) { + return err === 'route' || err === 'router' +} + /** * Invoke a handler wrapped in the request TracingChannel. Only called when the * channel has subscribers, so ctx is always present. @@ -226,10 +232,9 @@ function recordError (req, err) { function invokeWithTrace (exec, ctx, next) { const wrappedNext = function (err) { - // 'route' and 'router' are control-flow sentinels (skip route / exit router), - // not real errors — don't pollute the error channel with them. An error that - // already bubbled up from an inner layer is only reported at its origin. - if (err && err !== 'route' && err !== 'router' && recordError(ctx.req, err)) { + // Don't pollute the error channel with routing signals, and only report an + // error at its origin, not again as it bubbles up through outer layers. + if (err && !isRoutingSignal(err) && recordError(ctx.req, err)) { ctx.error = err requestChannel.error.publish(ctx) } @@ -237,7 +242,30 @@ function invokeWithTrace (exec, ctx, next) { } try { - const ret = requestChannel.tracePromise(function () { return handlePromise(exec(wrappedNext)) }, ctx) + const ret = requestChannel.tracePromise(function () { + // Catch thrown/rejected routing signals here so tracePromise doesn't + // report them as errors; real errors propagate and are reported as usual. + let out + try { + out = handlePromise(exec(wrappedNext)) + } catch (err) { + if (isRoutingSignal(err)) { + next(err) + return + } + throw err + } + + if (out) { + return out.then(undefined, function (err) { + if (isRoutingSignal(err)) { + next(err) + return + } + throw err + }) + } + }, ctx) if (ret) { ret.then(null, function (error) { diff --git a/test/tracing.js b/test/tracing.js index b6d93f05..307e9dfc 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -222,7 +222,7 @@ describeTracing('TracingChannel', function () { assert.ok(failingError, 'origin layer should emit error for next(err)') assert.equal(failingError.ctx.error.message, 'boom') assert.ok(!failingError.ctx.handled, - 'origin layer ctx is not the handler — should not be marked handled') + 'origin layer ctx is not the handler, so it should not be marked handled') done() }) @@ -257,11 +257,11 @@ describeTracing('TracingChannel', function () { const failingError = failingEvents.find(function (e) { return e.phase === 'error' }) assert.ok(failingError, - 'originating layer should emit error — unhandled-at-origin is always observable') + 'originating layer should emit error, since unhandled-at-origin is always observable') assert.equal(failingError.ctx.error.message, 'boom') assert.ok(!errorHandlerEvents.some(function (e) { return e.phase === 'error' }), - 'recovering error handler itself did not throw — should not emit error') + 'recovering error handler itself did not throw, so it should not emit error') const errorHandlerStart = errorHandlerEvents.find(function (e) { return e.phase === 'start' }) assert.equal(errorHandlerStart.ctx.handled, true, @@ -269,7 +269,7 @@ describeTracing('TracingChannel', function () { const errorEvents = events.filter(function (e) { return e.phase === 'error' }) assert.equal(errorEvents.length, 1, - 'exactly one error event fires — on the origin layer that called next(err)') + 'exactly one error event fires, on the origin layer that called next(err)') done() }) @@ -318,13 +318,13 @@ describeTracing('TracingChannel', function () { assert.ok(errorHandlerStart < errorHandlerEnd, 'error handler start should come before its own end') assert.ok(errorHandlerEnd < failingEnd, - 'error handler end should come before failing layer end — nesting contract: the error handler that runs via next(err) is nested inside the layer that triggered it, letting APMs attribute the error to the correct parent span') + 'error handler end should come before failing layer end. Nesting contract: the error handler that runs via next(err) is nested inside the layer that triggered it, letting APMs attribute the error to the correct parent span') done() }) }) - it('should not emit error for next("route") control-flow sentinel', function (done) { + it('should not emit error for next("route") routing signal', function (done) { const router = new Router() const server = createServer(router) @@ -346,13 +346,13 @@ describeTracing('TracingChannel', function () { const errorEvents = events.filter(function (e) { return e.phase === 'error' }) assert.equal(errorEvents.length, 0, - 'next("route") is a control-flow sentinel, not an error — nothing should publish') + 'next("route") is a routing signal, not an error, so nothing should publish') done() }) }) - it('should not emit error for next("router") control-flow sentinel', function (done) { + it('should not emit error for next("router") routing signal', function (done) { const router = new Router() const server = createServer(router) @@ -374,7 +374,63 @@ describeTracing('TracingChannel', function () { const errorEvents = events.filter(function (e) { return e.phase === 'error' }) assert.equal(errorEvents.length, 0, - 'next("router") is a control-flow sentinel, not an error — nothing should publish') + 'next("router") is a routing signal, not an error, so nothing should publish') + + done() + }) + }) + + it('should not emit error when a handler throws the "route" routing signal', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express.router.request').subscribe(handlers) + + router.get('/skip', function throwRoute (req, res) { + throw 'route' // eslint-disable-line no-throw-literal + }) + + router.get('/skip', function nextRouteHandler (req, res) { + res.statusCode = 200 + res.end('skipped') + }) + + request(server) + .get('/skip') + .expect(200, 'skipped', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 0, + 'a thrown "route" routing signal is not an error, so nothing should publish') + + done() + }) + }) + + it('should not emit error when a handler throws the "router" routing signal', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express.router.request').subscribe(handlers) + + router.use(function throwRouter (req, res) { + throw 'router' // eslint-disable-line no-throw-literal + }) + + router.get('/foo', function shouldNotRun (req, res) { + res.statusCode = 200 + res.end('should not reach') + }) + + request(server) + .get('/foo') + .expect(404, function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 0, + 'a thrown "router" routing signal is not an error, so nothing should publish') done() }) @@ -406,7 +462,7 @@ describeTracing('TracingChannel', function () { const errorEvents = events.filter(function (e) { return e.phase === 'error' }) assert.equal(errorEvents.length, 1, - 'exactly one error event fires — on the origin layer that called next(err)') + 'exactly one error event fires, on the origin layer that called next(err)') done() }) @@ -556,7 +612,7 @@ describeTracing('TracingChannel', function () { const routeError = byName('throwingHandler') assert.ok(routeError, 'route layer should emit error') assert.ok(!routeError.ctx.handled, - 'route layer is not an error handler — handled flag must be absent') + 'route layer is not an error handler, so handled flag must be absent') const handlerError = byName('throwingErrorHandler') assert.ok(handlerError, 'error handler should emit its own error') @@ -597,7 +653,7 @@ describeTracing('TracingChannel', function () { const routeError = byName('rejectingHandler') assert.ok(routeError, 'route layer should emit error') assert.ok(!routeError.ctx.handled, - 'route layer is not an error handler — handled flag must be absent') + 'route layer is not an error handler, so handled flag must be absent') const handlerError = byName('throwingErrorHandler') assert.ok(handlerError, 'error handler should emit its own error') From 10a47bc0b01a534e8d6c6b874e577b6edbbd6519 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 00:58:27 -0400 Subject: [PATCH 18/24] docs: clarify error semantics on the request tracing channel --- README.md | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/README.md b/README.md index a15dac2a..f9fd5130 100644 --- a/README.md +++ b/README.md @@ -414,12 +414,14 @@ contains: - `req`: the incoming `http.IncomingMessage` - `res`: the `http.ServerResponse` - `layer`: the internal `Layer` instance being invoked (exposes `.name`, `.path`, `.handle`, etc.). Note that `Layer` is an internal implementation detail and its shape may change between releases. -- `error`: the error passed to `next(err)`, when applicable +- `error`: the error the layer failed with, when applicable - `handled`: `true` when the layer is an error-handling middleware (4-arg signature) -The `error` event is also published when a handler calls `next(err)` with a real -error. The control-flow sentinels `'route'` and `'router'` are not treated as -errors and will not publish to the `error` channel. +The `error` event is published once, on the layer where the error originates, +whether the handler calls `next(err)`, throws, or returns a rejected promise. An +error bubbling up through outer layers is not reported again. The `'route'` and +`'router'` routing signals are not treated as errors and will not publish to the +`error` channel. When no subscribers are attached, tracing is bypassed entirely, so there is no context allocation or channel publishing overhead on the hot path. From cc5deb7aa30bf76dff546d2e1de2de77d7e4c2e3 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 01:09:59 -0400 Subject: [PATCH 19/24] fix: report value-less rejections as the forwarded error on the channel A handler that rejects or throws a falsy value (Promise.reject(), throw undefined) was reported on the error channel as that raw value, while the router forwards new Error('Rejected promise') to next(). Normalize once, before tracePromise reports it, so the channel and downstream handlers see the same error instance. --- lib/layer.js | 12 +++++++----- test/tracing.js | 27 +++++++++++++++++++++++++++ 2 files changed, 34 insertions(+), 5 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index b8b7f69b..620c2ac7 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -245,6 +245,8 @@ function invokeWithTrace (exec, ctx, next) { const ret = requestChannel.tracePromise(function () { // Catch thrown/rejected routing signals here so tracePromise doesn't // report them as errors; real errors propagate and are reported as usual. + // A falsy rejection is normalized to the same error the router forwards to + // next(), so the error channel and downstream handlers see one instance. let out try { out = handlePromise(exec(wrappedNext)) @@ -253,7 +255,7 @@ function invokeWithTrace (exec, ctx, next) { next(err) return } - throw err + throw err || new Error('Rejected promise') } if (out) { @@ -262,17 +264,17 @@ function invokeWithTrace (exec, ctx, next) { next(err) return } - throw err + throw err || new Error('Rejected promise') }) } }, ctx) if (ret) { ret.then(null, function (error) { - // tracePromise already reported the rejection on this layer; record it - // so outer layers don't report it again. + // tracePromise already reported the rejection on this layer (with the + // normalized error); record it so outer layers don't report it again. recordError(ctx.req, error) - next(error || new Error('Rejected promise')) + next(error) }) } } catch (err) { diff --git a/test/tracing.js b/test/tracing.js index 307e9dfc..07b0c32b 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -524,6 +524,33 @@ describeTracing('TracingChannel', function () { }) }) + it('should normalize a falsy rejection to the error the router forwards', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel('express.router.request').subscribe(handlers) + + router.get('/reject', async function rejectFalsy (req, res) { + return Promise.reject() // eslint-disable-line prefer-promise-reject-errors + }) + + request(server) + .get('/reject') + .expect(500, function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 1, 'should report the rejection once') + + const reported = errorEvents[0].ctx.error + assert.ok(reported instanceof Error, + 'a falsy rejection is reported as the Error the router forwards to next(), not the raw value') + assert.equal(reported.message, 'Rejected promise') + + done() + }) + }) + it('should emit error on route only when sync throw is recovered by a clean error handler', function (done) { const router = new Router() const server = createServer(router) From 9aa666a1b406a587676026cb722b46de221f03ea Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 14:08:38 -0400 Subject: [PATCH 20/24] test: extract channel-name constant and shared byLayer helper Replace the repeated 'express.router.request' literal with a CHANNEL constant, and hoist the per-test byLayer/byName predicate into a single shared helper at the bottom of the file. --- test/tracing.js | 87 +++++++++++++++++++++++-------------------------- 1 file changed, 40 insertions(+), 47 deletions(-) diff --git a/test/tracing.js b/test/tracing.js index 07b0c32b..a8cbc86d 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -6,6 +6,8 @@ const assert = utils.assert const createServer = utils.createServer const request = utils.request +const CHANNEL = 'express.router.request' + let dc let tracingChannel @@ -34,7 +36,7 @@ describeTracing('TracingChannel', function () { }) afterEach(function () { - dc.tracingChannel('express.router.request').unsubscribe(handlers) + dc.tracingChannel(CHANNEL).unsubscribe(handlers) }) describe('when no subscribers', function () { @@ -58,7 +60,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.use(function myMiddleware (req, res, next) { next() @@ -93,7 +95,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.use(function (req, res, next) { next() @@ -126,7 +128,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/users/:id', function getUser (req, res) { res.statusCode = 200 @@ -155,7 +157,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/foo', function myHandler (req, res) { res.statusCode = 200 @@ -184,7 +186,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/fail', function failingHandler (req, res, next) { next(new Error('boom')) @@ -200,10 +202,6 @@ describeTracing('TracingChannel', function () { .expect(500, 'boom', function (err) { if (err) return done(err) - const byLayer = function (name) { - return function (e) { return e.ctx.layer && e.ctx.layer.name === name } - } - const failingEvents = events.filter(byLayer('failingHandler')) const errorHandlerEvents = events.filter(byLayer('myErrorHandler')) @@ -232,7 +230,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/fail', function failingHandler (req, res, next) { next(new Error('boom')) @@ -248,10 +246,6 @@ describeTracing('TracingChannel', function () { .expect(500, 'boom', function (err) { if (err) return done(err) - const byLayer = function (name) { - return function (e) { return e.ctx.layer && e.ctx.layer.name === name } - } - const failingEvents = events.filter(byLayer('failingHandler')) const errorHandlerEvents = events.filter(byLayer('myErrorHandler')) @@ -279,7 +273,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.use(function firstMiddleware (req, res, next) { next() @@ -328,7 +322,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/skip', function skipToNextRoute (req, res, next) { next('route') @@ -356,7 +350,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.use(function ejectFromRouter (req, res, next) { next('router') @@ -384,7 +378,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/skip', function throwRoute (req, res) { throw 'route' // eslint-disable-line no-throw-literal @@ -412,7 +406,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.use(function throwRouter (req, res) { throw 'router' // eslint-disable-line no-throw-literal @@ -440,7 +434,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/fail', function failingHandler (req, res, next) { next(new Error('unhandled boom')) @@ -474,7 +468,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/throw', function (req, res) { throw new Error('sync boom') @@ -501,7 +495,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/reject', async function (req, res) { throw new Error('async boom') @@ -528,7 +522,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/reject', async function rejectFalsy (req, res) { return Promise.reject() // eslint-disable-line prefer-promise-reject-errors @@ -555,7 +549,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/throw', function throwingHandler (req, res) { throw new Error('sync boom') @@ -584,7 +578,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/reject', async function rejectingHandler (req, res) { throw new Error('async boom') @@ -613,7 +607,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/throw', function throwingHandler (req, res) { throw new Error('sync boom') @@ -630,18 +624,15 @@ describeTracing('TracingChannel', function () { if (err) return done(err) const errorEvents = events.filter(function (e) { return e.phase === 'error' }) - const byName = function (name) { - return errorEvents.find(function (e) { return e.ctx.layer.name === name }) - } assert.equal(errorEvents.length, 2, 'error should fire on both layers') - const routeError = byName('throwingHandler') + const routeError = errorEvents.find(byLayer('throwingHandler')) assert.ok(routeError, 'route layer should emit error') assert.ok(!routeError.ctx.handled, 'route layer is not an error handler, so handled flag must be absent') - const handlerError = byName('throwingErrorHandler') + const handlerError = errorEvents.find(byLayer('throwingErrorHandler')) assert.ok(handlerError, 'error handler should emit its own error') assert.equal(handlerError.ctx.handled, true, 'error handler\'s own error event must carry handled:true so APMs can classify the span correctly') @@ -654,7 +645,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/reject', async function rejectingHandler (req, res) { throw new Error('async boom') @@ -671,18 +662,15 @@ describeTracing('TracingChannel', function () { if (err) return done(err) const errorEvents = events.filter(function (e) { return e.phase === 'error' }) - const byName = function (name) { - return errorEvents.find(function (e) { return e.ctx.layer.name === name }) - } assert.equal(errorEvents.length, 2, 'error should fire on both layers') - const routeError = byName('rejectingHandler') + const routeError = errorEvents.find(byLayer('rejectingHandler')) assert.ok(routeError, 'route layer should emit error') assert.ok(!routeError.ctx.handled, 'route layer is not an error handler, so handled flag must be absent') - const handlerError = byName('throwingErrorHandler') + const handlerError = errorEvents.find(byLayer('throwingErrorHandler')) assert.ok(handlerError, 'error handler should emit its own error') assert.equal(handlerError.ctx.handled, true, 'error handler\'s own error event must carry handled:true so APMs can classify the span correctly') @@ -697,7 +685,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/async', function asyncHandler (req, res) { return new Promise(function (resolve) { @@ -731,7 +719,7 @@ describeTracing('TracingChannel', function () { const nested = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) nested.get('/bar', function nestedHandler (req, res) { res.statusCode = 200 @@ -763,7 +751,7 @@ describeTracing('TracingChannel', function () { const nested = new Router() const server = createServer(outer) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) nested.get('/bar', function innerHandler (req, res, next) { next(new Error('boom')) @@ -795,7 +783,7 @@ describeTracing('TracingChannel', function () { const deep = new Router() const server = createServer(outer) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) deep.get('/baz', function deepHandler (req, res, next) { next(new Error('boom')) @@ -826,7 +814,7 @@ describeTracing('TracingChannel', function () { const nested = new Router() const server = createServer(outer) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) nested.get('/bar', function innerThrow (req, res) { throw new Error('boom') @@ -856,7 +844,7 @@ describeTracing('TracingChannel', function () { const nested = new Router() const server = createServer(outer) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) nested.get('/bar', async function innerReject (req, res) { throw new Error('boom') @@ -885,7 +873,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/fail', function origin (req, res, next) { next(new Error('boom')) @@ -918,7 +906,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.get('/order', function (req, res) { res.statusCode = 200 @@ -948,7 +936,7 @@ describeTracing('TracingChannel', function () { const router = new Router() const server = createServer(router) - dc.tracingChannel('express.router.request').subscribe(handlers) + dc.tracingChannel(CHANNEL).subscribe(handlers) router.use(function first (req, res, next) { next() @@ -979,3 +967,8 @@ describeTracing('TracingChannel', function () { }) }) }) + +// Predicate matching a captured event by its layer name. +function byLayer (name) { + return function (e) { return e.ctx.layer && e.ctx.layer.name === name } +} From 04b2f72b4162456648121e36b536af35034f972a Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 14:31:06 -0400 Subject: [PATCH 21/24] fix: route traced outcomes through next so tracing never changes routing Send every handler outcome (return, throw, rejection) through wrappedNext instead of re-throwing into tracePromise's own error publishing. This puts signal filtering and error dedup in one place and keeps two behaviors in line with the untraced router: - a sync falsy throw is forwarded verbatim, so it keeps routing instead of being turned into an error - an error rethrown by an error handler is the same error, so it is reported once at its origin rather than twice Async rejections with a falsy reason are still normalized to the error the router forwards to next(), reported once. --- lib/layer.js | 62 +++++++++++++++++-------------------------------- test/tracing.js | 59 ++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 80 insertions(+), 41 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index 620c2ac7..f4d5d9bb 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -232,8 +232,8 @@ function isRoutingSignal (err) { function invokeWithTrace (exec, ctx, next) { const wrappedNext = function (err) { - // Don't pollute the error channel with routing signals, and only report an - // error at its origin, not again as it bubbles up through outer layers. + // Routing signals aren't errors; only report a real error once, at its + // origin, not again as it bubbles up through outer layers. if (err && !isRoutingSignal(err) && recordError(ctx.req, err)) { ctx.error = err requestChannel.error.publish(ctx) @@ -241,48 +241,28 @@ function invokeWithTrace (exec, ctx, next) { next(err) } - try { - const ret = requestChannel.tracePromise(function () { - // Catch thrown/rejected routing signals here so tracePromise doesn't - // report them as errors; real errors propagate and are reported as usual. - // A falsy rejection is normalized to the same error the router forwards to - // next(), so the error channel and downstream handlers see one instance. - let out - try { - out = handlePromise(exec(wrappedNext)) - } catch (err) { - if (isRoutingSignal(err)) { - next(err) - return - } - throw err || new Error('Rejected promise') - } + // All outcomes flow through wrappedNext (never tracePromise's own error + // publishing), so signal filtering and dedup happen in one place and tracing + // never changes how the router routes. + requestChannel.tracePromise(function () { + let out + try { + out = handlePromise(exec(wrappedNext)) + } catch (err) { + // A sync throw is forwarded verbatim, so a falsy value keeps routing + // exactly as the untraced path does. + wrappedNext(err) + return + } - if (out) { - return out.then(undefined, function (err) { - if (isRoutingSignal(err)) { - next(err) - return - } - throw err || new Error('Rejected promise') - }) - } - }, ctx) - - if (ret) { - ret.then(null, function (error) { - // tracePromise already reported the rejection on this layer (with the - // normalized error); record it so outer layers don't report it again. - recordError(ctx.req, error) - next(error) + if (out) { + return out.then(undefined, function (err) { + // A rejected promise is an error even when the reason is falsy; + // normalize it to the error the router forwards to next(). + wrappedNext(err || new Error('Rejected promise')) }) } - } catch (err) { - // tracePromise already reported the sync throw on this layer; record it so - // outer layers don't report it again. - recordError(ctx.req, err) - next(err) - } + }, ctx) } /** diff --git a/test/tracing.js b/test/tracing.js index a8cbc86d..f6672727 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -545,6 +545,34 @@ describeTracing('TracingChannel', function () { }) }) + it('should keep routing after a sync falsy throw, same as the untraced path', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel(CHANNEL).subscribe(handlers) + + router.get('/falsy', function throwsFalsy (req, res) { + throw undefined // eslint-disable-line no-throw-literal + }) + + router.get('/falsy', function continues (req, res) { + res.statusCode = 200 + res.end('continued') + }) + + request(server) + .get('/falsy') + .expect(200, 'continued', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 0, + 'the untraced router treats a sync falsy throw as next(), so subscribing must not divert it to error handling') + + done() + }) + }) + it('should emit error on route only when sync throw is recovered by a clean error handler', function (done) { const router = new Router() const server = createServer(router) @@ -899,6 +927,37 @@ describeTracing('TracingChannel', function () { done() }) }) + + it('should report next(err) once when an error handler rethrows it', function (done) { + const router = new Router() + const server = createServer(router) + + dc.tracingChannel(CHANNEL).subscribe(handlers) + + router.get('/fail', function origin (req, res, next) { + next(new Error('boom')) + }) + router.use(function rethrowing (err, req, res, next) { // eslint-disable-line no-unused-vars + throw err + }) + router.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) + }) + + request(server) + .get('/fail') + .expect(500, 'boom', function (err) { + if (err) return done(err) + + const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + assert.equal(errorEvents.length, 1, + 'throw err and next(err) are equivalent to the router, so rethrowing the same error must not re-report it') + assert.equal(errorEvents[0].ctx.layer.name, 'origin') + + done() + }) + }) }) describe('event ordering', function () { From 97da6d861dd0c1ce29aa9a6e524d8ba8c5aea4ba Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 14:45:01 -0400 Subject: [PATCH 22/24] test: hoist repeated setup and predicates into shared helpers Add a traced() helper for the router+server+subscribe setup, a byPhase() predicate to match the byLayer() one, and a shared recover error handler, replacing the copies repeated across the tracing tests. --- test/tracing.js | 269 ++++++++++++++++-------------------------------- 1 file changed, 90 insertions(+), 179 deletions(-) diff --git a/test/tracing.js b/test/tracing.js index f6672727..d682ee53 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -39,6 +39,14 @@ describeTracing('TracingChannel', function () { dc.tracingChannel(CHANNEL).unsubscribe(handlers) }) + // Build a router and server with the tracing handlers subscribed. + function traced () { + const router = new Router() + const server = createServer(router) + dc.tracingChannel(CHANNEL).subscribe(handlers) + return { router, server } + } + describe('when no subscribers', function () { it('should not affect normal behavior', function (done) { const router = new Router() @@ -57,10 +65,7 @@ describeTracing('TracingChannel', function () { describe('context shape', function () { it('should provide req, res, and layer in context', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.use(function myMiddleware (req, res, next) { next() @@ -76,7 +81,7 @@ describeTracing('TracingChannel', function () { .expect(200, function (err) { if (err) return done(err) - const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const startEvents = events.filter(byPhase('start')) const middlewareStart = startEvents.find(function (e) { return e.ctx.layer && e.ctx.layer.name === 'myMiddleware' }) @@ -92,10 +97,7 @@ describeTracing('TracingChannel', function () { }) it('should have layer.name as for unnamed middleware', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.use(function (req, res, next) { next() @@ -111,7 +113,7 @@ describeTracing('TracingChannel', function () { .expect(200, function (err) { if (err) return done(err) - const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const startEvents = events.filter(byPhase('start')) const anonMiddleware = startEvents.find(function (e) { return e.ctx.layer && e.ctx.layer.name === '' }) @@ -125,10 +127,7 @@ describeTracing('TracingChannel', function () { describe('route handler tracing', function () { it('should have req.route set for route handlers', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/users/:id', function getUser (req, res) { res.statusCode = 200 @@ -140,7 +139,7 @@ describeTracing('TracingChannel', function () { .expect(200, function (err) { if (err) return done(err) - const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const startEvents = events.filter(byPhase('start')) const handlerStart = startEvents.find(function (e) { return e.ctx.layer && e.ctx.layer.name === 'getUser' }) @@ -154,10 +153,7 @@ describeTracing('TracingChannel', function () { }) it('should not trace the route dispatch wrapper', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/foo', function myHandler (req, res) { res.statusCode = 200 @@ -169,7 +165,7 @@ describeTracing('TracingChannel', function () { .expect(200, function (err) { if (err) return done(err) - const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const startEvents = events.filter(byPhase('start')) const dispatchWrapper = startEvents.find(function (e) { return e.ctx.layer && e.ctx.layer.name === 'handle' }) @@ -183,10 +179,7 @@ describeTracing('TracingChannel', function () { describe('error handler tracing', function () { it('should trace error handlers (fn.length === 4) and mark their ctx as handled', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/fail', function failingHandler (req, res, next) { next(new Error('boom')) @@ -205,7 +198,7 @@ describeTracing('TracingChannel', function () { const failingEvents = events.filter(byLayer('failingHandler')) const errorHandlerEvents = events.filter(byLayer('myErrorHandler')) - const errorHandlerStart = errorHandlerEvents.find(function (e) { return e.phase === 'start' }) + const errorHandlerStart = errorHandlerEvents.find(byPhase('start')) assert.ok(errorHandlerStart, 'should have start event for error handler') assert.equal(errorHandlerStart.ctx.layer.handle.length, 4) assert.equal(errorHandlerStart.ctx.handled, true, @@ -213,10 +206,10 @@ describeTracing('TracingChannel', function () { assert.ok(errorHandlerStart.ctx.error, 'error handler ctx should expose the error it received') - assert.ok(!errorHandlerEvents.some(function (e) { return e.phase === 'error' }), + assert.ok(!errorHandlerEvents.some(byPhase('error')), 'error handler itself did not throw, so it should not emit error') - const failingError = failingEvents.find(function (e) { return e.phase === 'error' }) + const failingError = failingEvents.find(byPhase('error')) assert.ok(failingError, 'origin layer should emit error for next(err)') assert.equal(failingError.ctx.error.message, 'boom') assert.ok(!failingError.ctx.handled, @@ -227,10 +220,7 @@ describeTracing('TracingChannel', function () { }) it('should emit error on originating layer when next(err) is recovered downstream', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/fail', function failingHandler (req, res, next) { next(new Error('boom')) @@ -249,19 +239,19 @@ describeTracing('TracingChannel', function () { const failingEvents = events.filter(byLayer('failingHandler')) const errorHandlerEvents = events.filter(byLayer('myErrorHandler')) - const failingError = failingEvents.find(function (e) { return e.phase === 'error' }) + const failingError = failingEvents.find(byPhase('error')) assert.ok(failingError, 'originating layer should emit error, since unhandled-at-origin is always observable') assert.equal(failingError.ctx.error.message, 'boom') - assert.ok(!errorHandlerEvents.some(function (e) { return e.phase === 'error' }), + assert.ok(!errorHandlerEvents.some(byPhase('error')), 'recovering error handler itself did not throw, so it should not emit error') - const errorHandlerStart = errorHandlerEvents.find(function (e) { return e.phase === 'start' }) + const errorHandlerStart = errorHandlerEvents.find(byPhase('start')) assert.equal(errorHandlerStart.ctx.handled, true, 'error handler ctx is marked handled so APMs can dedup against the origin error') - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'exactly one error event fires, on the origin layer that called next(err)') @@ -270,10 +260,7 @@ describeTracing('TracingChannel', function () { }) it('should nest the error handler span inside the originating layer span', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.use(function firstMiddleware (req, res, next) { next() @@ -319,10 +306,7 @@ describeTracing('TracingChannel', function () { }) it('should not emit error for next("route") routing signal', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/skip', function skipToNextRoute (req, res, next) { next('route') @@ -338,7 +322,7 @@ describeTracing('TracingChannel', function () { .expect(200, 'skipped', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 0, 'next("route") is a routing signal, not an error, so nothing should publish') @@ -347,10 +331,7 @@ describeTracing('TracingChannel', function () { }) it('should not emit error for next("router") routing signal', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.use(function ejectFromRouter (req, res, next) { next('router') @@ -366,7 +347,7 @@ describeTracing('TracingChannel', function () { .expect(404, function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 0, 'next("router") is a routing signal, not an error, so nothing should publish') @@ -375,10 +356,7 @@ describeTracing('TracingChannel', function () { }) it('should not emit error when a handler throws the "route" routing signal', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/skip', function throwRoute (req, res) { throw 'route' // eslint-disable-line no-throw-literal @@ -394,7 +372,7 @@ describeTracing('TracingChannel', function () { .expect(200, 'skipped', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 0, 'a thrown "route" routing signal is not an error, so nothing should publish') @@ -403,10 +381,7 @@ describeTracing('TracingChannel', function () { }) it('should not emit error when a handler throws the "router" routing signal', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.use(function throwRouter (req, res) { throw 'router' // eslint-disable-line no-throw-literal @@ -422,7 +397,7 @@ describeTracing('TracingChannel', function () { .expect(404, function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 0, 'a thrown "router" routing signal is not an error, so nothing should publish') @@ -431,10 +406,7 @@ describeTracing('TracingChannel', function () { }) it('should emit error on originating layer when next(err) is unhandled', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/fail', function failingHandler (req, res, next) { next(new Error('unhandled boom')) @@ -449,12 +421,12 @@ describeTracing('TracingChannel', function () { return e.ctx.layer && e.ctx.layer.name === 'failingHandler' }) - const failingError = failingEvents.find(function (e) { return e.phase === 'error' }) + const failingError = failingEvents.find(byPhase('error')) assert.ok(failingError, 'unhandled next(err) must be observable on the origin layer') assert.equal(failingError.ctx.error.message, 'unhandled boom') - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'exactly one error event fires, on the origin layer that called next(err)') @@ -465,10 +437,7 @@ describeTracing('TracingChannel', function () { describe('error channel', function () { it('should emit error when handler throws synchronously', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/throw', function (req, res) { throw new Error('sync boom') @@ -479,7 +448,7 @@ describeTracing('TracingChannel', function () { .expect(500, function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.ok(errorEvents.length > 0, 'should have error events') const errorEvent = errorEvents.find(function (e) { @@ -492,10 +461,7 @@ describeTracing('TracingChannel', function () { }) it('should emit error when async handler rejects', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/reject', async function (req, res) { throw new Error('async boom') @@ -506,7 +472,7 @@ describeTracing('TracingChannel', function () { .expect(500, function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.ok(errorEvents.length > 0, 'should have error events') const errorEvent = errorEvents.find(function (e) { @@ -519,10 +485,7 @@ describeTracing('TracingChannel', function () { }) it('should normalize a falsy rejection to the error the router forwards', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/reject', async function rejectFalsy (req, res) { return Promise.reject() // eslint-disable-line prefer-promise-reject-errors @@ -533,7 +496,7 @@ describeTracing('TracingChannel', function () { .expect(500, function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'should report the rejection once') const reported = errorEvents[0].ctx.error @@ -546,10 +509,7 @@ describeTracing('TracingChannel', function () { }) it('should keep routing after a sync falsy throw, same as the untraced path', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/falsy', function throwsFalsy (req, res) { throw undefined // eslint-disable-line no-throw-literal @@ -565,7 +525,7 @@ describeTracing('TracingChannel', function () { .expect(200, 'continued', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 0, 'the untraced router treats a sync falsy throw as next(), so subscribing must not divert it to error handling') @@ -574,10 +534,7 @@ describeTracing('TracingChannel', function () { }) it('should emit error on route only when sync throw is recovered by a clean error handler', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/throw', function throwingHandler (req, res) { throw new Error('sync boom') @@ -593,7 +550,7 @@ describeTracing('TracingChannel', function () { .expect(500, 'sync boom', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'exactly one error event should fire') assert.equal(errorEvents[0].ctx.layer.name, 'throwingHandler', 'error event should belong to the throwing route layer') @@ -603,10 +560,7 @@ describeTracing('TracingChannel', function () { }) it('should emit error on route only when async reject is recovered by a clean error handler', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/reject', async function rejectingHandler (req, res) { throw new Error('async boom') @@ -622,7 +576,7 @@ describeTracing('TracingChannel', function () { .expect(500, 'async boom', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'exactly one error event should fire') assert.equal(errorEvents[0].ctx.layer.name, 'rejectingHandler', 'error event should belong to the rejecting route layer') @@ -632,10 +586,7 @@ describeTracing('TracingChannel', function () { }) it('should emit error on both layers when sync throw is followed by a throwing error handler', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/throw', function throwingHandler (req, res) { throw new Error('sync boom') @@ -651,7 +602,7 @@ describeTracing('TracingChannel', function () { .expect(500, function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 2, 'error should fire on both layers') @@ -670,10 +621,7 @@ describeTracing('TracingChannel', function () { }) it('should emit error on both layers when async reject is followed by a throwing error handler', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/reject', async function rejectingHandler (req, res) { throw new Error('async boom') @@ -689,7 +637,7 @@ describeTracing('TracingChannel', function () { .expect(500, function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 2, 'error should fire on both layers') @@ -710,10 +658,7 @@ describeTracing('TracingChannel', function () { describe('async handlers', function () { it('should trace async handlers that return promises', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/async', function asyncHandler (req, res) { return new Promise(function (resolve) { @@ -730,8 +675,8 @@ describeTracing('TracingChannel', function () { .expect(200, 'async hello', function (err) { if (err) return done(err) - const startEvents = events.filter(function (e) { return e.phase === 'start' }) - const asyncEndEvents = events.filter(function (e) { return e.phase === 'asyncEnd' }) + const startEvents = events.filter(byPhase('start')) + const asyncEndEvents = events.filter(byPhase('asyncEnd')) assert.ok(startEvents.length > 0, 'should have start events') assert.ok(asyncEndEvents.length > 0, 'should have asyncEnd events') @@ -743,11 +688,8 @@ describeTracing('TracingChannel', function () { describe('nested routers', function () { it('should trace middleware in nested routers', function (done) { - const router = new Router() + const { router, server } = traced() const nested = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) nested.get('/bar', function nestedHandler (req, res) { res.statusCode = 200 @@ -761,7 +703,7 @@ describeTracing('TracingChannel', function () { .expect(200, 'nested', function (err) { if (err) return done(err) - const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const startEvents = events.filter(byPhase('start')) const handlerEvent = startEvents.find(function (e) { return e.ctx.layer && e.ctx.layer.name === 'nestedHandler' }) @@ -775,27 +717,21 @@ describeTracing('TracingChannel', function () { describe('error deduplication', function () { it('should report a next(err) error once, on the origin layer, across mounted routers', function (done) { - const outer = new Router() + const { router: outer, server } = traced() const nested = new Router() - const server = createServer(outer) - - dc.tracingChannel(CHANNEL).subscribe(handlers) nested.get('/bar', function innerHandler (req, res, next) { next(new Error('boom')) }) outer.use('/foo', nested) - outer.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars - res.statusCode = 500 - res.end(err.message) - }) + outer.use(recover) request(server) .get('/foo/bar') .expect(500, 'boom', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'the same error bubbling through the mounted router must be reported once') assert.equal(errorEvents[0].ctx.layer.name, 'innerHandler', @@ -806,29 +742,23 @@ describeTracing('TracingChannel', function () { }) it('should report a next(err) error once across two mount levels', function (done) { - const outer = new Router() + const { router: outer, server } = traced() const mid = new Router() const deep = new Router() - const server = createServer(outer) - - dc.tracingChannel(CHANNEL).subscribe(handlers) deep.get('/baz', function deepHandler (req, res, next) { next(new Error('boom')) }) mid.use('/bar', deep) outer.use('/foo', mid) - outer.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars - res.statusCode = 500 - res.end(err.message) - }) + outer.use(recover) request(server) .get('/foo/bar/baz') .expect(500, 'boom', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'the error must not be re-reported at each ancestor router') assert.equal(errorEvents[0].ctx.layer.name, 'deepHandler') @@ -838,27 +768,21 @@ describeTracing('TracingChannel', function () { }) it('should report a thrown error once across mounted routers', function (done) { - const outer = new Router() + const { router: outer, server } = traced() const nested = new Router() - const server = createServer(outer) - - dc.tracingChannel(CHANNEL).subscribe(handlers) nested.get('/bar', function innerThrow (req, res) { throw new Error('boom') }) outer.use('/foo', nested) - outer.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars - res.statusCode = 500 - res.end(err.message) - }) + outer.use(recover) request(server) .get('/foo/bar') .expect(500, 'boom', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'a thrown error must be reported once, at its origin') assert.equal(errorEvents[0].ctx.layer.name, 'innerThrow') @@ -868,27 +792,21 @@ describeTracing('TracingChannel', function () { }) it('should report a rejected error once across mounted routers', function (done) { - const outer = new Router() + const { router: outer, server } = traced() const nested = new Router() - const server = createServer(outer) - - dc.tracingChannel(CHANNEL).subscribe(handlers) nested.get('/bar', async function innerReject (req, res) { throw new Error('boom') }) outer.use('/foo', nested) - outer.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars - res.statusCode = 500 - res.end(err.message) - }) + outer.use(recover) request(server) .get('/foo/bar') .expect(500, 'boom', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'a rejected error must be reported once, at its origin') assert.equal(errorEvents[0].ctx.layer.name, 'innerReject') @@ -898,10 +816,7 @@ describeTracing('TracingChannel', function () { }) it('should report next(err) once when an error handler forwards it', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/fail', function origin (req, res, next) { next(new Error('boom')) @@ -909,17 +824,14 @@ describeTracing('TracingChannel', function () { router.use(function forwarding (err, req, res, next) { next(err) }) - router.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars - res.statusCode = 500 - res.end(err.message) - }) + router.use(recover) request(server) .get('/fail') .expect(500, 'boom', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'forwarding the same error with next(err) must not re-report it') assert.equal(errorEvents[0].ctx.layer.name, 'origin') @@ -929,10 +841,7 @@ describeTracing('TracingChannel', function () { }) it('should report next(err) once when an error handler rethrows it', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/fail', function origin (req, res, next) { next(new Error('boom')) @@ -940,17 +849,14 @@ describeTracing('TracingChannel', function () { router.use(function rethrowing (err, req, res, next) { // eslint-disable-line no-unused-vars throw err }) - router.use(function recover (err, req, res, next) { // eslint-disable-line no-unused-vars - res.statusCode = 500 - res.end(err.message) - }) + router.use(recover) request(server) .get('/fail') .expect(500, 'boom', function (err) { if (err) return done(err) - const errorEvents = events.filter(function (e) { return e.phase === 'error' }) + const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, 'throw err and next(err) are equivalent to the router, so rethrowing the same error must not re-report it') assert.equal(errorEvents[0].ctx.layer.name, 'origin') @@ -962,10 +868,7 @@ describeTracing('TracingChannel', function () { describe('event ordering', function () { it('should emit start before asyncEnd', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.get('/order', function (req, res) { res.statusCode = 200 @@ -992,10 +895,7 @@ describeTracing('TracingChannel', function () { describe('multiple middleware', function () { it('should emit events for each middleware in the chain', function (done) { - const router = new Router() - const server = createServer(router) - - dc.tracingChannel(CHANNEL).subscribe(handlers) + const { router, server } = traced() router.use(function first (req, res, next) { next() @@ -1015,7 +915,7 @@ describeTracing('TracingChannel', function () { .expect(200, function (err) { if (err) return done(err) - const startEvents = events.filter(function (e) { return e.phase === 'start' }) + const startEvents = events.filter(byPhase('start')) const names = startEvents.map(function (e) { return e.ctx.layer.name }) assert.ok(names.indexOf('first') >= 0, 'should trace first middleware') @@ -1031,3 +931,14 @@ describeTracing('TracingChannel', function () { function byLayer (name) { return function (e) { return e.ctx.layer && e.ctx.layer.name === name } } + +// Predicate matching a captured event by its lifecycle phase. +function byPhase (name) { + return function (e) { return e.phase === name } +} + +// Error handler that recovers by ending the response with the error message. +function recover (err, req, res, next) { // eslint-disable-line no-unused-vars + res.statusCode = 500 + res.end(err.message) +} From 583c8c4343c8503a30ba7424fbf91aa00b6769e3 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 16:32:25 -0400 Subject: [PATCH 23/24] refactor: rename the error-handler context flag to errorHandler The flag marks that the layer is an error-handling middleware, which 'handled' read as 'the error was resolved' (misleading for a rethrowing handler). Rename it to errorHandler in the context, README, and tests. --- README.md | 2 +- lib/layer.js | 2 +- test/tracing.js | 30 +++++++++++++++--------------- 3 files changed, 17 insertions(+), 17 deletions(-) diff --git a/README.md b/README.md index f9fd5130..5f3d53b6 100644 --- a/README.md +++ b/README.md @@ -415,7 +415,7 @@ contains: - `res`: the `http.ServerResponse` - `layer`: the internal `Layer` instance being invoked (exposes `.name`, `.path`, `.handle`, etc.). Note that `Layer` is an internal implementation detail and its shape may change between releases. - `error`: the error the layer failed with, when applicable -- `handled`: `true` when the layer is an error-handling middleware (4-arg signature) +- `errorHandler`: `true` when the layer is an error-handling middleware (4-arg signature) The `error` event is published once, on the layer where the error originates, whether the handler calls `next(err)`, throws, or returns a rejected promise. An diff --git a/lib/layer.js b/lib/layer.js index f4d5d9bb..b07c022f 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -154,7 +154,7 @@ Layer.prototype.handleError = function handleError (error, req, res, next) { const layer = this invokeWithTrace(function (wrappedNext) { return fn(error, req, res, wrappedNext) - }, { req, res, layer, error, handled: true }, next) + }, { req, res, layer, error, errorHandler: true }, next) } /** diff --git a/test/tracing.js b/test/tracing.js index d682ee53..15b7fa3f 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -178,7 +178,7 @@ describeTracing('TracingChannel', function () { }) describe('error handler tracing', function () { - it('should trace error handlers (fn.length === 4) and mark their ctx as handled', function (done) { + it('should trace error handlers (fn.length === 4) and flag their ctx as errorHandler', function (done) { const { router, server } = traced() router.get('/fail', function failingHandler (req, res, next) { @@ -201,8 +201,8 @@ describeTracing('TracingChannel', function () { const errorHandlerStart = errorHandlerEvents.find(byPhase('start')) assert.ok(errorHandlerStart, 'should have start event for error handler') assert.equal(errorHandlerStart.ctx.layer.handle.length, 4) - assert.equal(errorHandlerStart.ctx.handled, true, - 'error handler ctx should be marked handled so APMs can dedup the origin error') + assert.equal(errorHandlerStart.ctx.errorHandler, true, + 'error handler ctx should be flagged errorHandler so APMs can dedup the origin error') assert.ok(errorHandlerStart.ctx.error, 'error handler ctx should expose the error it received') @@ -212,8 +212,8 @@ describeTracing('TracingChannel', function () { const failingError = failingEvents.find(byPhase('error')) assert.ok(failingError, 'origin layer should emit error for next(err)') assert.equal(failingError.ctx.error.message, 'boom') - assert.ok(!failingError.ctx.handled, - 'origin layer ctx is not the handler, so it should not be marked handled') + assert.ok(!failingError.ctx.errorHandler, + 'origin layer is not an error handler, so it should not be flagged errorHandler') done() }) @@ -248,8 +248,8 @@ describeTracing('TracingChannel', function () { 'recovering error handler itself did not throw, so it should not emit error') const errorHandlerStart = errorHandlerEvents.find(byPhase('start')) - assert.equal(errorHandlerStart.ctx.handled, true, - 'error handler ctx is marked handled so APMs can dedup against the origin error') + assert.equal(errorHandlerStart.ctx.errorHandler, true, + 'error handler ctx is flagged errorHandler so APMs can dedup against the origin error') const errorEvents = events.filter(byPhase('error')) assert.equal(errorEvents.length, 1, @@ -608,13 +608,13 @@ describeTracing('TracingChannel', function () { const routeError = errorEvents.find(byLayer('throwingHandler')) assert.ok(routeError, 'route layer should emit error') - assert.ok(!routeError.ctx.handled, - 'route layer is not an error handler, so handled flag must be absent') + assert.ok(!routeError.ctx.errorHandler, + 'route layer is not an error handler, so errorHandler flag must be absent') const handlerError = errorEvents.find(byLayer('throwingErrorHandler')) assert.ok(handlerError, 'error handler should emit its own error') - assert.equal(handlerError.ctx.handled, true, - 'error handler\'s own error event must carry handled:true so APMs can classify the span correctly') + assert.equal(handlerError.ctx.errorHandler, true, + 'error handler\'s own error event must carry errorHandler:true so APMs can classify the span correctly') done() }) @@ -643,13 +643,13 @@ describeTracing('TracingChannel', function () { const routeError = errorEvents.find(byLayer('rejectingHandler')) assert.ok(routeError, 'route layer should emit error') - assert.ok(!routeError.ctx.handled, - 'route layer is not an error handler, so handled flag must be absent') + assert.ok(!routeError.ctx.errorHandler, + 'route layer is not an error handler, so errorHandler flag must be absent') const handlerError = errorEvents.find(byLayer('throwingErrorHandler')) assert.ok(handlerError, 'error handler should emit its own error') - assert.equal(handlerError.ctx.handled, true, - 'error handler\'s own error event must carry handled:true so APMs can classify the span correctly') + assert.equal(handlerError.ctx.errorHandler, true, + 'error handler\'s own error event must carry errorHandler:true so APMs can classify the span correctly') done() }) From d0d8f7efbe4d3a1bcd7a931df8b6db77486c77e2 Mon Sep 17 00:00:00 2001 From: Abdelrahman Awad Date: Wed, 15 Jul 2026 16:55:05 -0400 Subject: [PATCH 24/24] perf: publish lifecycle via start.runStores instead of tracePromise tracePromise coerces every call into a resolved promise, so it emits an async phase (and pays for it) even for synchronous layers. Publish start via start.runStores and the remaining events manually, roughly halving per-layer tracing overhead for synchronous middleware. Observable change: a synchronous layer now emits only start/end, not asyncStart/asyncEnd. Consumers should treat end as the terminal event for a sync layer and asyncEnd for an async one, rather than assuming an async phase always fires. Routing, error dedup, signal filtering, error normalization, and async context propagation are unchanged. --- lib/layer.js | 31 ++++++++++++++++++++++--------- test/tracing.js | 38 ++++++++++++++++++++++++++++++-------- 2 files changed, 52 insertions(+), 17 deletions(-) diff --git a/lib/layer.js b/lib/layer.js index b07c022f..929fca80 100644 --- a/lib/layer.js +++ b/lib/layer.js @@ -241,10 +241,10 @@ function invokeWithTrace (exec, ctx, next) { next(err) } - // All outcomes flow through wrappedNext (never tracePromise's own error - // publishing), so signal filtering and dedup happen in one place and tracing - // never changes how the router routes. - requestChannel.tracePromise(function () { + // runStores fires `start` and sets the async context; the rest are published + // manually, so a synchronous layer emits only start/end. All outcomes flow + // through wrappedNext to keep signal filtering and dedup in one place. + requestChannel.start.runStores(ctx, function () { let out try { out = handlePromise(exec(wrappedNext)) @@ -252,17 +252,30 @@ function invokeWithTrace (exec, ctx, next) { // A sync throw is forwarded verbatim, so a falsy value keeps routing // exactly as the untraced path does. wrappedNext(err) + requestChannel.end.publish(ctx) return } - if (out) { - return out.then(undefined, function (err) { + if (!out) { + requestChannel.end.publish(ctx) + return + } + + requestChannel.end.publish(ctx) + out.then( + function () { + requestChannel.asyncStart.publish(ctx) + requestChannel.asyncEnd.publish(ctx) + }, + function (err) { // A rejected promise is an error even when the reason is falsy; // normalize it to the error the router forwards to next(). wrappedNext(err || new Error('Rejected promise')) - }) - } - }, ctx) + requestChannel.asyncStart.publish(ctx) + requestChannel.asyncEnd.publish(ctx) + } + ) + }) } /** diff --git a/test/tracing.js b/test/tracing.js index 15b7fa3f..50d31a1c 100644 --- a/test/tracing.js +++ b/test/tracing.js @@ -867,10 +867,10 @@ describeTracing('TracingChannel', function () { }) describe('event ordering', function () { - it('should emit start before asyncEnd', function (done) { + it('should emit only start and end for a synchronous handler', function (done) { const { router, server } = traced() - router.get('/order', function (req, res) { + router.get('/order', function syncHandler (req, res) { res.statusCode = 200 res.end('ok') }) @@ -880,13 +880,35 @@ describeTracing('TracingChannel', function () { .expect(200, function (err) { if (err) return done(err) - const phases = events.map(function (e) { return e.phase }) - const firstStart = phases.indexOf('start') - const lastAsyncEnd = phases.lastIndexOf('asyncEnd') + const phases = events.filter(byLayer('syncHandler')).map(function (e) { return e.phase }) + assert.equal(phases.length, 2, 'a synchronous handler has no async phase') + assert.equal(phases[0], 'start') + assert.equal(phases[1], 'end') + assert.ok(phases.indexOf('asyncStart') < 0 && phases.indexOf('asyncEnd') < 0, + 'a synchronous handler should not emit asyncStart/asyncEnd') - assert.ok(firstStart >= 0, 'should have start') - assert.ok(lastAsyncEnd >= 0, 'should have asyncEnd') - assert.ok(firstStart < lastAsyncEnd, 'start should come before asyncEnd') + done() + }) + }) + + it('should emit start before asyncEnd for an asynchronous handler', function (done) { + const { router, server } = traced() + + router.get('/order', async function asyncHandler (req, res) { + res.statusCode = 200 + res.end('ok') + }) + + request(server) + .get('/order') + .expect(200, function (err) { + if (err) return done(err) + + const phases = events.filter(byLayer('asyncHandler')).map(function (e) { return e.phase }) + assert.ok(phases.indexOf('start') >= 0, 'should have start') + assert.ok(phases.indexOf('asyncEnd') >= 0, 'should have asyncEnd') + assert.ok(phases.indexOf('start') < phases.indexOf('asyncEnd'), + 'start should come before asyncEnd') done() })