test: enable trace_events tests with perfetto

.github/workflows/test-linux-perfetto.yml

@@ -62,6 +62,9 @@ jobs:
       - name: Build
         working-directory: node
         run: make build-ci -j4 V=1 CONFIG_FLAGS="--error-on-warn --v8-enable-temporal-support --with-perfetto"
+      - name: Get trace_processor
+        working-directory: node
+        run: make tools/perfetto/trace_processor_shell
       - name: Test
         working-directory: node
         run: make test-ci -j1 V=1 TEST_CI_ARGS="-p actions --measure-flakiness 9"

.gitignore

@@ -116,6 +116,9 @@ tools/*/*.i.tmp
 /tools/eslint/node_modules
 /tools/lint-md/node_modules
 
+# === Rules for tools/perfetto ===
+/tools/perfetto/trace_processor_shell
+
 # === Rules for test artifacts ===
 /*.tap
 /*.xml

Makefile

@@ -235,6 +235,7 @@ distclean: ## Remove all build and test artifacts.
 	$(RM) -r node_modules
 	$(RM) -r deps/icu
 	$(RM) -r deps/icu4c*.tgz deps/icu4c*.zip deps/icu-tmp
+	$(RM) tools/perfetto/trace_processor_shell
 	$(RM) $(BINARYTAR).* $(TARBALL).*
 
 .PHONY: check
@@ -338,6 +339,18 @@ coverage-run-js: ## Run JavaScript tests with coverage.
 					TEST_CI_ARGS="$(TEST_CI_ARGS) --type=coverage" $(MAKE) jstest
 	$(MAKE) coverage-report-js
 
+TRACE_PROCESSOR_SHELL_PATH ?= tools/perfetto/trace_processor_shell
+
+# The downloaded copy has to match the vendored perfetto, so a version bump
+# re-downloads it. An overridden path is a build we do not manage and may not
+# be writable, so it gets no prerequisite and is left alone once it exists.
+ifeq ($(TRACE_PROCESSOR_SHELL_PATH),tools/perfetto/trace_processor_shell)
+TRACE_PROCESSOR_SHELL_DEPS = deps/perfetto/VERSION
+endif
+
+$(TRACE_PROCESSOR_SHELL_PATH): $(TRACE_PROCESSOR_SHELL_DEPS)
+	@tools/perfetto/get_trace_processor $@
+
 .PHONY: test
 # This does not run tests of third-party libraries inside deps.
 test: all ## Run default tests and build docs.

shell.nix

@@ -172,6 +172,9 @@ pkgs.mkShell {
   // pkgs.lib.optionalAttrs (!withSQLite) {
     NOSQLITE = "1";
   }
+  // pkgs.lib.optionalAttrs (withPerfetto) {
+    TRACE_PROCESSOR_SHELL_PATH = "${pkgs.perfetto.tools}/bin/trace_processor_shell";
+  }
   // pkgs.lib.optionalAttrs (pkcs11 != false && pkcs11 != null) (
     let
       pkcs11' =

test/common/index.js

@@ -1029,6 +1029,7 @@ const common = {
   hasSQLite,
   hasFFI,
   hasLocalStorage,
+  hasPerfetto,
   invalidArgTypeHelper,
   isAlive,
   isASan,

test/common/trace_events.js

@@ -0,0 +1,66 @@
+'use strict';
+
+// Helpers to deal with both Chrome legacy JSON trace format, and Perfetto
+// binary format.
+// This depends on perfetto's `trace_processor_shell` converts to pftrace format
+// to JSON format. Run `make tools/perfetto/trace_processor_shell` to download
+// it, or point `TRACE_PROCESSOR_SHELL_PATH` at an existing build of it.
+
+const assert = require('assert');
+const { spawnSync } = require('child_process');
+const fs = require('fs');
+const path = require('path');
+const common = require('./');
+
+const traceProcessor = path.resolve(
+  __dirname, '..', '..',
+  process.env.TRACE_PROCESSOR_SHELL_PATH || 'tools/perfetto/trace_processor_shell');
+
+// The JSON form of a trace runs about three times the size of the trace it was
+// converted from, and the traces these tests produce are a few hundred KiB at
+// most. This is an assumed MAX size of a JSON conversion size limit for tests.
+const kMaxTraceJsonBytes = 64 * 1024 * 1024;
+
+const traceFileExt = common.hasPerfetto ? 'pftrace' : 'log';
+const defaultTraceFileName = `node_trace.1.${traceFileExt}`;
+
+// Only perfetto traces need converting, so a missing `trace_processor_shell`
+// does not stop anything on a legacy build.
+function checkTraceProcessor() {
+  if (common.hasPerfetto && !fs.existsSync(traceProcessor)) {
+    assert.fail('trace_processor_shell is missing, ' +
+                'run `make tools/perfetto/trace_processor_shell` to download it');
+  }
+}
+
+function readTraceEvents(file) {
+  if (!common.hasPerfetto) {
+    return JSON.parse(fs.readFileSync(file, 'utf8')).traceEvents;
+  }
+
+  const converted = spawnSync(traceProcessor, ['convert', 'json', file],
+                              { maxBuffer: kMaxTraceJsonBytes });
+  assert.ifError(converted.error);
+  assert.strictEqual(
+    converted.status, 0,
+    `trace_processor_shell failed: ${converted.stderr}`);
+  return JSON.parse(converted.stdout.toString()).traceEvents;
+}
+
+// A perfetto trace event carries the single category it was emitted with. The
+// legacy backend instead groups it with every ancestor category, so
+// `node.net.native` is recorded as `node,node.net,node.net.native`.
+function traceCategory(name) {
+  if (common.hasPerfetto) {
+    return name;
+  }
+  const parts = name.split('.');
+  return parts.map((_, i) => parts.slice(0, i + 1).join('.')).join(',');
+}
+
+module.exports = {
+  defaultTraceFileName,
+  readTraceEvents,
+  checkTraceProcessor,
+  traceCategory,
+};

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

@@ -3,6 +3,9 @@
 const common = require('../common');
 
 common.skipIfInspectorDisabled();
+// The inspector NodeTracing domain is not wired up on a perfetto build, see
+// src/inspector_agent.cc, so every command here fails with
+// ERR_INSPECTOR_COMMAND.
 common.skipIfPerfettoEnabled();
 
 const { isMainThread } = require('worker_threads');

test/parallel/test-module-print-timing.mjs

@@ -7,6 +7,8 @@ import tmpdir from '../common/tmpdir.js';
 import { spawnSyncAndAssert } from '../common/child_process.js';
 import fixtures from '../common/fixtures.js';
 
+// The dynamic tracing case below records nothing on a perfetto build: a
+// category enabled after the tracing session started stays off.
 skipIfPerfettoEnabled();
 tmpdir.refresh();
 

test/parallel/test-permission-fs-write-trace-events.js

@@ -1,18 +1,17 @@
-// Flags: --expose-internals
 'use strict';
 
 const common = require('../common');
 const { spawnSyncAndExitWithoutError } = require('../common/child_process');
 const { isMainThread } = require('worker_threads');
 
-common.skipIfPerfettoEnabled();
 if (!isMainThread) {
   common.skip('This test only works on a main thread');
 }
 
 const assert = require('assert');
 const fs = require('fs');
 const tmpdir = require('../common/tmpdir');
+const { defaultTraceFileName } = require('../common/trace_events');
 
 try {
   require('trace_events');
@@ -56,7 +55,7 @@ assert.throws(() => {
 }, common.expectsError({
   code: 'ERR_ACCESS_DENIED',
   permission: 'FileSystemWrite',
-  resource: 'node_trace.1.log',
+  resource: defaultTraceFileName,
 }));
 
-assert.strictEqual(fs.existsSync('node_trace.1.log'), false);
+assert.strictEqual(fs.existsSync(defaultTraceFileName), false);

test/parallel/test-trace-events-async-hooks-dynamic.js

@@ -10,6 +10,8 @@ try {
   common.skip('missing trace events');
 }
 
+// Perfetto records nothing for a category enabled after the tracing session
+// started, so there is no dynamic enabling to test there yet.
 common.skipIfPerfettoEnabled();
 
 const assert = require('assert');

test/parallel/test-trace-events-binding.js

@@ -4,6 +4,8 @@ const assert = require('assert');
 const cp = require('child_process');
 const fs = require('fs');
 
+// V8's trace() builtin only accepts the begin, end and instant phases on a
+// perfetto build, so the nestable async phase used here throws a TypeError.
 common.skipIfPerfettoEnabled();
 
 const CODE = `

test/parallel/test-trace-events-console.js

@@ -5,6 +5,9 @@ const cp = require('child_process');
 const fs = require('fs');
 const tmpdir = require('../common/tmpdir');
 
+// console.count() throws on a perfetto build once node.console is enabled:
+// internal/trace_events picks the nestable async instant phase for counters,
+// which V8's trace() builtin rejects there.
 common.skipIfPerfettoEnabled();
 
 // Tests that node.console trace events for counters and time methods are

test/parallel/test-trace-events-dynamic-enable.js

@@ -4,6 +4,8 @@
 const common = require('../common');
 
 common.skipIfInspectorDisabled();
+// Needs two things a perfetto build does not have: the inspector NodeTracing
+// domain, and recording for a category enabled after the session started.
 common.skipIfPerfettoEnabled();
 
 const { isMainThread } = require('worker_threads');

test/parallel/test-trace-events-fs-async.js

@@ -5,6 +5,11 @@ const cp = require('child_process');
 const fs = require('fs');
 const util = require('util');
 
+// MKDir passes UV_FS_UNLINK to FS_ASYNC_TRACE_BEGIN1 (src/node_file.cc), so
+// the begin event is named `unlink` while the end event is named `mkdir`. The
+// legacy backend records both names, and this test passes off the end event.
+// Perfetto matches an async pair by name and drops the unmatched end, leaving
+// no `mkdir` event at all.
 common.skipIfPerfettoEnabled();
 
 const tests = { __proto__: null };

test/parallel/test-trace-events-get-category-enabled-buffer.js

@@ -10,6 +10,8 @@ try {
   common.skip('missing trace events');
 }
 
+// Perfetto aborts on a category that is not in its static registry, and its
+// enabled flag does not follow createTracing().enable().
 common.skipIfPerfettoEnabled();
 
 const { createTracing, getEnabledCategories } = require('trace_events');

test/parallel/test-trace-events-metadata.js

@@ -4,6 +4,8 @@ const assert = require('assert');
 const cp = require('child_process');
 const fs = require('fs');
 
+// A perfetto build drops the legacy metadata events, so none of the
+// process_name, version or node entries checked here are recorded.
 common.skipIfPerfettoEnabled();
 
 const CODE =