Skip to content

Commit

Permalink
events: show throw stack trace for uncaught exception
Browse files Browse the repository at this point in the history
Show the stack trace for the `eventemitter.emit('error')` call
in the case of an uncaught exception.

Previously, there would be no clue in Node’s output about where
the actual `throw` comes from.

PR-URL: #19003
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
  • Loading branch information
addaleax committed Mar 5, 2018
1 parent db8d197 commit 5b8c97f
Show file tree
Hide file tree
Showing 10 changed files with 169 additions and 2 deletions.
55 changes: 54 additions & 1 deletion lib/events.js
Original file line number Diff line number Diff line change
Expand Up @@ -94,6 +94,47 @@ EventEmitter.prototype.getMaxListeners = function getMaxListeners() {
return $getMaxListeners(this);
};

// Returns the longest sequence of `a` that fully appears in `b`,
// of length at least 3.
// This is a lazy approach but should work well enough, given that stack
// frames are usually unequal or otherwise appear in groups, and that
// we only run this code in case of an unhandled exception.
function longestSeqContainedIn(a, b) {
for (var len = a.length; len >= 3; --len) {
for (var i = 0; i < a.length - len; ++i) {
// Attempt to find a[i:i+len] in b
for (var j = 0; j < b.length - len; ++j) {
let matches = true;
for (var k = 0; k < len; ++k) {
if (a[i + k] !== b[j + k]) {
matches = false;
break;
}
}
if (matches)
return [ len, i, j ];
}
}
}

return [ 0, 0, 0 ];
}

function enhanceStackTrace(err, own) {
const sep = '\nEmitted \'error\' event at:\n';

const errStack = err.stack.split('\n').slice(1);
const ownStack = own.stack.split('\n').slice(1);

const [ len, off ] = longestSeqContainedIn(ownStack, errStack);
if (len > 0) {
ownStack.splice(off + 1, len - 1,
' [... lines matching original stack trace ...]');
}
// Do this last, because it is the only operation with side effects.
err.stack = err.stack + sep + ownStack.join('\n');
}

EventEmitter.prototype.emit = function emit(type, ...args) {
let doError = (type === 'error');

Expand All @@ -109,13 +150,25 @@ EventEmitter.prototype.emit = function emit(type, ...args) {
if (args.length > 0)
er = args[0];
if (er instanceof Error) {
try {
const { kExpandStackSymbol } = require('internal/util');
const capture = {};
Error.captureStackTrace(capture, EventEmitter.prototype.emit);
Object.defineProperty(er, kExpandStackSymbol, {
value: enhanceStackTrace.bind(null, er, capture),
configurable: true
});
} catch (e) {}

// Note: The comments on the `throw` lines are intentional, they show
// up in Node's output if this results in an unhandled exception.
throw er; // Unhandled 'error' event
}
// At least give some kind of context to the user
const errors = lazyErrors();
const err = new errors.Error('ERR_UNHANDLED_ERROR', er);
err.context = er;
throw err;
throw err; // Unhandled 'error' event
}

const handler = events[type];
Expand Down
5 changes: 5 additions & 0 deletions lib/internal/bootstrap_node.js
Original file line number Diff line number Diff line change
Expand Up @@ -438,6 +438,11 @@
} catch (er) {
// nothing to be done about it at this point.
}
try {
const { kExpandStackSymbol } = NativeModule.require('internal/util');
if (typeof er[kExpandStackSymbol] === 'function')
er[kExpandStackSymbol]();
} catch (er) {}
return false;
}

Expand Down
3 changes: 2 additions & 1 deletion lib/internal/util.js
Original file line number Diff line number Diff line change
Expand Up @@ -320,5 +320,6 @@ module.exports = {

// Used by the buffer module to capture an internal reference to the
// default isEncoding implementation, just in case userland overrides it.
kIsEncodingSymbol: Symbol('node.isEncoding')
kIsEncodingSymbol: Symbol('kIsEncodingSymbol'),
kExpandStackSymbol: Symbol('kExpandStackSymbol')
};
20 changes: 20 additions & 0 deletions test/message/events_unhandled_error_common_trace.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
'use strict';
require('../common');
const EventEmitter = require('events');

function foo() {
function bar() {
return new Error('foo:bar');
}

return bar();
}

