test(worker-threads): trace worker.js phases for the intermittent stall

[szegedi]

Worker Threads should work flakes on CI with nothing but:

Error: Timeout of 20000ms exceeded.

This records which phase the child was in, so whoever picks the stall up can see where it died instead of reconstructing it. It does not fix the stall, and there is no behaviour change unless DD_WORKER_TRACE_FILE is set.

Why it is a stall, not a slow runner

Measured on darwin-arm64 / Node 22:

	result
60 runs idle	0 anomalies, ~3.5–4.1s
80 runs under 8-way contention	0 stalls — median 4597ms, p90 4621ms, max 4635ms
deadline cut to 1ms	~60ms total

worker.js is almost entirely wall-clock deadline work, so only ~60ms actually scales with machine speed. On the same CI runner where a passing job ran should work in 5105ms, the failing job exceeded 20s while its CPU-bound sibling test took a comparable 13846ms vs 14138ms — so the runner was not slower. Reaching 20s is four to five times beyond anything slowness explains, and raising the timeout would hide it rather than fix it.

What this adds

Phase marks — per worker chain: spawned, sent a profile, exited — costing a string and an array push. DD_WORKER_TRACE_FILE additionally appends each mark to a file as it happens.

A file rather than stdout, deliberately: execFile buffers a child's output and only delivers it once the child closes, so a wedged child yields nothing. Appending synchronously as we go also means the trail survives the child being killed, which is exactly what the reap in afterEach does to it. Verified — SIGTERM mid-run still leaves the phases on disk:

+1069ms chain 1: first worker exited (0)
+1169ms chain 1: spawning second worker     <- last line before the kill

What was removed, and why

An earlier version of this PR armed a watchdog timer that produced a diagnostic report and called process.exit(). It wedged CI jobs for 40+ minutes each. Bisected over three runs:

change	Linux Node 22
test-side only (env option + async rewrite)	4/4 green
full change, watchdog armed	2/4 wedged >9 min
same instrumentation, timer never created	0/4 wedged

So arming the timer is the trigger. The mechanism was not identified — process.exit() with a live busy worker and process.report.getReport() against an unresponsive worker both complete in ~550ms locally, so neither explains it. Hence no timer, no report call and no process.exit() here. Nothing in this PR runs on a schedule.

Also worth recording

The bisect showed the stall reproduces on Linux Node 22, at roughly one job in four. The earlier 20-run history — in which only win32-test-22 (12×) and darwin-arm64-test-22 (5×) ever failed — was undersampling, not a platform boundary. Linux is a much easier target for whoever debugs this.

It is also not our profiler configuration: on win32, DD_WALL_USE_SIGPROF and DD_WALL_USE_CPED are both false for every Node version (they sit inside #ifndef _WIN32) and worker.js sets withContexts = darwin || linux, so all five win32 versions run identical configuration and identical compiled paths — yet only Node 22 fails.

Verification

Full matrix green: 30/30 test jobs, 100–172s each, across alpine / centos / linux-x64 / linux-arm64 / darwin-arm64 / win32 on Node 18, 20, 22, 24, 26. Locally: gts check 0 errors, should work 3847ms with tracing off, 22 trace lines with it on.

[github-actions]

Overall package size

Self size: 2.49 MB
Deduped: 3.19 MB
No deduping: 3.19 MB

Dependency sizes

| name | version | self size | total size | |------|---------|-----------|------------| | pprof-format | 2.3.1 | 504.33 kB | 504.33 kB | | source-map | 0.8.0 | 185.66 kB | 185.66 kB | | node-gyp-build | 4.8.4 | 13.86 kB | 13.86 kB |

_{🤖 This report was automatically generated by heaviest-objects-in-the-universe}