From 2ea25ad3e2480e28050797de98a3caee2f3cb72b 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. Backport-PR-URL: https://github.com/nodejs/node/pull/16590 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 e32a026cd69155..4ccf862697756d 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 beaebde1c3e45a..efc0ffc15c5b85 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 9119e7263b2799..24fae116f94a3e 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 86095d16c30e0f..797adfecd64cf5 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 00000000000000..681697b8c43425 --- /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 c5577363fd653a..00000000000000 --- 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); -});