From 570052e845ecced86d956550349b93fe0f5fafdd 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 --- deps/v8/include/v8-inspector.h | 2 ++ deps/v8/include/v8-version.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/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/include/v8-version.h b/deps/v8/include/v8-version.h index 459646b5a4844e..a7b8401025d8d3 100644 --- a/deps/v8/include/v8-version.h +++ b/deps/v8/include/v8-version.h @@ -11,7 +11,7 @@ #define V8_MAJOR_VERSION 6 #define V8_MINOR_VERSION 1 #define V8_BUILD_NUMBER 534 -#define V8_PATCH_LEVEL 45 +#define V8_PATCH_LEVEL 46 // Use 1 for candidates and 0 otherwise. // (Boolean macro values are not supported by all preprocessors.) diff --git a/deps/v8/src/inspector/v8-debugger.cc b/deps/v8/src/inspector/v8-debugger.cc index 03bf57cf7d2822..7356cb48d2c434 100644 --- a/deps/v8/src/inspector/v8-debugger.cc +++ b/deps/v8/src/inspector/v8-debugger.cc @@ -965,6 +965,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 767168b29769b8..4c133cee1fc36c 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)); @@ -485,6 +489,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 bd97a927e89085..2e9a64f66deef4 100644 --- a/deps/v8/test/inspector/isolate-data.cc +++ b/deps/v8/test/inspector/isolate-data.cc @@ -355,6 +355,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(); @@ -381,3 +385,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 c96a8d1bbd2bf8..af2bf0ef1e2846 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); @@ -105,6 +106,7 @@ class IsolateData : public v8_inspector::V8InspectorClient { const v8_inspector::StringView& url, unsigned lineNumber, unsigned columnNumber, v8_inspector::V8StackTrace*) override; + void maxAsyncCallStackDepthChanged(int depth) override; TaskRunner* task_runner_; SetupGlobalTasks setup_global_tasks_; @@ -122,6 +124,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; DISALLOW_COPY_AND_ASSIGN(IsolateData); }; From 9b73ae7ae2087bf12dbd108880e09003b1c386f0 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); -});