From 0fd652468003fcf00cadd04ff5bf7ee7fc07af84 Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Thu, 20 Jun 2019 07:13:26 +0800 Subject: [PATCH] process: split routines used to enhance fatal exception stack traces Previously the enhancement were done right after emitting `'uncaughtException'`, which meant by the time we knew the exception was fatal in C++, the error.stack had already been patched. This patch moves those routines to be called later during the fatal exception handling, and split them into two stages: before and after the inspector is notified by the invocation of `V8Inspector::exceptionThrown`. We now expand the stack to include additional informations about unhandled 'error' events before the inspector is notified, but delay the highlighting of the frames until after the inspector is notified, so that the ANSI escape sequences won't show up in the inspector console. PR-URL: https://github.com/nodejs/node/pull/28308 Fixes: https://github.com/nodejs/node/issues/28287 Reviewed-By: Benjamin Gruenbaum --- lib/events.js | 13 ++-- lib/internal/bootstrap/node.js | 17 ++++- lib/internal/errors.js | 41 ++++++++++ lib/internal/process/execution.js | 12 --- lib/internal/util.js | 1 - lib/internal/util/inspect.js | 3 +- src/env.h | 2 + src/inspector_agent.cc | 7 +- src/inspector_agent.h | 4 +- src/node_errors.cc | 121 +++++++++++++++++++++++------- 10 files changed, 166 insertions(+), 55 deletions(-) diff --git a/lib/events.js b/lib/events.js index 438c8f8306246a..6f279a0bff603c 100644 --- a/lib/events.js +++ b/lib/events.js @@ -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 @@ -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) { @@ -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 }); diff --git a/lib/internal/bootstrap/node.js b/lib/internal/bootstrap/node.js index 22dabf4d7ed459..e8735c2049cc36 100644 --- a/lib/internal/bootstrap/node.js +++ b/lib/internal/bootstrap/node.js @@ -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() { diff --git a/lib/internal/errors.js b/lib/internal/errors.js index 20a7ae1e155072..56cb13f1cbeafc 100644 --- a/lib/internal/errors.js +++ b/lib/internal/errors.js @@ -617,6 +617,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](); + } 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; + try { + return inspect(error, { colors }); + } catch { + return originalStack; + } + } +}; + module.exports = { addCodeToName, // Exported for NghttpError codes, @@ -633,6 +672,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 diff --git a/lib/internal/process/execution.js b/lib/internal/process/execution.js index b9904f66b3621b..b8c4e673b2c8ca 100644 --- a/lib/internal/process/execution.js +++ b/lib/internal/process/execution.js @@ -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; @@ -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; } diff --git a/lib/internal/util.js b/lib/internal/util.js index 931bcea5b4fbfb..67d4130ddd3053 100644 --- a/lib/internal/util.js +++ b/lib/internal/util.js @@ -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') }; diff --git a/lib/internal/util/inspect.js b/lib/internal/util/inspect.js index c85c524047168f..20bdc33786054f 100644 --- a/lib/internal/util/inspect.js +++ b/lib/internal/util/inspect.js @@ -1658,5 +1658,6 @@ function formatWithOptions(inspectOptions, ...args) { module.exports = { inspect, format, - formatWithOptions + formatWithOptions, + inspectDefaultOptions }; diff --git a/src/env.h b/src/env.h index 59ad030f30ff9b..3d955297920a98 100644 --- a/src/env.h +++ b/src/env.h @@ -386,6 +386,8 @@ constexpr size_t kFsStatsBufferLength = kFsStatsFieldsNumber * 2; 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) \ diff --git a/src/inspector_agent.cc b/src/inspector_agent.cc index 2e51648196672f..ceba6a59a83e4d 100644 --- a/src/inspector_agent.cc +++ b/src/inspector_agent.cc @@ -570,7 +570,7 @@ class NodeInspectorClient : public V8InspectorClient { } } - void FatalException(Local error, Local message) { + void ReportUncaughtException(Local error, Local message) { Isolate* isolate = env_->isolate(); Local context = env_->context(); @@ -836,10 +836,11 @@ void Agent::WaitForDisconnect() { } } -void Agent::FatalException(Local error, Local message) { +void Agent::ReportUncaughtException(Local error, + Local message) { if (!IsListening()) return; - client_->FatalException(error, message); + client_->ReportUncaughtException(error, message); WaitForDisconnect(); } diff --git a/src/inspector_agent.h b/src/inspector_agent.h index 1c2bde0da73e84..5447a68485c228 100644 --- a/src/inspector_agent.h +++ b/src/inspector_agent.h @@ -65,8 +65,8 @@ class Agent { void WaitForConnect(); // Blocks till all the sessions with "WaitForDisconnectOnShutdown" disconnect void WaitForDisconnect(); - void FatalException(v8::Local error, - v8::Local message); + void ReportUncaughtException(v8::Local error, + v8::Local message); // Async stack traces instrumentation. void AsyncTaskScheduled(const v8_inspector::StringView& taskName, void* task, diff --git a/src/node_errors.cc b/src/node_errors.cc index f89b1472101c70..298d84b4f362b3 100644 --- a/src/node_errors.cc +++ b/src/node_errors.cc @@ -264,38 +264,82 @@ void AppendExceptionLine(Environment* env, Abort(); } -void ReportException(Environment* env, - Local er, - Local message) { - CHECK(!er.IsEmpty()); - HandleScope scope(env->isolate()); +enum class EnhanceFatalException { kEnhance, kDontEnhance }; + +/** + * Report the exception to the inspector, then print it to stderr. + * This should only be used when the Node.js instance is about to exit + * (i.e. this should be followed by a env->Exit() or an Abort()). + * + * Use enhance_stack = EnhanceFatalException::kDontEnhance + * when it's unsafe to call into JavaScript. + */ +static void ReportFatalException(Environment* env, + Local error, + Local message, + EnhanceFatalException enhance_stack) { + Isolate* isolate = env->isolate(); + CHECK(!error.IsEmpty()); + CHECK(!message.IsEmpty()); + HandleScope scope(isolate); - if (message.IsEmpty()) message = Exception::CreateMessage(env->isolate(), er); + AppendExceptionLine(env, error, message, FATAL_ERROR); - AppendExceptionLine(env, er, message, FATAL_ERROR); + auto report_to_inspector = [&]() { +#if HAVE_INSPECTOR + env->inspector_agent()->ReportUncaughtException(error, message); +#endif + }; - Local trace_value; Local arrow; - const bool decorated = IsExceptionDecorated(env, er); - - if (er->IsUndefined() || er->IsNull()) { - trace_value = Undefined(env->isolate()); + Local stack_trace; + bool decorated = IsExceptionDecorated(env, error); + + if (!error->IsObject()) { // We can only enhance actual errors. + report_to_inspector(); + stack_trace = Undefined(isolate); + // If error is not an object, AppendExceptionLine() has already print the + // source line and the arrow to stderr. + // TODO(joyeecheung): move that side effect out of AppendExceptionLine(). + // It is done just to preserve the source line as soon as possible. } else { - Local err_obj = er->ToObject(env->context()).ToLocalChecked(); + Local err_obj = error.As(); + + auto enhance_with = [&](Local enhancer) { + Local enhanced; + Local argv[] = {err_obj}; + if (!enhancer.IsEmpty() && + enhancer + ->Call(env->context(), Undefined(isolate), arraysize(argv), argv) + .ToLocal(&enhanced)) { + stack_trace = enhanced; + } + }; - if (!err_obj->Get(env->context(), env->stack_string()) - .ToLocal(&trace_value)) { - trace_value = Undefined(env->isolate()); + switch (enhance_stack) { + case EnhanceFatalException::kEnhance: { + enhance_with(env->enhance_fatal_stack_before_inspector()); + report_to_inspector(); + enhance_with(env->enhance_fatal_stack_after_inspector()); + break; + } + case EnhanceFatalException::kDontEnhance: { + report_to_inspector(); + break; + } + default: + UNREACHABLE(); } + arrow = err_obj->GetPrivate(env->context(), env->arrow_message_private_symbol()) .ToLocalChecked(); } - node::Utf8Value trace(env->isolate(), trace_value); + node::Utf8Value trace(env->isolate(), stack_trace); // range errors have a trace member set to undefined - if (trace.length() > 0 && !trace_value->IsUndefined()) { + if (trace.length() > 0 && !stack_trace->IsUndefined()) { if (arrow.IsEmpty() || !arrow->IsString() || decorated) { PrintErrorString("%s\n", *trace); } else { @@ -309,8 +353,8 @@ void ReportException(Environment* env, MaybeLocal message; MaybeLocal name; - if (er->IsObject()) { - Local err_obj = er.As(); + if (error->IsObject()) { + Local err_obj = error.As(); message = err_obj->Get(env->context(), env->message_string()); name = err_obj->Get(env->context(), env->name_string()); } @@ -318,7 +362,7 @@ void ReportException(Environment* env, if (message.IsEmpty() || message.ToLocalChecked()->IsUndefined() || name.IsEmpty() || name.ToLocalChecked()->IsUndefined()) { // Not an error object. Just print as-is. - String::Utf8Value message(env->isolate(), er); + String::Utf8Value message(env->isolate(), error); PrintErrorString("%s\n", *message ? *message : ""); @@ -337,10 +381,6 @@ void ReportException(Environment* env, } fflush(stderr); - -#if HAVE_INSPECTOR - env->inspector_agent()->FatalException(er, message); -#endif } void PrintErrorString(const char* format, ...) { @@ -406,7 +446,12 @@ namespace errors { TryCatchScope::~TryCatchScope() { if (HasCaught() && !HasTerminated() && mode_ == CatchMode::kFatal) { HandleScope scope(env_->isolate()); - ReportException(env_, Exception(), Message()); + Local exception = Exception(); + Local message = Message(); + if (message.IsEmpty()) + message = Exception::CreateMessage(env_->isolate(), exception); + ReportFatalException( + env_, exception, message, EnhanceFatalException::kDontEnhance); env_->Exit(7); } } @@ -771,6 +816,15 @@ void SetPrepareStackTraceCallback(const FunctionCallbackInfo& args) { env->set_prepare_stack_trace_callback(args[0].As()); } +static void SetEnhanceStackForFatalException( + const FunctionCallbackInfo& args) { + Environment* env = Environment::GetCurrent(args); + CHECK(args[0]->IsFunction()); + CHECK(args[1]->IsFunction()); + env->set_enhance_fatal_stack_before_inspector(args[0].As()); + env->set_enhance_fatal_stack_after_inspector(args[1].As()); +} + // Side effect-free stringification that will never throw exceptions. static void NoSideEffectsToString(const FunctionCallbackInfo& args) { Local context = args.GetIsolate()->GetCurrentContext(); @@ -785,7 +839,8 @@ static void TriggerUncaughtException(const FunctionCallbackInfo& args) { Local exception = args[0]; Local message = Exception::CreateMessage(isolate, exception); if (env != nullptr && env->abort_on_uncaught_exception()) { - ReportException(env, exception, message); + ReportFatalException( + env, exception, message, EnhanceFatalException::kEnhance); Abort(); } bool from_promise = args[1]->IsTrue(); @@ -799,6 +854,9 @@ void Initialize(Local target, Environment* env = Environment::GetCurrent(context); env->SetMethod( target, "setPrepareStackTraceCallback", SetPrepareStackTraceCallback); + env->SetMethod(target, + "setEnhanceStackForFatalException", + SetEnhanceStackForFatalException); env->SetMethodNoSideEffect( target, "noSideEffectsToString", NoSideEffectsToString); env->SetMethod(target, "triggerUncaughtException", TriggerUncaughtException); @@ -847,6 +905,8 @@ void TriggerUncaughtException(Isolate* isolate, CHECK(!error.IsEmpty()); HandleScope scope(isolate); + if (message.IsEmpty()) message = Exception::CreateMessage(isolate, error); + CHECK(isolate->InContext()); Local context = isolate->GetCurrentContext(); Environment* env = Environment::GetCurrent(context); @@ -873,7 +933,8 @@ void TriggerUncaughtException(Isolate* isolate, // during bootstrap, or if the user has patched it incorrectly, exit // the current Node.js instance. if (!fatal_exception_function->IsFunction()) { - ReportException(env, error, message); + ReportFatalException( + env, error, message, EnhanceFatalException::kDontEnhance); env->Exit(6); return; } @@ -914,7 +975,9 @@ void TriggerUncaughtException(Isolate* isolate, return; } - ReportException(env, error, message); + // Now we are certain that the exception is fatal. + ReportFatalException(env, error, message, EnhanceFatalException::kEnhance); + // If the global uncaught exception handler sets process.exitCode, // exit with that code. Otherwise, exit with 1. Local exit_code = env->exit_code_string();