Report async tasks to V8 Inspector

lib/internal/bootstrap_node.js

@@ -45,6 +45,8 @@
     if (global.__coverage__)
       NativeModule.require('internal/process/write-coverage').setup();
 
+    NativeModule.require('internal/inspector_async_hook').setup();
+
     // Do not initialize channel in debugger agent, it deletes env variable
     // and the main thread won't see it.
     if (process.argv[1] !== '--debug-agent')

lib/internal/inspector_async_hook.js

@@ -0,0 +1,64 @@
+'use strict';
+
+const { createHook } = require('async_hooks');
+const inspector = process.binding('inspector');
+const config = process.binding('config');
+
+if (!inspector || !inspector.asyncTaskScheduled) {
+  exports.setup = function() {};
+  return;
+}
+
+const hook = createHook({
+  init(asyncId, type, triggerAsyncId, resource) {
+    // It's difficult to tell which tasks will be recurring and which won't,
+    // therefore we mark all tasks as recurring. Based on the discussion
+    // in https://github.com/nodejs/node/pull/13870#discussion_r124515293,
+    // this should be fine as long as we call asyncTaskCanceled() too.
+    const recurring = true;
+    inspector.asyncTaskScheduled(type, asyncId, recurring);
+  },
+
+  before(asyncId) {
+    inspector.asyncTaskStarted(asyncId);
+  },
+
+  after(asyncId) {
+    inspector.asyncTaskFinished(asyncId);
+  },
+
+  destroy(asyncId) {
+    inspector.asyncTaskCanceled(asyncId);
+  },
+});
+
+function enable() {
+  if (config.bits < 64) {
+    // V8 Inspector stores task ids as (void*) pointers.
+    // async_hooks store ids as 64bit numbers.
+    // As a result, we cannot reliably translate async_hook ids to V8 async_task
+    // ids on 32bit platforms.
+    process.emitWarning(
+      'Warning: Async stack traces in debugger are not available ' +
+      `on ${config.bits}bit platforms. The feature is disabled.`,
+      {
+        code: 'INSPECTOR_ASYNC_STACK_TRACES_NOT_AVAILABLE',
+      });
+  } else {
+    hook.enable();
+  }
+}
+
+function disable() {
+  hook.disable();
+}
+
+exports.setup = function() {
+  inspector.registerAsyncHook(enable, disable);
+
+  if (inspector.isEnabled()) {
+    // If the inspector was already enabled via --inspect or --inspect-brk,
+    // the we need to enable the async hook immediately at startup.
+    enable();
+  }
+};

node.gyp

@@ -88,6 +88,7 @@
       'lib/internal/freelist.js',
       'lib/internal/fs.js',
       'lib/internal/http.js',
+      'lib/internal/inspector_async_hook.js',
       'lib/internal/linkedlist.js',
       'lib/internal/net.js',
       'lib/internal/module.js',

src/inspector_agent.cc

