src: implement --trace-promises

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 <[email protected]>
Reviewed-By: Geoffrey Booth <[email protected]>
Reviewed-By: Vinícius Lourenço Claro Cardoso <[email protected]>
Reviewed-By: Chengzhong Wu <[email protected]>
Reviewed-By: Benjamin Gruenbaum <[email protected]>

src/env.cc

@@ -30,6 +30,7 @@
 #include <iostream>
 #include <limits>
 #include <memory>
+#include <optional>
 #include <unordered_map>
 
 namespace node {
@@ -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;
@@ -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) {

src/env.h

@@ -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);
@@ -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_;
 

src/env_properties.h

@@ -28,6 +28,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

src/node.cc

@@ -264,6 +264,9 @@ void Environment::InitializeDiagnostics() {
       env->isolate()->SetAtomicsWaitCallback(nullptr, nullptr);
     }, this);
   }
+  if (options_->trace_promises) {
+    isolate_->SetPromiseHook(TracePromises);
+  }
 }
 
 static

src/node_errors.cc

@@ -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,

src/node_internals.h

@@ -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);

src/node_options.cc

@@ -672,6 +672,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,

src/node_options.h

@@ -179,6 +179,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;

test/parallel/test-process-env-allowed-flags-are-documented.js

@@ -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) {