const ee = new EventEmitter();
const err = foo();

function quux() {
ee.emit('error', err);
}

quux();
22 changes: 22 additions & 0 deletions test/message/events_unhandled_error_common_trace.out
Original file line number Diff line number Diff line change
@@ -0,0 +1,22 @@
events.js:*
throw er; // Unhandled 'error' event
^

Error: foo:bar
at bar (*events_unhandled_error_common_trace.js:*:*)
at foo (*events_unhandled_error_common_trace.js:*:*)
at Object.<anonymous> (*events_unhandled_error_common_trace.js:*:*)
at Module._compile (module.js:*:*)
at Object.Module._extensions..js (module.js:*:*)
at Module.load (module.js:*:*)
at tryModuleLoad (module.js:*:*)
at Function.Module._load (module.js:*:*)
at Function.Module.runMain (module.js:*:*)
at startup (bootstrap_node.js:*:*)
Emitted 'error' event at:
at quux (*events_unhandled_error_common_trace.js:*:*)
at Object.<anonymous> (*events_unhandled_error_common_trace.js:*:*)
at Module._compile (module.js:*:*)
[... lines matching original stack trace ...]
at startup (bootstrap_node.js:*:*)
at bootstrap_node.js:*:*
7 changes: 7 additions & 0 deletions test/message/events_unhandled_error_nexttick.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,7 @@
'use strict';
require('../common');
const EventEmitter = require('events');
const er = new Error();
process.nextTick(() => {
new EventEmitter().emit('error', er);
});
20 changes: 20 additions & 0 deletions test/message/events_unhandled_error_nexttick.out
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
events.js:*
throw er; // Unhandled 'error' event
^

Error
at Object.<anonymous> (*events_unhandled_error_nexttick.js:*:*)
at Module._compile (module.js:*:*)
at Object.Module._extensions..js (module.js:*:*)
at Module.load (module.js:*:*)
at tryModuleLoad (module.js:*:*)
at Function.Module._load (module.js:*:*)
at Function.Module.runMain (module.js:*:*)
at startup (bootstrap_node.js:*:*)
at bootstrap_node.js:*:*
Emitted 'error' event at:
at process.nextTick (*events_unhandled_error_nexttick.js:*:*)
at process._tickCallback (internal/process/next_tick.js:*:*)
at Function.Module.runMain (module.js:*:*)
at startup (bootstrap_node.js:*:*)
at bootstrap_node.js:*:*
4 changes: 4 additions & 0 deletions test/message/events_unhandled_error_sameline.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
'use strict';
require('../common');
const EventEmitter = require('events');
new EventEmitter().emit('error', new Error());
19 changes: 19 additions & 0 deletions test/message/events_unhandled_error_sameline.out
Original file line number Diff line number Diff line change
@@ -0,0 +1,19 @@
events.js:*
throw er; // Unhandled 'error' event
^

Error
at Object.<anonymous> (*events_unhandled_error_sameline.js:*:*)
at Module._compile (module.js:*:*)
at Object.Module._extensions..js (module.js:*:*)
at Module.load (module.js:*:*)
at tryModuleLoad (module.js:*:*)
at Function.Module._load (module.js:*:*)
at Function.Module.runMain (module.js:*:*)
at startup (bootstrap_node.js:*:*)
at bootstrap_node.js:*:*
Emitted 'error' event at:
at Object.<anonymous> (*events_unhandled_error_sameline.js:*:*)
at Module._compile (module.js:*:*)
[... lines matching original stack trace ...]
at bootstrap_node.js:*:*
16 changes: 16 additions & 0 deletions test/parallel/test-events-uncaught-exception-stack.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,16 @@
'use strict';
const common = require('../common');
const assert = require('assert');
const EventEmitter = require('events');

// Tests that the error stack where the exception was thrown is *not* appended.

process.on('uncaughtException', common.mustCall((err) => {
const lines = err.stack.split('\n');
assert.strictEqual(lines[0], 'Error');
lines.slice(1).forEach((line) => {
assert(/^ at/.test(line), `${line} has an unexpected format`);
});
}));

new EventEmitter().emit('error', new Error());

0 comments on commit 5b8c97f

Please sign in to comment.