@@ -23,20 +23,27 @@
 namespace node {
 namespace inspector {
 namespace {
+
+using node::FatalError;
+
 using v8::Array;
+using v8::Boolean;
 using v8::Context;
 using v8::External;
 using v8::Function;
 using v8::FunctionCallbackInfo;
 using v8::HandleScope;
+using v8::Integer;
 using v8::Isolate;
 using v8::Local;
 using v8::Maybe;
 using v8::MaybeLocal;
+using v8::Name;
 using v8::NewStringType;
 using v8::Object;
 using v8::Persistent;
 using v8::String;
+using v8::Undefined;
 using v8::Value;
 
 using v8_inspector::StringBuffer;
@@ -616,6 +623,28 @@ class NodeInspectorClient : public V8InspectorClient {
     timers_.erase(data);
   }
 
+  // Async stack traces instrumentation.
+  void AsyncTaskScheduled(const StringView& task_name, void* task,
+                          bool recurring) {
+    client_->asyncTaskScheduled(task_name, task, recurring);
+  }
+
+  void AsyncTaskCanceled(void* task) {
+    client_->asyncTaskCanceled(task);
+  }
+
+  void AsyncTaskStarted(void* task) {
+    client_->asyncTaskStarted(task);
+  }
+
+  void AsyncTaskFinished(void* task) {
+    client_->asyncTaskFinished(task);
+  }
+
+  void AllAsyncTasksCanceled() {
+    client_->allAsyncTasksCanceled();
+  }
+
  private:
   node::Environment* env_;
   v8::Platform* platform_;
@@ -676,9 +705,21 @@ bool Agent::StartIoThread(bool wait_for_connect) {
   }
 
   v8::Isolate* isolate = parent_env_->isolate();
+  HandleScope handle_scope(isolate);
+
+  // Enable tracking of async stack traces
+  if (!enable_async_hook_function_.IsEmpty()) {
+    Local<Function> enable_fn = enable_async_hook_function_.Get(isolate);
+    auto context = parent_env_->context();
+    auto result = enable_fn->Call(context, Undefined(isolate), 0, nullptr);
+    if (result.IsEmpty()) {
+      FatalError(
+        "node::InspectorAgent::StartIoThread",
+        "Cannot enable Inspector's AsyncHook, please report this.");
+    }
+  }
 
   // Send message to enable debug in workers
-  HandleScope handle_scope(isolate);
   Local<Object> process_object = parent_env_->process_object();
   Local<Value> emit_fn =
       process_object->Get(FIXED_ONE_BYTE_STRING(isolate, "emit"));
@@ -717,10 +758,40 @@ void Agent::Stop() {
   if (io_ != nullptr) {
     io_->Stop();
     io_.reset();
+    enabled_ = false;
+  }
+
+  v8::Isolate* isolate = parent_env_->isolate();
+  HandleScope handle_scope(isolate);
+
+  // Disable tracking of async stack traces
+  if (!disable_async_hook_function_.IsEmpty()) {
+    Local<Function> disable_fn = disable_async_hook_function_.Get(isolate);
+    auto result = disable_fn->Call(parent_env_->context(),
+      Undefined(parent_env_->isolate()), 0, nullptr);
+    if (result.IsEmpty()) {
+      FatalError(
+        "node::InspectorAgent::Stop",
+        "Cannot disable Inspector's AsyncHook, please report this.");
+    }
   }
 }
 
 void Agent::Connect(InspectorSessionDelegate* delegate) {
+  if (!enabled_) {
+    // Enable tracking of async stack traces
+    v8::Isolate* isolate = parent_env_->isolate();
+    HandleScope handle_scope(isolate);
+    auto context = parent_env_->context();
+    Local<Function> enable_fn = enable_async_hook_function_.Get(isolate);
+    auto result = enable_fn->Call(context, Undefined(isolate), 0, nullptr);
+    if (result.IsEmpty()) {
+      FatalError(
+        "node::InspectorAgent::Connect",
+        "Cannot enable Inspector's AsyncHook, please report this.");
+    }
+  }
+
   enabled_ = true;
   client_->connectFrontend(delegate);
 }
@@ -773,6 +844,34 @@ void Agent::PauseOnNextJavascriptStatement(const std::string& reason) {
     channel->schedulePauseOnNextStatement(reason);
 }
 
+void Agent::RegisterAsyncHook(Isolate* isolate,
+                              v8::Local<v8::Function> enable_function,
+                              v8::Local<v8::Function> disable_function) {
+  enable_async_hook_function_.Reset(isolate, enable_function);
+  disable_async_hook_function_.Reset(isolate, disable_function);
+}
+
+void Agent::AsyncTaskScheduled(const StringView& task_name, void* task,
+                               bool recurring) {
+  client_->AsyncTaskScheduled(task_name, task, recurring);
+}
+
+void Agent::AsyncTaskCanceled(void* task) {
+  client_->AsyncTaskCanceled(task);
+}
+
+void Agent::AsyncTaskStarted(void* task) {
+  client_->AsyncTaskStarted(task);
+}
+
+void Agent::AsyncTaskFinished(void* task) {
+  client_->AsyncTaskFinished(task);
+}
+
+void Agent::AllAsyncTasksCanceled() {
+  client_->AllAsyncTasksCanceled();
+}
+
 void Open(const FunctionCallbackInfo<Value>& args) {
   Environment* env = Environment::GetCurrent(args);
   inspector::Agent* agent = env->inspector_agent();
@@ -810,6 +909,59 @@ void Url(const FunctionCallbackInfo<Value>& args) {
   args.GetReturnValue().Set(OneByteString(env->isolate(), url.c_str()));
 }
 
+static void* GetAsyncTask(int64_t asyncId) {
+  // The inspector assumes that when other clients use its asyncTask* API,
+  // they use real pointers, or at least something aligned like real pointer.
+  // In general it means that our task_id should always be even.
+  //
+  // On 32bit platforms, the 64bit asyncId would get truncated when converted
+  // to a 32bit pointer. However, the javascript part will never enable
+  // the async_hook on 32bit platforms, therefore the truncation will never
+  // happen in practice.
+  return reinterpret_cast<void*>(asyncId << 1);
+}
+
+template<void (Agent::*asyncTaskFn)(void*)>
+static void InvokeAsyncTaskFnWithId(const FunctionCallbackInfo<Value>& args) {
+  Environment* env = Environment::GetCurrent(args);
+  CHECK(args[0]->IsNumber());
+  int64_t task_id = args[0]->IntegerValue(env->context()).FromJust();
+  (env->inspector_agent()->*asyncTaskFn)(GetAsyncTask(task_id));
+}
+
+static void AsyncTaskScheduledWrapper(const FunctionCallbackInfo<Value>& args) {
+  Environment* env = Environment::GetCurrent(args);
+
+  CHECK(args[0]->IsString());
+  Local<String> task_name = args[0].As<String>();
+  String::Value task_name_value(task_name);
+  StringView task_name_view(*task_name_value, task_name_value.length());
+
+  CHECK(args[1]->IsNumber());
+  int64_t task_id = args[1]->IntegerValue(env->context()).FromJust();
+  void* task = GetAsyncTask(task_id);
+
+  CHECK(args[2]->IsBoolean());
+  bool recurring = args[2]->BooleanValue(env->context()).FromJust();
+
+  env->inspector_agent()->AsyncTaskScheduled(task_name_view, task, recurring);
+}
+
+static void RegisterAsyncHookWrapper(const FunctionCallbackInfo<Value>& args) {
+  Environment* env = Environment::GetCurrent(args);
+
+  CHECK(args[0]->IsFunction());
+  v8::Local<v8::Function> enable_function = args[0].As<Function>();
+  CHECK(args[1]->IsFunction());
+  v8::Local<v8::Function> disable_function = args[1].As<Function>();
+  env->inspector_agent()->RegisterAsyncHook(env->isolate(),
+    enable_function, disable_function);
+}
+
+static void IsEnabled(const FunctionCallbackInfo<Value>& args) {
+  Environment* env = Environment::GetCurrent(args);
+  args.GetReturnValue().Set(env->inspector_agent()->enabled());
+}
 
 // static
 void Agent::InitInspector(Local<Object> target, Local<Value> unused,
@@ -830,6 +982,17 @@ void Agent::InitInspector(Local<Object> target, Local<Value> unused,
   env->SetMethod(target, "connect", ConnectJSBindingsSession);
   env->SetMethod(target, "open", Open);
   env->SetMethod(target, "url", Url);
+
+  env->SetMethod(target, "asyncTaskScheduled", AsyncTaskScheduledWrapper);
+  env->SetMethod(target, "asyncTaskCanceled",
+      InvokeAsyncTaskFnWithId<&Agent::AsyncTaskCanceled>);
+  env->SetMethod(target, "asyncTaskStarted",
+      InvokeAsyncTaskFnWithId<&Agent::AsyncTaskStarted>);
+  env->SetMethod(target, "asyncTaskFinished",
+      InvokeAsyncTaskFnWithId<&Agent::AsyncTaskFinished>);
+
+  env->SetMethod(target, "registerAsyncHook", RegisterAsyncHookWrapper);
+  env->SetMethod(target, "isEnabled", IsEnabled);
 }
 
 void Agent::RequestIoThreadStart() {

src/inspector_agent.h

@@ -16,17 +16,7 @@ namespace node {
 class Environment;
 }  // namespace node
 
-namespace v8 {
-class Context;
-template <typename V>
-class FunctionCallbackInfo;
-template<typename T>
-class Local;
-class Message;
-class Object;
-class Platform;
-class Value;
-}  // namespace v8
+#include "v8.h"
 
 namespace v8_inspector {
 class StringView;
@@ -67,6 +57,18 @@ class Agent {
   void FatalException(v8::Local<v8::Value> error,
                       v8::Local<v8::Message> message);
 
+  // Async stack traces instrumentation.
+  void AsyncTaskScheduled(const v8_inspector::StringView& taskName, void* task,
+                          bool recurring);
+  void AsyncTaskCanceled(void* task);
+  void AsyncTaskStarted(void* task);
+  void AsyncTaskFinished(void* task);
+  void AllAsyncTasksCanceled();
+
+  void RegisterAsyncHook(v8::Isolate* isolate,
+    v8::Local<v8::Function> enable_function,
+    v8::Local<v8::Function> disable_function);
+
   // These methods are called by the WS protocol and JS binding to create
   // inspector sessions.  The inspector responds by using the delegate to send
   // messages back.
@@ -107,6 +109,9 @@ class Agent {
   std::string path_;
   DebugOptions debug_options_;
   int next_context_number_;
+
+  v8::Persistent<v8::Function> enable_async_hook_function_;
+  v8::Persistent<v8::Function> disable_async_hook_function_;
 };
 
 }  // namespace inspector

src/node_config.cc

@@ -13,6 +13,7 @@ using v8::Boolean;
 using v8::Context;
 using v8::Integer;
 using v8::Local;
+using v8::Number;
 using v8::Object;
 using v8::ReadOnly;
 using v8::String;
@@ -30,6 +31,15 @@ using v8::Value;
                               True(env->isolate()), ReadOnly).FromJust();     \
   } while (0)
 
+#define READONLY_PROPERTY(obj, name, value)                                   \
+  do {                                                                        \
+    obj->DefineOwnProperty(env->context(),                                    \
+                           OneByteString(env->isolate(), name),               \
+                           value,                                             \
+                           ReadOnly).FromJust();                              \
+  } while (0)
+
+
 static void InitConfig(Local<Object> target,
                        Local<Value> unused,
                        Local<Context> context) {
@@ -91,6 +101,10 @@ static void InitConfig(Local<Object> target,
 
   if (config_expose_http2)
     READONLY_BOOLEAN_PROPERTY("exposeHTTP2");
+
+  READONLY_PROPERTY(target,
+                    "bits",
+                    Number::New(env->isolate(), 8 * sizeof(intptr_t)));
 }  // InitConfig
 
 }  // namespace node