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

trace_events: add trace category enabled tracking #22128

Closed
wants to merge 1 commit into from
Closed
Show file tree
Hide file tree
Changes from all commits
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
43 changes: 30 additions & 13 deletions lib/internal/bootstrap/node.js
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,8 @@
// bootstrapper properties... destructured to
// avoid retaining a reference to the bootstrap
// object.
{ _setupProcessObject, _setupNextTick,
{ _setupTraceCategoryState,
_setupProcessObject, _setupNextTick,
_setupPromises, _chdir, _cpuUsage,
_hrtime, _hrtimeBigInt,
_memoryUsage, _rawDebug,
Expand All @@ -35,6 +36,8 @@

EventEmitter.call(process);

setupTraceCategoryState();

setupProcessObject();

// Do this good and early, since it handles errors.
Expand Down Expand Up @@ -98,18 +101,6 @@
if (global.__coverage__)
NativeModule.require('internal/process/write-coverage').setup();


{
const traceEvents = internalBinding('trace_events');
const traceEventCategory = 'node,node.async_hooks';

if (traceEvents.isTraceCategoryEnabled(traceEventCategory)) {
NativeModule.require('internal/trace_events_async_hooks')
.setup(traceEvents, traceEventCategory);
}
}


if (process.config.variables.v8_enable_inspector) {
NativeModule.require('internal/inspector_async_hook').setup();
}
Expand Down Expand Up @@ -311,6 +302,32 @@
}
}

function setupTraceCategoryState() {
const { traceCategoryState } = internalBinding('trace_events');
const kCategoryAsyncHooks = 0;
Copy link
Contributor

Choose a reason for hiding this comment

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

Apologies that I took so long to do a full review. Post-landing LGTM w/ the following comment, which can be addressed as a follow-on.

AFAICT, this 0 is a hard-coded constant that appears here and also at env.cc:109. Is it possible to define this symbolically somewhere?

let traceEventsAsyncHook;

function toggleTraceCategoryState() {
// Dynamically enable/disable the traceEventsAsyncHook
const asyncHooksEnabled = !!traceCategoryState[kCategoryAsyncHooks];

if (asyncHooksEnabled) {
// Lazy load internal/trace_events_async_hooks only if the async_hooks
// trace event category is enabled.
if (!traceEventsAsyncHook) {
traceEventsAsyncHook =
NativeModule.require('internal/trace_events_async_hooks');
}
traceEventsAsyncHook.enable();
} else if (traceEventsAsyncHook) {
traceEventsAsyncHook.disable();
}
}

toggleTraceCategoryState();
_setupTraceCategoryState(toggleTraceCategoryState);
}

