[rush-lib, rush-client-core, rush-daemon-transport] Fix the tests that fail in the publish pipeline and in CI

[Sean Larkin (TheLarkInn)]

Summary

Every publish run since #6046 merged (1e18b16) has failed in "Rush retest", so nothing has been published since. The publish pipelines set FORCE_COLOR: 1, which GitHub CI does not, and they run on busy agents. Under those conditions, three tests fail:

Run	Pipeline	Failed
12800	rushstack NPM Publish	A, B
12801	rushstack NPM Publish	A, B
12802	rushstack NPM Publish (rush)	A, B, C
12803	rushstack NPM Publish	A, B

B is a product bug: with FORCE_COLOR set, the error that the client reports for a crashed daemon included the stack of the daemon's crash report. A and C are test bugs.

This PR's own CI then found D, a test that reads /proc of a process before the process has finished starting. Three other test files had the same bug; the second commit fixes all four. It also found E, a rush-lib test that can take longer on Windows than Jest's default timeout allows; the third commit gives it 30 s.

Details

A. rush-daemon-transport DaemonOperationGroupRecorder.test.ts, "keeps a detached child record until inherited streams close":

TypeError: The "pid" argument must be of type number. Received type number (NaN)

With FORCE_COLOR, console.log(child.pid) in the test's child script writes \x1b[33m<pid>\x1b[39m, and Number() of that is NaN. The child now writes the PID with process.stdout.write(String(child.pid)).

B. rush-client-core DaemonDisconnect.test.ts, "findLoggedFatalError › returns the message of an unhandled rejection":

Expected pattern: /^UnhandledPromiseRejection: .* "reason"\.$/
Received string:  "UnhandledPromiseRejection: … The promise rejected with the reason \"reason\".     at throwUnhandledRejectionsMode (node:internal/process/promises:392:7)     at processPromiseRejections (node:internal/process/promises:475:17)     at process.processTicksAndRejections (node:internal/process/task_queues:104:32) { code: 'ERR_UNHANDLED_REJECTION' }"

