process: trace sync api

Author: theanarkh

doc/api/tracing.md

@@ -40,6 +40,8 @@ The available categories are:
     measures and marks.
   * `node.perf.timerify`: Enables capture of only Performance API timerify
     measurements.
+* `node.process.sync`: Enables capture of trace data for the sync APIs of
+  process module.
 * `node.promises.rejections`: Enables capture of trace data tracking the number
   of unhandled Promise rejections and handled-after-rejections.
 * `node.vm.script`: Enables capture of trace data for the `node:vm` module's

src/inspector/tracing_agent.cc

@@ -190,6 +190,7 @@ DispatchResponse TracingAgent::getCategories(
   categories_list->emplace_back("node.perf");
   categories_list->emplace_back("node.perf.timerify");
   categories_list->emplace_back("node.perf.usertiming");
+  categories_list->emplace_back("node.process.sync");
   categories_list->emplace_back("node.promises.rejections");
   categories_list->emplace_back("node.threadpoolwork.async");
   categories_list->emplace_back("node.threadpoolwork.sync");

src/spawn_sync.cc

@@ -25,6 +25,7 @@
 #include "node_external_reference.h"
 #include "node_internals.h"
 #include "string_bytes.h"
+#include "tracing/trace_event.h"
 #include "util-inl.h"
 
 #include <cstring>
@@ -519,8 +520,21 @@ Maybe<bool> SyncProcessRunner::TryInitializeAndRunLoop(Local<Value> options) {
       }
     }
   }
+  if (*TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
+          TRACING_CATEGORY_NODE2(process, sync)) != 0) {
+    TRACE_EVENT_BEGIN1(TRACING_CATEGORY_NODE2(process, sync),
+                       "spawnSync",
+                       "file",
+                       TRACE_STR_COPY(uv_process_options_.file));
+  }
 
   r = uv_run(uv_loop_, UV_RUN_DEFAULT);
+
+  if (*TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
+          TRACING_CATEGORY_NODE2(process, sync)) != 0) {
+    TRACE_EVENT_END0(TRACING_CATEGORY_NODE2(process, sync), "spawnSync");
+  }
+
   if (r < 0)
     // We can't handle uv_run failure.
     ABORT();

test/parallel/test-inspector-tracing-domain.js

@@ -58,6 +58,7 @@ async function test() {
     'node.perf',
     'node.perf.timerify',
     'node.perf.usertiming',
+    'node.process.sync',
     'node.promises.rejections',
     'node.threadpoolwork.async',
     'node.threadpoolwork.sync',

test/parallel/test-trace-process-sync-event.js

@@ -0,0 +1,39 @@
+'use strict';
+require('../common');
+const assert = require('assert');
+const cp = require('child_process');
+const fs = require('fs');
+const path = require('path');
+const tmpdir = require('../common/tmpdir');
+
+if (process.env.isChild === '1') {
+  cp.execFileSync('node', ['-e', '']);
+  cp.execSync('node', ['-e', '']);
+  cp.spawnSync('node', ['-e', '']);
+  return;
+}
+
+tmpdir.refresh();
+const FILE_NAME = path.join(tmpdir.path, 'node_trace.1.log');
+
+cp.spawnSync(process.execPath,
+             [
+               '--trace-events-enabled',
+               '--trace-event-categories', 'node.process.sync',
+               __filename,
+             ],
+             {
+               cwd: tmpdir.path,
+               env: {
+                 ...process.env,
+                 isChild: '1',
+               },
+             });
+
+assert(fs.existsSync(FILE_NAME));
+const data = fs.readFileSync(FILE_NAME);
+const traces = JSON.parse(data.toString()).traceEvents;
+assert(traces.length > 0);
+const count = traces.filter((item) => item.name === 'spawnSync').length;
+// Two begin, Two end
+assert.strictEqual(count === 3 * 2, true);