From c08750275882f1472f7ff2a98916f857a0857dc6 Mon Sep 17 00:00:00 2001 From: Ali Ijaz Sheikh Date: Wed, 18 Oct 2017 15:19:43 -0700 Subject: [PATCH 1/2] deps: V8: backport b1cd96e from upstream Original commit message: [inspector] added V8InspectorClient::maxAsyncCallStackDepthChanged R=dgozman@chromium.org Bug: none Cq-Include-Trybots: master.tryserver.blink:linux_trusty_blink_rel;master.tryserver.chromium.linux:linux_chromium_rel_ng Change-Id: I0fa10978266feb3c3907ce1f3386ae7a34a33582 Reviewed-on: https://chromium-review.googlesource.com/726490 Reviewed-by: Dmitry Gozman Commit-Queue: Aleksey Kozyatinskiy Cr-Commit-Position: refs/heads/master@{#48705} PR-URL: https://github.com/nodejs/node/pull/16308 Refs: https://github.com/v8/v8/commit/b1cd96ec4b836348bcffba357cd29076ab3ae48b Reviewed-By: Eugene Ostroukhov Reviewed-By: Refael Ackermann Reviewed-By: James M Snell Reviewed-By: Ben Noordhuis Reviewed-By: Timothy Gu --- common.gypi | 2 +- deps/v8/include/v8-inspector.h | 2 ++ deps/v8/src/inspector/v8-debugger.cc | 2 ++ ...x-async-call-stack-depth-changed-expected.txt | 5 +++++ .../max-async-call-stack-depth-changed.js | 16 ++++++++++++++++ deps/v8/test/inspector/inspector-test.cc | 15 +++++++++++++++ deps/v8/test/inspector/isolate-data.cc | 9 +++++++++ deps/v8/test/inspector/isolate-data.h | 3 +++ 8 files changed, 53 insertions(+), 1 deletion(-) create mode 100644 deps/v8/test/inspector/debugger/max-async-call-stack-depth-changed-expected.txt create mode 100644 deps/v8/test/inspector/debugger/max-async-call-stack-depth-changed.js diff --git a/common.gypi b/common.gypi index 404fd4615e2e8c..c7c367ec83bfc6 100644 --- a/common.gypi +++ b/common.gypi @@ -27,7 +27,7 @@ # Reset this number to 0 on major V8 upgrades. # Increment by one for each non-official patch applied to deps/v8. - 'v8_embedder_string': '-node.7', + 'v8_embedder_string': '-node.8', # Enable disassembler for `--print-code` v8 options 'v8_enable_disassembler': 1, diff --git a/deps/v8/include/v8-inspector.h b/deps/v8/include/v8-inspector.h index 43bf3b4f60b1c8..d0bb9b47fe4d69 100644 --- a/deps/v8/include/v8-inspector.h +++ b/deps/v8/include/v8-inspector.h @@ -211,6 +211,8 @@ class V8_EXPORT V8InspectorClient { // TODO(dgozman): this was added to support service worker shadow page. We // should not connect at all. virtual bool canExecuteScripts(int contextGroupId) { return true; } + + virtual void maxAsyncCallStackDepthChanged(int depth) {} }; class V8_EXPORT V8Inspector { diff --git a/deps/v8/src/inspector/v8-debugger.cc b/deps/v8/src/inspector/v8-debugger.cc index acd778b2b69825..bc5437c6d42a72 100644 --- a/deps/v8/src/inspector/v8-debugger.cc +++ b/deps/v8/src/inspector/v8-debugger.cc @@ -726,6 +726,8 @@ void V8Debugger::setAsyncCallStackDepth(V8DebuggerAgentImpl* agent, int depth) { if (m_maxAsyncCallStackDepth == maxAsyncCallStackDepth) return; // TODO(dgozman): ideally, this should be per context group. m_maxAsyncCallStackDepth = maxAsyncCallStackDepth; + m_inspector->client()->maxAsyncCallStackDepthChanged( + m_maxAsyncCallStackDepth); if (!maxAsyncCallStackDepth) allAsyncTasksCanceled(); } diff --git a/deps/v8/test/inspector/debugger/max-async-call-stack-depth-changed-expected.txt b/deps/v8/test/inspector/debugger/max-async-call-stack-depth-changed-expected.txt new file mode 100644 index 00000000000000..0f94b592e02fc3 --- /dev/null +++ b/deps/v8/test/inspector/debugger/max-async-call-stack-depth-changed-expected.txt @@ -0,0 +1,5 @@ +Tests for max async call stack depth changed. +maxAsyncCallStackDepthChanged: 8 +maxAsyncCallStackDepthChanged: 0 +maxAsyncCallStackDepthChanged: 8 +maxAsyncCallStackDepthChanged: 0 diff --git a/deps/v8/test/inspector/debugger/max-async-call-stack-depth-changed.js b/deps/v8/test/inspector/debugger/max-async-call-stack-depth-changed.js new file mode 100644 index 00000000000000..2d5853981087a1 --- /dev/null +++ b/deps/v8/test/inspector/debugger/max-async-call-stack-depth-changed.js @@ -0,0 +1,16 @@ +// Copyright 2017 the V8 project authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +let {session, contextGroup, Protocol} = + InspectorTest.start('Tests for max async call stack depth changed.'); + +(async function test(){ + utils.setLogMaxAsyncCallStackDepthChanged(true); + await Protocol.Debugger.enable(); + await Protocol.Debugger.setAsyncCallStackDepth({maxDepth: 8}); + await Protocol.Debugger.setAsyncCallStackDepth({maxDepth: 0}); + await Protocol.Debugger.setAsyncCallStackDepth({maxDepth: 8}); + await Protocol.Debugger.disable(); + InspectorTest.completeTest(); +})(); diff --git a/deps/v8/test/inspector/inspector-test.cc b/deps/v8/test/inspector/inspector-test.cc index dcaf5823ef7c93..de89271fbfcbab 100644 --- a/deps/v8/test/inspector/inspector-test.cc +++ b/deps/v8/test/inspector/inspector-test.cc @@ -299,6 +299,10 @@ class UtilsExtension : public IsolateData::SetupGlobalTask { utils->Set(ToV8String(isolate, "setLogConsoleApiMessageCalls"), v8::FunctionTemplate::New( isolate, &UtilsExtension::SetLogConsoleApiMessageCalls)); + utils->Set( + ToV8String(isolate, "setLogMaxAsyncCallStackDepthChanged"), + v8::FunctionTemplate::New( + isolate, &UtilsExtension::SetLogMaxAsyncCallStackDepthChanged)); utils->Set(ToV8String(isolate, "createContextGroup"), v8::FunctionTemplate::New(isolate, &UtilsExtension::CreateContextGroup)); @@ -486,6 +490,17 @@ class UtilsExtension : public IsolateData::SetupGlobalTask { args[0].As()->Value()); } + static void SetLogMaxAsyncCallStackDepthChanged( + const v8::FunctionCallbackInfo& args) { + if (args.Length() != 1 || !args[0]->IsBoolean()) { + fprintf(stderr, + "Internal error: setLogMaxAsyncCallStackDepthChanged(bool)."); + Exit(); + } + backend_runner_->data()->SetLogMaxAsyncCallStackDepthChanged( + args[0].As()->Value()); + } + static void CreateContextGroup( const v8::FunctionCallbackInfo& args) { if (args.Length() != 0) { diff --git a/deps/v8/test/inspector/isolate-data.cc b/deps/v8/test/inspector/isolate-data.cc index 82a5cc04834312..4c1d81670f377b 100644 --- a/deps/v8/test/inspector/isolate-data.cc +++ b/deps/v8/test/inspector/isolate-data.cc @@ -370,6 +370,10 @@ void IsolateData::SetLogConsoleApiMessageCalls(bool log) { log_console_api_message_calls_ = log; } +void IsolateData::SetLogMaxAsyncCallStackDepthChanged(bool log) { + log_max_async_call_stack_depth_changed_ = log; +} + v8::MaybeLocal IsolateData::memoryInfo(v8::Isolate* isolate, v8::Local) { if (memory_info_.IsEmpty()) return v8::MaybeLocal(); @@ -396,3 +400,8 @@ void IsolateData::consoleAPIMessage(int contextGroupId, Print(isolate_, stack->toString()->string()); fprintf(stdout, "\n"); } + +void IsolateData::maxAsyncCallStackDepthChanged(int depth) { + if (!log_max_async_call_stack_depth_changed_) return; + fprintf(stdout, "maxAsyncCallStackDepthChanged: %d\n", depth); +} diff --git a/deps/v8/test/inspector/isolate-data.h b/deps/v8/test/inspector/isolate-data.h index b8f3b9e76c99b0..455b44b49bbd7d 100644 --- a/deps/v8/test/inspector/isolate-data.h +++ b/deps/v8/test/inspector/isolate-data.h @@ -64,6 +64,7 @@ class IsolateData : public v8_inspector::V8InspectorClient { void SetCurrentTimeMS(double time); void SetMemoryInfo(v8::Local memory_info); void SetLogConsoleApiMessageCalls(bool log); + void SetLogMaxAsyncCallStackDepthChanged(bool log); void SetMaxAsyncTaskStacksForTest(int limit); void DumpAsyncTaskStacksStateForTest(); void FireContextCreated(v8::Local context, int context_group_id); @@ -106,6 +107,7 @@ class IsolateData : public v8_inspector::V8InspectorClient { unsigned lineNumber, unsigned columnNumber, v8_inspector::V8StackTrace*) override; bool isInspectableHeapObject(v8::Local) override; + void maxAsyncCallStackDepthChanged(int depth) override; TaskRunner* task_runner_; SetupGlobalTasks setup_global_tasks_; @@ -123,6 +125,7 @@ class IsolateData : public v8_inspector::V8InspectorClient { bool current_time_set_ = false; double current_time_ = 0.0; bool log_console_api_message_calls_ = false; + bool log_max_async_call_stack_depth_changed_ = false; v8::Global not_inspectable_private_; DISALLOW_COPY_AND_ASSIGN(IsolateData); From 5886e204f04013879c00aca5ab653c16bef5befc Mon Sep 17 00:00:00 2001 From: Ali Ijaz Sheikh Date: Wed, 18 Oct 2017 16:00:03 -0700 Subject: [PATCH 2/2] 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 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); -});