From 145a4ec56f65d2709d1b5104e54051389e85e60b Mon Sep 17 00:00:00 2001 From: theanarkh Date: Fri, 21 Jul 2023 03:44:26 +0800 Subject: [PATCH] process: trace sync api --- doc/api/tracing.md | 2 + src/inspector/tracing_agent.cc | 1 + src/spawn_sync.cc | 14 +++++++ .../parallel/test-inspector-tracing-domain.js | 1 + .../parallel/test-trace-process-sync-event.js | 39 +++++++++++++++++++ 5 files changed, 57 insertions(+) create mode 100644 test/parallel/test-trace-process-sync-event.js diff --git a/doc/api/tracing.md b/doc/api/tracing.md index 0adeed4713a7d8..41a4ca712f2b92 100644 --- a/doc/api/tracing.md +++ b/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 diff --git a/src/inspector/tracing_agent.cc b/src/inspector/tracing_agent.cc index cdbdd63f8aff9f..66a48d7b07a35c 100644 --- a/src/inspector/tracing_agent.cc +++ b/src/inspector/tracing_agent.cc @@ -190,6 +190,7 @@ DispatchResponse TracingAgent::getCategories( categories_list->addItem("node.perf"); categories_list->addItem("node.perf.timerify"); categories_list->addItem("node.perf.usertiming"); + categories_list->addItem("node.process.sync"); categories_list->addItem("node.promises.rejections"); categories_list->addItem("node.threadpoolwork.async"); categories_list->addItem("node.threadpoolwork.sync"); diff --git a/src/spawn_sync.cc b/src/spawn_sync.cc index b3c0fabafdaad2..f353dcf0c6dcb5 100644 --- a/src/spawn_sync.cc +++ b/src/spawn_sync.cc @@ -24,6 +24,7 @@ #include "env-inl.h" #include "node_internals.h" #include "string_bytes.h" +#include "tracing/trace_event.h" #include "util-inl.h" #include @@ -514,8 +515,21 @@ Maybe SyncProcessRunner::TryInitializeAndRunLoop(Local 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(); diff --git a/test/parallel/test-inspector-tracing-domain.js b/test/parallel/test-inspector-tracing-domain.js index f5ac6875a0f643..91b009bae76abb 100644 --- a/test/parallel/test-inspector-tracing-domain.js +++ b/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', diff --git a/test/parallel/test-trace-process-sync-event.js b/test/parallel/test-trace-process-sync-event.js new file mode 100644 index 00000000000000..9dcb73e20f3920 --- /dev/null +++ b/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);