inspector: track async stacks when necessary

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 =
@@ -542,32 +535,11 @@ void Agent::Stop() {
 
   // 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.");
-    }
+    ToggleAsyncHook(isolate, disable_async_hook_function_.Get(isolate));
   }
 }
 
 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 +565,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 +598,24 @@ 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;
+    ToggleAsyncHook(isolate, enable_async_hook_function_.Get(isolate));
+  } else if (pending_disable_async_hook_) {
+    pending_disable_async_hook_ = false;
+    ToggleAsyncHook(isolate, disable_async_hook_function_.Get(isolate));
+  }
+}
+
+void Agent::ToggleAsyncHook(Isolate* isolate, Local<Function> fn) {
+  HandleScope handle_scope(isolate);
+  auto context = parent_env_->context();
+  auto result = fn->Call(context, Undefined(isolate), 0, nullptr);
+  if (result.IsEmpty()) {
+    FatalError(
+      "node::inspector::Agent::ToggleAsyncHook",
+      "Cannot toggle Inspector's AsyncHook, please report this.");
+  }
 }
 
 void Agent::AsyncTaskScheduled(const StringView& task_name, void* task,
@@ -648,6 +639,92 @@ 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++.
+  //
+  // TODO: for performance reasons, it would be good to pre-scan the string for
+  // 'Debugger.setAsyncCallStackDepth' and return early if not found.
+
+  v8::Isolate* isolate = parent_env_->isolate();
+  HandleScope handle_scope(isolate);
+  Local<Context> context = parent_env_->context();
+
+  v8::TryCatch try_catch(isolate); // catch and ignore exceptions.
+  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.
+
+  Local<Value> scratch;
+  Local<Object> parsed;
+  if (!v8::JSON::Parse(context, string.ToLocalChecked()).ToLocal(&scratch) ||
+      !scratch->IsObject() ||
+      !scratch->ToObject(context).ToLocal(&parsed)) {
+    return;
+  }
+
+  Local<Value> method;
+  if (!parsed->Get(context, parent_env_->method_string()).ToLocal(&method) ||
+      !method->IsString() ||
+      !method->StrictEquals(parent_env_->async_stack_depth_string())) {
+    return;
+  }
+
+  Local<Value> params;
+  if (!parsed->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;
+  }
+
+  double depth = depth_value->NumberValue(context).FromJust();
+  if (depth == 0) {
+    // Disable.
+    if (pending_enable_async_hook_) {
+      CHECK(!pending_disable_async_hook_);
+      pending_enable_async_hook_ = false;
+    } else if (!disable_async_hook_function_.IsEmpty()) {
+      ToggleAsyncHook(isolate, disable_async_hook_function_.Get(isolate));
+    } else {
+      pending_disable_async_hook_ = true;
+    }
+  } else {
+    // Enable.
+    if (pending_disable_async_hook_) {
+      CHECK(!pending_enable_async_hook_);
+      pending_disable_async_hook_ = false;
+    } else if (!enable_async_hook_function_.IsEmpty()) {
+      ToggleAsyncHook(isolate, enable_async_hook_function_.Get(isolate));
+    } 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,8 @@ class Agent {
   void ContextCreated(v8::Local<v8::Context> context);
 
  private:
+  void ToggleAsyncHook(v8::Isolate* isolate, v8::Local<v8::Function> fn);
+
   node::Environment* parent_env_;
   std::unique_ptr<NodeInspectorClient> client_;
   std::unique_ptr<InspectorIo> io_;
@@ -102,6 +105,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('connecting 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 (string) 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');
+        });
+      });
+    });
+  });
+});