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 executionAsyncId to init events #17196

Closed
wants to merge 2 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
4 changes: 3 additions & 1 deletion lib/internal/trace_events_async_hooks.js
Original file line number Diff line number Diff line change
Expand Up @@ -28,7 +28,9 @@ const hook = async_hooks.createHook({

typeMemory.set(asyncId, type);
trace_events.emit(BEFORE_EVENT, 'node.async_hooks',
type, asyncId, 'triggerAsyncId', triggerAsyncId);
type, asyncId,
'triggerAsyncId', triggerAsyncId,
'executionAsyncId', async_hooks.executionAsyncId());
},

before(asyncId) {
Expand Down
7 changes: 5 additions & 2 deletions src/async_wrap.cc
Original file line number Diff line number Diff line change
Expand Up @@ -703,9 +703,12 @@ void AsyncWrap::AsyncReset(double execution_async_id, bool silent) {
switch (provider_type()) {
#define V(PROVIDER) \
case PROVIDER_ ## PROVIDER: \
TRACE_EVENT_NESTABLE_ASYNC_BEGIN1("node.async_hooks", \
TRACE_EVENT_NESTABLE_ASYNC_BEGIN2("node.async_hooks", \
#PROVIDER, static_cast<int64_t>(get_async_id()), \
"triggerAsyncId", static_cast<int64_t>(get_trigger_async_id())); \
"executionAsyncId", \
static_cast<int64_t>(env()->execution_async_id()), \
"triggerAsyncId", \
static_cast<int64_t>(get_trigger_async_id())); \
break;
NODE_ASYNC_PROVIDER_TYPES(V)
#undef V
Expand Down
27 changes: 20 additions & 7 deletions src/node_trace_events.cc
Original file line number Diff line number Diff line change
Expand Up @@ -70,20 +70,20 @@ static void Emit(const FunctionCallbackInfo<Value>& args) {
id = args[3]->IntegerValue(context).ToChecked();
}

// TODO(AndreasMadsen): Two extra arguments are not supported.
// TODO(AndreasMadsen): String values are not supported.
int32_t num_args = 0;
const char* arg_names[1];
uint8_t arg_types[1];
uint64_t arg_values[1];
const char* arg_names[2];
uint8_t arg_types[2];
uint64_t arg_values[2];

// Create Utf8Value in the function scope to prevent deallocation.
// The c-string will be copied by TRACE_EVENT_API_ADD_TRACE_EVENT at the end.
Utf8Value arg1NameValue(env->isolate(), args[4]);
Utf8Value arg2NameValue(env->isolate(), args[6]);

if (args.Length() < 6 || (args[4]->IsUndefined() && args[5]->IsUndefined())) {
num_args = 0;
} else {
if (args.Length() >= 6 &&
!args[4]->IsUndefined() &&
Copy link
Member

Choose a reason for hiding this comment

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

Was the logic wrong here before? If we're not changing the logic, the negation of the statement should be
if(args.Length() >= 6 && (!args[4]->IsUndefined() || !args[5]->IsUndefined())). DeMorgan changes the second && to a ||.

Copy link
Member Author

Choose a reason for hiding this comment

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

Right. I think it is a matter of opinion. But since we have validation after we should properly go with what you suggest.

!args[5]->IsUndefined()) {
num_args = 1;
arg_types[0] = TRACE_VALUE_TYPE_INT;

Expand All @@ -94,6 +94,19 @@ static void Emit(const FunctionCallbackInfo<Value>& args) {
arg_values[0] = args[5]->IntegerValue(context).ToChecked();
}

if (args.Length() >= 8 &&
!args[6]->IsUndefined() &&
!args[7]->IsUndefined()) {
num_args = 2;
arg_types[1] = TRACE_VALUE_TYPE_INT;

CHECK(args[6]->IsString());
arg_names[1] = arg2NameValue.out();

CHECK(args[7]->IsNumber());
arg_values[1] = args[7]->IntegerValue(context).ToChecked();
}

// The TRACE_EVENT_FLAG_COPY flag indicates that the name and argument
// name should be copied thus they don't need to long-lived pointers.
// The category name still won't be copied and thus need to be a long-lived
Expand Down
10 changes: 9 additions & 1 deletion test/parallel/test-trace-events-async-hooks.js
Original file line number Diff line number Diff line change
Expand Up @@ -43,7 +43,6 @@ proc.once('exit', common.mustCall(() => {
return true;
}));


// JavaScript async_hooks trace events should be generated.
assert(traces.some((trace) => {
if (trace.pid !== proc.pid)
Expand All @@ -54,5 +53,14 @@ proc.once('exit', common.mustCall(() => {
return false;
return true;
}));

// Check args in init events
const initEvents = traces.filter((trace) => {
return (trace.ph === 'b' && !trace.name.includes('_CALLBACK'));
});
assert(initEvents.every((trace) => {
return (trace.args.executionAsyncId > 0 &&
trace.args.triggerAsyncId > 0);
}));
}));
}));
19 changes: 16 additions & 3 deletions test/parallel/test-trace-events-binding.js
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,10 @@ const CODE = `
'type-value', 10, 'extra-value', 20);
process.binding("trace_events").emit(
'b'.charCodeAt(0), 'custom',
'type-value', 20);
'type-value', 20, 'first-value', 20, 'second-value', 30);
process.binding("trace_events").emit(
'b'.charCodeAt(0), 'custom',
'type-value', 30);
process.binding("trace_events").emit(
'b'.charCodeAt(0), 'missing',
'type-value', 10, 'extra-value', 20);
Expand All @@ -29,7 +32,7 @@ proc.once('exit', common.mustCall(() => {
assert(common.fileExists(FILE_NAME));
fs.readFile(FILE_NAME, common.mustCall((err, data) => {
const traces = JSON.parse(data.toString()).traceEvents;
assert.strictEqual(traces.length, 2);
assert.strictEqual(traces.length, 3);

assert.strictEqual(traces[0].pid, proc.pid);
assert.strictEqual(traces[0].ph, 'b');
Expand All @@ -43,6 +46,16 @@ proc.once('exit', common.mustCall(() => {
assert.strictEqual(traces[1].cat, 'custom');
assert.strictEqual(traces[1].name, 'type-value');
assert.strictEqual(traces[1].id, '0x14');
assert.deepStrictEqual(traces[1].args, { });
assert.deepStrictEqual(traces[1].args, {
'first-value': 20,
'second-value': 30
});

assert.strictEqual(traces[2].pid, proc.pid);
assert.strictEqual(traces[2].ph, 'b');
assert.strictEqual(traces[2].cat, 'custom');
assert.strictEqual(traces[2].name, 'type-value');
assert.strictEqual(traces[2].id, '0x1e');
assert.deepStrictEqual(traces[2].args, { });
}));
}));