-
Notifications
You must be signed in to change notification settings - Fork 29.6k
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
Report async tasks to V8 Inspector #13870
Changes from all commits
7a0e3b8
97ea1cb
0e4e338
8164c77
c197bc8
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -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(); | ||
} | ||
}; |
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -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<Function> enable_fn = enable_async_hook_function_.Get(isolate); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. The function should be called in ConnectJSBindingsSession as well. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Done in eb1bca3, PTAL. I have literally zero knowledge about There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I'll tak a look at the commit tomorrow, but the function is used in the JS bindings API for inspector (require('inspector').Session). Check its documentation for how to use it. #14231 has a few examples of how to test it. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Uff, I am afraid this is a bit over my head. Would it be a problem to land my pull request without any tests for There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Actually I think it should be all good now, as that function calls There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Oh you mean tests. Yeah i'm alright with that. We are exploring ways to make inspector tests easier for both the current WS and local JS version in #14460, so we can always add it later! |
||
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<Object> process_object = parent_env_->process_object(); | ||
Local<Value> 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<Function> disable_fn = disable_async_hook_function_.Get(isolate); | ||
auto result = disable_fn->Call(parent_env_->context(), | ||
Undefined(parent_env_->isolate()), 0, nullptr); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Is it actually necessary to pass an undefined when argument length is already 0? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I believe it is necessary - See how V8_WARN_UNUSED_RESULT MaybeLocal<Value> Call(Local<Context> context,
Local<Value> recv, int argc,
Local<Value> argv[]); There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Oh, sorry I should've checked the docs before replying here. |
||
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<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); | ||
} | ||
|
@@ -773,6 +844,34 @@ void Agent::PauseOnNextJavascriptStatement(const std::string& reason) { | |
channel->schedulePauseOnNextStatement(reason); | ||
} | ||
|
||
void Agent::RegisterAsyncHook(Isolate* isolate, | ||
v8::Local<v8::Function> enable_function, | ||
v8::Local<v8::Function> 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<Value>& args) { | ||
Environment* env = Environment::GetCurrent(args); | ||
inspector::Agent* agent = env->inspector_agent(); | ||
|
@@ -810,6 +909,59 @@ void Url(const FunctionCallbackInfo<Value>& 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<void*>(asyncId << 1); | ||
} | ||
|
||
template<void (Agent::*asyncTaskFn)(void*)> | ||
static void InvokeAsyncTaskFnWithId(const FunctionCallbackInfo<Value>& 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<Value>& args) { | ||
Environment* env = Environment::GetCurrent(args); | ||
|
||
CHECK(args[0]->IsString()); | ||
Local<String> task_name = args[0].As<String>(); | ||
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<Value>& args) { | ||
Environment* env = Environment::GetCurrent(args); | ||
|
||
CHECK(args[0]->IsFunction()); | ||
v8::Local<v8::Function> enable_function = args[0].As<Function>(); | ||
CHECK(args[1]->IsFunction()); | ||
v8::Local<v8::Function> disable_function = args[1].As<Function>(); | ||
env->inspector_agent()->RegisterAsyncHook(env->isolate(), | ||
enable_function, disable_function); | ||
} | ||
|
||
static void IsEnabled(const FunctionCallbackInfo<Value>& args) { | ||
Environment* env = Environment::GetCurrent(args); | ||
args.GetReturnValue().Set(env->inspector_agent()->enabled()); | ||
} | ||
|
||
// static | ||
void Agent::InitInspector(Local<Object> target, Local<Value> unused, | ||
|
@@ -830,6 +982,17 @@ void Agent::InitInspector(Local<Object> target, Local<Value> 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() { | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
does "canceled" mean that no other "started"/"finished" calls can be made? b/c when I read that it sounds like the async task was supposed to fire a "started", but was destroyed before that happened.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Good point, it looks a bit suspicious to me as well. @ak239 could you perhaps help us to understand this better?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Your understanding is right. asyncTaskCanceled means that asynchronous task would never be executed again (no other started/finished calls) so on inspector side we can cleanup all related to this task data.