From 245ef105982bc779e9110bfcfbf8f26b309f560c Mon Sep 17 00:00:00 2001 From: theanarkh Date: Wed, 31 Aug 2022 00:26:26 +0800 Subject: [PATCH] src: trace threadpool event --- doc/api/tracing.md | 2 + src/threadpoolwork-inl.h | 7 ++- test/parallel/test-trace-events-threadpool.js | 49 +++++++++++++++++++ 3 files changed, 57 insertions(+), 1 deletion(-) create mode 100644 test/parallel/test-trace-events-threadpool.js diff --git a/doc/api/tracing.md b/doc/api/tracing.md index a0bd4060ca4d51..4d52b98bc6b421 100644 --- a/doc/api/tracing.md +++ b/doc/api/tracing.md @@ -22,6 +22,8 @@ The available categories are: * `node.bootstrap`: Enables capture of Node.js bootstrap milestones. * `node.console`: Enables capture of `console.time()` and `console.count()` output. +* `node.threadpool`: Enables capture of Node.js threadpool, + except asynchronous file IO and DNS. * `node.dns.native`: Enables capture of trace data for DNS queries. * `node.net.native`: Enables capture of trace data for network. * `node.environment`: Enables capture of Node.js Environment milestones. diff --git a/src/threadpoolwork-inl.h b/src/threadpoolwork-inl.h index 8bba988b18db0f..607f4609798942 100644 --- a/src/threadpoolwork-inl.h +++ b/src/threadpoolwork-inl.h @@ -24,13 +24,16 @@ #if defined(NODE_WANT_INTERNALS) && NODE_WANT_INTERNALS -#include "util-inl.h" #include "node_internals.h" +#include "tracing/trace_event.h" +#include "util-inl.h" namespace node { void ThreadPoolWork::ScheduleWork() { env_->IncreaseWaitingRequestCounter(); + TRACE_EVENT_NESTABLE_ASYNC_BEGIN0( + TRACING_CATEGORY_NODE1(threadpool), "", this); int status = uv_queue_work( env_->event_loop(), &work_req_, @@ -41,6 +44,8 @@ void ThreadPoolWork::ScheduleWork() { [](uv_work_t* req, int status) { ThreadPoolWork* self = ContainerOf(&ThreadPoolWork::work_req_, req); self->env_->DecreaseWaitingRequestCounter(); + TRACE_EVENT_NESTABLE_ASYNC_END1( + TRACING_CATEGORY_NODE1(threadpool), "", self, "result", status); self->AfterThreadPoolWork(status); }); CHECK_EQ(status, 0); diff --git a/test/parallel/test-trace-events-threadpool.js b/test/parallel/test-trace-events-threadpool.js new file mode 100644 index 00000000000000..688ec3da5c455b --- /dev/null +++ b/test/parallel/test-trace-events-threadpool.js @@ -0,0 +1,49 @@ +'use strict'; +const common = 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 (!common.hasCrypto) + common.skip('missing crypto'); + +const { hkdf } = require('crypto'); +const { deflate } = require('zlib'); +const { Blob } = require('buffer'); + + +if (process.env.isChild === '1') { + hkdf('sha512', 'key', 'salt', 'info', 64, () => {}); + deflate('hello', () => {}); + // Make async call + const blob = new Blob(['h'.repeat(4096 * 2)]); + blob.arrayBuffer(); + 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.threadpool', + __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((trace) => trace.cat === 'node,node.threadpool').length; +// There are three types, each type has two events at least +assert.strictEqual(count > 3 * 2, true);