Skip to content

Windows evidence runs dispatched from stale refs used a pre-#4876 ci.yml and reproduced its batch-serialization bug #4901

Closed

Description

@lidge-jun

Client or integration

Other

Area

Platform (Windows / macOS / Linux)

Summary

Two Windows test shards failed on two different files during a period of heavy Actions queue contention, and both failures are the same defect: an in-test deadline that has to cover a Windows cold first child process start is sized for an idle runner.

Neither failure is a defect in the code under test. A lane=all dispatch of dev at 6d19a07369 (run 35215552842) passed all nine Windows shards with zero failures or cancellations.

The two failures blamed different tests, which is the pattern tests/helpers/test-budget.ts opens by warning about: "a run of windows-latest failures kept blaming a different test each time. The blame moved; the cause did not."

Failure 1 — run 35211904734, windows 3/9, tests/codex-integration/codex-write-lock.test.ts, two real processes contend for one lock > one OS user and one home take ONE lock case 1 (15.5s) and case 2 (17.2s); case 0 passed.

The stack resolves to waitFor at line 340 called from line 459, which is await waitFor(holdMarker). So the holder child did not publish its hold marker within INTERNAL_DEADLINE_MS (15s). The contention assertion was never reached, and holdMs (20s) was never approached. The 15.5s and 17.2s case durations line up with the 15s deadline plus overhead.

Failure 2 — run 35210400258, windows 7/9, tests/codex-integration/native-main-owner-lifetime.test.ts, a successor scrubs a hard-killed production auth write before recovery or main admission (46.7s), reported as child event timeout; events=[] stderr=.

The stack resolves to ChildHarness.waitFor at line 215. The failing wait is the first one in the test, await owner.waitFor(event => event.event === "listening"), bounded by OWNER_EVENT_WAIT_MS = watchdogMs(10_000). An empty events array means the child never emitted listening at all.

Why this is one defect. Both waits bound the cold start of a file's first spawned child on Windows, and both are sized below the range this repository has already measured for exactly that. COLD_SPAWN_BUDGET_MS documents a first child publishing its port at 50.7s while the next spawn in the same file was ready in 1.76s, with surviving readiness waits spanning 2.0s to 19.7s. codex-write-lock.test.ts states in its own comment that "a spawned holder child boots in 8-19 s on a loaded windows-latest shard" while bounding that wait at 15s. The documented range is wider than the deadline.

A second, independent defect makes both failures unreadable. Neither wait observes the child process. waitFor in the lock test polls a file size and throws timed out waiting for <path> with no other information; ChildHarness.waitFor prints buffered events and stderr but never inspects child.exited or child.exitCode. A child that died and a child that is merely slow produce the identical message, so the two cannot be distinguished from CI output alone. That is why events=[] stderr= is not conclusive on its own.

Reproduction

  1. Push enough branches to saturate the Actions queue so Windows shards run under contention.
  2. Observe run 35211904734 job windows 3/9 and run 35210400258 job windows 7/9.
  3. Compare against run 35215552842, a lane=all dispatch of dev at 6d19a07369 on an idle queue, where all nine Windows shards pass.

The two pull requests carrying those branches have no file-level overlap with either failing test, and both failing assertions are child-process readiness waits rather than assertions about the changed code.

Version

6d19a07

Operating system

Windows (hosted windows-latest shards). Both failures are Windows-only; the Linux and macOS shards of the same runs were unaffected.

Provider and model

Not applicable — test harness defect.

Logs or error output

# run 35211904734, windows 3/9
Test failure in shard 3/9 batch 9/25 (exit 1); not retrying assertion/test failures.
tests\codex-integration\codex-write-lock.test.ts:340
      at waitFor (D:\a\opencodex\opencodex\tests\codex-integration\codex-write-lock.test.ts:340:15)
      at async <anonymous> (D:\a\opencodex\opencodex\tests\codex-integration\codex-write-lock.test.ts:459:13)

