inspector: track async stacks when necessary

With this change, we do async stack tracking only when explicitly
requested by the inspector client. This avoids unnecessary overhead
for clients that might not be interested in async stack traces.

Fixes: #16180

Author: ofrobots

lib/internal/inspector_async_hook.js

@@ -55,10 +55,4 @@ function 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();
-  }
 };

src/env.h

@@ -101,6 +101,7 @@ class ModuleWrap;
   V(address_string, "address")                                                \
   V(args_string, "args")                                                      \
   V(async, "async")                                                           \
+  V(async_stack_depth_string, "Debugger.setAsyncCallStackDepth")              \
   V(buffer_string, "buffer")                                                  \
   V(bytes_string, "bytes")                                                    \
   V(bytes_parsed_string, "bytesParsed")                                       \
@@ -185,7 +186,9 @@ class ModuleWrap;
   V(length_string, "length")                                                  \
   V(mac_string, "mac")                                                        \
   V(max_buffer_string, "maxBuffer")                                           \
+  V(max_depth_string, "maxDepth")                                             \
   V(message_string, "message")                                                \
+  V(method_string, "method")                                                  \
   V(minttl_string, "minttl")                                                  \
   V(model_string, "model")                                                    \
   V(modulus_string, "modulus")                                                \
@@ -228,6 +231,7 @@ class ModuleWrap;
   V(output_string, "output")                                                  \
   V(order_string, "order")                                                    \
   V(owner_string, "owner")                                                    \
+  V(params_string, "params")                                                  \
   V(parse_error_string, "Parse Error")                                        \
   V(path_string, "path")                                                      \
   V(pbkdf2_error_string, "PBKDF2 Error")                                      \

src/inspector_agent.cc

@@ -29,7 +29,10 @@ using v8::Function;
 using v8::HandleScope;
 using v8::Isolate;
 using v8::Local;
+using v8::Maybe;
+using v8::MaybeLocal;
 using v8::Object;
+using v8::String;
 using v8::Value;
 
 using v8_inspector::StringBuffer;
@@ -449,7 +452,9 @@ Agent::Agent(Environment* env) : parent_env_(env),
                                  client_(nullptr),
                                  platform_(nullptr),
                                  enabled_(false),
-                                 next_context_number_(1) {}
+                                 next_context_number_(1),
+                                 pending_enable_async_hook_(false),
+                                 pending_disable_async_hook_(false) {}
 
 // Destructor needs to be defined here in implementation file as the header
 // does not have full definition of some classes.
@@ -497,18 +502,6 @@ 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
   Local<Object> process_object = parent_env_->process_object();
   Local<Value> emit_fn =
@@ -554,20 +547,6 @@ void Agent::Stop() {
 }
 
 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);
 }
