diff --git a/src/node.cc b/src/node.cc index 72eb4283d0b568..3236c7ae675e9a 100644 --- a/src/node.cc +++ b/src/node.cc @@ -4559,6 +4559,9 @@ inline int Start(Isolate* isolate, IsolateData* isolate_data, Environment env(isolate_data, context, v8_platform.GetTracingAgent()); env.Start(argc, argv, exec_argc, exec_argv, v8_is_profiling); + TRACE_EVENT_METADATA1("__metadata", "thread_name", "name", + "JavaScriptMainThread"); + const char* path = argc > 1 ? argv[1] : nullptr; StartInspector(&env, path, debug_options); diff --git a/src/tracing/trace_event.h b/src/tracing/trace_event.h index 3fbe1b0a1f9a46..1165fca59a99ea 100644 --- a/src/tracing/trace_event.h +++ b/src/tracing/trace_event.h @@ -118,6 +118,15 @@ enum CategoryGroupEnabledFlags { node::tracing::TraceEventHelper::GetTracingController() \ ->UpdateTraceEventDuration +// Adds a metadata event to the trace log. The |AppendValueAsTraceFormat| method +// on the convertable value will be called at flush time. +// TRACE_EVENT_API_ADD_METADATA_EVENT( +// const unsigned char* category_group_enabled, +// const char* event_name, +// const char* arg_name, +// std::unique_ptr arg_value) +#define TRACE_EVENT_API_ADD_METADATA_EVENT node::tracing::AddMetadataEvent + // Defines atomic operations used internally by the tracing system. #define TRACE_EVENT_API_ATOMIC_WORD intptr_t #define TRACE_EVENT_API_ATOMIC_LOAD(var) (var) @@ -259,6 +268,16 @@ enum CategoryGroupEnabledFlags { } \ } while (0) +#define INTERNAL_TRACE_EVENT_METADATA_ADD(category_group, name, ...) \ + do { \ + INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category_group); \ + if (INTERNAL_TRACE_EVENT_CATEGORY_GROUP_ENABLED_FOR_RECORDING_MODE()) { \ + TRACE_EVENT_API_ADD_METADATA_EVENT( \ + INTERNAL_TRACE_EVENT_UID(category_group_enabled), name, \ + ##__VA_ARGS__); \ + } \ + } while(0) + // Enter and leave a context based on the current scope. #define INTERNAL_TRACE_EVENT_SCOPED_CONTEXT(category_group, name, context) \ struct INTERNAL_TRACE_EVENT_UID(ScopedContext) { \ @@ -612,6 +631,26 @@ static V8_INLINE uint64_t AddTraceEventWithTimestamp( arg_names, arg_types, arg_values, flags, timestamp); } +template +static V8_INLINE uint64_t AddMetadataEvent( + const uint8_t* category_group_enabled, const char* name, + const char* arg1_name, ARG1_TYPE&& arg1_val) { + const int num_args = 1; + uint8_t arg_type; + uint64_t arg_value; + SetTraceValue(std::forward(arg1_val), &arg_type, &arg_value); + // TODO(ofrobots): It would be good to add metadata events to a separate + // buffer so that they can be periodically reemitted. For now, we have a + // single buffer, so we just add them to the main buffer. + return TRACE_EVENT_API_ADD_TRACE_EVENT( + TRACE_EVENT_PHASE_METADATA, + category_group_enabled, name, + node::tracing::kGlobalScope, // scope + node::tracing::kNoId, // id + node::tracing::kNoId, // bind_id + num_args, &arg1_name, &arg_type, &arg_value, TRACE_EVENT_FLAG_NONE); +} + // Used by TRACE_EVENTx macros. Do not use directly. class ScopedTracer { public: diff --git a/test/parallel/test-trace-events-api.js b/test/parallel/test-trace-events-api.js index b4f7112d07ac77..a68a2850a37c45 100644 --- a/test/parallel/test-trace-events-api.js +++ b/test/parallel/test-trace-events-api.js @@ -130,7 +130,8 @@ if (isChild) { assert(common.fileExists(file)); fs.readFile(file, common.mustCall((err, data) => { - const traces = JSON.parse(data.toString()).traceEvents; + const traces = JSON.parse(data.toString()).traceEvents + .filter((trace) => trace.cat !== '__metadata'); assert.strictEqual(traces.length, expectedMarks.length + expectedBegins.length + diff --git a/test/parallel/test-trace-events-binding.js b/test/parallel/test-trace-events-binding.js index 35fbfc3692a5d3..e52f1c769f5283 100644 --- a/test/parallel/test-trace-events-binding.js +++ b/test/parallel/test-trace-events-binding.js @@ -31,7 +31,8 @@ const proc = cp.spawn(process.execPath, 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; + const traces = JSON.parse(data.toString()).traceEvents + .filter((trace) => trace.cat !== '__metadata'); assert.strictEqual(traces.length, 3); assert.strictEqual(traces[0].pid, proc.pid); diff --git a/test/parallel/test-trace-events-bootstrap.js b/test/parallel/test-trace-events-bootstrap.js index a0bfcf123e7233..6f8c76564a8ac4 100644 --- a/test/parallel/test-trace-events-bootstrap.js +++ b/test/parallel/test-trace-events-bootstrap.js @@ -42,7 +42,8 @@ if (process.argv[2] === 'child') { assert(common.fileExists(file)); fs.readFile(file, common.mustCall((err, data) => { - const traces = JSON.parse(data.toString()).traceEvents; + const traces = JSON.parse(data.toString()).traceEvents + .filter((trace) => trace.cat !== '__metadata'); traces.forEach((trace) => { assert.strictEqual(trace.pid, proc.pid); assert(names.includes(trace.name)); diff --git a/test/parallel/test-trace-events-metadata.js b/test/parallel/test-trace-events-metadata.js new file mode 100644 index 00000000000000..f8fcdcfe5bb788 --- /dev/null +++ b/test/parallel/test-trace-events-metadata.js @@ -0,0 +1,26 @@ +'use strict'; +const common = require('../common'); +const assert = require('assert'); +const cp = require('child_process'); +const fs = require('fs'); + +const CODE = + 'setTimeout(() => { for (var i = 0; i < 100000; i++) { "test" + i } }, 1)'; +const FILE_NAME = 'node_trace.1.log'; + +const tmpdir = require('../common/tmpdir'); +tmpdir.refresh(); +process.chdir(tmpdir.path); + +const proc = cp.spawn(process.execPath, + [ '--trace-events-enabled', '-e', CODE ]); +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(traces.length > 0); + assert(traces.some((trace) => + trace.cat === '__metadata' && trace.name === 'thread_name' && + trace.args.name === 'JavaScriptMainThread')); + })); +})); diff --git a/test/parallel/test-trace-events-none.js b/test/parallel/test-trace-events-none.js index 6b60ce999ac118..a3f0338f28af35 100644 --- a/test/parallel/test-trace-events-none.js +++ b/test/parallel/test-trace-events-none.js @@ -2,6 +2,7 @@ const common = require('../common'); const assert = require('assert'); const cp = require('child_process'); +const fs = require('fs'); const CODE = 'setTimeout(() => { for (var i = 0; i < 100000; i++) { "test" + i } }, 1)'; @@ -17,5 +18,10 @@ const proc_no_categories = cp.spawn( ); proc_no_categories.once('exit', common.mustCall(() => { - assert(!common.fileExists(FILE_NAME)); + assert(common.fileExists(FILE_NAME)); + // Only __metadata categories should have been emitted. + fs.readFile(FILE_NAME, common.mustCall((err, data) => { + assert.ok(JSON.parse(data.toString()).traceEvents.every( + (trace) => trace.cat === '__metadata')); + })); })); diff --git a/test/parallel/test-trace-events-perf.js b/test/parallel/test-trace-events-perf.js index 5758082b6efa43..57ac0e3142f66d 100644 --- a/test/parallel/test-trace-events-perf.js +++ b/test/parallel/test-trace-events-perf.js @@ -49,7 +49,8 @@ if (process.argv[2] === 'child') { assert(common.fileExists(file)); fs.readFile(file, common.mustCall((err, data) => { - const traces = JSON.parse(data.toString()).traceEvents; + const traces = JSON.parse(data.toString()).traceEvents + .filter((trace) => trace.cat !== '__metadata'); assert.strictEqual(traces.length, expectedMarks.length + expectedBegins.length + diff --git a/test/parallel/test-trace-events-vm.js b/test/parallel/test-trace-events-vm.js index fc7af34d8866d2..3dc6e263e1b6a1 100644 --- a/test/parallel/test-trace-events-vm.js +++ b/test/parallel/test-trace-events-vm.js @@ -32,7 +32,8 @@ if (process.argv[2] === 'child') { assert(common.fileExists(file)); fs.readFile(file, common.mustCall((err, data) => { - const traces = JSON.parse(data.toString()).traceEvents; + const traces = JSON.parse(data.toString()).traceEvents + .filter((trace) => trace.cat !== '__metadata'); traces.forEach((trace) => { assert.strictEqual(trace.pid, proc.pid); assert(names.includes(trace.name));