Skip to content

Commit

Permalink
src: implement --trace-promises
Browse files Browse the repository at this point in the history
This patch implements a debugging flag that dumps the current
stack trace when a promise is created or resolved. To reduce
noise we ignore before and after events (as the execution is
less interesting) and use the per-isolate hook to avoid extra
JS frames. This flag can assist work in reducing unnecessary
promise overhead.

PR-URL: #50899
Reviewed-By: Yagiz Nizipli <yagiz.nizipli@sentry.io>
Reviewed-By: Geoffrey Booth <webadmin@geoffreybooth.com>
Reviewed-By: Vinícius Lourenço Claro Cardoso <contact@viniciusl.com.br>
Reviewed-By: Chengzhong Wu <legendecas@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
  • Loading branch information
joyeecheung authored and richardlau committed Mar 25, 2024
1 parent 5c7a9c8 commit c705b73
Show file tree
Hide file tree
Showing 9 changed files with 82 additions and 0 deletions.
58 changes: 58 additions & 0 deletions src/env.cc
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,7 @@
#include <iostream>
#include <limits>
#include <memory>
#include <optional>
#include <unordered_map>

namespace node {
Expand All @@ -55,13 +56,16 @@ using v8::Number;
using v8::Object;
using v8::ObjectTemplate;
using v8::Private;
using v8::Promise;
using v8::PromiseHookType;
using v8::Script;
using v8::SnapshotCreator;
using v8::StackTrace;
using v8::String;
using v8::Symbol;
using v8::TracingController;
using v8::TryCatch;
using v8::Uint32;
using v8::Undefined;
using v8::Value;
using v8::WrapperDescriptor;
Expand Down Expand Up @@ -1839,6 +1843,60 @@ void Environment::BuildEmbedderGraph(Isolate* isolate,
tracker.Track(env);
}

std::optional<uint32_t> GetPromiseId(Environment* env, Local<Promise> promise) {
Local<Value> id_val;
if (!promise->GetPrivate(env->context(), env->promise_trace_id())
.ToLocal(&id_val) ||
!id_val->IsUint32()) {
return std::nullopt;
}
return id_val.As<Uint32>()->Value();
}

void Environment::TracePromises(PromiseHookType type,
Local<Promise> promise,
Local<Value> parent) {
// We don't care about the execution of promises, just the
// creation/resolution.
if (type == PromiseHookType::kBefore || type == PromiseHookType::kAfter) {
return;
}
Isolate* isolate = Isolate::GetCurrent();
Local<Context> context = isolate->GetCurrentContext();
Environment* env = Environment::GetCurrent(context);
if (env == nullptr) return;

std::optional<uint32_t> parent_id;
if (!parent.IsEmpty() && parent->IsPromise()) {
parent_id = GetPromiseId(env, parent.As<Promise>());
}

uint32_t id = 0;
std::string action;
if (type == PromiseHookType::kInit) {
id = env->trace_promise_id_counter_++;
promise->SetPrivate(
context, env->promise_trace_id(), Uint32::New(isolate, id));
action = "created";
} else if (type == PromiseHookType::kResolve) {
auto opt = GetPromiseId(env, promise);
if (!opt.has_value()) return;
id = opt.value();
action = "resolved";
} else {
UNREACHABLE();
}

FPrintF(stderr, "[--trace-promises] ");
if (parent_id.has_value()) {
FPrintF(stderr, "promise #%d ", parent_id.value());
}
FPrintF(stderr, "%s promise #%d\n", action, id);
// TODO(joyeecheung): we can dump the native stack trace too if the
// JS stack trace is empty i.e. it may be resolved on the native side.
PrintCurrentStackTrace(isolate);
}

size_t Environment::NearHeapLimitCallback(void* data,
size_t current_heap_limit,
size_t initial_heap_limit) {
Expand Down
4 changes: 4 additions & 0 deletions src/env.h
Original file line number Diff line number Diff line change
Expand Up @@ -934,6 +934,9 @@ class Environment : public MemoryRetainer {
inline void RemoveCleanupHook(CleanupQueue::Callback cb, void* arg);
void RunCleanup();

static void TracePromises(v8::PromiseHookType type,
v8::Local<v8::Promise> promise,
v8::Local<v8::Value> parent);
static size_t NearHeapLimitCallback(void* data,
size_t current_heap_limit,
size_t initial_heap_limit);
Expand Down Expand Up @@ -1094,6 +1097,7 @@ class Environment : public MemoryRetainer {
uint32_t module_id_counter_ = 0;
uint32_t script_id_counter_ = 0;
uint32_t function_id_counter_ = 0;
uint32_t trace_promise_id_counter_ = 0;

AliasedInt32Array exit_info_;

Expand Down
1 change: 1 addition & 0 deletions src/env_properties.h
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@
V(napi_wrapper, "node:napi:wrapper") \
V(untransferable_object_private_symbol, "node:untransferableObject") \
V(exit_info_private_symbol, "node:exit_info_private_symbol") \
V(promise_trace_id, "node:promise_trace_id") \
V(require_private_symbol, "node:require_private_symbol")

// Symbols are per-isolate primitives but Environment proxies them
Expand Down
3 changes: 3 additions & 0 deletions src/node.cc
Original file line number Diff line number Diff line change
Expand Up @@ -264,6 +264,9 @@ void Environment::InitializeDiagnostics() {
env->isolate()->SetAtomicsWaitCallback(nullptr, nullptr);
}, this);
}
if (options_->trace_promises) {
isolate_->SetPromiseHook(TracePromises);
}
}

static
Expand Down
7 changes: 7 additions & 0 deletions src/node_errors.cc
Original file line number Diff line number Diff line change
Expand Up @@ -291,6 +291,13 @@ void PrintStackTrace(Isolate* isolate,
PrintToStderrAndFlush(FormatStackTrace(isolate, stack, prefix));
}

void PrintCurrentStackTrace(Isolate* isolate, StackTracePrefix prefix) {
Local<StackTrace> stack;
if (GetCurrentStackTrace(isolate).ToLocal(&stack)) {
PrintStackTrace(isolate, stack, prefix);
}
}

std::string FormatCaughtException(Isolate* isolate,
Local<Context> context,
Local<Value> err,
Expand Down
2 changes: 2 additions & 0 deletions src/node_internals.h
Original file line number Diff line number Diff line change
Expand Up @@ -87,6 +87,8 @@ enum class StackTracePrefix {
kAt, // " at "
kNumber
};
void PrintCurrentStackTrace(v8::Isolate* isolate,
StackTracePrefix prefix = StackTracePrefix::kAt);
void PrintStackTrace(v8::Isolate* isolate,
v8::Local<v8::StackTrace> stack,
StackTracePrefix prefix = StackTracePrefix::kAt);
Expand Down
4 changes: 4 additions & 0 deletions src/node_options.cc
Original file line number Diff line number Diff line change
Expand Up @@ -667,6 +667,10 @@ EnvironmentOptionsParser::EnvironmentOptionsParser() {
"show stack traces on process warnings",
&EnvironmentOptions::trace_warnings,
kAllowedInEnvvar);
AddOption("--trace-promises",
"show stack traces on promise initialization and resolution",
&EnvironmentOptions::trace_promises,
kAllowedInEnvvar);
AddOption("--experimental-default-type",
"set module system to use by default",
&EnvironmentOptions::type,
Expand Down
1 change: 1 addition & 0 deletions src/node_options.h
Original file line number Diff line number Diff line change
Expand Up @@ -178,6 +178,7 @@ class EnvironmentOptions : public Options {
bool trace_tls = false;
bool trace_uncaught = false;
bool trace_warnings = false;
bool trace_promises = false;
bool extra_info_on_fatal_exception = true;
std::string unhandled_rejections;
std::vector<std::string> userland_loaders;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -106,6 +106,8 @@ assert(undocumented.delete('--no-node-snapshot'));
assert(undocumented.delete('--loader'));
assert(undocumented.delete('--verify-base-objects'));
assert(undocumented.delete('--no-verify-base-objects'));
assert(undocumented.delete('--trace-promises'));
assert(undocumented.delete('--no-trace-promises'));

// Remove negated versions of the flags.
for (const flag of undocumented) {
Expand Down

0 comments on commit c705b73

Please sign in to comment.