# run 35210400258, windows 7/9
Test failure in shard 7/9 batch 9/25 (exit 1); not retrying assertion/test failures.
tests\codex-integration\native-main-owner-lifetime.test.ts:215
      at waitFor (D:\a\opencodex\opencodex\tests\codex-integration\native-main-owner-lifetime.test.ts:215:19)
child event timeout; events=[] stderr=

Screenshots and supporting files

Baseline for comparison: run 35215552842 (lane=all dispatch, dev at 6d19a07369), nine of nine Windows shards successful.

Redacted configuration

{}

Checks

  • I searched existing issues and documentation.
  • I removed secrets, tokens, account details, request credentials, and personal data.

Activity

  1. added
    platformOS/service/tray/ACL (Windows-heavy, not Windows-only)
    on Sep 17, 2026
  2. lidge-jun commented on Sep 17, 2026

    @lidge-jun
    OwnerAuthor

    Four failures, four files, one region of the corpus

    Updating this issue with every Windows failure observed today. The claim this issue makes is that these are not four bugs.

    Run Shard / batch File Test Duration
    35211904734 windows 3/9 batch 9/25 codex-write-lock.test.ts two real processes contend for one lock > one OS user and one home take ONE lock cases 1, 2 15.5s, 17.2s
    35210400258 windows 7/9 batch 9/25 native-main-owner-lifetime.test.ts a successor scrubs a hard-killed production auth write before recovery or main admission 46.7s
    35217346076 windows 1/9 batch 9/25 main quota policy file main quota policy at native admission > fresh startup restores durable main policy only after owned recovery (conflicting-claims) 31.9s
    35217346076 windows 6/9 batch 10/25 token-guardian.test.ts token guardian > token far from expiry is not refreshed 15.1s

    Baseline: run 35215552842, lane=all dispatch of dev at 6d19a07369. All nine Windows shards succeeded, Linux test 1..4/4 succeeded, gates and docs site build succeeded. The only failure was the ci aggregate, caused by macos 2/2 and macos control being cancelled for runner capacity. So the code is healthy and this is not a regression.

    The batches are not a coincidence

    Three of the four failures are in batch 9, the fourth in batch 10.

    The batch assignment is fully deterministic: scripts/ci/run-bun-test-batches.sh takes find tests -type f under LC_ALL=C sort, keeps test files, assigns them round-robin with index % SHARD_COUNT == SHARD_INDEX - 1, then cuts each shard into consecutive batches of BUN_TEST_BATCH_SIZE (6 on Windows). Round-robin preserves sort order inside a shard, so the same sorted region lands on the same batch number in every shard.

    Reconstructing that assignment against the current dev file list (1329 test files, 9 shards, batch size 6) places every one of these files in batch 9 or 10:

    codex-write-lock.test.ts               shard 4/9  batch  9/25
    main-quota-evidence-validation.test.ts shard 7/9  batch  9/25
    main-quota-provenance.test.ts          shard 8/9  batch  9/25
    main-quota-window-observation.test.ts  shard 9/9  batch  9/25
    native-main-owner-lifetime.test.ts     shard 8/9  batch  9/25
    token-guardian.test.ts                 shard 7/9  batch 10/25
    

    The shard numbers differ from the observed ones because each evidence branch has a slightly different test-file list, which shifts the round-robin by a position or two. The batch index does not shift, and that is the part that matters: batch 9 is where tests/codex-integration/ sits in every shard.

    That directory is this repository's cross-process integration suite — the tests that spawn real child processes, bind real servers, and take real cross-process locks. Batch 9 is therefore the one batch of each shard in which roughly six heavyweight integration files run together in a single bun test --isolate process on a two-core hosted Windows VM.

    What this changes

    The amplifier is sorted adjacency, not batch size. A smaller batch would still draw its members from the same contiguous codex-integration/ region, so it would reduce how many run together without dispersing the concentration. Interleaving the corpus so that heavyweight integration files do not occupy consecutive positions addresses the cause; shrinking BUN_TEST_BATCH_SIZE addresses the symptom.

    A raw count of files matching Bun.spawn puts only 2 of 6 in each of these batches, which understates it: several of these files spawn through helpers or bind servers without matching that pattern. The count is a floor, not a measure.

    Not claimed

    This does not establish which of the four tests would still fail alone. Per-file deadline sizing and the batch-composition amplifier are separate defects and are being addressed separately; #4902 covers only the first, for two of the four files.

  3. lidge-jun commented on Sep 17, 2026

    @lidge-jun
    OwnerAuthor

    A second, distinct phenomenon: a batch that hangs while every file in it passes alone

    The failures recorded above are individual tests dying on their own deadlines. This one is not, and it should not be read as the same thing.

    Run 35217342703, codex/ci-evidence-4871, windows 1/9:

    ##[warning]Bun test process timed out after 480s in shard 1/9 batch 4/25.
    ##[group]shard 1/9 batch 4/25 (6 files)
      tests/claude-integration/claude-inbound-debug.test.ts
      tests/claude-integration/claude-shell-hook.test.ts
      tests/cli/cli-codex-cli-update.test.ts
      tests/cli/cli-effort.test.ts
      tests/cli/cli-models-reasoning.test.ts
      tests/cli/cli-restart-health.test.ts
    ##[error]Shard 1/9 batch 4: every file passed alone, so the timeout lives in
    multi-file process state, not in any single test.
    

    The attribution sweep passed each of the six in 1-4 seconds. Together they consume the 480s process bound.

    How it differs from the deadline failures

    Batch 9/10 failures This one
    What fails one test, on its own in-test deadline the whole bun test process, on the batch bound
    Region tests/codex-integration/ tests/claude-integration/ and tests/cli/
    Alone not established every file passes, in 1-4s
    Reachable by per-file fixes yes, for sizing and diagnostics no, by construction

    Because every file passes alone, no per-file change can address this, and the ordering work discussed for the other phenomenon would at best avoid this particular six-file combination rather than remove its cause.

    Same signature as #4876, different cause

    #4876 turned off the scripts/test-run-lock.ts user-scoped lock on this leg (OCX_TEST_NO_QUEUE=1) because it was serializing batches against each other. That lock is already disabled here and the batch still wedges, so a different serialization or resource conflict is involved.

    What the six files do and do not share — static reading so far

    None of the six spawns a child process; they are in-process handler tests. So this is not a lost subprocess holding a pipe open.

    • claude-shell-hook.test.ts is the only one that mutates process-global state: it replaces process.env.PATH wholesale with its fixture bin directory in beforeEach, and one case calls process.chdir. Both are restored — PATH in afterEach, the working directory in a finally — so neither leaks past the file. Whether the window in between can be observed by another file depends on whether bun test --isolate interleaves files within one process or runs them one after another; that is the pivotal unknown and is not settled here.
    • Four of the six create mkdtemp trees under the system temp directory and remove them with removeTreeWithRetry, which retries on Windows.
    • All six import large src/cli/ or src/claude/ module graphs, which --isolate re-instantiates per file.

    No fixed port binding, no shared singleton lock file, and no shared fixed path outside the system temp directory was found across the six.

    Not concluded

    The cause is not identified. The candidates above are what a static reading supports; none of them has been shown to produce a 480s stall, and guessing between them would not be evidence. The next useful datum is whether --isolate runs these files concurrently in one process.


    Unrelated confirmation for the record: on #4902, which touches neither docs-site/ nor .github/workflows/ci.yml, the docs site build job reports skipping. Together with it running and passing on #4895 and on #4873, the docs filter is now observed discriminating in both directions.

  4. lidge-jun commented on Sep 17, 2026

    @lidge-jun
    OwnerAuthor

    The 480s batch: the arithmetic works out

    Two facts settle the shape of this, both from source rather than from a run.

    --isolate is single-process sequential. The runner invokes bun test --isolate --timeout 60000 with no --parallel, and tests/preload.ts distinguishes the two modes explicitly ("a single-process runner uses its own PID while true parallel workers rendezvous on their short-lived controller PID"). So the six files run one after another in one OS process, with only the module registry rebuilt per file.

    That rules out the PATH hypothesis: claude-shell-hook.test.ts replaces process.env.PATH wholesale but restores it in afterEach, and under sequential execution no other file can observe the window.

    It also makes the opposite hypothesis strong. --isolate rebuilds the module registry, not the process: open file handles, unclosed sockets and live timers survive a file boundary.

    The multiplier

    scripts/test-temp.ts gives removeTreeWithRetry a REMOVE_RETRY_BUDGET_MS of 15 s per removal (50 ms base delay, 250 ms cap). Counting how many trees this batch creates:

    File Test cases Temp trees
    cli-effort.test.ts 27 one per case, from beforeEach
    cli-models-reasoning.test.ts 18 one per helper call
    claude-shell-hook.test.ts 10 one per case, from beforeEach
    cli-restart-health.test.ts 8 one per helper call
    claude-inbound-debug.test.ts — none
    cli-codex-cli-update.test.ts — none

    Roughly 63 removals in one process. At a 15 s budget each, 32 exhausted removals reach 480 s, and cli-effort alone has 27 opportunities.

    Why it matches every observation

    Alone, a file has no predecessor in its process holding a handle into its temp tree, so each removal succeeds on the first attempt and the file finishes in 1-4 s — which is exactly what the attribution sweep reported. Together, a handle left open by an earlier file in the same process makes Windows refuse the delete, and the retry loop spends its budget.

    It also explains why the per-test bound does not catch it: the time accumulates in afterEach cleanup across many cases, never inside one test body, so --timeout 60000 is never approached.

    What this makes the fix

    Not a smaller retry budget. The retry loop is the cushion that has been absorbing the real defect, which is something not releasing a handle into a temp tree it no longer owns. Identifying that holder is the fix; the budget is the symptom, in the same sense test-budget.ts argues about waits.

    Still to confirm from the job log once run 35217342703 finishes: the gap between the last test completion and the 480 s wall, and whether the inter-test timestamps show 15 s multiples.

  5. lidge-jun commented on Sep 17, 2026

    @lidge-jun
    OwnerAuthor

    Correction: these four failures were an artifact of how the evidence was produced

    There is no Windows flake family here. Retitling and correcting rather than closing, because the mechanics recorded above are accurate and reusable; what was wrong is the conclusion drawn from them.

    What actually happened

    The evidence branches were dispatched from refs whose merge-base predates #4876 (f1dfda8e48). workflow_dispatch reads the workflow file from the dispatched ref, so those runs executed an old ci.yml with no OCX_TEST_NO_QUEUE — and reproduced precisely the batch-serialization bug #4876 had already fixed, where a batch queues behind a straggler from the previous one on the preload's user-scoped lock.

    Verified on the branches themselves: OCX_TEST_NO_QUEUE occurs 0 times in codex/ci-evidence-4875's ci.yml (merge-base e18ca24630) and 1 time in dev's.

    The batch-4 log says it outright. The batch opens at 11:48:09.735, and at 11:48:10.576 prints:

    [test] bare Bun worker 5208 is waiting for test run pid 8964 to release the user lock.
    

    then produces nothing until 11:56:09 — zero (pass) lines in that window. The first test never started. That is a lock wait, not accumulated cleanup retries and not a readiness deadline.

    This explains every observation at once: dev passed all nine Windows shards because it ran the fixed workflow; only the evidence branches failed because they ran the old one; and the blamed test moved between runs because which batch inherits the lock wait varies.

    What remains true

    These findings stand on their own and are worth keeping:

    • Batch assignment is deterministic, and round-robin preserves sort order inside a shard, so the same sorted region lands on the same batch number in every shard. The reconstruction that put all the failing files in batch 9 or 10 is correct.
    • --isolate is single-process sequential — bun test --isolate with no --parallel, and tests/preload.ts distinguishes the two modes. Module registries are rebuilt per file; handles, sockets and timers are not.
    • removeTreeWithRetry has a 15 s budget per removal, and this batch creates roughly 63 temp trees.

    What was wrong

    The conclusion that any of those caused these failures. The 63 × 15 s arithmetic is sound arithmetic about a mechanism that was not operating here — the log shows no cleanup phase, because no test ran. The batch 9/10 clustering is real and was not doing harm. And the claim that per-file readiness deadlines are undersized is undetermined again, since the runs that motivated it were serialized by the lock rather than by runner contention.

    #4902 has accordingly dropped its COLD_SPAWN_BUDGET_MS change and keeps only the two diagnostic fixes, which do not depend on this evidence.

    The transferable lesson

    Dispatching a stale ref does not merely test old code — it runs an old CI definition. An evidence run built that way can reproduce bugs that were fixed in the workflow itself, which is how a method for producing evidence became a method for producing artifacts.

  6. changed the title [-]Windows first-child readiness waits are sized below the measured cold-start range[/-] [+]Windows evidence runs dispatched from stale refs used a pre-#4876 ci.yml and reproduced its batch-serialization bug[/+] on Sep 17, 2026
  7. added a commit that references this issue on Sep 17, 2026
    a50f1de
  8. lidge-jun commented on Sep 17, 2026

    @lidge-jun
    OwnerAuthor

    리뷰 · 우선순위 38 / 80

    이 이슈는 처음에 Windows 콜드 퍼스트 차일드 readiness 데드라인이 COLD_SPAWN_BUDGET_MS 실측보다 짧아서 shard가 다른 파일을 번갈아 탓한다는 이야기로 열렸다. 실패 스택은 codex-write-lock의 waitFor(holdMarker)와 native-main-owner-lifetime의 listening 대기였고, 유휴 큐의 lane=all(dev 6d19a07)은 9/9 Windows가 통과했다.

    이후 작성자(메인테이너)가 댓글로 결론을 뒤집었다. evidence 브랜치가 #4876(f1dfda8, OCX_TEST_NO_QUEUE) 이전 merge-base에서 workflow_dispatch되어 옛 ci.yml로 돌았고, 배치가 preload 유저 락에 직렬로 묶이는 버그를 다시 만든 것이었다. 제목도 "Windows evidence runs dispatched from stale refs used a pre-#4876 ci.yml…"로 바뀌었다.

    현재 tip 41f1832(package 2.58.0)에는 이미 #4876 배치 직렬 수정과 #4902(죽은 차일드 진단; 본문에 Closes #4901이 있었으나 제목 재해석 후 이슈는 열린 채)가 있다. tests/helpers/test-budget.ts에서 COLD_SPAWN_BUDGET_MS는 win32 90s, INTERNAL_DEADLINE_MS는 15s다. 처음 주장한 "숫자를 올린다" 픽스는 #4902 두 번째 커밋에서 철회된 상태다.

    남은 가치는 stale-ref evidence dispatch 실수에 대한 프로세스 기록과, #4876이 고친 배치 직렬화의 재발 방지 체크리스트다. tip 기준으로 "Windows flake family"로 다시 열어 둘 이유는 약하다.

    라인 81 - tests/helpers/test-budget.ts COLD_SPAWN_BUDGET_MS (win32 90s): 초기 가설의 기준 상수
    라인 119 - tests/helpers/test-budget.ts INTERNAL_DEADLINE_MS=15s: 초기 실패 스택이 가리킨 내부 데드라인
    경로/심볼 - #4876 / f1dfda8 OCX_TEST_NO_QUEUE: evidence가 이전 ci.yml을 쓰면 배치 직렬 버그 재현
    경로/심볼 - #4902 / a50f1de: 죽은 차일드 진단, budget 상향 철회. Closes #4901은 제목 재해석과 어긋남

    메인테이너의 판단이 필요한 지점

    너의 추천
    close as completed/not-a-bug. 짧은 노트: evidence runs must dispatch from a ref that includes #4876 (OCX_TEST_NO_QUEUE). 남은 harness 숫자 조정은 별 이슈로만 다시 연다. 라벨은 바꾸지 않는다.

    이 댓글은 grok-bot이 작성했습니다

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingplatformOS/service/tray/ACL (Windows-heavy, not Windows-only)

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions