Skip to content

Commit

Permalink
trace_events: add trace category enabled tracking
Browse files Browse the repository at this point in the history
Track state of async_hooks trace event category enablement.
Enable/disable the async_hooks trace event dynamically.

PR-URL: #22128
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
  • Loading branch information
jasnell committed Aug 17, 2018
1 parent 2ce0380 commit 4b7cd4b
Show file tree
Hide file tree
Showing 8 changed files with 159 additions and 37 deletions.
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;
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

0 comments on commit 4b7cd4b

Please sign in to comment.