@@ -593,6 +572,7 @@ void Agent::FatalException(Local<Value> error, Local<v8::Message> message) {
 
 void Agent::Dispatch(const StringView& message) {
   CHECK_NE(client_, nullptr);
+  InterceptAsyncStackDepthMessage(message);
   client_->dispatchMessageFromFrontend(message);
 }
 
@@ -625,6 +605,37 @@ void Agent::RegisterAsyncHook(Isolate* isolate,
                               v8::Local<v8::Function> disable_function) {
   enable_async_hook_function_.Reset(isolate, enable_function);
   disable_async_hook_function_.Reset(isolate, disable_function);
+  if (pending_enable_async_hook_) {
+    pending_enable_async_hook_ = false;
+    EnableAsyncHook(isolate);
+  } else if (pending_disable_async_hook_) {
+    pending_disable_async_hook_ = false;
+    DisableAsyncHook(isolate);
+  }
+}
+
+void Agent::EnableAsyncHook(Isolate* isolate) {
+  CHECK(!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::inspector::Agent::EnableAsyncHook",
+      "Cannot enable Inspector's AsyncHook, please report this.");
+  }
+}
+
+void Agent::DisableAsyncHook(Isolate* isolate) {
+  CHECK(!disable_async_hook_function_.IsEmpty());
+  Local<Function> disable_fn = disable_async_hook_function_.Get(isolate);
+  auto context = parent_env_->context();
+  auto result = disable_fn->Call(context, Undefined(isolate), 0, nullptr);
+  if (result.IsEmpty()) {
+    FatalError(
+      "node::inspector::Agent::DisableAsyncHook",
+      "Cannot disable Inspector's AsyncHook, please report this.");
+  }
 }
 
 void Agent::AsyncTaskScheduled(const StringView& task_name, void* task,
@@ -648,6 +659,101 @@ void Agent::AllAsyncTasksCanceled() {
   client_->AllAsyncTasksCanceled();
 }
 
+void Agent::InterceptAsyncStackDepthMessage(const StringView& message) {
+  // This logic would be better implemented in JavaScript, but when using
+  // --inspect-brk, the debugger must necessarily attach before much JavaScript
+  // can execute. The Debugger.setAsyncCallStackDepth message arrives too early
+  // and we must intercept this in C++.
+
+  v8::Isolate* isolate = parent_env_->isolate();
+  Local<Context> context = parent_env_->context();
+
+  MaybeLocal<String> string =
+    String::NewFromTwoByte(isolate, message.characters16(),
+                           v8::NewStringType::kNormal, message.length());
+  if (string.IsEmpty()) {
+    return;
+  }
+
+  // Basically, the logic we want to implement is:
+  // let parsed; try {
+  //   parsed = JSON.parse(string);
+  // } catch (e) { return; }
+  // if (parsed && parsed.method && parsed.method === 'Debugger.setAsync..' &&
+  //     parsed.params && parsed.params.maxDepth &&
+  //     typeof parsed.params.maxDepth === 'number') {
+  //   // Enable or Disable, depending on maxDepth.
+  // }
+  //
+  // We ignore (return early) on malformed messages and let v8-inspector deal
+  // with them.
+
+  MaybeLocal<Value> maybe_parsed =
+    v8::JSON::Parse(context, string.ToLocalChecked());
+  if (maybe_parsed.IsEmpty()) {
+    return;
+  }
+
+  Local<Value> parsed = maybe_parsed.ToLocalChecked();
+  if (!parsed->IsObject()) {
+    return;
+  }
+
+  Local<Object> object = parsed.As<Object>();
+
+  Local<Value> method;
+  if (!object->Get(context, parent_env_->method_string()).ToLocal(&method) ||
+      !method->IsString() ||
+      !method->StrictEquals(parent_env_->async_stack_depth_string())) {
+    return;
+  }
+
+  Local<Value> params;
+  if (!object->Get(context, parent_env_->params_string()).ToLocal(&params) ||
+      !params->IsObject()) {
+    return;
+  }
+
+  Local<Value> depth_value;
+  if (!params.As<Object>()->Get(context, parent_env_->max_depth_string())
+                           .ToLocal(&depth_value) ||
+      !depth_value->IsNumber()) {
+    return;
+  }
+
+  Maybe<double> maybe_depth = depth_value->NumberValue(context);
+  if (maybe_depth.IsNothing()) {
+    return;
+  }
+
+  double depth = maybe_depth.FromJust();
+  if (depth == 0) {
+    // Disable.
+    if (!disable_async_hook_function_.IsEmpty()) {
+      DisableAsyncHook(isolate);
+    } else {
+      if (pending_enable_async_hook_) {
+        CHECK(!pending_disable_async_hook_);
+        pending_enable_async_hook_ = false;
+      } else {
+        pending_disable_async_hook_ = true;
+      }
+    }
+  } else {
+    // Enable.
+    if (!enable_async_hook_function_.IsEmpty()) {
+      EnableAsyncHook(isolate);
+    } else {
+      if (pending_disable_async_hook_) {
+        CHECK(!pending_enable_async_hook_);
+        pending_disable_async_hook_ = false;
+      } else {
+        pending_enable_async_hook_ = true;
+      }
+    }
+  }
+}
+
 void Agent::RequestIoThreadStart() {
   // We need to attempt to interrupt V8 flow (in case Node is running
   // continuous JS code) and to wake up libuv thread (in case Node is waiting

src/inspector_agent.h

@@ -62,6 +62,7 @@ class Agent {
   void AsyncTaskStarted(void* task);
   void AsyncTaskFinished(void* task);
   void AllAsyncTasksCanceled();
+  void InterceptAsyncStackDepthMessage(const v8_inspector::StringView& message);
 
   void RegisterAsyncHook(v8::Isolate* isolate,
     v8::Local<v8::Function> enable_function,
@@ -93,6 +94,9 @@ class Agent {
   void ContextCreated(v8::Local<v8::Context> context);
 
  private:
+  void EnableAsyncHook(v8::Isolate* isolate);
+  void DisableAsyncHook(v8::Isolate* isolate);
+
   node::Environment* parent_env_;
   std::unique_ptr<NodeInspectorClient> client_;
   std::unique_ptr<InspectorIo> io_;
@@ -102,6 +106,8 @@ class Agent {
   DebugOptions debug_options_;
   int next_context_number_;
 
+  bool pending_enable_async_hook_;
+  bool pending_disable_async_hook_;
   v8::Persistent<v8::Function> enable_async_hook_function_;
   v8::Persistent<v8::Function> disable_async_hook_function_;
 };

test/inspector/test-async-hook-inspector.js

@@ -0,0 +1,55 @@
+'use strict';
+const common = require('../common');
+common.skipIfInspectorDisabled();
+common.skipIf32Bits();
+
+const assert = require('assert');
+const async_hooks = require('async_hooks');
+const inspector = require('inspector');
+
+// Verify that inspector-async-hook is not registered,
+// thus emitInit() ignores invalid arguments
+// See test/async-hooks/test-emit-init.js
+function verifyAsyncHookDisabled(message) {
+  assert.doesNotThrow(() => async_hooks.emitInit(), message);
+}
+
+// Verify that inspector-async-hook is registered
+// by checking that emitInit with invalid arguments
+// throw an error.
+// See test/async-hooks/test-emit-init.js
+function verifyAsyncHookEnabled(message) {
+  assert.throws(() => async_hooks.emitInit(), message);
+}
+
+// By default inspector async hooks should not have been installed.
+verifyAsyncHookDisabled('inspector async hook should be disabled at startup');
+
+const session = new inspector.Session();
+verifyAsyncHookDisabled('creating a session should not enable async hooks');
+
+session.connect();
+verifyAsyncHookDisabled('creating a session should not enable async hooks');
+
+session.post('Debugger.setAsyncCallStackDepth', { invalid: 'message' }, () => {
+  verifyAsyncHookDisabled('invalid message should not enable async hooks');
+
+  session.post('Debugger.setAsyncCallStackDepth', { maxDepth: 'five' }, () => {
+    verifyAsyncHookDisabled('invalid maxDepth (sting) should not enable async' +
+      ' hooks');
+
+    session.post('Debugger.setAsyncCallStackDepth', { maxDepth: NaN }, () => {
+      verifyAsyncHookDisabled('invalid maxDepth (NaN) should not enable async' +
+        ' hooks');
+
+      session.post('Debugger.setAsyncCallStackDepth', { maxDepth: 10 }, () => {
+        verifyAsyncHookEnabled('valid message should enable async hook');
+
+        session.post('Debugger.setAsyncCallStackDepth', { maxDepth: 0 }, () => {
+          verifyAsyncHookDisabled('Setting maxDepth to 0 should disable ' +
+            'async hooks');
+        });
+      });
+    });
+  });
+});