E57D src: implement --trace-promises · nodejs/node@c3abdc5 · GitHub
[go: up one dir, main page]

Skip to content

Commit c3abdc5

Browse files
joyeecheungRafaelGSS
authored andcommitted
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 <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>
1 parent 7a8a2d5 commit c3abdc5

File tree

9 files changed

+82
-0
lines changed
  • test/parallel
  • 9 files changed

    +82
    -0
    lines changed

    src/env.cc

    Lines changed: 58 additions & 0 deletions
    Original file line numberDiff line numberDiff line change
    @@ -30,6 +30,7 @@
    3030
    #include <iostream>
    3131
    #include <limits>
    3232
    #include <memory>
    33+
    #include <optional>
    3334
    #include <unordered_map>
    3435

    3536
    namespace node {
    @@ -55,13 +56,16 @@ using v8::Number;
    5556
    using v8::Object;
    5657
    using v8::ObjectTemplate;
    5758
    using v8::Private;
    59+
    using v8::Promise;
    60+
    using v8::PromiseHookType;
    5861
    using v8::Script;
    5962
    using v8::SnapshotCreator;
    6063
    using v8::StackTrace;
    6164
    using v8::String;
    6265
    using v8::Symbol;
    6366
    using v8::TracingController;
    6467
    using v8::TryCatch;
    68+
    using v8::Uint32;
    6569
    using v8::Undefined;
    6670
    using v8::Value;
    6771
    using v8::WrapperDescriptor;
    @@ -1839,6 +1843,60 @@ void Environment::BuildEmbedderGraph(Isolate* isolate,
    18391843
    tracker.Track(env);
    18401844
    }
    18411845

    1846+
    std::optional<uint32_t> GetPromiseId(Environment* env, Local<Promise> promise) {
    1847+
    Local<Value> id_val;
    1848+
    if (!promise->GetPrivate(env->context(), env->promise_trace_id())
    1849+
    .ToLocal(&id_val) ||
    1850+
    !id_val->IsUint32()) {
    1851+
    return std::nullopt;
    1852+
    }
    1853+
    return id_val.As<Uint32>()->Value();
    1854+
    }
    1855+
    1856+
    void Environment::TracePromises(PromiseHookType type,
    1857+
    Local<Promise> promise,
    1858+
    Local<Value> parent) {
    1859+
    // We don't care about the execution of promises, just the
    1860+
    // creation/resolution.
    1861+
    if (type == PromiseHookType::kBefore || type == PromiseHookType::kAfter) {
    1862+
    return;
    1863+
    }
    1864+
    Isolate* isolate = Isolate::GetCurrent();
    1865+
    Local<Context> context = isolate->GetCurrentContext();
    1866+
    Environment* env = Environment::GetCurrent(context);
    1867+
    if (env == nullptr) return;
    1868+
    1869+
    std::optional<uint32_t> parent_id;
    1870+
    if (!parent.IsEmpty() && parent->IsPromise()) {
    1871+
    parent_id = GetPromiseId(env, parent.As<Promise>());
    1872+
    }
    1873+
    1874+
    uint32_t id = 0;
    1875+
    std::string action;
    1876+
    if (type == PromiseHookType::kInit) {
    1877+
    id = env->trace_promise_id_counter_++;
    1878+
    promise->SetPrivate(
    1879+
    context, env->promise_trace_id(), Uint32::New(isolate, id));
    1880+
    action = "created";
    1881+
    } else if (type == PromiseHookType::kResolve) {
    1882+
    auto opt = GetPromiseId(env, promise);
    1883+
    if (!opt.has_value()) return;
    1884+
    id = opt.value();
    1885+
    action = "resolved";
    1886+
    } else {
    1887+
    UNREACHABLE();
    1888+
    }
    1889+
    1890+
    FPrintF(stderr, "[--trace-promises] ");
    1891+
    if (parent_id.has_value()) {
    1892+
    FPrintF(stderr, "promise #%d ", parent_id.value());
    1893+
    }
    1894+
    FPrintF(stderr, "%s promise #%d\n", action, id);
    1895+
    // TODO(joyeecheung): we can dump the native stack trace too if the
    1896+
    // JS stack trace is empty i.e. it may be resolved on the native side.
    1897+
    PrintCurrentStackTrace(isolate);
    1898+
    }
    1899+
    18421900
    size_t Environment::NearHeapLimitCallback(void* data,
    18431901
    size_t current_heap_limit,
    18441902
    size_t initial_heap_limit) {

    src/env.h

    Lines changed: 4 additions & 0 deletions
    Original file line numberDiff line numberDiff line change
    @@ -934,6 +934,9 @@ class Environment : public MemoryRetainer {
    934934
    inline void RemoveCleanupHook(CleanupQueue::Callback cb, void* arg);
    935935
    void RunCleanup();
    936936

    937+
    static void TracePromises(v8::PromiseHookType type,
    938+
    v8::Local<v8::Promise> promise,
    939+
    v8::Local<v8::Value> parent);
    937940
    static size_t NearHeapLimitCallback(void* data,
    938941
    size_t current_heap_limit,
    939942
    size_t initial_heap_limit);
    @@ -1094,6 +1097,7 @@ class Environment : public MemoryRetainer {
    10941097
    uint32_t module_id_counter_ = 0;
    10951098
    uint32_t script_id_counter_ = 0;
    10961099
    uint32_t function_id_counter_ = 0;
    1100+
    uint32_t trace_promise_id_counter_ = 0;
    10971101

    10981102
    AliasedInt32Array exit_info_;
    10991103

    src/env_properties.h

    Lines changed: 1 addition & 0 deletions
    Original file line numberDiff line numberDiff line change
    @@ -28,6 +28,7 @@
    2828
    V(napi_wrapper, "node:napi:wrapper") \
    2929
    V(untransferable_object_private_symbol, "node:untransferableObject") \
    3030
    V(exit_info_private_symbol, "node:exit_info_private_symbol") \
    31+
    V(promise_trace_id, "node:promise_trace_id") \
    3132
    V(require_private_symbol, "node:require_private_symbol")
    3233

    3334
    // Symbols are per-isolate primitives but Environment proxies them

    src/node.cc

    Lines changed: 3 additions & 0 deletions
    Original file line numberDiff line numberDiff line change
    @@ -264,6 +264,9 @@ void Environment::InitializeDiagnostics() {
    264264
    env->isolate()->SetAtomicsWaitCallback(nullptr, nullptr);
    265265
    }, this);
    266266
    }
    267+
    if (options_->trace_promises) {
    268+
    isolate_->SetPromiseHook(TracePromises);
    269+
    }
    267270
    }
    268271

    269272
    static

    src/node_errors.cc

    Lines changed: 7 additions & 0 deletions
    Original file line numberDiff line numberDiff line change
    @@ -291,6 +291,13 @@ void PrintStackTrace(Isolate* isolate,
    291291
    PrintToStderrAndFlush(FormatStackTrace(isolate, stack, prefix));
    292292
    }
    293293

    294+
    void PrintCurrentStackTrace(Isolate* isolate, StackTracePrefix prefix) {
    295+
    Local<StackTrace> stack;
    296+
    if (GetCurrentStackTrace(isolate).ToLocal(&stack)) {
    297+
    PrintStackTrace(isolate, stack, prefix);
    298+
    }
    299+
    }
    300+
    294301
    std::string FormatCaughtException(Isolate* isolate,
    295302
    Local<Context> context,
    296303
    Local<Value> err,

    src/node_internals.h

    Lines changed: 2 additions & 0 deletions
    Original file line numberDiff line numberDiff line change
    @@ -87,6 +87,8 @@ enum class StackTracePrefix {
    8787
    kAt, // " at "
    8888
    kNumber
    8989
    };
    90+
    void PrintCurrentStackTrace(v8::Isolate* isolate,
    91+
    StackTracePrefix prefix = StackTracePrefix::kAt);
    9092
    void PrintStackTrace(v8::Isolate* isolate,
    9193
    v8::Local<v8::StackTrace> stack,
    9294
    StackTracePrefix prefix = StackTracePrefix::kAt);

    src/node_options.cc

    Lines changed: 4 additions & 0 deletions
    Original file line numberDiff line numberDiff line change
    @@ -672,6 +672,10 @@ EnvironmentOptionsParser::EnvironmentOptionsParser() {
    672672
    "show stack traces on process warnings",
    673673
    &EnvironmentOptions::trace_warnings,
    674674
    kAllowedInEnvvar);
    675+
    AddOption("--trace-promises",
    676+
    "show stack traces on promise initialization and resolution",
    677+
    &EnvironmentOptions::trace_promises,
    678+
    kAllowedInEnvvar);
    675679
    AddOption("--experimental-default-type",
    676680
    "set module system to use by default",
    677681
    &EnvironmentOptions::type,

    src/node_options.h

    Lines changed: 1 addition & 0 deletions
    Original file line numberDiff line numberDiff line change
    @@ -179,6 +179,7 @@ class EnvironmentOptions : public Options {
    179179
    bool trace_tls = false;
    180180
    bool trace_uncaught = false;
    181181
    bool trace_warnings = false;
    182+
    bool trace_promises = false;
    182183
    bool extra_info_on_fatal_exception = true;
    183184
    std::string unhandled_rejections;
    184185
    std::vector<std::string> userland_loaders;

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

    Lines changed: 2 additions & 0 deletions
    Original file line numberDiff line numberDiff line change
    @@ -106,6 +106,8 @@ assert(undocumented.delete('--no-node-snapshot'));
    106106
    assert(undocumented.delete('--loader'));
    107107
    assert(undocumented.delete('--verify-base-objects'));
    108108
    assert(undocumented.delete('--no-verify-base-objects'));
    109+
    assert(undocumented.delete('--trace-promises'));
    110+
    assert(undocumented.delete('--no-trace-promises'));
    109111

    110112
    // Remove negated versions of the flags.
    111113
    for (const flag of undocumented) {

    0 commit comments

    Comments
     (0)
    0