console: add trace-events for time and count

Add the `node.console` trace event category to capture
`console.count()`, `console.countReset()`, `console.time()`,
`console.timeLog()`, and `console.timeEnd()` to the trace
event log.

PR-URL: https://github.com/nodejs/node/pull/23703
Backport-PR-URL: https://github.com/nodejs/node/pull/28840
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Richard Lau <riclau@uk.ibm.com>

2 files changed, 64 insertions, 2 deletions

diff --git a/test/parallel/test-bootstrap-modules.js b/test/parallel/test-bootstrap-modules.js
index e2c7836a362..f3705b79153 100644
--- a/test/parallel/test-bootstrap-modules.js
+++ b/test/parallel/test-bootstrap-modules.js
@@ -11,5 +11,5 @@ const list = process.moduleLoadList.slice();
 
 const assert = require('assert');
 
-assert(list.length <= 82,
-       `Expected <= 82 elements in moduleLoadLists, got ${list.length}`);
+assert(list.length <= 83,
+       `Expected <= 83 elements in moduleLoadLists, got ${list.length}`);
diff --git a/test/parallel/test-trace-events-console.js b/test/parallel/test-trace-events-console.js
new file mode 100644
index 00000000000..a4860b5da00
--- /dev/null
+++ b/test/parallel/test-trace-events-console.js
@@ -0,0 +1,62 @@
+'use strict';
+const common = require('../common');
+const assert = require('assert');
+const cp = require('child_process');
+const path = require('path');
+const fs = require('fs');
+const tmpdir = require('../common/tmpdir');
+
+// Tests that node.console trace events for counters and time methods are
+// emitted as expected.
+
+const names = [
+  'time::foo',
+  'count::bar'
+];
+const expectedCounts = [ 1, 2, 0 ];
+const expectedTimeTypes = [ 'b', 'n', 'e' ];
+
+if (process.argv[2] === 'child') {
+  // The following console outputs exercise the test, causing node.console
+  // trace events to be emitted for the counter and time calls.
+  console.count('bar');
+  console.count('bar');
+  console.countReset('bar');
+  console.time('foo');
+  setImmediate(() => {
+    console.timeLog('foo');
+    setImmediate(() => {
+      console.timeEnd('foo');
+    });
+  });
+} else {
+  tmpdir.refresh();
+
+  const proc = cp.fork(__filename,
+                       [ 'child' ], {
+                         cwd: tmpdir.path,
+                         execArgv: [
+                           '--trace-event-categories',
+                           'node.console'
+                         ]
+                       });
+
+  proc.once('exit', common.mustCall(async () => {
+    const file = path.join(tmpdir.path, 'node_trace.1.log');
+
+    assert(fs.existsSync(file));
+    const data = await fs.promises.readFile(file, { encoding: 'utf8' });
+    JSON.parse(data).traceEvents
+      .filter((trace) => trace.cat !== '__metadata')
+      .forEach((trace) => {
+        assert.strictEqual(trace.pid, proc.pid);
+        assert(names.includes(trace.name));
+        if (trace.name === 'count::bar')
+          assert.strictEqual(trace.args.data, expectedCounts.shift());
+        else if (trace.name === 'time::foo')
+          assert.strictEqual(trace.ph, expectedTimeTypes.shift());
+      });
+    assert.strictEqual(expectedCounts.length, 0);
+    assert.strictEqual(expectedTimeTypes.length, 0);
+  }));
+}