With FORCE_COLOR, Node.js colors its crash report although stderr is the launcher log, not a terminal. It wraps internal stack frames in \x1b[90m…\x1b[39m, so STACK_FRAME did not match them and they joined the message. The other crash report tests passed only because their first frame is user code, which Node.js does not color; every frame of an ERR_UNHANDLED_REJECTION is internal. I checked Node.js 20.18.3, 22.23.3 and 24.12.0: each colors the report with FORCE_COLOR=1 and none does without it.

findLoggedFatalError now removes ANSI escape sequences before it reads the lines. The pattern is AnsiEscape's CSI pattern from @rushstack/terminal, which rush-client-core does not depend on. The crash report tests now run with FORCE_COLOR=0 and FORCE_COLOR=1, so GitHub CI covers the colored report too. I considered starting the daemon with NODE_DISABLE_COLORS instead, but that changes the environment the daemon runs in, and reading the log without escapes is enough.

C. rush-client-core connectOrStartDaemonLiveOwner.test.ts, "a live daemon owner that does not answer › names the parent that has not reaped an owner that exited", in 12802 only:

ENOENT: no such file or directory, open '/proc/39313/stat'

The test runs sh -c 'sleep 0 & echo $!; exec sleep 600' to get a zombie that its parent never reaps. If sleep 0 exits before the shell runs exec, the shell reaps it (dash and bash reap finished background jobs after a builtin), so the zombie is gone before the test reads it. I probed this with the shell pinned to a CPU that 3 busy loops share, 300 runs each:

Child	Alive at the first read	Gone at the first read
sleep 0	25	275
sleep 1	300	0

The test now uses sleep 1, as ZOMBIE_PARENT_SCRIPT in rush-daemon-transport's DaemonProcessStat.test.ts already does. This is a margin, not a guarantee: the shell must reach exec within 1 s. The original test did not fail on my machine (0 of 23 runs with its shell pinned to a busy CPU), so the evidence for C is the probe and the 12802 log.

D. Found by this PR's CI, not by the publish runs: rush-daemon-transport OperationGroupMarker.test.ts, "finds only an exact entry of the environment that a process started with", on Node.js v24 (ubuntu) in job 110952865222:

> 57 |   expect(hasEnvironmentEntry(pid, ENTRY)).toBe(true);
Expected: true
Received: false

The test read the child's /proc/<pid>/environ right after the 'spawn' event, which does not mean that the child's exec has finished. libuv reports a spawn when the child's close-on-exec signal pipe reaches EOF. Usually the parent closes its end of the pipe first, so the child's exec makes the last close, and EOF comes after the exec. If the parent is delayed between fork and its close, as on a loaded CI runner, the child's exec closes its end first, and the parent's close is the last one: EOF comes at once, while the child is still in execve and /proc shows no environment yet. #6046's CI hit the same race in run 36754086279, where a just-spawned sleep had no command line yet; that test already waits for the process to sleep.

To prove it, an LD_PRELOAD shim delays the parent's close of that pipe, and a large environment makes the child's exec slow enough to land in. Runs that found no marker in the child's environment, of 90 per cell:

Read	Node.js 24.12.0	Node.js 22.23.3
node child, right after 'spawn' (old)	80	71
node child, after it prints (new)	0	0
sleep, right after 'spawn' (old)	63	82
sleep, polled until /proc shows the marker (new)	0	0

To reproduce the race

delayclose.c, preloaded into the parent only, delays libuv's close of the signal pipe:

#define _GNU_SOURCE
#include <dlfcn.h>
#include <fcntl.h>
#include <stdarg.h>
#include <stdlib.h>
#include <sys/stat.h>
#include <sys/syscall.h>
#include <time.h>
#include <unistd.h>

static pid_t parent;
__attribute__((constructor)) static void init(void) { parent = getpid(); }

typedef long (*syscall_fn)(long, ...);

long syscall(long number, ...) {
  static syscall_fn real;
  if (!real) real = (syscall_fn)dlsym(RTLD_NEXT, "syscall");
  va_list ap;
  va_start(ap, number);
  long a1 = va_arg(ap, long), a2 = va_arg(ap, long), a3 = va_arg(ap, long);
  long a4 = va_arg(ap, long), a5 = va_arg(ap, long), a6 = va_arg(ap, long);
  va_end(ap);
  const char *delay = number == SYS_close && getpid() == parent ? getenv("CLOSE_DELAY_US") : NULL;
  if (delay) {
    struct stat st;
    int fd = (int)a1;
    if (fstat(fd, &st) == 0 && S_ISFIFO(st.st_mode) && (fcntl(fd, F_GETFL) & O_ACCMODE) == O_WRONLY &&
        (fcntl(fd, F_GETFD) & FD_CLOEXEC)) {
      long us = atol(delay);
      struct timespec ts = { us / 1000000, (us % 1000000) * 1000 };
      nanosleep(&ts, NULL);
    }
  }
  return real(number, a1, a2, a3, a4, a5, a6);
}

probe.js reads the environment right after 'spawn', as the old test did:

const { spawn } = require('node:child_process');
const { once } = require('node:events');
const fs = require('node:fs');

const env = { MARKER: '1' };
for (let i = 0; i < 20000; i++) env[`F${i}`] = 'x';

(async () => {
  let missed = 0;
  for (let i = 0; i < 30; i++) {
    const child = spawn(process.execPath, ['-e', 'setTimeout(() => {}, 30000)'], { env, stdio: 'ignore' });
    await once(child, 'spawn');
    if (!fs.readFileSync(`/proc/${child.pid}/environ`, 'utf8').includes('MARKER=1')) missed++;
    child.kill('SIGKILL');
    await once(child, 'exit');
  }
  console.log(`${missed} of 30 reads missed the environment`);
})();

$ gcc -shared -fPIC -O2 -o delayclose.so delayclose.c -ldl
$ node probe.js
0 of 30 reads missed the environment
$ LD_PRELOAD=$PWD/delayclose.so CLOSE_DELAY_US=2200 node probe.js
28 of 30 reads missed the environment

The delay must land inside the child's exec, which depends on the machine; on mine, 2100 to 2300 µs did.

Four test files read /proc of a process they had just spawned. They now wait until it runs:

• OperationGroupMarker.test.ts and rush-client-core NativeLockHolder.test.ts: the child prints once it runs, and the test waits for that. In NativeLockHolder.test.ts, "skips a lock file whose PID now belongs to a process that started after it was written" reads the holder's command line, and "names only the PID of a holder whose command it cannot shorten" could pass on an empty one.
• OperationGroupSpawnMarkReap.test.ts and OperationMarkerInheritance.test.ts: sleep cannot print, so the test polls until /proc shows the marker. Without the wait, "never signals a process with the marker that started over 1 s after the spawn mark" could pass only because the environment was not readable yet.
• The /proc/uptime reader of OperationGroupSpawnMarkReap.test.ts moves to UptimeTicksFixture.ts, to keep the file within the package's 100-line limit.

E. Also found by this PR's CI: rush-lib OperationBuildCacheDeferredWrites.test.ts, "kills tar, and deletes its partial archive and the sealed files, when aborted", on Node.js v26 (windows) in job 110987993537:

thrown: "Exceeded timeout of 5000 ms for a test.

The test ran under Jest's default timeout of 5 s. On Windows, its stand-in for the clone copies all 2 GB of the sparse file that tar archives, and then the test waits up to 10 s for the partial archive and 5 s for tar to exit. In the previous run, where it passed, the file's 6 tests took 5.0 and 5.3 s on Windows and 1.8 s on Linux; in this run they took 8.8 s. The test now has a timeout of 30 s.

GitHub CI does not set FORCE_COLOR, which is why #6046's checks passed. The new FORCE_COLOR=1 tests cover B in CI. Setting FORCE_COLOR in .github/workflows/ci.yml would catch tests like A in every project; this PR does not change CI.

After this merges, the publish pipelines need to run again. #6046's change files are still pending.

How it was tested

• rush retest of both projects under the publish agent's conditions, Node.js 24.12.0 with FORCE_COLOR=1:
  • rush-daemon-transport: 237 passed, 0 failed. The publish runs had 236 passed and 1 failed.
  • rush-client-core: 381 passed, 0 failed. The publish runs had 375 passed and 1 failed, or 374 and 2 in 12802. The 5 additional tests are the FORCE_COLOR=1 variants.
• The same on Node.js 22.23.3 without FORCE_COLOR: 237 and 381 passed, 0 failed.
• Node.js 20.18.3, the 3 changed test files, with and without FORCE_COLOR=1: all passed.
• Against the old DaemonDisconnect.ts, the new FORCE_COLOR=1 test for B fails with the publish run's message, without FORCE_COLOR in the environment.
• C: the fixed test passed 10 of 10 runs with its shell pinned to a CPU that 8 busy loops share, with FORCE_COLOR=1.
• D: the shim runs above. After the second commit, rush retest of both projects passed again with the same totals, on Node.js 24.12.0 with FORCE_COLOR=1, on Node.js 22.23.3, and on Node.js 20.18.3.
• E: rush retest of rush-lib on Node.js 22.23.3 (Linux): 139 suites, 1,884 passed, 0 failed. This PR's Windows CI jobs run the changed test on Windows.
• rush build of the three projects: no warnings.