Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

process: split routines used to enhance fatal exception stack traces #28308

Closed
wants to merge 1 commit into from
Closed

process: split routines used to enhance fatal exception stack traces #28308

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 8 additions & 5 deletions lib/events.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,11 +25,15 @@ const { Math, Object, Reflect } = primordials;

var spliceOne;

const {
kEnhanceStackBeforeInspector,
codes
} = require('internal/errors');
const {
ERR_INVALID_ARG_TYPE,
ERR_OUT_OF_RANGE,
ERR_UNHANDLED_ERROR
} = require('internal/errors').codes;
} = codes;

const {
inspect
Expand Down Expand Up @@ -142,8 +146,8 @@ function enhanceStackTrace(err, own) {
ownStack.splice(off + 1, len - 2,
' [... 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');

return err.stack + sep + ownStack.join('\n');
}

EventEmitter.prototype.emit = function emit(type, ...args) {
Expand All @@ -162,11 +166,10 @@ EventEmitter.prototype.emit = function emit(type, ...args) {
er = args[0];
if (er instanceof Error) {
try {
const { kExpandStackSymbol } = require('internal/util');
const capture = {};
// eslint-disable-next-line no-restricted-syntax
Error.captureStackTrace(capture, EventEmitter.prototype.emit);
Object.defineProperty(er, kExpandStackSymbol, {
Object.defineProperty(er, kEnhanceStackBeforeInspector, {
value: enhanceStackTrace.bind(null, er, capture),
configurable: true
});
Expand Down
17 changes: 15 additions & 2 deletions lib/internal/bootstrap/node.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -299,9 +299,22 @@ process.emitWarning = emitWarning;
}

function setupPrepareStackTrace() {
const { setPrepareStackTraceCallback } = internalBinding('errors');
const { prepareStackTrace } = require('internal/errors');
const {
setEnhanceStackForFatalException,
setPrepareStackTraceCallback
} = internalBinding('errors');
const {
prepareStackTrace,
fatalExceptionStackEnhancers: {
beforeInspector,
afterInspector
}
} = require('internal/errors');
// Tell our PrepareStackTraceCallback passed to the V8 API
// to call prepareStackTrace().
setPrepareStackTraceCallback(prepareStackTrace);
// Set the function used to enhance the error stack for printing
setEnhanceStackForFatalException(beforeInspector, afterInspector);
}

function setupProcessObject() {
Expand Down
41 changes: 41 additions & 0 deletions lib/internal/errors.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -622,6 +622,45 @@ function addNumericalSeparator(val) {
return `${val.slice(0, i)}${res}`;
}

// Used to enhance the stack that will be picked up by the inspector
const kEnhanceStackBeforeInspector = Symbol('kEnhanceStackBeforeInspector');

// These are supposed to be called only on fatal exceptions before
// the process exits.
const fatalExceptionStackEnhancers = {
beforeInspector(error) {
if (typeof error[kEnhanceStackBeforeInspector] !== 'function') {
return error.stack;
}

try {
// Set the error.stack here so it gets picked up by the
// inspector.
error.stack = error[kEnhanceStackBeforeInspector]();
Copy link
Member Author

@joyeecheung joyeecheung Jun 19, 2019 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ideally we probably should not even have to do this, instead we can just return a string to some API and leave the error.stack intact, because patching error.stack (which is just a randomly formatted string) over and over is error-prone, especially in the presence of Error.prepareStackTrace...but there does not seem to be a hook to customize the stack trace in the console message logged by the inspector.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah and error.stack might not be writeable, (should be fine in this case)

} catch {
// We are just enhancing the error. If it fails, ignore it.
}
return error.stack;
},
afterInspector(error) {
const originalStack = error.stack;
const {
inspect,
inspectDefaultOptions: {
colors: defaultColors
}
} = lazyInternalUtilInspect();
const colors = internalBinding('util').guessHandleType(2) === 'TTY' &&
require('internal/tty').hasColors() ||
defaultColors;
Copy link
Member Author

@joyeecheung joyeecheung Jun 26, 2019 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

On the windows issue: we could temporarily disable the coloring by adding process.plaform === 'win32' to the conditions here, though I would prefer an alternative fix with changing the implementation of PrintErrorString() to use uv_write for TTY instead. I have a WIP in https://github.com/joyeecheung/node/tree/print-uv-write which still fails a few tests that I need to investigate. Either way that's kind of orthognal to this PR as this only tries to fix #28287

try {
return inspect(error, { colors });
} catch {
return originalStack;
Copy link
Member Author

@joyeecheung joyeecheung Jun 19, 2019 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note that here we don't patch error.stack at all - patching error.stack is only one of the many ways to pass some metadata around along with the error. The cleanest way, however, is to just wrap those metadata in something else instead of polluting error itself over and over, which is also what V8 does in its embedder API (the source of truth of the stack trace is message->GetStackTrace(), not error->Get(context, stack_string), and there are many other structured metadata in Message)

Ideally we could also just pass structured data (e.g. error.code, error.requireStack) back to the caller and it knows how to format and print those out without relying on error.stack at all

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can't we do this in a WeakMap? Their point is extending things from the outside after all

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think we need a WeakMap for this, as this is kind of a one-off thing so there is no mapping necessary. We only need to pass a separate object around, the association between the error and the object can already be known from how they are passed around, and we probably don't need an equivalent of Exception::CreateMessage.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

(Also now that you mentioned it...I believe V8 still does not have embedder API to interface with WeakMaps? That's why we still have to create our ESM module wrap map in JS land)

}
}
};

module.exports = {
addCodeToName, // Exported for NghttpError
codes,
Expand All @@ -638,6 +677,8 @@ module.exports = {
// This is exported only to facilitate testing.
E,
prepareStackTrace,
kEnhanceStackBeforeInspector,
fatalExceptionStackEnhancers
};

// To declare an error message, use the E(sym, val, def) function above. The sym
Expand Down
12 changes: 0 additions & 12 deletions lib/internal/process/execution.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -150,10 +150,6 @@ function createOnGlobalUncaughtException() {
} else if (!process.emit('uncaughtException', er, type)) {
// If someone handled it, then great. Otherwise, die in C++ land
// since that means that we'll exit the process, emit the 'exit' event.
const { inspect } = require('internal/util/inspect');
const colors = internalBinding('util').guessHandleType(2) === 'TTY' &&
require('internal/tty').hasColors() ||
inspect.defaultOptions.colors;
try {
if (!process._exiting) {
process._exiting = true;
Expand All @@ -163,14 +159,6 @@ function createOnGlobalUncaughtException() {
} catch {
// Nothing to be done about it at this point.
}
try {
const { kExpandStackSymbol } = require('internal/util');
if (typeof er[kExpandStackSymbol] === 'function')
er[kExpandStackSymbol]();
er.stack = inspect(er, { colors });
} catch {
// Nothing to be done about it at this point.
}
return false;
}

Expand Down
1 change: 0 additions & 1 deletion lib/internal/util.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -414,6 +414,5 @@ 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('kIsEncodingSymbol'),
kExpandStackSymbol: Symbol('kExpandStackSymbol'),
kVmBreakFirstLineSymbol: Symbol('kVmBreakFirstLineSymbol')
};
3 changes: 2 additions & 1 deletion lib/internal/util/inspect.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1688,5 +1688,6 @@ function formatWithOptions(inspectOptions, ...args) {
module.exports = {
inspect,
format,
formatWithOptions
formatWithOptions,
inspectDefaultOptions
};
2 changes: 2 additions & 0 deletions src/env.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -408,6 +408,8 @@ constexpr size_t kFsStatsBufferLength =
V(crypto_key_object_constructor, v8::Function) \
V(domain_callback, v8::Function) \
V(domexception_function, v8::Function) \
V(enhance_fatal_stack_after_inspector, v8::Function) \
V(enhance_fatal_stack_before_inspector, v8::Function) \
V(fs_use_promises_symbol, v8::Symbol) \
V(host_import_module_dynamically_callback, v8::Function) \
V(host_initialize_import_meta_object_callback, v8::Function) \
Expand Down
7 changes: 4 additions & 3 deletions src/inspector_agent.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -570,7 +570,7 @@ class NodeInspectorClient : public V8InspectorClient {
}
}

void FatalException(Local<Value> error, Local<Message> message) {
void ReportUncaughtException(Local<Value> error, Local<Message> message) {
Isolate* isolate = env_->isolate();
Local<Context> context = env_->context();

Expand Down Expand Up @@ -836,10 +836,11 @@ void Agent::WaitForDisconnect() {
}
}

void Agent::FatalException(Local<Value> error, Local<Message> message) {
void Agent::ReportUncaughtException(Local<Value> error,
Local<Message> message) {
if (!IsListening())
return;
client_->FatalException(error, message);
client_->ReportUncaughtException(error, message);
WaitForDisconnect();
}

Expand Down
4 changes: 2 additions & 2 deletions src/inspector_agent.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -65,8 +65,8 @@ class Agent {
void WaitForConnect();
// Blocks till all the sessions with "WaitForDisconnectOnShutdown" disconnect
void WaitForDisconnect();
void FatalException(v8::Local<v8::Value> error,
v8::Local<v8::Message> message);
void ReportUncaughtException(v8::Local<v8::Value> error,
v8::Local<v8::Message> message);

// Async stack traces instrumentation.
void AsyncTaskScheduled(const v8_inspector::StringView& taskName, void* task,
Expand Down
Loading