From 0ee6ed93a11d21b68ca1a06e6b1005c0be46f866 Mon Sep 17 00:00:00 2001 From: Ali Ijaz Sheikh Date: Wed, 18 Oct 2017 16:00:03 -0700 Subject: [PATCH] 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. PR-URL: https://github.com/nodejs/node/pull/16308 Fixes: https://github.com/nodejs/node/issues/16180 Reviewed-By: Eugene Ostroukhov Reviewed-By: Refael Ackermann Reviewed-By: James M Snell Reviewed-By: Ben Noordhuis Reviewed-By: Timothy Gu --- lib/internal/inspector_async_hook.js | 6 -- src/inspector_agent.cc | 96 +++++++++++-------- src/inspector_agent.h | 7 ++ test/sequential/sequential.status | 1 + .../test-inspector-async-call-stack.js | 79 +++++++++++++++ ...pector-async-hook-teardown-at-debug-end.js | 22 ----- 6 files changed, 142 insertions(+), 69 deletions(-) create mode 100644 test/sequential/test-inspector-async-call-stack.js delete mode 100644 test/sequential/test-inspector-async-hook-teardown-at-debug-end.js diff --git a/lib/internal/inspector_async_hook.js b/lib/internal/inspector_async_hook.js index e32a026cd6..4ccf862697 100644 --- a/lib/internal/inspector_async_hook.js +++ b/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(); - } }; diff --git a/src/inspector_agent.cc b/src/inspector_agent.cc index 673da80d87..d5b3b43ec2 100644 --- a/src/inspector_agent.cc +++ b/src/inspector_agent.cc @@ -319,6 +319,14 @@ class NodeInspectorClient : public V8InspectorClient { return uv_hrtime() * 1.0 / NANOS_PER_MSEC; } + void maxAsyncCallStackDepthChanged(int depth) override { + if (depth == 0) { + env_->inspector_agent()->DisableAsyncHook(); + } else { + env_->inspector_agent()->EnableAsyncHook(); + } + } + void contextCreated(Local context, const std::string& name) { std::unique_ptr name_buffer = Utf8ToStringView(name); v8_inspector::V8ContextInfo info(context, CONTEXT_GROUP_ID, @@ -449,7 +457,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. @@ -498,17 +508,6 @@ bool Agent::StartIoThread(bool wait_for_connect) { HandleScope handle_scope(isolate); auto context = parent_env_->context(); - // Enable tracking of async stack traces - if (!enable_async_hook_function_.IsEmpty()) { - Local enable_fn = enable_async_hook_function_.Get(isolate); - 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 process_object = parent_env_->process_object(); Local emit_fn = @@ -537,38 +536,9 @@ void Agent::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 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 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); } @@ -626,6 +596,50 @@ void Agent::RegisterAsyncHook(Isolate* isolate, v8::Local disable_function) { enable_async_hook_function_.Reset(isolate, enable_function); disable_async_hook_function_.Reset(isolate, disable_function); + if (pending_enable_async_hook_) { + CHECK(!pending_disable_async_hook_); + pending_enable_async_hook_ = false; + EnableAsyncHook(); + } else if (pending_disable_async_hook_) { + CHECK(!pending_enable_async_hook_); + pending_disable_async_hook_ = false; + DisableAsyncHook(); + } +} + +void Agent::EnableAsyncHook() { + if (!enable_async_hook_function_.IsEmpty()) { + Isolate* isolate = parent_env_->isolate(); + ToggleAsyncHook(isolate, enable_async_hook_function_.Get(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::DisableAsyncHook() { + if (!disable_async_hook_function_.IsEmpty()) { + Isolate* isolate = parent_env_->isolate(); + ToggleAsyncHook(isolate, disable_async_hook_function_.Get(isolate)); + } else if (pending_enable_async_hook_) { + CHECK(!pending_disable_async_hook_); + pending_enable_async_hook_ = false; + } else { + pending_disable_async_hook_ = true; + } +} + +void Agent::ToggleAsyncHook(Isolate* isolate, Local 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, diff --git a/src/inspector_agent.h b/src/inspector_agent.h index 9119e7263b..24fae116f9 100644 --- a/src/inspector_agent.h +++ b/src/inspector_agent.h @@ -92,7 +92,12 @@ class Agent { DebugOptions& options() { return debug_options_; } void ContextCreated(v8::Local context); + void EnableAsyncHook(); + void DisableAsyncHook(); + private: + void ToggleAsyncHook(v8::Isolate* isolate, v8::Local fn); + node::Environment* parent_env_; std::unique_ptr client_; std::unique_ptr io_; @@ -102,6 +107,8 @@ class Agent { DebugOptions debug_options_; int next_context_number_; + bool pending_enable_async_hook_; + bool pending_disable_async_hook_; v8::Persistent enable_async_hook_function_; v8::Persistent disable_async_hook_function_; }; diff --git a/test/sequential/sequential.status b/test/sequential/sequential.status index 86095d16c3..797adfecd6 100644 --- a/test/sequential/sequential.status +++ b/test/sequential/sequential.status @@ -7,6 +7,7 @@ prefix sequential [true] # This section applies to all platforms [$system==win32] +test-inspector-async-call-stack : PASS, FLAKY test-inspector-bindings : PASS, FLAKY test-inspector-debug-end : PASS, FLAKY test-inspector-stop-profile-after-done: PASS, FLAKY diff --git a/test/sequential/test-inspector-async-call-stack.js b/test/sequential/test-inspector-async-call-stack.js new file mode 100644 index 0000000000..681697b8c4 --- /dev/null +++ b/test/sequential/test-inspector-async-call-stack.js @@ -0,0 +1,79 @@ +'use strict'; +const common = require('../common'); +common.skipIfInspectorDisabled(); +common.skipIf32Bits(); + +const assert = require('assert'); +const async_wrap = process.binding('async_wrap'); +const { kTotals } = async_wrap.constants; +const inspector = require('inspector'); + +const setDepth = 'Debugger.setAsyncCallStackDepth'; + +function verifyAsyncHookDisabled(message) { + assert.strictEqual(async_wrap.async_hook_fields[kTotals], 0); +} + +function verifyAsyncHookEnabled(message) { + assert.strictEqual(async_wrap.async_hook_fields[kTotals], 4); +} + +// 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.enable', () => { + verifyAsyncHookDisabled('enabling debugger should not enable async hooks'); + + session.post(setDepth, { invalid: 'message' }, () => { + verifyAsyncHookDisabled('invalid message should not enable async hooks'); + + session.post(setDepth, { maxDepth: 'five' }, () => { + verifyAsyncHookDisabled('invalid maxDepth (string) should not enable ' + + 'async hooks'); + + session.post(setDepth, { maxDepth: NaN }, () => { + verifyAsyncHookDisabled('invalid maxDepth (NaN) should not enable ' + + 'async hooks'); + + session.post(setDepth, { maxDepth: 10 }, () => { + verifyAsyncHookEnabled('valid message should enable async hooks'); + + session.post(setDepth, { maxDepth: 0 }, () => { + verifyAsyncHookDisabled('Setting maxDepth to 0 should disable ' + + 'async hooks'); + + runTestSet2(session); + }); + }); + }); + }); + }); +}); + +function runTestSet2(session) { + session.post(setDepth, { maxDepth: 32 }, () => { + verifyAsyncHookEnabled('valid message should enable async hooks'); + + session.post('Debugger.disable', () => { + verifyAsyncHookDisabled('Debugger.disable should disable async hooks'); + + session.post('Debugger.enable', () => { + verifyAsyncHookDisabled('Enabling debugger should not enable hooks'); + + session.post(setDepth, { maxDepth: 64 }, () => { + verifyAsyncHookEnabled('valid message should enable async hooks'); + + session.disconnect(); + verifyAsyncHookDisabled('Disconnecting session should disable ' + + 'async hooks'); + }); + }); + }); + }); +} diff --git a/test/sequential/test-inspector-async-hook-teardown-at-debug-end.js b/test/sequential/test-inspector-async-hook-teardown-at-debug-end.js deleted file mode 100644 index c5577363fd..0000000000 --- a/test/sequential/test-inspector-async-hook-teardown-at-debug-end.js +++ /dev/null @@ -1,22 +0,0 @@ -'use strict'; -const common = require('../common'); -common.skipIfInspectorDisabled(); -common.skipIf32Bits(); - -const spawn = require('child_process').spawn; - -const script = ` -const assert = require('assert'); -const async_wrap = process.binding('async_wrap'); -const { kTotals } = async_wrap.constants; - -assert.strictEqual(async_wrap.async_hook_fields[kTotals], 4); -process._debugEnd(); -assert.strictEqual(async_wrap.async_hook_fields[kTotals], 0); -`; - -const args = ['--inspect', '-e', script]; -const child = spawn(process.execPath, args, { stdio: 'inherit' }); -child.on('exit', (code, signal) => { - process.exit(code || signal); -});