Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

inspector: track async stacks when necessary #16260

Closed
wants to merge 3 commits into from
Closed
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 0 additions & 6 deletions lib/internal/inspector_async_hook.js
Original file line number Diff line number Diff line change
Expand Up @@ -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();
}
};
4 changes: 4 additions & 0 deletions src/env.h
Original file line number Diff line number Diff line change
Expand Up @@ -101,6 +101,7 @@ class ModuleWrap;
V(address_string, "address") \
V(args_string, "args") \
V(async, "async") \
V(async_stack_depth_string, "Debugger.setAsyncCallStackDepth") \
V(buffer_string, "buffer") \
V(bytes_string, "bytes") \
V(bytes_parsed_string, "bytesParsed") \
Expand Down Expand Up @@ -185,7 +186,9 @@ class ModuleWrap;
V(length_string, "length") \
V(mac_string, "mac") \
V(max_buffer_string, "maxBuffer") \
V(max_depth_string, "maxDepth") \
V(message_string, "message") \
V(method_string, "method") \
V(minttl_string, "minttl") \
V(model_string, "model") \
V(modulus_string, "modulus") \
Expand Down Expand Up @@ -228,6 +231,7 @@ class ModuleWrap;
V(output_string, "output") \
V(order_string, "order") \
V(owner_string, "owner") \
V(params_string, "params") \
V(parse_error_string, "Parse Error") \
V(path_string, "path") \
V(pbkdf2_error_string, "PBKDF2 Error") \
Expand Down
160 changes: 133 additions & 27 deletions src/inspector_agent.cc
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,10 @@ using v8::Function;
using v8::HandleScope;
using v8::Isolate;
using v8::Local;
using v8::Maybe;
using v8::MaybeLocal;
using v8::Object;
using v8::String;
using v8::Value;

using v8_inspector::StringBuffer;
Expand Down Expand Up @@ -449,7 +452,9 @@ Agent::Agent(Environment* env) : parent_env_(env),
client_(nullptr),
platform_(nullptr),
enabled_(false),
next_context_number_(1) {}
next_context_number_(1),
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Question: any reason do keep using initialization lists when we support C++11 (i.e. "Class Member Initialization")?

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.
Expand Down Expand Up @@ -497,18 +502,6 @@ 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<Function> 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
Local<Object> process_object = parent_env_->process_object();
Local<Value> emit_fn =
Expand Down Expand Up @@ -554,20 +547,6 @@ void Agent::Stop() {
}

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<Function> 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);
}
Expand All @@ -593,6 +572,7 @@ void Agent::FatalException(Local<Value> error, Local<v8::Message> message) {

void Agent::Dispatch(const StringView& message) {
CHECK_NE(client_, nullptr);
InterceptAsyncStackDepthMessage(message);
client_->dispatchMessageFromFrontend(message);
}

Expand Down Expand Up @@ -625,6 +605,37 @@ void Agent::RegisterAsyncHook(Isolate* isolate,
v8::Local<v8::Function> disable_function) {
enable_async_hook_function_.Reset(isolate, enable_function);
disable_async_hook_function_.Reset(isolate, disable_function);
if (pending_enable_async_hook_) {
pending_enable_async_hook_ = false;
EnableAsyncHook(isolate);
} else if (pending_disable_async_hook_) {
pending_disable_async_hook_ = false;
DisableAsyncHook(isolate);
}
}

void Agent::EnableAsyncHook(Isolate* isolate) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would be good to add a HandleScope here and in the method below because currently they leak handles into the caller's HandleScope. It's harmless right now but could become an issue in future refactorings.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

CHECK(!enable_async_hook_function_.IsEmpty());
Local<Function> 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::inspector::Agent::EnableAsyncHook",
"Cannot enable Inspector's AsyncHook, please report this.");
}
}

