Skip to content

Commit 2678600

Browse files
test(cli): runServe spawns the source entry under node, not the tsx binary, and settles once its child is gone (#28666)
<!-- claude-projects-attribution: {"github_login":"os-project-manager"} --> _Requested by **Leehom** · [project thread](https://claude.ai/code/project/chan_01TenzsRopZj4jMbvjX8uz1X?thread=cmsg_01TenzsRopZj4jMbvjX8uz1X92FCS32KeSJM272mPgBt82)_ Part of #23181 (slice 35, the tsx wrapper lever inside the shared `runServe()` helper, with seat ruling 6556896224 as amended by 6557574123). The card stays open for later slices. Clause-②: no Metadata-protocol: none ## 维护者速读 - **改了什么**:`packages/cli/test/helpers/serve-process.ts` 里的共享测试辅助函数 `runServe()` 起 `os serve` 子进程时,不再经 `node_modules/.bin/tsx` 包一层,改为用当前 `node`(`process.execPath`)直接跑 `bin/run-dev.js`。入口、参数、cwd、`childEnv({...})` 环境、stdio 处理、`waitFor` 匹配与超时都不变;`TSX` 导出保留(别的文件还在用)。另外,停子进程时先发 SIGTERM,最多等 1 秒,子进程还在就 SIGKILL,确认子进程已退出后才返回结果(按席位裁决 A2)。只改这一个文件,调用方一个没动。 - **为什么改**:卡 #23181 的测试提速职责。tsx 可执行文件本身是一个启动进程,再起第二个 node 去跑入口,每次启动白付几秒。slice 29、34 已对测试文件自己的子进程做了同样替换,但都不许碰 `test/helpers/**`,这是剩下的那一处。 - **风险与回滚**:tsx 以前会在转发 SIGTERM 约 30 ms 后 SIGKILL 子进程,换成 node 后没有这层,曾有被拒绝启动的 `os serve` 子进程在测试结束后残留(约 900 MB);本 PR 用上面的 1 秒兜底补回,确定性探针证明残留归零。只改测试辅助文件,不发布任何东西(cli 的 `files[]` 只有 dist、README、CHANGELOG);没有改任何断言、用例、超时、分层或 `// test-budget:` 头;回滚即 revert。 - **先看**:`packages/cli/test/helpers/serve-process.ts` 的 `runServe()`:`spawn(process.execPath, [CLI, 'serve', …])` 那一行,`finish()` / `childGone()` / `settle()` 三段,以及 `SIGKILL_GRACE_MS` 的说明。 - **两分钟验证**:`cd packages/cli && OS_TEST_TIERS=nightly pnpm exec vitest run test/serve-organizations-mount-failure.e2e.test.ts` → 4/4 通过,墙钟约 30 s(改前约 48 s)。 - **需要你做的**:无,席位落地。 ## What changes `runServe()` in `packages/cli/test/helpers/serve-process.ts` spawned `TSX, [CLI, 'serve', …]`. It now spawns `process.execPath, [CLI, 'serve', …]`, slice 12's way. Nothing else in the call changes: the argv (including the `--port 0` default), `cwd`, the `childEnv({...})` block, the stdout/stderr collection, the `waitFor` matching, the port read-back and the timeout are byte-identical. - The `TSX` export stays: `oclif-manifest.global-setup.ts` and other test files import it. - The helper's own prose that said this spawn goes through tsx now says what it does: the `CLI` docblock, the "other entrypoint" header (two lines) and a new paragraph in the `runServe()` docblock stating why the child is node and not the tsx binary. - **Stopping the child (seat ruling A2).** The tsx binary's signal relay SIGKILLed a child that had not acknowledged a relayed SIGTERM within about 30 ms, and that is what kept the docblock's "never leaves the child running" true. A node child has no relay. `finish()` now sends SIGTERM, waits for the child's `exit` for at most `SIGKILL_GRACE_MS` (1 s), sends SIGKILL if it is still running, and only then settles. `stdout` and `stderr` are snapshotted at the match, so a caller reads the same bytes as before. A child whose spawn failed (no pid) settles at once. No deadline a caller reads changes. - Why not a timer: the vitest forks worker is torn down soon after its last case, so a timer inside it (unref'd or ref'd) or a process `exit` hook never fires for a file's last boot. Measured on the probe below: 1 of 1, 2 of 2 and 3 of 3 survivors. - Why plain node still runs `src/`: `bin/run-dev.js` sets `NODE_ENV=development`, under which @oclif/core registers tsx in-process for the command modules, as slices 12, 29 and 34 rely on. **Left on tsx, deliberately:** | spawn | why | |:--|:--| | `test/helpers/oclif-manifest.global-setup.ts` | runs its own `.ts` file through the tsx binary (`execFile(TSX, [THIS_FILE, …])`), and that file imports `./serve-process.js`, a `.js` specifier onto a `.ts` file, which plain node cannot resolve. It is also outside this slice's file surface. | | any other spawn in `serve-process.ts` | there is none: the helper's only other child is the `node -e` port-draw probe, already `process.execPath`. | **Callers, re-derived on `0e78922e`.** The order's list (`pm-orders/server/evidence/23181-s35/callers.txt`) is a text grep: 20 files, 61 mentions. Counting only files that import `runServe` from the helper and call it in code (comments masked), the real population is **10 files, 22 call sites**: `serve-app-runtime-hooks.e2e` (1) · `serve-boot-diagnostics-noise-budget.e2e` (1) · `serve-boot-diagnostics.e2e` (2) · `serve-cluster-driver-diagnosis.e2e` (1) · `serve-no-artifact.e2e` (5) · `serve-organizations-host-resolution.e2e` (3) · `serve-organizations-mount-failure.e2e` (4) · `serve-package-declared-capabilities` (1) · `serve-package-registry-always-on.e2e` (1) · `serve-port-readback.e2e` (3) The other 10 listed files name `runServe` in prose, or define a local function of the same name (`artifact-pinned-boot.e2e`, `uncreatable-directory-doors.integration`), or hold it as census vocabulary (`released-port-production-spawn.pin`). All 20 import the helper module, so all 20 were run. No caller asserts on the child's process title, `argv[0]`, a wrapper process or signal relay through tsx, and all pass unchanged. The relay mattered to the helper itself, not to a caller: see *Stopping the child*. Not changed: no caller file, no assertion, expected output, case name, timeout, tier, project, `// test-budget:` header, other helper or source file. ## Tests - **Every listed file passes on the final head `23e32949`** (after merging `origin/main` once, which brought in slices 29, 30 and 34). Queue tier: 6/6 files, 41/41 tests. Nightly tier (`OS_TEST_TIERS=nightly`, where the `.e2e` files run): 14/14 files, 69/69 tests. Both exit 0, no skips. Same counts on `95062773` and `3bb649e4`. - **Leak red/green (the deterministic probe, seat amendment 6557574123).** A temporary test file, never committed, whose only case is `runServe` on a config that installs a SIGTERM listener and never finishes loading. Read with `pgrep` + the child's cwd 3 s after vitest exits. With A2 (`3bb649e4`): 0 survivors, 3 of 3 runs. The switch alone (`95062773` bytes written into the same path, blob-hash checked, restored from `HEAD`): 1 survivor in each of 3 of 3 runs. Probe and rows: `pm-orders/server/evidence/23181-s35/sigterm-probe.test.ts.txt`, `sig-probe.sh`, `redgreen.sh`, `sig-rows.txt`. - The first reading was `serve-package-declared-capabilities`' refused-boot case (`tiers`): on the switch alone it left its `os serve` running after the file, about 900 MB each, 4 of 4 runs between 09:10Z and 09:41Z, and 0 of 3 on base. It then read 0 of 4 on the same bytes between 11:36Z and 11:40Z, so it is intermittent and is not the proof. - **A/B** (one box, one lock hold, N=3, `--maxWorkers=1`, one vitest invocation per leg, base first in rounds 1 and 3, head first in round 2). For each base leg the base bytes of `serve-process.ts` were written into the same path and restored from `HEAD` after it, checked by blob hash; tree restored, `git diff HEAD` empty. `.e2e` files ran with `OS_TEST_TIERS=nightly`, `serve-package-declared-capabilities` with `queue` (the oclif test manifest on, as in CI). Whole process wall per run, seconds; every leg exit 0 with the same test count on both sides: | file | base | head | mean | change | |:--|:--|:--|:--|--:| | `serve-package-declared-capabilities` (queue) | 67.0, 72.2, 69.0 | 45.6, 47.0, 47.7 | 69.4 → 46.8 | −32.6% | | `serve-no-artifact.e2e` | 63.2, 69.0, 72.1 | 39.3, 41.5, 41.2 | 68.1 → 40.7 | −40.3% | | `serve-organizations-mount-failure.e2e` | 47.8, 47.0, 48.8 | 27.9, 27.9, 28.3 | 47.9 → 28.0 | −41.4% | | `serve-port-readback.e2e` | 29.1, 30.3, 30.3 | 18.6, 20.6, 20.7 | 29.9 → 20.0 | −33.2% | | `serve-boot-diagnostics.e2e` | 28.2, 29.0, 32.3 | 18.3, 18.8, 20.1 | 29.8 → 19.1 | −36.1% | | `serve-cluster-driver-diagnosis.e2e` | 63.5, 65.8, 70.4 | 37.9, 37.4, 40.7 | 66.6 → 38.7 | −41.9% | | `serve-app-runtime-hooks.e2e` | 33.3, 32.6, 36.7 | 26.1, 27.2, 28.9 | 34.2 → 27.4 | −19.9% | | **sum of means** | | | **345.9 → 220.6** | **−36.2%** | Rows and script: `pm-orders/server/evidence/23181-s35/ab-rows.txt`, `ab.sh` (project files). This A/B is the switch alone (`95062773`). With A2 the same seven files read 231.1 s (N=1), so −33% against base: the price of waiting for each child to exit. - **cli integration tier wall** (`OS_TEST_TIERS=nightly`, `--project integration`, `--maxWorkers=2`, N=1 each side, one lock hold, the switch alone): base 3126.6 s → head 2972.2 s (−4.9%), 85/85 files and 887/887 tests both sides. Only 9 of its 85 files call `runServe`. The queue integration tier holds one caller, so its whole-tier wall was not measured: one file's −22.6 s is inside N=1 noise there. - `pnpm --filter @objectstack/cli typecheck` exit 0 on the final head (with `NODE_OPTIONS=--max-old-space-size=4096`; the default heap OOMs in `check:test-typecheck`, unrelated to the diff). - Ablation: none. Test-only; no tested behaviour changed. ## Acceptance notes - **`skip-changeset`.** Test-only. `@objectstack/cli`'s `files[]` is `dist`, `README.md`, `CHANGELOG.md`; `test/helpers/` does not build into `dist/`, so no `files[]` content changes. - **Not reproduced: `os serve` ignoring SIGTERM outside the test.** A refused `os serve` boot (the `tiers` fixture) under plain node, given SIGTERM 0, 20, 40 or 60 ms after its fatal line or none at all, exited with code 1 within about 80 ms, 5 of 5 (`sigterm-probe.mjs`, `sigterm-delay.mjs` in the evidence folder). The orphans from the intermittent reading sat with their main thread in `futex_do_wait`, a SIGTERM listener installed (`SigCgt`) and an esbuild service child, so no JS was running to act on the signal. No card filed, because it does not reproduce through the public door. - **Where the saving lands.** 9 of the 10 real callers are `.e2e` files, which run only in the nightly battery, not in PR or merge-queue CI. So this PR's own Test Core shards carry one caller (`serve-package-declared-capabilities`); the rest of the saving shows in the hourly/nightly runs. ## Verification <details><summary>Derived gates on the final head 23e3294</summary> `node scripts/pm/dispatch-gates.mjs --commands --repo objectstack-ai/objectstack`: 42 commands. Each ran with its exit code captured before any pipe: 41 exit 0. `pnpm check:dual-build-cjs-loads` exit 3 (prerequisite not met: it needs a full `pnpm build`, and six packages outside the cli closure have no `dist/`): NOT MEASURED locally, CI runs it. `dispatch-gates --ran`: "42 derived famil(ies) accounted for — 41 run, 1 NOT-MEASURED (1 DERIVED from a recorded exit 3)". Record: `pm-orders/server/evidence/23181-s35/gates-ran-23e32949.txt`. Also, on the final head: `eslint --no-inline-config packages/cli/test/helpers/serve-process.ts` exit 0 (`@objectstack/cli` has no lint script of its own); `check-commit-card-trailers --range origin/main..HEAD` exit 0; `check-nul-bytes` exit 0. </details> 🤖 Generated with [Claude Code](https://claude.com/claude-code) https://claude.ai/code/session_01FEkQ5mQCvMVzNjNr4dStTS --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent e4ec4f2 commit 2678600

1 file changed

Lines changed: 64 additions & 4 deletions

File tree

‎packages/cli/test/helpers/serve-process.ts‎

Lines changed: 64 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -18,15 +18,18 @@ import { fileURLToPath } from 'node:url';
1818

1919
const HERE = resolve(fileURLToPath(import.meta.url), '..');
2020

21-
/** `bin/run-dev.js` — the CLI entrypoint that runs from TS source via tsx. */
21+
/**
22+
* `bin/run-dev.js` — the CLI entrypoint that runs from TS source. `runServe()`
23+
* spawns it with `process.execPath`; a caller may still put {@link TSX} in front.
24+
*/
2225
export const CLI = resolve(HERE, '../../bin/run-dev.js');
2326
export const TSX = resolve(HERE, '../../../../node_modules/.bin/tsx');
2427

2528
// ─────────────────────────────────────────────────────────────────────────
2629
// THE OTHER ENTRYPOINT: `bin/run.js`, and the build state it silently needs
2730
//
2831
// `CLI` above is `bin/run-dev.js`, which pins `NODE_ENV=development` and runs
29-
// the command from `src/` through tsx — so a file using `runServe()` needs no
32+
// the command from `src/` — so a file using `runServe()` needs no
3033
// `packages/cli/dist` at all. A handful of e2e files deliberately spawn the
3134
// OTHER entrypoint instead, because the thing they measure only exists when
3235
// oclif resolves the command from the BUILT artifact. Those files, and only
@@ -41,7 +44,7 @@ export const TSX = resolve(HERE, '../../../../node_modules/.bin/tsx');
4144
// the same defect the refusal exists to prevent, one level up.
4245
//
4346
// ⛔ It is NOT a general "is the CLI ready" preflight. `runServe()` must never
44-
// call it: a tsx child reads `src/`, so `packages/cli/dist` is not that child's
47+
// call it: a `bin/run-dev.js` child reads `src/`, so `packages/cli/dist` is not that child's
4548
// prerequisite and a guard that refused there would be a false red on a tree
4649
// that can run the test perfectly well.
4750
// ─────────────────────────────────────────────────────────────────────────
@@ -926,6 +929,28 @@ function portOf(args: string[]): string | undefined {
926929
return undefined;
927930
}
928931

932+
/**
933+
* How long `runServe()` lets a child it sent SIGTERM keep running before it
934+
* sends SIGKILL.
935+
*
936+
* The tsx binary used to give this for free: its signal relay forwards the
937+
* SIGTERM, waits about 30 ms for the child to acknowledge it, and then
938+
* SIGKILLs the child. A node child has no relay in front of it, and a boot that
939+
* was refused (`serve-package-declared-capabilities`, the `tiers` case) has
940+
* stayed alive after its SIGTERM: one orphaned `os serve` of about 900 MB per
941+
* run (#23181). This restores the guarantee the docblock below states.
942+
*
943+
* ⚠️ The SIGKILL cannot be left to a timer that outlives the call. The vitest
944+
* worker is torn down soon after its last case, so a timer there, `unref()`'d
945+
* or not, never fires for a file's last boot, and neither does a process
946+
* `exit` hook (measured: a child that ignores SIGTERM survived its file every
947+
* time with each of the three). So `runServe()` settles only once the child is
948+
* gone: SIGTERM first, so a child that drains promptly ends the way it always
949+
* did, then SIGKILL at this bound. The output a caller reads is still what the
950+
* child had printed when `waitFor` matched.
951+
*/
952+
const SIGKILL_GRACE_MS = 1_000;
953+
929954
/**
930955
* Boot `os serve` in `cwd`, collect its output until `waitFor` matches (or the
931956
* process exits), then stop it. Never leaves the child running.
@@ -966,6 +991,13 @@ function portOf(args: string[]): string | undefined {
966991
* matching stdout alone would wait for a stream that stays empty for the whole
967992
* boot. Both streams are still returned separately, which is what lets
968993
* `serve-stdio-stdout-purity.e2e.test.ts` assert stdout carries NOTHING else.
994+
*
995+
* The child is `process.execPath` running `bin/run-dev.js`, not the `tsx` binary
996+
* in front of it. That binary is a launcher process of its own that spawns a
997+
* second node to run the entry, so it doubled the process start and put a relay
998+
* between `child.kill()` and the CLI. One spawn of the entry measured
999+
* 9.5–11.8 s through it and 5.3–5.4 s through node, byte-identical stdout
1000+
* (#23181). The entry, its `src/` reads, argv, cwd and env are the same.
9691001
*/
9701002
export function runServe(
9711003
cwd: string,
@@ -979,7 +1011,7 @@ export function runServe(
9791011
const requested = portOf(args);
9801012
const argv = requested === undefined ? [...args, '--port', KERNEL_ASSIGNED_PORT] : args;
9811013
return new Promise((resolveRun, rejectRun) => {
982-
const child = spawn(TSX, [CLI, 'serve', opts.config ?? 'objectstack.config.ts', ...argv], {
1014+
const child = spawn(process.execPath, [CLI, 'serve', opts.config ?? 'objectstack.config.ts', ...argv], {
9831015
cwd,
9841016
// `childEnv`, never a bare `...process.env` — see its header for the
9851017
// measured reason (commit 1ddda1d00).
@@ -1012,6 +1044,34 @@ export function runServe(
10121044
} catch {
10131045
/* already gone */
10141046
}
1047+
// The bytes the caller reads are the ones printed up to the match; see
1048+
// SIGKILL_GRACE_MS for why settling waits until the child is gone.
1049+
const stdoutAtMatch = stdout;
1050+
const stderrAtMatch = stderr;
1051+
void childGone().then(() => settle(err, stdoutAtMatch, stderrAtMatch));
1052+
};
1053+
1054+
const childGone = () =>
1055+
new Promise<void>((done) => {
1056+
// No pid: the spawn itself failed (`error`), and no `exit` may follow.
1057+
if (child.pid === undefined || child.exitCode !== null || child.signalCode !== null) {
1058+
done();
1059+
return;
1060+
}
1061+
const fallback = setTimeout(() => {
1062+
try {
1063+
child.kill('SIGKILL');
1064+
} catch {
1065+
/* already gone */
1066+
}
1067+
}, SIGKILL_GRACE_MS);
1068+
child.once('exit', () => {
1069+
clearTimeout(fallback);
1070+
done();
1071+
});
1072+
});
1073+
1074+
const settle = (err: Error | undefined, stdout: string, stderr: string) => {
10151075
if (err) {
10161076
rejectRun(err);
10171077
return;

0 commit comments

Comments
 (0)