From 7a0e3b85b14738d8a0ada6ec0a2f62266cfe306c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Miroslav=20Bajto=C5=A1?= Date: Mon, 17 Jul 2017 16:51:26 +0200 Subject: [PATCH 1/5] process: add "process.bits" property Expose a new property that can be used by JS-land code to detect whether Node.js was compiled in 32bit or 64bit mode. This is important when converting from JavaScript numbers to raw pointers: JavaScript always stores numbers as 64bit, but the pointer size is 32 bits or 64 bits depending on the platform. --- src/node_config.cc | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/src/node_config.cc b/src/node_config.cc index 041e18f6b76ff9..fbff3a9869c886 100644 --- a/src/node_config.cc +++ b/src/node_config.cc @@ -14,6 +14,7 @@ using v8::Context; using v8::Integer; using v8::Local; using v8::Object; +using v8::Number; using v8::ReadOnly; using v8::String; using v8::Value; @@ -30,6 +31,15 @@ using v8::Value; True(env->isolate()), ReadOnly).FromJust(); \ } while (0) +#define READONLY_PROPERTY(obj, name, value) \ + do { \ + obj->DefineOwnProperty(env->context(), \ + OneByteString(env->isolate(), name), \ + value, \ + ReadOnly).FromJust(); \ + } while (0) + + static void InitConfig(Local target, Local unused, Local context) { @@ -91,6 +101,10 @@ static void InitConfig(Local target, if (config_expose_http2) READONLY_BOOLEAN_PROPERTY("exposeHTTP2"); + + READONLY_PROPERTY(target, + "bits", + Number::New(env->isolate(), 8 * sizeof(intptr_t))); } // InitConfig } // namespace node From 97ea1cb9b6b66593de6a9a33a76a6a66b9898b43 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Miroslav=20Bajto=C5=A1?= Date: Tue, 30 May 2017 17:39:40 +0200 Subject: [PATCH 2/5] inspector: enable async stack traces Implement a special async_hooks listener that forwards information about async tasks to V8Inspector asyncTask* API, thus enabling DevTools feature "async stack traces". The feature is enabled only on 64bit platforms due to a technical limitation of V8 Inspector: inspector uses a pointer as a task id, while async_hooks use 64bit numbers as ids. To avoid performance penalty of async_hooks when not debugging, the new listener is enabled only when the process enters a debug mode: - When the process is started with `--inspect` or `--inspect-brk`, the listener is enabled immediately and async stack traces lead all the way to the first tick of the event loop. - When the debug mode is enabled via SIGUSR1 or `_debugProcess()`, the listener is enabled together with the debugger. As a result, only async operations started after the signal was received will be correctly observed and reported to V8 Inspector. For example, a `setInterval()` called in the first tick of the event will not be shown in the async stack trace when the callback is invoked. This behaviour is consistent with Chrome DevTools. Last but not least, this commit fixes handling of InspectorAgent's internal property `enabled_` to ensure it's set back to `false` after the debugger is deactivated (typically via `process._debugEnd()`). --- lib/internal/bootstrap_node.js | 2 + lib/internal/inspector_async_hook.js | 64 +++++++ node.gyp | 1 + src/inspector_agent.cc | 165 +++++++++++++++++- src/inspector_agent.h | 27 +-- src/node_config.cc | 2 +- test/common/README.md | 10 ++ test/common/index.js | 7 + .../test-async-hook-setup-at-inspect-brk.js | 21 +++ .../test-async-hook-teardown-at-debug-end.js | 33 ++++ .../test-async-stack-traces-promise-then.js | 69 ++++++++ .../test-async-stack-traces-set-interval.js | 14 ++ test/inspector/test-inspector-enabled.js | 26 +++ .../test-async-hook-setup-at-inspect.js | 19 ++ .../test-async-hook-setup-at-signal.js | 66 +++++++ 15 files changed, 513 insertions(+), 13 deletions(-) create mode 100644 lib/internal/inspector_async_hook.js create mode 100644 test/inspector/test-async-hook-setup-at-inspect-brk.js create mode 100644 test/inspector/test-async-hook-teardown-at-debug-end.js create mode 100644 test/inspector/test-async-stack-traces-promise-then.js create mode 100644 test/inspector/test-async-stack-traces-set-interval.js create mode 100644 test/inspector/test-inspector-enabled.js create mode 100644 test/known_failures/inspector/test-async-hook-setup-at-inspect.js create mode 100644 test/known_failures/inspector/test-async-hook-setup-at-signal.js diff --git a/lib/internal/bootstrap_node.js b/lib/internal/bootstrap_node.js index a576eeb5e579f6..492e3a21190e2e 100644 --- a/lib/internal/bootstrap_node.js +++ b/lib/internal/bootstrap_node.js @@ -45,6 +45,8 @@ if (global.__coverage__) NativeModule.require('internal/process/write-coverage').setup(); + NativeModule.require('internal/inspector_async_hook').setup(); + // Do not initialize channel in debugger agent, it deletes env variable // and the main thread won't see it. if (process.argv[1] !== '--debug-agent') diff --git a/lib/internal/inspector_async_hook.js b/lib/internal/inspector_async_hook.js new file mode 100644 index 00000000000000..e32a026cd69155 --- /dev/null +++ b/lib/internal/inspector_async_hook.js @@ -0,0 +1,64 @@ +'use strict'; + +const { createHook } = require('async_hooks'); +const inspector = process.binding('inspector'); +const config = process.binding('config'); + +if (!inspector || !inspector.asyncTaskScheduled) { + exports.setup = function() {}; + return; +} + +const hook = createHook({ + init(asyncId, type, triggerAsyncId, resource) { + // It's difficult to tell which tasks will be recurring and which won't, + // therefore we mark all tasks as recurring. Based on the discussion + // in https://github.com/nodejs/node/pull/13870#discussion_r124515293, + // this should be fine as long as we call asyncTaskCanceled() too. + const recurring = true; + inspector.asyncTaskScheduled(type, asyncId, recurring); + }, + + before(asyncId) { + inspector.asyncTaskStarted(asyncId); + }, + + after(asyncId) { + inspector.asyncTaskFinished(asyncId); + }, + + destroy(asyncId) { + inspector.asyncTaskCanceled(asyncId); + }, +}); + +function enable() { + if (config.bits < 64) { + // V8 Inspector stores task ids as (void*) pointers. + // async_hooks store ids as 64bit numbers. + // As a result, we cannot reliably translate async_hook ids to V8 async_task + // ids on 32bit platforms. + process.emitWarning( + 'Warning: Async stack traces in debugger are not available ' + + `on ${config.bits}bit platforms. The feature is disabled.`, + { + code: 'INSPECTOR_ASYNC_STACK_TRACES_NOT_AVAILABLE', + }); + } else { + hook.enable(); + } +} + +function disable() { + hook.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/node.gyp b/node.gyp index 14eb9886785a7f..5ef250d5dd7023 100644 --- a/node.gyp +++ b/node.gyp @@ -88,6 +88,7 @@ 'lib/internal/freelist.js', 'lib/internal/fs.js', 'lib/internal/http.js', + 'lib/internal/inspector_async_hook.js', 'lib/internal/linkedlist.js', 'lib/internal/net.js', 'lib/internal/module.js', diff --git a/src/inspector_agent.cc b/src/inspector_agent.cc index 0f9caa32f2a22e..2520fbdd533bdc 100644 --- a/src/inspector_agent.cc +++ b/src/inspector_agent.cc @@ -23,20 +23,27 @@ namespace node { namespace inspector { namespace { + +using node::FatalError; + using v8::Array; +using v8::Boolean; using v8::Context; using v8::External; using v8::Function; using v8::FunctionCallbackInfo; using v8::HandleScope; +using v8::Integer; using v8::Isolate; using v8::Local; using v8::Maybe; using v8::MaybeLocal; +using v8::Name; using v8::NewStringType; using v8::Object; using v8::Persistent; using v8::String; +using v8::Undefined; using v8::Value; using v8_inspector::StringBuffer; @@ -616,6 +623,28 @@ class NodeInspectorClient : public V8InspectorClient { timers_.erase(data); } + // Async stack traces instrumentation. + void AsyncTaskScheduled(const StringView& task_name, void* task, + bool recurring) { + client_->asyncTaskScheduled(task_name, task, recurring); + } + + void AsyncTaskCanceled(void* task) { + client_->asyncTaskCanceled(task); + } + + void AsyncTaskStarted(void* task) { + client_->asyncTaskStarted(task); + } + + void AsyncTaskFinished(void* task) { + client_->asyncTaskFinished(task); + } + + void AllAsyncTasksCanceled() { + client_->allAsyncTasksCanceled(); + } + private: node::Environment* env_; v8::Platform* platform_; @@ -676,9 +705,21 @@ 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 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 - HandleScope handle_scope(isolate); Local process_object = parent_env_->process_object(); Local emit_fn = process_object->Get(FIXED_ONE_BYTE_STRING(isolate, "emit")); @@ -717,10 +758,40 @@ void Agent::Stop() { if (io_ != nullptr) { io_->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); } @@ -773,6 +844,34 @@ void Agent::PauseOnNextJavascriptStatement(const std::string& reason) { channel->schedulePauseOnNextStatement(reason); } +void Agent::RegisterAsyncHook(Isolate* isolate, + v8::Local enable_function, + v8::Local disable_function) { + enable_async_hook_function_.Reset(isolate, enable_function); + disable_async_hook_function_.Reset(isolate, disable_function); +} + +void Agent::AsyncTaskScheduled(const StringView& task_name, void* task, + bool recurring) { + client_->AsyncTaskScheduled(task_name, task, recurring); +} + +void Agent::AsyncTaskCanceled(void* task) { + client_->AsyncTaskCanceled(task); +} + +void Agent::AsyncTaskStarted(void* task) { + client_->AsyncTaskStarted(task); +} + +void Agent::AsyncTaskFinished(void* task) { + client_->AsyncTaskFinished(task); +} + +void Agent::AllAsyncTasksCanceled() { + client_->AllAsyncTasksCanceled(); +} + void Open(const FunctionCallbackInfo& args) { Environment* env = Environment::GetCurrent(args); inspector::Agent* agent = env->inspector_agent(); @@ -810,6 +909,59 @@ void Url(const FunctionCallbackInfo& args) { args.GetReturnValue().Set(OneByteString(env->isolate(), url.c_str())); } +static void* GetAsyncTask(int64_t asyncId) { + // The inspector assumes that when other clients use its asyncTask* API, + // they use real pointers, or at least something aligned like real pointer. + // In general it means that our task_id should always be even. + // + // On 32bit platforms, the 64bit asyncId would get truncated when converted + // to a 32bit pointer. However, the javascript part will never enable + // the async_hook on 32bit platforms, therefore the truncation will never + // happen in practice. + return reinterpret_cast(asyncId << 1); +} + +template +static void InvokeAsyncTaskFnWithId(const FunctionCallbackInfo& args) { + Environment* env = Environment::GetCurrent(args); + CHECK(args[0]->IsNumber()); + int64_t task_id = args[0]->IntegerValue(env->context()).FromJust(); + (env->inspector_agent()->*asyncTaskFn)(GetAsyncTask(task_id)); +} + +static void AsyncTaskScheduledWrapper(const FunctionCallbackInfo& args) { + Environment* env = Environment::GetCurrent(args); + + CHECK(args[0]->IsString()); + Local task_name = args[0].As(); + String::Value task_name_value(task_name); + StringView task_name_view(*task_name_value, task_name_value.length()); + + CHECK(args[1]->IsNumber()); + int64_t task_id = args[1]->IntegerValue(env->context()).FromJust(); + void* task = GetAsyncTask(task_id); + + CHECK(args[2]->IsBoolean()); + bool recurring = args[2]->BooleanValue(env->context()).FromJust(); + + env->inspector_agent()->AsyncTaskScheduled(task_name_view, task, recurring); +} + +static void RegisterAsyncHookWrapper(const FunctionCallbackInfo& args) { + Environment* env = Environment::GetCurrent(args); + + CHECK(args[0]->IsFunction()); + v8::Local enable_function = args[0].As(); + CHECK(args[1]->IsFunction()); + v8::Local disable_function = args[1].As(); + env->inspector_agent()->RegisterAsyncHook(env->isolate(), + enable_function, disable_function); +} + +static void IsEnabled(const FunctionCallbackInfo& args) { + Environment* env = Environment::GetCurrent(args); + args.GetReturnValue().Set(env->inspector_agent()->enabled()); +} // static void Agent::InitInspector(Local target, Local unused, @@ -830,6 +982,17 @@ void Agent::InitInspector(Local target, Local unused, env->SetMethod(target, "connect", ConnectJSBindingsSession); env->SetMethod(target, "open", Open); env->SetMethod(target, "url", Url); + + env->SetMethod(target, "asyncTaskScheduled", AsyncTaskScheduledWrapper); + env->SetMethod(target, "asyncTaskCanceled", + InvokeAsyncTaskFnWithId<&Agent::AsyncTaskCanceled>); + env->SetMethod(target, "asyncTaskStarted", + InvokeAsyncTaskFnWithId<&Agent::AsyncTaskStarted>); + env->SetMethod(target, "asyncTaskFinished", + InvokeAsyncTaskFnWithId<&Agent::AsyncTaskFinished>); + + env->SetMethod(target, "registerAsyncHook", RegisterAsyncHookWrapper); + env->SetMethod(target, "isEnabled", IsEnabled); } void Agent::RequestIoThreadStart() { diff --git a/src/inspector_agent.h b/src/inspector_agent.h index cf9a8bff8645ec..6ec1bc28dc2e22 100644 --- a/src/inspector_agent.h +++ b/src/inspector_agent.h @@ -16,17 +16,7 @@ namespace node { class Environment; } // namespace node -namespace v8 { -class Context; -template -class FunctionCallbackInfo; -template -class Local; -class Message; -class Object; -class Platform; -class Value; -} // namespace v8 +#include "v8.h" namespace v8_inspector { class StringView; @@ -67,6 +57,18 @@ class Agent { void FatalException(v8::Local error, v8::Local message); + // Async stack traces instrumentation. + void AsyncTaskScheduled(const v8_inspector::StringView& taskName, void* task, + bool recurring); + void AsyncTaskCanceled(void* task); + void AsyncTaskStarted(void* task); + void AsyncTaskFinished(void* task); + void AllAsyncTasksCanceled(); + + void RegisterAsyncHook(v8::Isolate* isolate, + v8::Local enable_function, + v8::Local disable_function); + // These methods are called by the WS protocol and JS binding to create // inspector sessions. The inspector responds by using the delegate to send // messages back. @@ -107,6 +109,9 @@ class Agent { std::string path_; DebugOptions debug_options_; int next_context_number_; + + v8::Persistent enable_async_hook_function_; + v8::Persistent disable_async_hook_function_; }; } // namespace inspector diff --git a/src/node_config.cc b/src/node_config.cc index fbff3a9869c886..d4fb991c5818a2 100644 --- a/src/node_config.cc +++ b/src/node_config.cc @@ -13,8 +13,8 @@ using v8::Boolean; using v8::Context; using v8::Integer; using v8::Local; -using v8::Object; using v8::Number; +using v8::Object; using v8::ReadOnly; using v8::String; using v8::Value; diff --git a/test/common/README.md b/test/common/README.md index 59b02cf52a9a48..b8d9af2fcf70f5 100644 --- a/test/common/README.md +++ b/test/common/README.md @@ -325,6 +325,16 @@ Path to the 'root' directory. either `/` or `c:\\` (windows) Logs '1..0 # Skipped: ' + `msg` and exits with exit code `0`. +### skipIfInspectorDisabled() + +Skip the rest of the tests in the current file when the Inspector +was disabled at compile time. + +### skipIf32Bits() + +Skip the rest of the tests in the current file when the Node.js executable +was compiled with a pointer size smaller than 64 bits. + ### spawnPwd(options) * `options` [<Object>] * return [<Object>] diff --git a/test/common/index.js b/test/common/index.js index 2564b227fe3efd..c3dd788661a49c 100644 --- a/test/common/index.js +++ b/test/common/index.js @@ -746,6 +746,13 @@ exports.skipIfInspectorDisabled = function skipIfInspectorDisabled() { } }; +exports.skipIf32Bits = function skipIf32Bits() { + if (process.binding('config').bits < 64) { + exports.skip('The tested feature is not available in 32bit builds'); + process.exit(0); + } +}; + const arrayBufferViews = [ Int8Array, Uint8Array, diff --git a/test/inspector/test-async-hook-setup-at-inspect-brk.js b/test/inspector/test-async-hook-setup-at-inspect-brk.js new file mode 100644 index 00000000000000..535bf555e0e7bb --- /dev/null +++ b/test/inspector/test-async-hook-setup-at-inspect-brk.js @@ -0,0 +1,21 @@ +'use strict'; +const common = require('../common'); +common.skipIfInspectorDisabled(); +common.skipIf32Bits(); +const helper = require('./inspector-helper'); +const assert = require('assert'); + +const script = 'setTimeout(() => { debugger; }, 50);'; + +helper.startNodeForInspectorTest(runTests, + `--inspect-brk=${common.PORT}`, + script); + +function runTests(harness) { + helper.setupDebuggerAndAssertPausedMessage(harness, (msg) => { + assert( + !!msg.params.asyncStackTrace, + `${Object.keys(msg.params)} contains "asyncStackTrace" property`); + }); + // no need to kill the debugged process, it will quit naturally +} diff --git a/test/inspector/test-async-hook-teardown-at-debug-end.js b/test/inspector/test-async-hook-teardown-at-debug-end.js new file mode 100644 index 00000000000000..9084efdd412bcf --- /dev/null +++ b/test/inspector/test-async-hook-teardown-at-debug-end.js @@ -0,0 +1,33 @@ +'use strict'; +const common = require('../common'); +common.skipIfInspectorDisabled(); +common.skipIf32Bits(); + +const spawn = require('child_process').spawn; + +const script = ` +const assert = require('assert'); + +// 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 +assert.throws( + () => async_hooks.emitInit(), + 'inspector async hook should have been enabled initially'); + +process._debugEnd(); + +// Verify that inspector-async-hook is no longer registered, +// thus emitInit() ignores invalid arguments +// See test/async-hooks/test-emit-init.js +assert.doesNotThrow( + () => async_hooks.emitInit(), + 'inspector async hook should have beend disabled by _debugEnd()'); +`; + +const args = ['--inspect', '-e', script]; +const child = spawn(process.execPath, args, { stdio: 'inherit' }); +child.on('exit', (code, signal) => { + process.exit(code || signal); +}); diff --git a/test/inspector/test-async-stack-traces-promise-then.js b/test/inspector/test-async-stack-traces-promise-then.js new file mode 100644 index 00000000000000..a8927f78fdfeac --- /dev/null +++ b/test/inspector/test-async-stack-traces-promise-then.js @@ -0,0 +1,69 @@ +'use strict'; +const common = require('../common'); +common.skipIfInspectorDisabled(); +common.skipIf32Bits(); +const helper = require('./inspector-helper'); +const assert = require('assert'); + +const script = `runTest(); +function runTest() { + const p = Promise.resolve(); + p.then(function break1() { // lineNumber 3 + debugger; + }); + p.then(function break2() { // lineNumber 6 + debugger; + }); +} +`; + +helper.startNodeForInspectorTest(runTests, + `--inspect-brk=${common.PORT}`, + script); + +function runTests(harness) { + harness.runFrontendSession([ + helper.setupDebugger, + (session) => { + console.error('[test] Waiting for break1'); + session.expectMessages(debuggerPausedAt('break1', 'runTest:3')); + }, + (session) => { + console.error('[test] Waiting for break2'); + session + .sendInspectorCommands({ method: 'Debugger.resume' }) + .expectMessages(debuggerPausedAt('break2', 'runTest:6')); + }, + (session) => { + console.log('[test] Disconnecting the debugging session'); + session.disconnect(true); + } + ]); + // no need to kill the debugged process, it will quit naturally + + function debuggerPausedAt(functionName, previousTickLocation) { + return function(msg) { + if (msg.method !== 'Debugger.paused') return; + + assert( + !!msg.params.asyncStackTrace, + `${Object.keys(msg.params)} contains "asyncStackTrace" property`); + + assert.strictEqual(msg.params.callFrames[0].functionName, functionName); + assert.strictEqual(msg.params.asyncStackTrace.description, 'PROMISE'); + + const frameLocations = msg.params.asyncStackTrace.callFrames.map( + (frame) => `${frame.functionName}:${frame.lineNumber}`); + assertArrayIncludes(frameLocations, previousTickLocation); + return true; + }; + } + + function assertArrayIncludes(actual, expected) { + const expectedString = JSON.stringify(expected); + const actualString = JSON.stringify(actual); + assert( + actual.includes(expected), + `Expected ${actualString} to contain ${expectedString}.`); + } +} diff --git a/test/inspector/test-async-stack-traces-set-interval.js b/test/inspector/test-async-stack-traces-set-interval.js new file mode 100644 index 00000000000000..6c2f98db4412e5 --- /dev/null +++ b/test/inspector/test-async-stack-traces-set-interval.js @@ -0,0 +1,14 @@ +'use strict'; +const common = require('../common'); +common.skipIfInspectorDisabled(); +common.skipIf32Bits(); +const helper = require('./inspector-helper'); +const assert = require('assert'); + +const script = 'setInterval(() => { debugger; }, 50);'; + +helper.debugScriptAndAssertPausedMessage(script, (msg) => { + assert( + !!msg.params.asyncStackTrace, + `${Object.keys(msg.params)} contains "asyncStackTrace" property`); +}); diff --git a/test/inspector/test-inspector-enabled.js b/test/inspector/test-inspector-enabled.js new file mode 100644 index 00000000000000..a7a0832793283c --- /dev/null +++ b/test/inspector/test-inspector-enabled.js @@ -0,0 +1,26 @@ +'use strict'; +const common = require('../common'); +common.skipIfInspectorDisabled(); + +const spawn = require('child_process').spawn; + +const script = ` +const assert = require('assert'); +const inspector = process.binding('inspector'); + +assert( + !!inspector.isEnabled(), + 'inspector.isEnabled() should be true when run with --inspect'); + +process._debugEnd(); + +assert( + !inspector.isEnabled(), + 'inspector.isEnabled() should be false after _debugEnd()'); +`; + +const args = ['--inspect', '-e', script]; +const child = spawn(process.execPath, args, { stdio: 'inherit' }); +child.on('exit', (code, signal) => { + process.exit(code || signal); +}); diff --git a/test/known_failures/inspector/test-async-hook-setup-at-inspect.js b/test/known_failures/inspector/test-async-hook-setup-at-inspect.js new file mode 100644 index 00000000000000..80e44f6050e6be --- /dev/null +++ b/test/known_failures/inspector/test-async-hook-setup-at-inspect.js @@ -0,0 +1,19 @@ +'use strict'; +const common = require('../common'); +common.skipIfInspectorDisabled(); +common.skipIf32Bits(); +const helper = require('./inspector-helper'); +const assert = require('assert'); + +const script = 'setInterval(() => { debugger; }, 50);'; + +helper.startNodeForInspectorTest(runTests, `--inspect=${common.PORT}`, script); + +function runTests(harness) { + helper.setupDebuggerAndAssertPausedMessage(harness, (msg) => { + assert( + !!msg.params.asyncStackTrace, + `${Object.keys(msg.params)} contains "asyncStackTrace" property`); + }); + harness.kill(); +} diff --git a/test/known_failures/inspector/test-async-hook-setup-at-signal.js b/test/known_failures/inspector/test-async-hook-setup-at-signal.js new file mode 100644 index 00000000000000..586b02e6ad1c27 --- /dev/null +++ b/test/known_failures/inspector/test-async-hook-setup-at-signal.js @@ -0,0 +1,66 @@ +'use strict'; +const common = require('../common'); +common.skipIfInspectorDisabled(); +common.skipIf32Bits(); +const helper = require('./inspector-helper'); +const assert = require('assert'); + +const script = ` +process._rawDebug('Waiting until a signal enables the inspector...'); +let waiting = setInterval(setupIntervalIfDebugged, 50); + +function setupIntervalIfDebugged() { + if (!process.binding('inspector').isEnabled()) return; + clearInterval(waiting); + // It seems that AsyncTask tracking engine may not be initialised yet + // when isEnabled() flag changes to true, therefore we need to introduce + // a small delay. Using a timeout would be brittle and it would unnecesarily + // slow down the test on most machines. + // Triggering a debugger break is a faster and more reliable way. + process._rawDebug('Signal received, waiting for debugger setup'); + waiting = setInterval(() => { debugger; }, 50); +} + +// This function is called by the inspector client (session) +function setupIntervalWithBreak() { + clearInterval(waiting); + process._rawDebug('Debugger ready, setting up interval with a break'); + setInterval(() => { debugger; }, 50); +} +`; + +helper.startNodeAndDebuggerViaSignal(runTests, script); + +function runTests(harness) { + harness.runFrontendSession([ + helper.setupDebugger, + waitForFirstBreak, + continueAndAssertPausedMessage, + (session) => session.disconnect(true), + ]); + + harness.kill(); + + function waitForFirstBreak(session) { + session.expectMessages((msg) => msg.method === 'Debugger.paused'); + } + + function continueAndAssertPausedMessage(session) { + session.sendInspectorCommands([ + { + method: 'Runtime.evaluate', + params: { expression: 'setupIntervalWithBreak()' }, + }, + { + method: 'Debugger.resume', + }]); + + session.expectMessages((msg) => { + if (msg.method !== 'Debugger.paused') return; + assert( + !!msg.params.asyncStackTrace, + `${Object.keys(msg.params)} contains "asyncStackTrace" property`); + return true; + }); + } +} From 0e4e338e8991b266948cd4029e3db0096de37d60 Mon Sep 17 00:00:00 2001 From: Timothy Gu Date: Thu, 17 Aug 2017 14:53:25 +0800 Subject: [PATCH 3/5] test: fix inspector helper port sniffing --- test/inspector/inspector-helper.js | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/test/inspector/inspector-helper.js b/test/inspector/inspector-helper.js index e9464c3679a00c..11e86395407b5c 100644 --- a/test/inspector/inspector-helper.js +++ b/test/inspector/inspector-helper.js @@ -325,9 +325,10 @@ class NodeInstance { console.log('[err]', line); if (this._portCallback) { const matches = line.match(/Debugger listening on ws:\/\/.+:(\d+)\/.+/); - if (matches) + if (matches) { this._portCallback(matches[1]); - this._portCallback = null; + this._portCallback = null; + } } if (this._stderrLineCallback) { this._stderrLineCallback(line); From 8164c77b462596c5a87edee3e1cca289a9207398 Mon Sep 17 00:00:00 2001 From: Timothy Gu Date: Thu, 17 Aug 2017 09:20:25 +0800 Subject: [PATCH 4/5] fixup! convert tests --- test/inspector/inspector-helper.js | 16 +++- .../test-async-hook-setup-at-inspect-brk.js | 48 +++++++--- .../test-async-hook-setup-at-inspect.js | 41 +++++++++ .../test-async-hook-setup-at-signal.js | 79 +++++++++++++++++ .../test-async-stack-traces-promise-then.js | 88 +++++++++---------- .../test-async-stack-traces-set-interval.js | 39 ++++++-- test/inspector/test-inspector.js | 3 +- .../test-async-hook-setup-at-inspect.js | 19 ---- .../test-async-hook-setup-at-signal.js | 66 -------------- 9 files changed, 247 insertions(+), 152 deletions(-) create mode 100644 test/inspector/test-async-hook-setup-at-inspect.js create mode 100644 test/inspector/test-async-hook-setup-at-signal.js delete mode 100644 test/known_failures/inspector/test-async-hook-setup-at-inspect.js delete mode 100644 test/known_failures/inspector/test-async-hook-setup-at-signal.js diff --git a/test/inspector/inspector-helper.js b/test/inspector/inspector-helper.js index 11e86395407b5c..9c1cca3a771293 100644 --- a/test/inspector/inspector-helper.js +++ b/test/inspector/inspector-helper.js @@ -9,7 +9,7 @@ const url = require('url'); const _MAINSCRIPT = path.join(common.fixturesDir, 'loop.js'); const DEBUG = false; -const TIMEOUT = 15 * 1000; +const TIMEOUT = common.platformTimeout(15 * 1000); function spawnChildProcess(inspectorFlags, scriptContents, scriptFile) { const args = [].concat(inspectorFlags); @@ -253,9 +253,7 @@ class InspectorSession { .waitForNotification( (notification) => this._isBreakOnLineNotification(notification, line, url), - `break on ${url}:${line}`) - .then((notification) => - notification.params.callFrames[0].scopeChain[0].object.objectId); + `break on ${url}:${line}`); } _matchesConsoleOutputNotification(notification, type, values) { @@ -321,6 +319,16 @@ class NodeInstance { }); } + static async startViaSignal(scriptContents) { + const instance = new NodeInstance( + [], `${scriptContents}\nprocess._rawDebug('started');`, undefined); + const msg = 'Timed out waiting for process to start'; + while (await common.fires(instance.nextStderrString(), msg, TIMEOUT) !== + 'started') {} + process._debugProcess(instance._process.pid); + return instance; + } + onStderrLine(line) { console.log('[err]', line); if (this._portCallback) { diff --git a/test/inspector/test-async-hook-setup-at-inspect-brk.js b/test/inspector/test-async-hook-setup-at-inspect-brk.js index 535bf555e0e7bb..70887ff63d9d4e 100644 --- a/test/inspector/test-async-hook-setup-at-inspect-brk.js +++ b/test/inspector/test-async-hook-setup-at-inspect-brk.js @@ -2,20 +2,44 @@ const common = require('../common'); common.skipIfInspectorDisabled(); common.skipIf32Bits(); -const helper = require('./inspector-helper'); +common.crashOnUnhandledRejection(); +const { NodeInstance } = require('./inspector-helper.js'); const assert = require('assert'); -const script = 'setTimeout(() => { debugger; }, 50);'; +const script = ` +setTimeout(() => { + debugger; + process.exitCode = 55; +}, 50); +`; -helper.startNodeForInspectorTest(runTests, - `--inspect-brk=${common.PORT}`, - script); +async function checkAsyncStackTrace(session) { + console.error('[test]', 'Verify basic properties of asyncStackTrace'); + const paused = await session.waitForBreakOnLine(2, '[eval]'); + assert(paused.params.asyncStackTrace, + `${Object.keys(paused.params)} contains "asyncStackTrace" property`); + assert(paused.params.asyncStackTrace.description, 'Timeout'); + assert(paused.params.asyncStackTrace.callFrames + .some((frame) => frame.functionName === 'Module._compile')); +} + +async function runTests() { + const instance = new NodeInstance(undefined, script); + const session = await instance.connectInspectorSession(); + await session.send([ + { 'method': 'Runtime.enable' }, + { 'method': 'Debugger.enable' }, + { 'method': 'Debugger.setAsyncCallStackDepth', + 'params': { 'maxDepth': 10 } }, + { 'method': 'Debugger.setBlackboxPatterns', + 'params': { 'patterns': [] } }, + { 'method': 'Runtime.runIfWaitingForDebugger' } + ]); -function runTests(harness) { - helper.setupDebuggerAndAssertPausedMessage(harness, (msg) => { - assert( - !!msg.params.asyncStackTrace, - `${Object.keys(msg.params)} contains "asyncStackTrace" property`); - }); - // no need to kill the debugged process, it will quit naturally + await checkAsyncStackTrace(session); + + await session.runToCompletion(); + assert.strictEqual(55, (await instance.expectShutdown()).exitCode); } + +runTests(); diff --git a/test/inspector/test-async-hook-setup-at-inspect.js b/test/inspector/test-async-hook-setup-at-inspect.js new file mode 100644 index 00000000000000..7f2111c516e2af --- /dev/null +++ b/test/inspector/test-async-hook-setup-at-inspect.js @@ -0,0 +1,41 @@ +'use strict'; +const common = require('../common'); +common.skipIfInspectorDisabled(); +common.skipIf32Bits(); +common.crashOnUnhandledRejection(); +const { NodeInstance } = require('../inspector/inspector-helper.js'); +const assert = require('assert'); + +const script = 'setInterval(() => { debugger; }, 50);'; + +async function checkAsyncStackTrace(session) { + console.error('[test]', 'Verify basic properties of asyncStackTrace'); + const paused = await session.waitForBreakOnLine(0, '[eval]'); + assert(paused.params.asyncStackTrace, + `${Object.keys(paused.params)} contains "asyncStackTrace" property`); + assert(paused.params.asyncStackTrace.description, 'Timeout'); + assert(paused.params.asyncStackTrace.callFrames + .some((frame) => frame.functionName === 'Module._compile')); +} + +async function runTests() { + const instance = new NodeInstance(['--inspect=0'], script); + const session = await instance.connectInspectorSession(); + await session.send([ + { 'method': 'Runtime.enable' }, + { 'method': 'Debugger.enable' }, + { 'method': 'Debugger.setAsyncCallStackDepth', + 'params': { 'maxDepth': 10 } }, + { 'method': 'Debugger.setBlackboxPatterns', + 'params': { 'patterns': [] } }, + { 'method': 'Runtime.runIfWaitingForDebugger' } + ]); + + await checkAsyncStackTrace(session); + + console.error('[test]', 'Stopping child instance'); + session.disconnect(); + instance.kill(); +} + +runTests(); diff --git a/test/inspector/test-async-hook-setup-at-signal.js b/test/inspector/test-async-hook-setup-at-signal.js new file mode 100644 index 00000000000000..0b39248fba91a8 --- /dev/null +++ b/test/inspector/test-async-hook-setup-at-signal.js @@ -0,0 +1,79 @@ +'use strict'; +const common = require('../common'); +common.skipIfInspectorDisabled(); +common.skipIf32Bits(); +common.crashOnUnhandledRejection(); +const { NodeInstance } = require('../inspector/inspector-helper.js'); +const assert = require('assert'); + +const script = ` +process._rawDebug('Waiting until a signal enables the inspector...'); +let waiting = setInterval(setupIntervalIfDebugged, 50); + +function setupIntervalIfDebugged() { + if (!process.binding('inspector').isEnabled()) return; + clearInterval(waiting); + // It seems that AsyncTask tracking engine may not be initialised yet + // when isEnabled() flag changes to true, therefore we need to introduce + // a small delay. Using a timeout would be brittle and it would unnecesarily + // slow down the test on most machines. + // Triggering a debugger break is a faster and more reliable way. + process._rawDebug('Signal received, waiting for debugger setup'); + waiting = setInterval(() => { debugger; }, 50); +} + +// This function is called by the inspector client (session) +function setupIntervalWithBreak() { + clearInterval(waiting); + process._rawDebug('Debugger ready, setting up interval with a break'); + setInterval(() => { debugger; }, 50); +} +`; + +async function waitForInitialSetup(session) { + console.error('[test]', 'Waiting for initial setup'); + await session.waitForBreakOnLine(13, '[eval]'); +} + +async function setupOwnInterval(session) { + console.error('[test]', 'Setting up our own interval'); + await session.send([ + { 'method': 'Runtime.evaluate', + 'params': { expression: 'setupIntervalWithBreak()' } }, + { 'method': 'Debugger.resume' } + ]); +} + +async function checkAsyncStackTrace(session) { + console.error('[test]', 'Verify basic properties of asyncStackTrace'); + const paused = await session.waitForBreakOnLine(20, '[eval]'); + assert(paused.params.asyncStackTrace, + `${Object.keys(paused.params)} contains "asyncStackTrace" property`); + assert(paused.params.asyncStackTrace.description, 'Timeout'); + assert(paused.params.asyncStackTrace.callFrames + .some((frame) => frame.functionName === 'setupIntervalWithBreak')); +} + +async function runTests() { + const instance = await NodeInstance.startViaSignal(script); + const session = await instance.connectInspectorSession(); + await session.send([ + { 'method': 'Runtime.enable' }, + { 'method': 'Debugger.enable' }, + { 'method': 'Debugger.setAsyncCallStackDepth', + 'params': { 'maxDepth': 10 } }, + { 'method': 'Debugger.setBlackboxPatterns', + 'params': { 'patterns': [] } }, + { 'method': 'Runtime.runIfWaitingForDebugger' } + ]); + + await waitForInitialSetup(session); + await setupOwnInterval(session); + await checkAsyncStackTrace(session); + + console.error('[test]', 'Stopping child instance'); + session.disconnect(); + instance.kill(); +} + +runTests(); diff --git a/test/inspector/test-async-stack-traces-promise-then.js b/test/inspector/test-async-stack-traces-promise-then.js index a8927f78fdfeac..68584b0a3c5dad 100644 --- a/test/inspector/test-async-stack-traces-promise-then.js +++ b/test/inspector/test-async-stack-traces-promise-then.js @@ -2,7 +2,8 @@ const common = require('../common'); common.skipIfInspectorDisabled(); common.skipIf32Bits(); -const helper = require('./inspector-helper'); +common.crashOnUnhandledRejection(); +const { NodeInstance } = require('./inspector-helper'); const assert = require('assert'); const script = `runTest(); @@ -17,53 +18,52 @@ function runTest() { } `; -helper.startNodeForInspectorTest(runTests, - `--inspect-brk=${common.PORT}`, - script); - -function runTests(harness) { - harness.runFrontendSession([ - helper.setupDebugger, - (session) => { - console.error('[test] Waiting for break1'); - session.expectMessages(debuggerPausedAt('break1', 'runTest:3')); - }, - (session) => { - console.error('[test] Waiting for break2'); - session - .sendInspectorCommands({ method: 'Debugger.resume' }) - .expectMessages(debuggerPausedAt('break2', 'runTest:6')); - }, - (session) => { - console.log('[test] Disconnecting the debugging session'); - session.disconnect(true); - } +async function runTests() { + const instance = new NodeInstance(undefined, script); + const session = await instance.connectInspectorSession(); + await session.send([ + { 'method': 'Runtime.enable' }, + { 'method': 'Debugger.enable' }, + { 'method': 'Debugger.setAsyncCallStackDepth', + 'params': { 'maxDepth': 10 } }, + { 'method': 'Debugger.setBlackboxPatterns', + 'params': { 'patterns': [] } }, + { 'method': 'Runtime.runIfWaitingForDebugger' } ]); - // no need to kill the debugged process, it will quit naturally - function debuggerPausedAt(functionName, previousTickLocation) { - return function(msg) { - if (msg.method !== 'Debugger.paused') return; + console.error('[test] Waiting for break1'); + debuggerPausedAt(await session.waitForBreakOnLine(4, '[eval]'), + 'break1', 'runTest:3'); + + await session.send({ 'method': 'Debugger.resume' }); - assert( - !!msg.params.asyncStackTrace, - `${Object.keys(msg.params)} contains "asyncStackTrace" property`); + console.error('[test] Waiting for break2'); + debuggerPausedAt(await session.waitForBreakOnLine(7, '[eval]'), + 'break2', 'runTest:6'); + + await session.runToCompletion(); + assert.strictEqual(0, (await instance.expectShutdown()).exitCode); +} - assert.strictEqual(msg.params.callFrames[0].functionName, functionName); - assert.strictEqual(msg.params.asyncStackTrace.description, 'PROMISE'); +function debuggerPausedAt(msg, functionName, previousTickLocation) { + assert( + !!msg.params.asyncStackTrace, + `${Object.keys(msg.params)} contains "asyncStackTrace" property`); - const frameLocations = msg.params.asyncStackTrace.callFrames.map( - (frame) => `${frame.functionName}:${frame.lineNumber}`); - assertArrayIncludes(frameLocations, previousTickLocation); - return true; - }; - } + assert.strictEqual(msg.params.callFrames[0].functionName, functionName); + assert.strictEqual(msg.params.asyncStackTrace.description, 'PROMISE'); - function assertArrayIncludes(actual, expected) { - const expectedString = JSON.stringify(expected); - const actualString = JSON.stringify(actual); - assert( - actual.includes(expected), - `Expected ${actualString} to contain ${expectedString}.`); - } + const frameLocations = msg.params.asyncStackTrace.callFrames.map( + (frame) => `${frame.functionName}:${frame.lineNumber}`); + assertArrayIncludes(frameLocations, previousTickLocation); } + +function assertArrayIncludes(actual, expected) { + const expectedString = JSON.stringify(expected); + const actualString = JSON.stringify(actual); + assert( + actual.includes(expected), + `Expected ${actualString} to contain ${expectedString}.`); +} + +runTests(); diff --git a/test/inspector/test-async-stack-traces-set-interval.js b/test/inspector/test-async-stack-traces-set-interval.js index 6c2f98db4412e5..bc96df9588fc6a 100644 --- a/test/inspector/test-async-stack-traces-set-interval.js +++ b/test/inspector/test-async-stack-traces-set-interval.js @@ -2,13 +2,40 @@ const common = require('../common'); common.skipIfInspectorDisabled(); common.skipIf32Bits(); -const helper = require('./inspector-helper'); +common.crashOnUnhandledRejection(); +const { NodeInstance } = require('./inspector-helper'); const assert = require('assert'); const script = 'setInterval(() => { debugger; }, 50);'; -helper.debugScriptAndAssertPausedMessage(script, (msg) => { - assert( - !!msg.params.asyncStackTrace, - `${Object.keys(msg.params)} contains "asyncStackTrace" property`); -}); +async function checkAsyncStackTrace(session) { + console.error('[test]', 'Verify basic properties of asyncStackTrace'); + const paused = await session.waitForBreakOnLine(0, '[eval]'); + assert(paused.params.asyncStackTrace, + `${Object.keys(paused.params)} contains "asyncStackTrace" property`); + assert(paused.params.asyncStackTrace.description, 'Timeout'); + assert(paused.params.asyncStackTrace.callFrames + .some((frame) => frame.functionName === 'Module._compile')); +} + +async function runTests() { + const instance = new NodeInstance(undefined, script); + const session = await instance.connectInspectorSession(); + await session.send([ + { 'method': 'Runtime.enable' }, + { 'method': 'Debugger.enable' }, + { 'method': 'Debugger.setAsyncCallStackDepth', + 'params': { 'maxDepth': 10 } }, + { 'method': 'Debugger.setBlackboxPatterns', + 'params': { 'patterns': [] } }, + { 'method': 'Runtime.runIfWaitingForDebugger' } + ]); + + await checkAsyncStackTrace(session); + + console.error('[test]', 'Stopping child instance'); + session.disconnect(); + instance.kill(); +} + +runTests(); diff --git a/test/inspector/test-inspector.js b/test/inspector/test-inspector.js index 3139940451a515..6a5dbe60030a64 100644 --- a/test/inspector/test-inspector.js +++ b/test/inspector/test-inspector.js @@ -98,7 +98,8 @@ async function testBreakpoint(session) { `Script source is wrong: ${scriptSource}`); await session.waitForConsoleOutput('log', ['A message', 5]); - const scopeId = await session.waitForBreakOnLine(5, mainScriptPath); + const paused = await session.waitForBreakOnLine(5, mainScriptPath); + const scopeId = paused.params.callFrames[0].scopeChain[0].object.objectId; console.log('[test]', 'Verify we can read current application state'); const response = await session.send({ diff --git a/test/known_failures/inspector/test-async-hook-setup-at-inspect.js b/test/known_failures/inspector/test-async-hook-setup-at-inspect.js deleted file mode 100644 index 80e44f6050e6be..00000000000000 --- a/test/known_failures/inspector/test-async-hook-setup-at-inspect.js +++ /dev/null @@ -1,19 +0,0 @@ -'use strict'; -const common = require('../common'); -common.skipIfInspectorDisabled(); -common.skipIf32Bits(); -const helper = require('./inspector-helper'); -const assert = require('assert'); - -const script = 'setInterval(() => { debugger; }, 50);'; - -helper.startNodeForInspectorTest(runTests, `--inspect=${common.PORT}`, script); - -function runTests(harness) { - helper.setupDebuggerAndAssertPausedMessage(harness, (msg) => { - assert( - !!msg.params.asyncStackTrace, - `${Object.keys(msg.params)} contains "asyncStackTrace" property`); - }); - harness.kill(); -} diff --git a/test/known_failures/inspector/test-async-hook-setup-at-signal.js b/test/known_failures/inspector/test-async-hook-setup-at-signal.js deleted file mode 100644 index 586b02e6ad1c27..00000000000000 --- a/test/known_failures/inspector/test-async-hook-setup-at-signal.js +++ /dev/null @@ -1,66 +0,0 @@ -'use strict'; -const common = require('../common'); -common.skipIfInspectorDisabled(); -common.skipIf32Bits(); -const helper = require('./inspector-helper'); -const assert = require('assert'); - -const script = ` -process._rawDebug('Waiting until a signal enables the inspector...'); -let waiting = setInterval(setupIntervalIfDebugged, 50); - -function setupIntervalIfDebugged() { - if (!process.binding('inspector').isEnabled()) return; - clearInterval(waiting); - // It seems that AsyncTask tracking engine may not be initialised yet - // when isEnabled() flag changes to true, therefore we need to introduce - // a small delay. Using a timeout would be brittle and it would unnecesarily - // slow down the test on most machines. - // Triggering a debugger break is a faster and more reliable way. - process._rawDebug('Signal received, waiting for debugger setup'); - waiting = setInterval(() => { debugger; }, 50); -} - -// This function is called by the inspector client (session) -function setupIntervalWithBreak() { - clearInterval(waiting); - process._rawDebug('Debugger ready, setting up interval with a break'); - setInterval(() => { debugger; }, 50); -} -`; - -helper.startNodeAndDebuggerViaSignal(runTests, script); - -function runTests(harness) { - harness.runFrontendSession([ - helper.setupDebugger, - waitForFirstBreak, - continueAndAssertPausedMessage, - (session) => session.disconnect(true), - ]); - - harness.kill(); - - function waitForFirstBreak(session) { - session.expectMessages((msg) => msg.method === 'Debugger.paused'); - } - - function continueAndAssertPausedMessage(session) { - session.sendInspectorCommands([ - { - method: 'Runtime.evaluate', - params: { expression: 'setupIntervalWithBreak()' }, - }, - { - method: 'Debugger.resume', - }]); - - session.expectMessages((msg) => { - if (msg.method !== 'Debugger.paused') return; - assert( - !!msg.params.asyncStackTrace, - `${Object.keys(msg.params)} contains "asyncStackTrace" property`); - return true; - }); - } -} From c197bc88d2213540b7e03f0c89e9959beece1ca6 Mon Sep 17 00:00:00 2001 From: Timothy Gu Date: Thu, 17 Aug 2017 11:12:48 +0800 Subject: [PATCH 5/5] fixup! make tests more robust --- test/common/index.js | 1 - .../test-async-hook-setup-at-inspect.js | 35 ++++++++++++++++-- .../test-async-hook-setup-at-signal.js | 36 ++++++++++--------- 3 files changed, 51 insertions(+), 21 deletions(-) diff --git a/test/common/index.js b/test/common/index.js index c3dd788661a49c..8175474818b9dc 100644 --- a/test/common/index.js +++ b/test/common/index.js @@ -749,7 +749,6 @@ exports.skipIfInspectorDisabled = function skipIfInspectorDisabled() { exports.skipIf32Bits = function skipIf32Bits() { if (process.binding('config').bits < 64) { exports.skip('The tested feature is not available in 32bit builds'); - process.exit(0); } }; diff --git a/test/inspector/test-async-hook-setup-at-inspect.js b/test/inspector/test-async-hook-setup-at-inspect.js index 7f2111c516e2af..bbf418a858838c 100644 --- a/test/inspector/test-async-hook-setup-at-inspect.js +++ b/test/inspector/test-async-hook-setup-at-inspect.js @@ -6,16 +6,43 @@ common.crashOnUnhandledRejection(); const { NodeInstance } = require('../inspector/inspector-helper.js'); const assert = require('assert'); -const script = 'setInterval(() => { debugger; }, 50);'; +// Even with --inspect, the default async call stack depth is 0. We need a +// chance to call Debugger.setAsyncCallStackDepth *before* activating the timer +// for async stack traces to work. +const script = ` +process._rawDebug('Waiting until the inspector is activated...'); +const waiting = setInterval(() => { debugger; }, 50); + +// This function is called by the inspector client (session) +function setupTimeoutWithBreak() { + clearInterval(waiting); + process._rawDebug('Debugger ready, setting up timeout with a break'); + setTimeout(() => { debugger; }, 50); +} +`; + +async function waitForInitialSetup(session) { + console.error('[test]', 'Waiting for initial setup'); + await session.waitForBreakOnLine(2, '[eval]'); +} + +async function setupTimeoutForStackTrace(session) { + console.error('[test]', 'Setting up timeout for async stack trace'); + await session.send([ + { 'method': 'Runtime.evaluate', + 'params': { expression: 'setupTimeoutWithBreak()' } }, + { 'method': 'Debugger.resume' } + ]); +} async function checkAsyncStackTrace(session) { console.error('[test]', 'Verify basic properties of asyncStackTrace'); - const paused = await session.waitForBreakOnLine(0, '[eval]'); + const paused = await session.waitForBreakOnLine(8, '[eval]'); assert(paused.params.asyncStackTrace, `${Object.keys(paused.params)} contains "asyncStackTrace" property`); assert(paused.params.asyncStackTrace.description, 'Timeout'); assert(paused.params.asyncStackTrace.callFrames - .some((frame) => frame.functionName === 'Module._compile')); + .some((frame) => frame.functionName === 'setupTimeoutWithBreak')); } async function runTests() { @@ -31,6 +58,8 @@ async function runTests() { { 'method': 'Runtime.runIfWaitingForDebugger' } ]); + await waitForInitialSetup(session); + await setupTimeoutForStackTrace(session); await checkAsyncStackTrace(session); console.error('[test]', 'Stopping child instance'); diff --git a/test/inspector/test-async-hook-setup-at-signal.js b/test/inspector/test-async-hook-setup-at-signal.js index 0b39248fba91a8..f0150bc7acc0a9 100644 --- a/test/inspector/test-async-hook-setup-at-signal.js +++ b/test/inspector/test-async-hook-setup-at-signal.js @@ -8,50 +8,52 @@ const assert = require('assert'); const script = ` process._rawDebug('Waiting until a signal enables the inspector...'); -let waiting = setInterval(setupIntervalIfDebugged, 50); +let waiting = setInterval(waitUntilDebugged, 50); -function setupIntervalIfDebugged() { +function waitUntilDebugged() { if (!process.binding('inspector').isEnabled()) return; clearInterval(waiting); - // It seems that AsyncTask tracking engine may not be initialised yet - // when isEnabled() flag changes to true, therefore we need to introduce - // a small delay. Using a timeout would be brittle and it would unnecesarily - // slow down the test on most machines. - // Triggering a debugger break is a faster and more reliable way. + // At this point, even though the Inspector is enabled, the default async + // call stack depth is 0. We need a chance to call + // Debugger.setAsyncCallStackDepth *before* activating the actual timer for + // async stack traces to work. Directly using a debugger statement would be + // too brittle, and using a longer timeout would unnecesarily slow down the + // test on most machines. Triggering a debugger break through an interval is + // a faster and more reliable way. process._rawDebug('Signal received, waiting for debugger setup'); waiting = setInterval(() => { debugger; }, 50); } // This function is called by the inspector client (session) -function setupIntervalWithBreak() { +function setupTimeoutWithBreak() { clearInterval(waiting); - process._rawDebug('Debugger ready, setting up interval with a break'); - setInterval(() => { debugger; }, 50); + process._rawDebug('Debugger ready, setting up timeout with a break'); + setTimeout(() => { debugger; }, 50); } `; async function waitForInitialSetup(session) { console.error('[test]', 'Waiting for initial setup'); - await session.waitForBreakOnLine(13, '[eval]'); + await session.waitForBreakOnLine(15, '[eval]'); } -async function setupOwnInterval(session) { - console.error('[test]', 'Setting up our own interval'); +async function setupTimeoutForStackTrace(session) { + console.error('[test]', 'Setting up timeout for async stack trace'); await session.send([ { 'method': 'Runtime.evaluate', - 'params': { expression: 'setupIntervalWithBreak()' } }, + 'params': { expression: 'setupTimeoutWithBreak()' } }, { 'method': 'Debugger.resume' } ]); } async function checkAsyncStackTrace(session) { console.error('[test]', 'Verify basic properties of asyncStackTrace'); - const paused = await session.waitForBreakOnLine(20, '[eval]'); + const paused = await session.waitForBreakOnLine(22, '[eval]'); assert(paused.params.asyncStackTrace, `${Object.keys(paused.params)} contains "asyncStackTrace" property`); assert(paused.params.asyncStackTrace.description, 'Timeout'); assert(paused.params.asyncStackTrace.callFrames - .some((frame) => frame.functionName === 'setupIntervalWithBreak')); + .some((frame) => frame.functionName === 'setupTimeoutWithBreak')); } async function runTests() { @@ -68,7 +70,7 @@ async function runTests() { ]); await waitForInitialSetup(session); - await setupOwnInterval(session); + await setupTimeoutForStackTrace(session); await checkAsyncStackTrace(session); console.error('[test]', 'Stopping child instance');