void Agent::DisableAsyncHook(Isolate* isolate) {
CHECK(!disable_async_hook_function_.IsEmpty());
Local<Function> disable_fn = disable_async_hook_function_.Get(isolate);
auto context = parent_env_->context();
auto result = disable_fn->Call(context, Undefined(isolate), 0, nullptr);
if (result.IsEmpty()) {
FatalError(
"node::inspector::Agent::DisableAsyncHook",
"Cannot disable Inspector's AsyncHook, please report this.");
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These two methods could be dedup'd, e.g., by passing the Persistent<Function> to use as a parameter (and the name in the error message as a string.)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

}

void Agent::AsyncTaskScheduled(const StringView& task_name, void* task,
Expand All @@ -648,6 +659,101 @@ void Agent::AllAsyncTasksCanceled() {
client_->AllAsyncTasksCanceled();
}

void Agent::InterceptAsyncStackDepthMessage(const StringView& message) {
// This logic would be better implemented in JavaScript, but when using
// --inspect-brk, the debugger must necessarily attach before much JavaScript
// can execute. The Debugger.setAsyncCallStackDepth message arrives too early
// and we must intercept this in C++.

v8::Isolate* isolate = parent_env_->isolate();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This method looks like it needs a HandleScope.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

Local<Context> context = parent_env_->context();

MaybeLocal<String> string =
String::NewFromTwoByte(isolate, message.characters16(),
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

StringView does not convert between encodings. I believe, right now all messages are 16 bit. Can you add CHECK (!message.is8Bit()) just to be sure?

v8::NewStringType::kNormal, message.length());
if (string.IsEmpty()) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I can’t really tell how relevant performance is here, but if it makes sense to you, maybe add an early return if message doesn’t contain the substring Debugger.setAsync?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think it would be good to improve performance here, but that's a non-critical optimization and can be addressed once this lands. I have left a TODO.

return;
}

// Basically, the logic we want to implement is:
// let parsed; try {
// parsed = JSON.parse(string);
// } catch (e) { return; }
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there a TryCatch that corresponds to this conceptual try/catch? If so, it’s not obvious where… or, rather: If there is none, what happens with the exception if JSON.parse throws?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't believe that the v8::JSON::Parse API throws on a parse error (unlike the JavaScript JSON.parse). This is the comment I am basing this on: https://cs.chromium.org/chromium/src/v8/include/v8.h?type=cs&l=1815.

/cc @nodejs/v8 if my understanding here is incorrect.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Okay, tried it out myself. v8::JSON::Parse does indeed throw. I will add a TryCatch.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ofrobots Fwiw, as I understand it it’s a general principle of the V8 API that if a Maybe method returns an empty value, there is a corresponding pending exception

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

// if (parsed && parsed.method && parsed.method === 'Debugger.setAsync..' &&
// parsed.params && parsed.params.maxDepth &&
// typeof parsed.params.maxDepth === 'number') {
// // Enable or Disable, depending on maxDepth.
// }
//
// We ignore (return early) on malformed messages and let v8-inspector deal
// with them.

MaybeLocal<Value> maybe_parsed =
v8::JSON::Parse(context, string.ToLocalChecked());
if (maybe_parsed.IsEmpty()) {
return;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hint: what @addaleax is saying is that the return here won't make the exception magically go away. To replicate the return in JS a v8::TryCatch is needed.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Addressed.

}

Local<Value> parsed = maybe_parsed.ToLocalChecked();
if (!parsed->IsObject()) {
return;
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You could shorten this to:

Local<Value> scratch;
Local<Object> parsed;
if (!v8::JSON::Parse(context, string).ToLocal(&scratch) ||
    !scratch->IsObject() ||
    !scratch->ToObject(context).ToLocal(&parsed)) {
  return;
}

(General observation, applies to not just this block of code.)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks. Done.

It might be possible to condense the code a bit further along these lines, but I left it at a point which seemed to be a good balance between terseness and readability.


Local<Object> object = parsed.As<Object>();

Local<Value> method;
if (!object->Get(context, parent_env_->method_string()).ToLocal(&method) ||
!method->IsString() ||
!method->StrictEquals(parent_env_->async_stack_depth_string())) {
return;
}

Local<Value> params;
if (!object->Get(context, parent_env_->params_string()).ToLocal(&params) ||
!params->IsObject()) {
return;
}

Local<Value> depth_value;
if (!params.As<Object>()->Get(context, parent_env_->max_depth_string())
.ToLocal(&depth_value) ||
!depth_value->IsNumber()) {
return;
}

Maybe<double> maybe_depth = depth_value->NumberValue(context);
if (maybe_depth.IsNothing()) {
return;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this can’t actually be the case since you checked depths_value->IsNumber()

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

}

double depth = maybe_depth.FromJust();
if (depth == 0) {
// Disable.
if (!disable_async_hook_function_.IsEmpty()) {
DisableAsyncHook(isolate);
} else {
if (pending_enable_async_hook_) {
CHECK(!pending_disable_async_hook_);
pending_enable_async_hook_ = false;
} else {
pending_disable_async_hook_ = true;
}
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could this be flattened like this?

if (pending_enable_async_hook_) {
  // ...
} else if (!disable_async_hook_function_.IsEmpty()) {
  // ...
} else {
  // ...
}

If not, a code comment explaining why is probably in order.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

} else {
// Enable.
if (!enable_async_hook_function_.IsEmpty()) {
EnableAsyncHook(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::RequestIoThreadStart() {
// We need to attempt to interrupt V8 flow (in case Node is running
// continuous JS code) and to wake up libuv thread (in case Node is waiting
Expand Down
6 changes: 6 additions & 0 deletions src/inspector_agent.h
Original file line number Diff line number Diff line change
Expand Up @@ -62,6 +62,7 @@ class Agent {
void AsyncTaskStarted(void* task);
void AsyncTaskFinished(void* task);
void AllAsyncTasksCanceled();
void InterceptAsyncStackDepthMessage(const v8_inspector::StringView& message);

void RegisterAsyncHook(v8::Isolate* isolate,
v8::Local<v8::Function> enable_function,
Expand Down Expand Up @@ -93,6 +94,9 @@ class Agent {
void ContextCreated(v8::Local<v8::Context> context);

private:
void EnableAsyncHook(v8::Isolate* isolate);
void DisableAsyncHook(v8::Isolate* isolate);

node::Environment* parent_env_;
std::unique_ptr<NodeInspectorClient> client_;
std::unique_ptr<InspectorIo> io_;
Expand All @@ -102,6 +106,8 @@ class Agent {
DebugOptions debug_options_;
int next_context_number_;

bool pending_enable_async_hook_;
bool pending_disable_async_hook_;
v8::Persistent<v8::Function> enable_async_hook_function_;
v8::Persistent<v8::Function> disable_async_hook_function_;
};
Expand Down
55 changes: 55 additions & 0 deletions test/inspector/test-async-hook-inspector.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,55 @@
'use strict';
const common = require('../common');
common.skipIfInspectorDisabled();
common.skipIf32Bits();

const assert = require('assert');
const async_hooks = require('async_hooks');
const inspector = require('inspector');

// Verify that inspector-async-hook is not registered,
// thus emitInit() ignores invalid arguments
// See test/async-hooks/test-emit-init.js
function verifyAsyncHookDisabled(message) {
assert.doesNotThrow(() => async_hooks.emitInit(), message);
}

// 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
function verifyAsyncHookEnabled(message) {
assert.throws(() => async_hooks.emitInit(), message);
}

// 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('creating a session should not enable async hooks');

session.post('Debugger.setAsyncCallStackDepth', { invalid: 'message' }, () => {
verifyAsyncHookDisabled('invalid message should not enable async hooks');

session.post('Debugger.setAsyncCallStackDepth', { maxDepth: 'five' }, () => {
verifyAsyncHookDisabled('invalid maxDepth (sting) should not enable async' +
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

typo: sting - should be string?

' hooks');

session.post('Debugger.setAsyncCallStackDepth', { maxDepth: NaN }, () => {
verifyAsyncHookDisabled('invalid maxDepth (NaN) should not enable async' +
' hooks');
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Tiny nit: can you line this up here and below?


session.post('Debugger.setAsyncCallStackDepth', { maxDepth: 10 }, () => {
verifyAsyncHookEnabled('valid message should enable async hook');

session.post('Debugger.setAsyncCallStackDepth', { maxDepth: 0 }, () => {
verifyAsyncHookDisabled('Setting maxDepth to 0 should disable ' +
'async hooks');
});
});
});
});
});
33 changes: 0 additions & 33 deletions test/inspector/test-async-hook-teardown-at-debug-end.js

This file was deleted.