function setupProcessObject() {
_setupProcessObject(pushValueToArray);

Expand Down
72 changes: 48 additions & 24 deletions lib/internal/trace_events_async_hooks.js
Original file line number Diff line number Diff line change
@@ -1,34 +1,39 @@
'use strict';

exports.setup = function(traceEvents, traceEventCategory) {
const { trace } = traceEvents;
const async_wrap = process.binding('async_wrap');
const async_hooks = require('async_hooks');
const { internalBinding } = require('internal/bootstrap/loaders');
const { trace } = internalBinding('trace_events');
const async_wrap = process.binding('async_wrap');
const async_hooks = require('async_hooks');
const { SafeMap, SafeSet } = require('internal/safe_globals');

// Use small letters such that chrome://tracing groups by the name.
// The behavior is not only useful but the same as the events emitted using
// the specific C++ macros.
const BEFORE_EVENT = 'b'.charCodeAt(0);
const END_EVENT = 'e'.charCodeAt(0);
// Use small letters such that chrome://tracing groups by the name.
// The behavior is not only useful but the same as the events emitted using
// the specific C++ macros.
const kBeforeEvent = 'b'.charCodeAt(0);
const kEndEvent = 'e'.charCodeAt(0);
const kTraceEventCategory = 'node,node.async_hooks';

const kEnabled = Symbol('enabled');

// It is faster to emit traceEvents directly from C++. Thus, this happens
// in async_wrap.cc. However, events emitted from the JavaScript API or the
// Embedder C++ API can't be emitted from async_wrap.cc. Thus they are
// emitted using the JavaScript API. To prevent emitting the same event
// twice the async_wrap.Providers list is used to filter the events.
const nativeProviders = new SafeSet(Object.keys(async_wrap.Providers));
const typeMemory = new SafeMap();

function createHook() {
// In traceEvents it is not only the id but also the name that needs to be
// repeated. Since async_hooks doesn't expose the provider type in the
// non-init events, use a map to manually map the asyncId to the type name.
const typeMemory = new Map();

// It is faster to emit traceEvents directly from C++. Thus, this happens
// in async_wrap.cc. However, events emitted from the JavaScript API or the
// Embedder C++ API can't be emitted from async_wrap.cc. Thus they are
// emitted using the JavaScript API. To prevent emitting the same event
// twice the async_wrap.Providers list is used to filter the events.
const nativeProviders = new Set(Object.keys(async_wrap.Providers));

async_hooks.createHook({
const hook = async_hooks.createHook({
init(asyncId, type, triggerAsyncId, resource) {
if (nativeProviders.has(type)) return;

typeMemory.set(asyncId, type);
trace(BEFORE_EVENT, traceEventCategory,
trace(kBeforeEvent, kTraceEventCategory,
type, asyncId,
{
triggerAsyncId,
Expand All @@ -40,24 +45,43 @@ exports.setup = function(traceEvents, traceEventCategory) {
const type = typeMemory.get(asyncId);
if (type === undefined) return;

trace(BEFORE_EVENT, traceEventCategory, `${type}_CALLBACK`, asyncId);
trace(kBeforeEvent, kTraceEventCategory, `${type}_CALLBACK`, asyncId);
},

after(asyncId) {
const type = typeMemory.get(asyncId);
if (type === undefined) return;

trace(END_EVENT, traceEventCategory, `${type}_CALLBACK`, asyncId);
trace(kEndEvent, kTraceEventCategory, `${type}_CALLBACK`, asyncId);
},

destroy(asyncId) {
const type = typeMemory.get(asyncId);
if (type === undefined) return;

trace(END_EVENT, traceEventCategory, type, asyncId);
trace(kEndEvent, kTraceEventCategory, type, asyncId);

// cleanup asyncId to type map
typeMemory.delete(asyncId);
}
}).enable();
};
});

return {
enable() {
if (this[kEnabled])
return;
this[kEnabled] = true;
hook.enable();
},

disable() {
if (!this[kEnabled])
return;
this[kEnabled] = false;
hook.disable();
typeMemory.clear();
}
};
}

module.exports = createHook();
7 changes: 7 additions & 0 deletions src/bootstrapper.cc
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,12 @@ void RunMicrotasks(const FunctionCallbackInfo<Value>& args) {
args.GetIsolate()->RunMicrotasks();
}

void SetupTraceCategoryState(const FunctionCallbackInfo<Value>& args) {
Environment* env = Environment::GetCurrent(args);
CHECK(args[0]->IsFunction());
env->set_trace_category_state_function(args[0].As<Function>());
}

void SetupNextTick(const FunctionCallbackInfo<Value>& args) {
Environment* env = Environment::GetCurrent(args);
Isolate* isolate = env->isolate();
Expand Down Expand Up @@ -117,6 +123,7 @@ void SetupPromises(const FunctionCallbackInfo<Value>& args) {
// completes so that it can be gc'd as soon as possible.
void SetupBootstrapObject(Environment* env,
Local<Object> bootstrapper) {
BOOTSTRAP_METHOD(_setupTraceCategoryState, SetupTraceCategoryState);
BOOTSTRAP_METHOD(_setupProcessObject, SetupProcessObject);
BOOTSTRAP_METHOD(_setupNextTick, SetupNextTick);
BOOTSTRAP_METHOD(_setupPromises, SetupPromises);
Expand Down
5 changes: 5 additions & 0 deletions src/env-inl.h
Original file line number Diff line number Diff line change
Expand Up @@ -432,6 +432,11 @@ Environment::should_abort_on_uncaught_toggle() {
return should_abort_on_uncaught_toggle_;
}

inline AliasedBuffer<uint8_t, v8::Uint8Array>&
Environment::trace_category_state() {
return trace_category_state_;
}

Environment::ShouldNotAbortOnUncaughtScope::ShouldNotAbortOnUncaughtScope(
Environment* env)
: env_(env) {
Expand Down
33 changes: 33 additions & 0 deletions src/env.cc
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,8 @@ using v8::TryCatch;
using v8::Value;
using worker::Worker;

#define kTraceCategoryCount 1

int const Environment::kNodeContextTag = 0x6e6f64;
void* Environment::kNodeContextTagPtr = const_cast<void*>(
static_cast<const void*>(&Environment::kNodeContextTag));
Expand Down Expand Up @@ -103,6 +105,21 @@ void InitThreadLocalOnce() {
CHECK_EQ(0, uv_key_create(&Environment::thread_local_env));
}

void Environment::TrackingTraceStateObserver::UpdateTraceCategoryState() {
env_->trace_category_state()[0] =
*TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
TRACING_CATEGORY_NODE1(async_hooks));

Isolate* isolate = env_->isolate();
Local<Function> cb = env_->trace_category_state_function();
if (cb.IsEmpty())
return;
TryCatch try_catch(isolate);
try_catch.SetVerbose(true);
cb->Call(env_->context(), v8::Undefined(isolate),
0, nullptr).ToLocalChecked();
}

Environment::Environment(IsolateData* isolate_data,
Local<Context> context,
tracing::AgentWriterHandle* tracing_agent_writer)
Expand All @@ -118,6 +135,7 @@ Environment::Environment(IsolateData* isolate_data,
emit_env_nonstring_warning_(true),
makecallback_cntr_(0),
should_abort_on_uncaught_toggle_(isolate_, 1),
trace_category_state_(isolate_, kTraceCategoryCount),
#if HAVE_INSPECTOR
inspector_agent_(new inspector::Agent(this)),
#endif
Expand All @@ -132,6 +150,14 @@ Environment::Environment(IsolateData* isolate_data,

AssignToContext(context, ContextInfo(""));

if (tracing_agent_writer_ != nullptr) {
trace_state_observer_.reset(new TrackingTraceStateObserver(this));
v8::TracingController* tracing_controller =
tracing_agent_writer_->GetTracingController();
if (tracing_controller != nullptr)
tracing_controller->AddTraceStateObserver(trace_state_observer_.get());
}

destroy_async_id_list_.reserve(512);
performance_state_.reset(new performance::performance_state(isolate()));
performance_state_->Mark(
Expand Down Expand Up @@ -173,6 +199,13 @@ Environment::~Environment() {
context()->SetAlignedPointerInEmbedderData(
ContextEmbedderIndex::kEnvironment, nullptr);

if (tracing_agent_writer_ != nullptr) {
v8::TracingController* tracing_controller =
tracing_agent_writer_->GetTracingController();
if (tracing_controller != nullptr)
tracing_controller->RemoveTraceStateObserver(trace_state_observer_.get());
}

delete[] heap_statistics_buffer_;
delete[] heap_space_statistics_buffer_;
delete[] http_parser_buffer_;
Expand Down
26 changes: 26 additions & 0 deletions src/env.h
Original file line number Diff line number Diff line change
Expand Up @@ -344,6 +344,7 @@ struct PackageConfig {
V(tick_callback_function, v8::Function) \
V(timers_callback_function, v8::Function) \
V(tls_wrap_constructor_function, v8::Function) \
V(trace_category_state_function, v8::Function) \
V(tty_constructor_template, v8::FunctionTemplate) \
V(udp_constructor_function, v8::Function) \
V(url_constructor_function, v8::Function) \
Expand Down Expand Up @@ -649,6 +650,8 @@ class Environment {
inline AliasedBuffer<uint32_t, v8::Uint32Array>&
should_abort_on_uncaught_toggle();

inline AliasedBuffer<uint8_t, v8::Uint8Array>& trace_category_state();

// The necessary API for async_hooks.
inline double new_async_id();
inline double execution_async_id();
Expand Down Expand Up @@ -830,6 +833,25 @@ class Environment {
// This needs to be available for the JS-land setImmediate().
void ToggleImmediateRef(bool ref);

class TrackingTraceStateObserver :
public v8::TracingController::TraceStateObserver {
public:
explicit TrackingTraceStateObserver(Environment* env) : env_(env) {}

void OnTraceEnabled() override {
UpdateTraceCategoryState();
}

void OnTraceDisabled() override {
UpdateTraceCategoryState();
}

private:
void UpdateTraceCategoryState();

Environment* env_;
};

class ShouldNotAbortOnUncaughtScope {
public:
explicit inline ShouldNotAbortOnUncaughtScope(Environment* env);
Expand Down Expand Up @@ -889,6 +911,10 @@ class Environment {
AliasedBuffer<uint32_t, v8::Uint32Array> should_abort_on_uncaught_toggle_;
int should_not_abort_scope_counter_ = 0;

// Attached to a Uint8Array that tracks the state of trace category
AliasedBuffer<uint8_t, v8::Uint8Array> trace_category_state_;
std::unique_ptr<TrackingTraceStateObserver> trace_state_observer_;

std::unique_ptr<performance::performance_state> performance_state_;
std::unordered_map<std::string, uint64_t> performance_marks_;

Expand Down
4 changes: 4 additions & 0 deletions src/node_trace_events.cc
Original file line number Diff line number Diff line change
Expand Up @@ -127,6 +127,10 @@ void Initialize(Local<Object> target,
.FromJust();
target->Set(context, trace,
binding->Get(context, trace).ToLocalChecked()).FromJust();

target->Set(context,
FIXED_ONE_BYTE_STRING(env->isolate(), "traceCategoryState"),
env->trace_category_state().GetJSArray()).FromJust();
}

} // namespace node
Expand Down
6 changes: 6 additions & 0 deletions src/tracing/agent.h
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,8 @@ class AgentWriterHandle {

inline Agent* agent() { return agent_; }

inline v8::TracingController* GetTracingController();

private:
inline AgentWriterHandle(Agent* agent, int id) : agent_(agent), id_(id) {}

Expand Down Expand Up @@ -155,6 +157,10 @@ void AgentWriterHandle::Disable(const std::set<std::string>& categories) {
if (agent_ != nullptr) agent_->Disable(id_, categories);
}

inline v8::TracingController* AgentWriterHandle::GetTracingController() {
return agent_ != nullptr ? agent_->GetTracingController() : nullptr;
}

} // namespace tracing
} // namespace node

Expand Down