diff --git a/src/async-wrap.cc b/src/async-wrap.cc index 0afaf663716ad2..b5c199123d99a7 100644 --- a/src/async-wrap.cc +++ b/src/async-wrap.cc @@ -218,6 +218,16 @@ bool DomainExit(Environment* env, v8::Local object) { static bool PreCallbackExecution(AsyncWrap* wrap, bool run_domain_cbs) { + switch (wrap->provider_type()) { +#define V(PROVIDER) \ + case AsyncWrap::PROVIDER_ ## PROVIDER: \ + TRACE_EVENT_NESTABLE_ASYNC_BEGIN0("node", #PROVIDER " cb", \ + static_cast(wrap->get_id())); \ + break; + NODE_ASYNC_PROVIDER_TYPES(V) +#undef V + } + if (wrap->env()->using_domains() && run_domain_cbs) { bool is_disposed = DomainEnter(wrap->env(), wrap->object()); if (is_disposed) @@ -249,6 +259,16 @@ bool AsyncWrap::EmitBefore(Environment* env, double async_id) { static bool PostCallbackExecution(AsyncWrap* wrap, bool run_domain_cbs) { + switch (wrap->provider_type()) { +#define V(PROVIDER) \ + case AsyncWrap::PROVIDER_ ## PROVIDER: \ + TRACE_EVENT_NESTABLE_ASYNC_END0("node", #PROVIDER " cb", \ + static_cast(wrap->get_id())); \ + break; + NODE_ASYNC_PROVIDER_TYPES(V) +#undef V + } + if (!AsyncWrap::EmitAfter(wrap->env(), wrap->get_id())) return false; @@ -617,10 +637,29 @@ AsyncWrap::AsyncWrap(Environment* env, // Use AsyncReset() call to execute the init() callbacks. AsyncReset(silent); + + switch (provider_type()) { +#define V(PROVIDER) \ + case PROVIDER_ ## PROVIDER: \ + TRACE_EVENT_NESTABLE_ASYNC_BEGIN0("node", #PROVIDER, \ + static_cast(get_id())); \ + break; + NODE_ASYNC_PROVIDER_TYPES(V) +#undef V + } } AsyncWrap::~AsyncWrap() { + switch (provider_type()) { +#define V(PROVIDER) \ + case PROVIDER_ ## PROVIDER: \ + TRACE_EVENT_NESTABLE_ASYNC_END0("node", #PROVIDER, \ + static_cast(get_id())); \ + break; + NODE_ASYNC_PROVIDER_TYPES(V) +#undef V + } PushBackDestroyId(env(), get_id()); } @@ -774,6 +813,9 @@ async_context EmitAsyncInit(Isolate* isolate, trigger_async_id // trigger_async_id_ }; + TRACE_EVENT_NESTABLE_ASYNC_BEGIN0("node", "custom_event", + static_cast(context.async_id)); + // Run init hooks Local type = String::NewFromUtf8(isolate, name, v8::NewStringType::kInternalized) @@ -785,6 +827,8 @@ async_context EmitAsyncInit(Isolate* isolate, } void EmitAsyncDestroy(Isolate* isolate, async_context asyncContext) { + TRACE_EVENT_NESTABLE_ASYNC_END0("node", "custom_event", + static_cast(asyncContext.async_id)); PushBackDestroyId(Environment::GetCurrent(isolate), asyncContext.async_id); } diff --git a/test/parallel/test-trace-event.js b/test/parallel/test-trace-event.js index fde718d7bc06fb..c3dce93153fe72 100644 --- a/test/parallel/test-trace-event.js +++ b/test/parallel/test-trace-event.js @@ -4,7 +4,8 @@ const assert = require('assert'); const cp = require('child_process'); const fs = require('fs'); -const CODE = 'for (var i = 0; i < 100000; i++) { "test" + i }'; +const CODE = + 'setTimeout(() => { for (var i = 0; i < 100000; i++) { "test" + i } }, 1)'; const FILE_NAME = 'node_trace.1.log'; common.refreshTmpDir(); @@ -24,7 +25,7 @@ proc_no_categories.once('exit', common.mustCall(() => { fs.readFile(FILE_NAME, common.mustCall((err, data) => { const traces = JSON.parse(data.toString()).traceEvents; assert(traces.length > 0); - // Values that should be present on all runs to approximate correctness. + // V8 trace events should be generated. assert(traces.some((trace) => { if (trace.pid !== proc.pid) return false; @@ -34,6 +35,16 @@ proc_no_categories.once('exit', common.mustCall(() => { return false; return true; })); + // Async wrap trace events should be generated. + assert(traces.some((trace) => { + if (trace.pid !== proc.pid) + return false; + if (trace.cat !== 'node') + return false; + if (trace.name !== 'TIMERWRAP') + return false; + return true; + })); })); })); }));