src: trace threadpool event

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.

src/threadpoolwork-inl.h

@@ -26,11 +26,15 @@
 
 #include "util-inl.h"
 #include "node_internals.h"
+#include "tracing/trace_event.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 +45,11 @@ 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);

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);