test(cli): make the unread-reader ceiling a load-independent constant at RUN_TIMEOUT_MS - #14715
Conversation
…ad of a constant `run-dev-unbuilt-workspace.e2e.test.ts` case 5 armed a fixed `UNREAD_HARD_CAP_MS = 40_000` and asserted the child ended before it. The constant was derived as "the worst child runtime plus the shim's 15 s bound", which sums two terms that do not behave alike: the shim's bound is wall clock and does not move with load, while the child's pre-drain work is elastic and `bin/run-dev.js` itself records it at 1.0 s idle against 6.9 s contended. The elastic term's real budget was 25 s, sized against one box, and merge-queue shards running the full suite six ways sharded went over it. The ceiling is now derived per run from case 1 — the same argv under the same `--import` hook, measured on the same runner minutes earlier — clamped between the constant it replaces and `RUN_TIMEOUT_MS`, and budgeting two of the shim's bounds rather than one because `run-dev.js` awaits two announcers that can each pay it. Nothing is skipped, relaxed or removed: all three assertions stand, and each now carries the derivation so a queue triage can tell a hang from a ceiling that was too small. Adds a case holding the mirrored `SHIM_DRAIN_STALL_MS` equal to the shim's own `STDERR_DRAIN_STALL_MS`, so the derivation cannot be sized around a bound that moved. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016yfqQh2dBgPAymYd7xipza
…n-dev-unbuilt-workspace-flake
📓 Docs Drift CheckNothing in this diff resolved to a documentable surface (no symbol, route or SDK anchor derived from 0 changed package(s)), so this run has no opinion about the docs. What this run could not see
Coarse fallback — 0 page(s) merely mention a changed package (the pre-#9192 predicate, kept for the deliberately-wide backstop): |
⛔ merge queue 构建失败 — 先分诊,再决定要不要重排队列构建 33682230163 红了。队列跑的是全量套件(PR 侧 CI 只跑 affected 子集), 失败的 job(日志抽取,best effort):
跨 PR 相同签名(24h,按失败测试文件聚合):
历史信号:
分诊清单:
Generated by Claude Code · merge-queue-triage workflow (#4859) |
⛔ merge queue 构建失败 — 先分诊,再决定要不要重排队列构建 33685006566 红了。队列跑的是全量套件(PR 侧 CI 只跑 affected 子集), 失败的 job(日志抽取,best effort):
跨 PR 相同签名(24h,按失败测试文件聚合):
历史信号:
分诊清单:
Generated by Claude Code · merge-queue-triage workflow (#4859) |
…MEOUT_MS The derived ceiling was evicted from the merge queue by its own assertion: `cap 61464 ms = clamp(40000, 180000, 4 x 7866 ms measured child runtime + 2 x 15000 ms shim bound)` — the child outlived a ceiling built from a sample taken minutes earlier on the same runner by more than 7.8x that sample, against a FACTOR of 4. That is the second ceiling here beaten by a runner that got busier after the number was chosen; the first was `UNREAD_HARD_CAP_MS = 40_000`. Raising the factor would be the same move a third time, and nothing measures the spread between a calibration and a later run on a six-way-sharded queue runner, so no factor can be justified as enough — only as not beaten yet. What removes the choice is the property the case pins. The failure it was written against is an UNBOUNDED wait, observed alive at 25 s, 30 s and 60 s and ending only when something killed it, so ANY finite ceiling catches it. Tightening buys no detection, only false reds. The ceiling therefore wants to be the largest value that keeps the failure legible and must not track load: `RUN_TIMEOUT_MS`, past which a SIGKILL is replaced by a `beforeAll` timeout that reds all six cases and names none. It is already this file's budget for one child of this suite, so it is one number to get wrong instead of two. The `elapsedMs < cap` assertion goes with the derivation: against a constant cap it asserts nothing `signal === null` does not, since the harness kills at exactly that cap, and it was the only reading here a slower box could move on its own. The two product assertions stand — the child exits on its own, with code 2 — and the measurement is kept as evidence in the failure message rather than as an input to the threshold. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016yfqQh2dBgPAymYd7xipza
…green Measured twice on one box minutes apart, same tree: disabling the no-progress branch in `bin/run-dev.js` red case 5 at 180072 ms once, and passed it in 31.9 s the run before. The comment above already explains why — whether the tail finds bytes still pending moves with load — but it did not say that the consequence lands on anyone ABLATING the bound, who reads one green run as "this case does not discriminate" and goes looking for the wrong defect. Records the out-of-band reading that settles it either way, with the byte counts: 135408 bytes still held at a clean exit 2 in 19271 ms, against 145638 held by a child still alive at 90 s with the branch disabled. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016yfqQh2dBgPAymYd7xipza
…n-dev-unbuilt-workspace-flake
…clock `run-dev-unbuilt-workspace.e2e.test.ts` case 6 asserted `closedEnd.elapsedMs < STALL_MS` — a fixed wall-clock bound borrowed from case 4's parent stall, against a term that is entirely elastic. Tracing what produces that timing shows the bound was not merely fragile, it was a phantom. With the read end destroyed, oclif's `displayWarnings()` makes the first stderr write, the pipe is already gone, node raises `write EPIPE` as an `error` event on `process.stderr`, nothing is listening, and the child dies of an uncaught exception at ~1.4 s with exit 1. `writeStderr()` is never reached, so the bound the case was named after is never armed. Traced with a `--import` observer: the shim's own 415-byte write is #175 at 9250 ms, behind 174 oclif writes that all EPIPE — 7.8 s after the real child is already dead. Ablated on `bin/run-dev.js`, same box, same probe (old bound's verdict in brackets): pristine exit 1 at 1387-1711 ms [green]; write callback removed so a closed path could only finish on the bound, which is the regression this case named, exit 1 at 1517-1633 ms [GREEN]; EPIPE made non-fatal, exit 2 at 8787-8979 ms [green, 1.2 s spare]; both, so the path really pays the bound, exit 2 at 23601-23712 ms [red]. The measurement moved only where the exit code moved too, and it stayed green on its own regression. So the exit status is the observation the wall clock was standing in for, and it carries no load term: 1 means the child died on its first write, 2 means it reached `handle()`, which is only reachable through `writeStderr()`. This asserts that directly and keeps the elapsed reading as evidence in the failure message, the same split #14715 made for case 5. Exit 1 is what the CLI does rather than what anyone contracted — filed as #14858, and pinning today's value is what stops that changing silently. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016yfqQh2dBgPAymYd7xipza
Fixes #14648
Case 5 of
packages/cli/test/run-dev-unbuilt-workspace.e2e.test.tshas now ejected the merge queue under two different ceilings. This revision removes the ceiling as a tunable number rather than retuning it a third time.What the queue proved, and what it did not
The previous revision replaced the fixed
UNREAD_HARD_CAP_MS = 40_000with a per-run derivation. In the queue at 21:50Z it was evicted by its own new assertion:⭐ The diagnostic did its job — it is the only reason there are numbers to read. Calibration came in at 7 866 ms, the ceiling at 61 464 ms, and the child outlived it: more than 7.8x its own calibration, against a
FACTORof 4. The load model is falsified. The diagnosis is not.Why not "raise FACTOR"
Raising the factor is the same move a third time, and it has the same shape as the constant it replaced. Both previous ceilings were sized comfortably above the worst thing on record when they were written, and both were beaten by a runner that got busier afterwards:
40_000constantclamp(40_000, 180_000, 4 x calibration + 2 x bound)A factor picked now would be fitted to the last failure. Nothing on record measures the spread between a calibration and a later run on a shared, six-way-sharded queue runner, so no factor can be justified as enough — only as not beaten yet, which is exactly what the constant it replaced could also say. The derivation's extra term tracks load, and a term that tracks load is a prediction about contention drawn from a sample of the past.
What removes the choice: the property the case pins
This PR's own strongest argument points here, and it holds:
The failure this case was written against is a drain wait with no bound armed at all — observed alive at 25 s, 30 s and 60 s, and ending only when something else killed it. Tightening a ceiling buys no detection against that; it buys false reds, and each one here costs a queue rebuild. So the ceiling wants to be the largest value that keeps the failure legible, and it must not track load.
RUN_TIMEOUT_MSis that value, and it is not a new number:beforeAlltimeout, which reds all six cases and names none — so it is where legibility ends, not a preference;The change
deriveUnreadCapMs,UNREAD_CAP_RUNTIME_FACTOR,UNREAD_CAP_FLOOR_MS,UNREAD_CAP_CEILING_MSand the mutableunreadCapMsare gone.The
elapsedMsassertion is dropped — it was the only load-sensitive reading left. Against a constant cap it asserts nothingsignal === nulldoes not: the harness kills at exactly that cap, so a child that was not killed ran less than it. What it added was a race at the instant a self-exit and the timer coincide. Detection unchanged, one fewer way to red.The two remaining assertions are about product behaviour and are untouched: the child exits on its own (
signal === null), and it exitscode === 2.The measurement is kept as evidence, never as a threshold input. The failure message still carries the cap, this child's lifetime and case 1's calibration, so a triage can still tell a hang from a runner on fire without opening the file. Nothing is skipped, quarantined, relaxed or deleted, and the diagnostic message survives intact.
SHIM_DRAIN_STALL_MSand its parity case stay: the ceiling no longer budgets that bound, butSTALL_MSmust still sit strictly below it or case 4 stops discriminating, and case 6 reads the closed-reader fast path against it. The docblock is re-anchored to those two surviving consumers rather than to the derivation that is gone.Verification — final tree
cbd95772d0, clean working treeOne file changed,
134 insertions(+), 10 deletions(-). Heavy runs went throughscripts/pm/os-verify-lock.sh; verdicts are quoted from itsVERDICTline, and no narrowing was needed anywhere — the lock was free on every acquisition (waited 0s).pnpm --filter @objectstack/cli exec vitest run --maxWorkers=2 --reporter=verbose test/run-dev-unbuilt-workspace.e2e.test.ts— 11 passed (11), 47.54 s.VERDICT command-exit 0 · held the lock 49s.pnpm lint(eslint . --no-inline-config) —VERDICT command-exit 0 · held the lock 61s. Not narrowed.pnpm check:nul-bytes— OK, 8 042 text files scanned, 0 raw control bytes.node scripts/pm/dispatch-gates.mjs --commands --repo objectstack-ai/objectstack, re-derived after mergingorigin/mainbecause the first derivation reported a stale tree (17 commits behind, 4 gate scripts changed across the range). 27 derived, 27 run, 0 UNRUN per--ranreconciliation. Every exit captured by redirecting to a file first — no pipe touches the status.node scripts/check-test-completeness.mjs(exit 3): "local log to hand it, so the local reading for this gate is NOT MEASURED. ⛔ It is not a red, and there is nothing here to fix."pnpm check:dual-build-cjs-loads(exit 3): "PREREQUISITE NOT MET — this gate reads built output, and some package has no dist/. Runpnpm buildfirst. ⛔ This is NOT a pass: nothing was measured."typecheckdoes not cover this file —packages/cli/tsconfig.jsonhas"include": ["src"], so a greenpnpm --filter @objectstack/cli typechecksays nothing about atest/file. Checked explicitly instead:tsc --ignoreConfig --noEmit --strict --module nodenext --moduleResolution nodenext --target es2022 --skipLibCheck --types node test/run-dev-unbuilt-workspace.e2e.test.ts— exit 0, and--listFilesconfirms the file really is in that program (243 files, the target among them) rather than a green over nothing.Ablation on the final tree — the hang is still caught
The ceiling is only the instrument; the property is that a real hang reds. Mutation:
bin/run-dev.js'sif (Date.now() - lastProgressAt…finish();no-progress branch replaced by one that never finishes.1to0, injected-marker count0to1, bloba4fd1001toc85ad531.1 failed | 10 passed (11), 207.12 s,VERDICT command-exit 1— readingthe harness SIGKILLed the child — it was still alive at the ceiling. cap 180000 ms (RUN_TIMEOUT_MS, constant and load-independent by design); this child ran 180094 ms; case 1 measured the same child at 4782 ms on this runner minutes earlier. A 38x ratio against the calibration: unambiguously a hang, which is the whole point of keeping the measurement in the message.git checkout HEAD --on an absolute path undertrap … EXIT INT TERM: blob back toa4fd1001,git diff HEADempty.const CLI = resolve(HERE, '../bin/run-dev.js')), so nodist/mediates the spawn path.Measured here, and worth more than the pass it interrupted: the first ablation run went green in 31.9 s, and the same mutation on the same tree red at 180 072 ms minutes later. That is not my change and not a flake in the assertion — it is the fixture property the file's own comment already describes: whether the tail finds bytes still pending, and so whether the bound is reached at all, moves with load.
Settled out of band, driving the same child directly (
spawn,stderr.pause(), never read), where the pending bytes can actually be counted:code 2,signal null— exits on its owncode null,signal SIGKILL— still alive at the capSo the backpressure is real, the bound is what releases the child, and the mutation does produce a genuine hang. A commit in this PR writes that into the file, because the next person to ablate this bound will otherwise read one green run as "the case does not discriminate" and go looking for the wrong defect.
Scope
Only
packages/cli/test/run-dev-unbuilt-workspace.e2e.test.tsis changed.bin/run-dev.jswas mutated for the ablation and restored, proven by blob identity.packages/cli/vitest.config.tsandtest/vitest-tiers-partition.test.tsbelong to #14554 and are untouched here.The neighbouring
closedEnd.elapsedMs < STALL_MSassertion is the same class of oracle on a fully elastic measurement. It has ejected nothing, its margin is roughly twice this one's, and the load-robust rewrite is genuinely arguable rather than mechanical. Left alone deliberately rather than changed on a guess.No changeset: test-only, publishes nothing from any package.
skip-changesetis applied.Session: https://claude.ai/code/session_016yfqQh2dBgPAymYd7xipza
🤖 Generated with Claude Code
Generated by Claude Code