From 523deff2fe5cdf5290302fd4e873b873d832690a Mon Sep 17 00:00:00 2001 From: jun Date: Sat, 5 Sep 2026 07:59:26 +0900 Subject: [PATCH 1/5] docs(devlog): record the first all-green Windows CI run (33926041666) --- .../050_ci_residual_retained_root.md | 49 +++++++++++++++++++ 1 file changed, 49 insertions(+) diff --git a/devlog/_plan/260905_windows_suite_stabilization/050_ci_residual_retained_root.md b/devlog/_plan/260905_windows_suite_stabilization/050_ci_residual_retained_root.md index ba8949a975..2c66ae7c89 100644 --- a/devlog/_plan/260905_windows_suite_stabilization/050_ci_residual_retained_root.md +++ b/devlog/_plan/260905_windows_suite_stabilization/050_ci_residual_retained_root.md @@ -270,3 +270,52 @@ case reaps cleanly. process, no unhandled ENOENT. 3. CI re-dispatch: windows 2/4 SUCCESS with **no** "killed N dangling processes" line in the log, and every case in this file under its budget with margin. + +--- + +## Third CI round: all four Windows shards green + +Run 33926041666 (head `cfc8de963`): + +| shard | pass | fail | dangling | +|---|---|---|---| +| 1/4 | 4462 | **0** | 0 | +| 2/4 | 4628 | **0** | 0 | +| 3/4 | 4305 | **0** | — | +| 4/4 | 4413 | **0** | — | + +The file that failed twice, on the same hosted runner class: + +``` +(pass) startup and CLI sync-cache … owns K [8459.45ms] (was 18743 / 15536 timeout) +(pass) native restore … owns K [2935.56ms] +(pass) POST /api/sync … newer convergence catalog [7303.73ms] (was 20140 timeout) +(pass) POST /api/sync … newer retained catalog [9908.46ms] +(pass) a persisted runtime selection … [1772.21ms] +(pass) two processes at the post-approval seam … [3383.29ms] +``` + +Every case is under `SPAWN_BUDGET_MS` with 4-5× margin, and this run happened +to be a fast one (8.5 s where the previous run took 18.7 s for the same case). +That spread — 8.5 to 18.7 s for identical work — is the thing the 15 s and 20 s +budgets could never absorb, and it is why the class fix mattered more than the +first case fix. + +### What was actually wrong, in one paragraph + +Not the product. Not the lock. The file's per-case budgets were sized from a +~450 ms local run for work that costs 8-19 s on the hosted Windows runner, and +its harness had no reap-before-delete ordering, so any budget miss produced a +dangling child plus a follow-on ENOENT/unhandled-rejection that obscured the +real message. Three commits: a budget on one case (moved the failure), then the +class budget + child registration + a detached barrier race (fixed it). + +### Verification ledger for the barrier fix + +The unhandled-rejection claim was checked by a probe, not by reading: insert a +5 s sleep after the barrier under a 3 s budget. Original code reports the +timeout **plus** `Unhandled error between tests: sync exited before provider +barrier (143)`; fixed code reports the timeout alone. Two earlier attempts at +the fix (resolve-to-Error, catch-in-finally) still produced the unhandled error +under that probe and were discarded before commit. The probe was removed and the +file is 6/6 on macOS. From 3bfb9a7d2a99c926f3ee171a6c26357df9765f0f Mon Sep 17 00:00:00 2001 From: jun Date: Sat, 5 Sep 2026 08:31:17 +0900 Subject: [PATCH 2/5] docs(devlog): dev drift under the stack - the quorum-cache atime observer on Windows (060) --- .../060_dev_drift_atime.md | 82 +++++++++++++++++++ 1 file changed, 82 insertions(+) create mode 100644 devlog/_plan/260905_windows_suite_stabilization/060_dev_drift_atime.md diff --git a/devlog/_plan/260905_windows_suite_stabilization/060_dev_drift_atime.md b/devlog/_plan/260905_windows_suite_stabilization/060_dev_drift_atime.md new file mode 100644 index 0000000000..c313fc7142 --- /dev/null +++ b/devlog/_plan/260905_windows_suite_stabilization/060_dev_drift_atime.md @@ -0,0 +1,82 @@ +# 060 — wp4: dev moved under the stack — the quorum-cache atime observer on Windows + +Research doc. Found by the second confirmation run, which happened to be the first +run after rebasing the stack onto current `dev` (`d6b457462`, 36 commits ahead of +the original base). + +## The run + +Run 33928082123 (head `dc09663cb`, rebased): windows 1/4, 3/4, 4/4 SUCCESS; +2/4 FAILURE with three new cases: + +``` +(fail) Anthropic failover quorum cache > removing an account invalidates immediately, not after the TTL +(fail) Anthropic failover quorum cache > a rotation invalidates immediately rather than waiting out the TTL +(fail) Anthropic failover quorum cache > a manual account selection invalidates immediately + at tests/routing/anthropic-quorum-cache.test.ts:154:28 + expect(storeWasRead()).toBe(true) Expected: true Received: false +``` + +Everything this stack touches passed on the same run: `keep-native-v1` 12/12, +the six `retained-root-serialization` cases, `update-notify` with its skip. + +## Provenance + +`tests/routing/anthropic-quorum-cache.test.ts` reached `dev` today through +#3523 → #3526 → #3530 → #3533 (merged 21:44Z). None of those commits exist on +the pre-rebase stack, and the run before the rebase (33926041666) was all green. +So this is drift under the stack, not a regression the stack introduced. + +## Mechanism, from reading — NOT yet measured + +The test observes whether `loadAuthStore` hit the file by pinning `auth.json`'s +**atime** 60 s into the past and checking whether it moved: + +```ts +function markStoreUnread(): void { + utimesSync(storePath(), new Date(Date.now() - 60_000), stats.mtime); +} +function storeWasRead(): boolean { + return statSync(storePath()).atimeMs > Date.now() - 30_000; +} +``` + +On Windows, NTFS last-access-time updates are **disabled by default** on +client SKUs since Windows 7 (`NtfsDisableLastAccessUpdate`), and on newer +builds they are "system managed" — updated only when the volume is small or +at most once per hour. A `readFileSync` does not move atime there. So the +three cases that assert "the store WAS read" cannot see the read, while the +cases that assert "was NOT read" pass vacuously on the same platform. + +That is a hypothesis with a strong prior (it is a well-known NTFS default) +and it explains the exact split — three "invalidates immediately" cases red, +the "shares one read" and "holds no credential material" cases green. But +this unit has been wrong from reading before (`007`), so it is not a +diagnosis until the atime behaviour is measured on the runner. + +## Why it is a separate work-phase + +- It is not in this stack's write set and not caused by it. +- The fix belongs to the test's author's design: observing a syscall through + atime is the thing that does not port, and the replacement (an injected + reader counter, or a `readFileSync` spy) is a design choice in a file this + stack has never touched. +- The stack's own acceptance — the three defects it set out to fix — is met on + every surface. Holding #3548-#3550 hostage to a defect that landed on `dev` + after they were planned would be the wrong coupling. + +## Next + +A new work-phase, dependency-ordered after this stack lands or independently +as a fourth PR against `dev`: + +1. Measure: on windows-latest, does `readFileSync` move `atimeMs` at all? + A ten-line probe in a scratch `--eval`. +2. If not: replace the atime observer with a direct one (a counting wrapper + around the store reader injected for the test), keeping every assertion. +3. `fuck-powershell` case: `ntfs-atime-disabled-by-default` if (1) confirms. + +Until then, `c-1` ("0 fail twice consecutively") is met for the stack's own +scope at runs 33926041666 and — for the three files it changes — 33928082123, +but NOT for the suite as a whole, because `dev` now carries a Windows failure +of its own. From 8e0a0135c8505c934ef25431dbb2f1c31269d32d Mon Sep 17 00:00:00 2001 From: jun Date: Sat, 5 Sep 2026 08:37:14 +0900 Subject: [PATCH 3/5] docs(devlog): plan the quorum-cache read observer fix (070), atime measured on windows-latest --- .../070_quorum_cache_observer.md | 135 ++++++++++++++++++ 1 file changed, 135 insertions(+) create mode 100644 devlog/_plan/260905_windows_suite_stabilization/070_quorum_cache_observer.md diff --git a/devlog/_plan/260905_windows_suite_stabilization/070_quorum_cache_observer.md b/devlog/_plan/260905_windows_suite_stabilization/070_quorum_cache_observer.md new file mode 100644 index 0000000000..fab8cd7346 --- /dev/null +++ b/devlog/_plan/260905_windows_suite_stabilization/070_quorum_cache_observer.md @@ -0,0 +1,135 @@ +# 070 — wp4: the quorum-cache test observes file reads through atime, which NTFS does not update + +Implementation phase. Independent of the three landed fixes (disjoint write set: +one test file). Three failures on windows 2/4, present on `dev` since #3533. + +## Measured, not read + +A scratch step on `windows-latest` (run 33929916059, keyring windows job), the +exact operation the test performs: + +``` +$ fsutil behavior query DisableLastAccess +DisableLastAccess = 3 (System Managed, Last Access Time Updates DISABLED) + +PROBE {"before":1788564769875,"after":1788564769875,"moved":false,"storeWasRead":false} +``` + +`readFileSync` does not move `atimeMs` on the hosted Windows runner. The +hypothesis in `060` is confirmed on the platform where the failure occurs. + +## What the test does + +`tests/routing/anthropic-quorum-cache.test.ts:70-77`: + +```ts +function markStoreUnread(): void { + utimesSync(storePath(), new Date(Date.now() - 60_000), stats.mtime); // pin atime into the past +} +function storeWasRead(): boolean { + return statSync(storePath()).atimeMs > Date.now() - 30_000; // did it move? +} +``` + +Six cases use this observer. The three that assert `storeWasRead() === true` +("rotation / removal / manual selection invalidate immediately") fail on +Windows because the read leaves atime where `utimesSync` put it. The one that +asserts `false` ("a burst shares one read") passes there **vacuously** — it +would pass even if the cache were broken and read the file 25 times, which is +the worse of the two outcomes: a green test that cannot fail. + +The comment on the observer says why it was chosen: "without stubbing the +module … a direct observation of the syscall this cache exists to avoid." That +is a good instinct on POSIX. On NTFS the syscall leaves no trace to observe. + +## Fix: observe the read at the store's seam, not the filesystem's + +`loadAuthStoreInternal` (`src/oauth/store.ts:338`) is the single function every +store read goes through, and it is the exact thing the cache exists to avoid +calling. Count it. + +### MODIFY `src/oauth/store.ts` + +```ts ++/** @internal Test-only: how many times the auth store file has been read this process. */ ++let authStoreReadCountForTests = 0; ++export function authStoreReadCountForTestsOnly(): number { ++ if (process.env.OCX_TEST_HOME_GUARD !== "1") { ++ throw new Error("auth store read counter is available only under the repository test preload"); ++ } ++ return authStoreReadCountForTests; ++} + + function loadAuthStoreInternal(): { store: AuthStore; hadLegacy: boolean } { + const path = getAuthStorePath(); + hardenConfigDir(); + hardenExistingSecret(path); + if (!existsSync(path)) return { store: {}, hadLegacy: false }; ++ authStoreReadCountForTests += 1; + try { + return normalizeAuthStore(JSON.parse(readFileSync(path, "utf-8"))); +``` + +The increment sits immediately before `readFileSync`, so it counts exactly the +syscall the atime observer was trying to see. The guard follows the pattern the +repository already uses for test-only seams (`reset-credit-operation-ledger.ts:488`, +`reset-credit-recovery.ts:638`): it cannot be reached from production because +only the test preload sets `OCX_TEST_HOME_GUARD`. + +### MODIFY `tests/routing/anthropic-quorum-cache.test.ts` + +```ts +-import { mkdtempSync, statSync, utimesSync } from "node:fs"; ++import { mkdtempSync } from "node:fs"; +-import { getAccountSet, markAccountNeedsReauth, saveCredential } from "../../src/oauth/store"; ++import { authStoreReadCountForTestsOnly, getAccountSet, markAccountNeedsReauth, saveCredential } from "../../src/oauth/store"; + +-/** Observe the store read without stubbing the module: … atime … */ +-function storePath(): string { … } +-function markStoreUnread(): void { … } +-function storeWasRead(): boolean { … } ++/** ++ * Observe the store read at the store's own seam. An earlier version pinned atime and ++ * checked whether it moved; NTFS on windows-latest has last-access updates disabled ++ * (fsutil DisableLastAccess = 3), so readFileSync left atime untouched and the three ++ * "invalidates immediately" cases could never see the read they assert on — while the ++ * "shares one read" case passed vacuously. Counting loadAuthStoreInternal is the same ++ * observation, made where the platform cannot hide it. ++ */ ++let readsBefore = 0; ++function markStoreUnread(): void { readsBefore = authStoreReadCountForTestsOnly(); } ++function storeWasRead(): boolean { return authStoreReadCountForTestsOnly() > readsBefore; } +``` + +Every call site of `markStoreUnread` / `storeWasRead` is unchanged; only the +two helpers' bodies move. The six assertions keep their exact shape. + +### Why not spy on `readFileSync` + +A module-level spy on `node:fs` sees every read in the process — config, lock +files, hardening probes — and the test would have to filter by path, which is +the fragile part. The counter sits on the one function whose call count IS the +property under test. + +## Acceptance + +1. **Ablation first, on macOS**: temporarily make `hasAnthropicFailoverQuorum` + skip its cache (return `computeQuorum()` unconditionally). The "burst shares + one read" case must go red on `storeWasRead() === false` — proving the + counter observes what atime could not. Reverted before commit. +2. macOS: `bun test tests/routing/anthropic-quorum-cache.test.ts` 7/7. +3. `bun run typecheck` clean; `bun run privacy:scan` unchanged (the counter + holds a number, never content). +4. CI dispatch on the stacked head: windows 2/4 SUCCESS, the three cases + green in the log. + +## Stack position + +PR 4 on top of #3550, against `codex/win-3-k-owner-budget`. Touches one +`src/` file for a guarded test seam — the first product-side edit in this unit, +and the guard is what keeps it out of any production path. + +## Corpus + +New `fuck-powershell` case `ntfs-atime-disabled-by-default` with the +`fsutil` output and the probe as its repro. From 7d031eb19cd5dd3190d1a9d0ae16d403f8e08254 Mon Sep 17 00:00:00 2001 From: jun Date: Sat, 5 Sep 2026 08:37:42 +0900 Subject: [PATCH 4/5] docs(devlog): record the stack's confirmation status and PR numbers in 000_plan --- .../_plan/260905_windows_suite_stabilization/000_plan.md | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/devlog/_plan/260905_windows_suite_stabilization/000_plan.md b/devlog/_plan/260905_windows_suite_stabilization/000_plan.md index 306805f50d..984f6449ba 100644 --- a/devlog/_plan/260905_windows_suite_stabilization/000_plan.md +++ b/devlog/_plan/260905_windows_suite_stabilization/000_plan.md @@ -73,6 +73,15 @@ prevent a defect that does not exist. ## Acceptance for the unit 1. Four shards, pinned runtime, **0 fail, twice consecutively**, with logs. + + Status: CI run 33926041666 (`cfc8de963`) — all four Windows shards green, + 4462/4628/4305/4413 pass. Second run 33928082123 on the rebased head + (`dc09663cb`): every file this unit touches green again, but windows 2/4 + red on three cases that arrived on `dev` via #3533 between the two runs + (`060`). The stack's own scope is met twice; the suite-wide bar is not, + and `070` is the next work-phase for that drift. + + Published as #3548 → #3549 → #3550 against `dev`. 2. Every fix is a root-cause change: no assertion weakened, no timeout inflated without naming the intrinsic operation it covers. 3. macOS unchanged for every touched file, verified by running it. From 70d904109a38fc7943c24deee6108a209b0ec0f5 Mon Sep 17 00:00:00 2001 From: jun Date: Sat, 5 Sep 2026 08:46:45 +0900 Subject: [PATCH 5/5] test(routing): observe the quorum-cache store read with a path-filtered spy, not atime Three cases in anthropic-quorum-cache failed on windows 2/4 as soon as #3533 landed: the observer pinned auth.json's atime into the past and asserted that readFileSync moved it. Measured on windows-latest (run 33929916059): fsutil DisableLastAccess = 3, and readFileSync left atimeMs unchanged. So the three 'invalidates immediately' cases could never see the read they assert on, and the 'shares one read' case passed vacuously on the same platform. The observer now counts pass-through spyOn(fs, 'readFileSync') calls against this home's auth.json - the same instrument claude-system-env-auto.test.ts already uses, filtered so refresh-intent files, lock snapshots and peekAuthStore never enter the count. All four call sites and every assertion keep their shape. No src/ change. Ablation: disabling the cache-hit return at anthropic-routing.ts:291 turns the burst case red on the spy (Expected false, Received true), which atime could not do on Windows. A comment records that the burst case proves zero reads during hits, not one read per fill - a fill is up to three reads through getAccountCredential, and tightening to ===1 would be wrong. --- .../070_quorum_cache_observer.md | 138 +++++++++++++----- tests/routing/anthropic-quorum-cache.test.ts | 38 +++-- 2 files changed, 125 insertions(+), 51 deletions(-) diff --git a/devlog/_plan/260905_windows_suite_stabilization/070_quorum_cache_observer.md b/devlog/_plan/260905_windows_suite_stabilization/070_quorum_cache_observer.md index fab8cd7346..eda175ab5a 100644 --- a/devlog/_plan/260905_windows_suite_stabilization/070_quorum_cache_observer.md +++ b/devlog/_plan/260905_windows_suite_stabilization/070_quorum_cache_observer.md @@ -31,7 +31,7 @@ function storeWasRead(): boolean { } ``` -Six cases use this observer. The three that assert `storeWasRead() === true` +Four of the seven cases use this observer (`:87`, `:112`, `:154`, `:166`). The three that assert `storeWasRead() === true` ("rotation / removal / manual selection invalidate immediately") fail on Windows because the read leaves atime where `utimesSync` put it. The one that asserts `false` ("a burst shares one read") passes there **vacuously** — it @@ -42,39 +42,97 @@ The comment on the observer says why it was chosen: "without stubbing the module … a direct observation of the syscall this cache exists to avoid." That is a good instinct on POSIX. On NTFS the syscall leaves no trace to observe. -## Fix: observe the read at the store's seam, not the filesystem's +## Fix: observe the syscall with a path-filtered spy — no `src/` change -`loadAuthStoreInternal` (`src/oauth/store.ts:338`) is the single function every -store read goes through, and it is the exact thing the cache exists to avoid -calling. Count it. +An earlier draft added a guarded read counter to `src/oauth/store.ts`. The audit +rejected it, correctly: the guard only stops production from READING the +counter, the increment itself still executes on every production store read, +and that is process-global test instrumentation inside a credential module. +The repository already observes filesystem calls from tests without touching +`src/` — `tests/claude-integration/claude-system-env-auto.test.ts:76` spies on +`node:fs` `readFileSync`. The same instrument, filtered to the one path that +matters, is the observation the atime trick was reaching for. -### MODIFY `src/oauth/store.ts` +What the spy has to see: `hasAnthropicFailoverQuorum` → `getAccountSet` → +`loadAuthStoreInternal` → `readFileSync(auth.json)` (`src/oauth/store.ts:344`). +The refresh-intent reads at `:166`/`:177`, the lock snapshot at `:404` and +`peekAuthStore` at `:383` are other files or other callers and never satisfy +this cache, so the filter must be the exact `auth.json` path — not "any read". + +### MODIFY `tests/routing/anthropic-quorum-cache.test.ts` (the only file) ```ts -+/** @internal Test-only: how many times the auth store file has been read this process. */ -+let authStoreReadCountForTests = 0; -+export function authStoreReadCountForTestsOnly(): number { -+ if (process.env.OCX_TEST_HOME_GUARD !== "1") { -+ throw new Error("auth store read counter is available only under the repository test preload"); -+ } -+ return authStoreReadCountForTests; +-import { afterEach, beforeEach, describe, expect, test } from "bun:test"; +-import { mkdtempSync, statSync, utimesSync } from "node:fs"; ++import { afterEach, beforeEach, describe, expect, spyOn, test } from "bun:test"; ++import * as fs from "node:fs"; ++import { mkdtempSync } from "node:fs"; + + const originalHome = process.env.OPENCODEX_HOME; + let home: string; ++let readSpy: ReturnType | undefined; ++let authReadsBefore = 0; + ++/** ++ * Count readFileSync calls against THIS home's auth.json. The previous observer pinned ++ * atime and checked whether readFileSync moved it; on windows-latest NTFS last-access ++ * updates are disabled (fsutil DisableLastAccess = 3, measured in run 33929916059), so ++ * the read left atime untouched, the three "invalidates immediately" cases could never ++ * see the read they assert on, and the "shares one read" case passed vacuously. The ++ * spy observes the same syscall where the platform cannot hide it. ++ */ ++function authReadCount(): number { ++ const target = join(home, "auth.json"); ++ return (readSpy?.mock.calls ?? []).filter(([p]) => String(p) === target).length; +} - function loadAuthStoreInternal(): { store: AuthStore; hadLegacy: boolean } { - const path = getAuthStorePath(); - hardenConfigDir(); - hardenExistingSecret(path); - if (!existsSync(path)) return { store: {}, hadLegacy: false }; -+ authStoreReadCountForTests += 1; - try { - return normalizeAuthStore(JSON.parse(readFileSync(path, "utf-8"))); + beforeEach(() => { + home = mkdtempSync(join(tmpdir(), "ocx-quorum-cache-")); + process.env.OPENCODEX_HOME = home; ++ readSpy = spyOn(fs, "readFileSync"); // pass-through: no mockImplementation + clearAnthropicAccountPoolState(); + forgetAnthropicFailoverQuorum(); + }); + + afterEach(() => { ++ readSpy?.mockRestore(); ++ readSpy = undefined; + clearAnthropicAccountPoolState(); + … + }); + +-function storePath() … markStoreUnread() … storeWasRead() // atime versions, deleted ++function markStoreUnread(): void { authReadsBefore = authReadCount(); } ++function storeWasRead(): boolean { return authReadCount() > authReadsBefore; } ``` -The increment sits immediately before `readFileSync`, so it counts exactly the -syscall the atime observer was trying to see. The guard follows the pattern the -repository already uses for test-only seams (`reset-credit-operation-ledger.ts:488`, -`reset-credit-recovery.ts:638`): it cannot be reached from production because -only the test preload sets `OCX_TEST_HOME_GUARD`. +Every call site of `markStoreUnread` / `storeWasRead` is unchanged; only the +helpers' bodies move. `spyOn` without `mockImplementation` records calls and +passes through to the real `readFileSync`, so the store behaves exactly as in +production. + +The spy is installed AFTER `mkdtempSync` (which does not read) and restored in +`afterEach` before the sandbox is removed, matching the claude-system-env +pattern. + +## The "one read" oracle, stated precisely + +The burst case's name says "shares one store read", but a cache FILL is not one +read: `hasAnthropicFailoverQuorum` calls `getAccountSet` (one `auth.json` read) +and then `isPoolCredentialUsable` → `getAccountCredential` for up to two +accounts (`src/oauth/anthropic-routing.ts:222,294,300`) — each of which goes +through `loadAuthStore` again. So a fill is one-to-three reads. + +What the case actually proves — and what `markStoreUnread` AFTER the prime +call measures — is **zero additional reads while the cache is warm**. That is +the property that matters (the cache exists to keep reads off the request +path), it is exactly what the original atime version was asserting, and it is +what the spy version asserts. The case name is kept; a one-line comment in the +test says "zero reads during hits, not one read per fill", so nobody later +tightens it to `=== 1` and discovers the fill count the hard way. + +Refactoring the fill to a single read is a product change outside this +unit's scope and is not needed to make the observation honest. ### MODIFY `tests/routing/anthropic-quorum-cache.test.ts` @@ -104,30 +162,30 @@ only the test preload sets `OCX_TEST_HOME_GUARD`. Every call site of `markStoreUnread` / `storeWasRead` is unchanged; only the two helpers' bodies move. The six assertions keep their exact shape. -### Why not spy on `readFileSync` +### Why the path filter is not the fragile part -A module-level spy on `node:fs` sees every read in the process — config, lock -files, hardening probes — and the test would have to filter by path, which is -the fragile part. The counter sits on the one function whose call count IS the -property under test. +The earlier draft worried that a filesystem spy "sees every read and has to +filter by path". It does — and the path is `join(home, "auth.json")`, the same +expression the test already used for `storePath()`. An exact-string match on a +path this test itself created is not fragile; it is the most specific +observation available, and it needs no seam in `src/`. ## Acceptance -1. **Ablation first, on macOS**: temporarily make `hasAnthropicFailoverQuorum` - skip its cache (return `computeQuorum()` unconditionally). The "burst shares - one read" case must go red on `storeWasRead() === false` — proving the - counter observes what atime could not. Reverted before commit. +1. **Ablation first, on macOS**: temporarily disable the cache-hit return at + `src/oauth/anthropic-routing.ts:291` (make the `if` condition `false`). The + burst case must go red on `storeWasRead() === false` — proving the spy sees + the reads atime could not. Reverted before commit; `git diff --stat` shows + only the test file. 2. macOS: `bun test tests/routing/anthropic-quorum-cache.test.ts` 7/7. -3. `bun run typecheck` clean; `bun run privacy:scan` unchanged (the counter - holds a number, never content). +3. `bun run typecheck` clean. No `src/` change, so `privacy:scan` is untouched. 4. CI dispatch on the stacked head: windows 2/4 SUCCESS, the three cases green in the log. ## Stack position -PR 4 on top of #3550, against `codex/win-3-k-owner-budget`. Touches one -`src/` file for a guarded test seam — the first product-side edit in this unit, -and the guard is what keeps it out of any production path. +PR 4 on top of #3550, against `codex/win-3-k-owner-budget`. One test file; no +product source touched, which keeps this unit's record intact. ## Corpus diff --git a/tests/routing/anthropic-quorum-cache.test.ts b/tests/routing/anthropic-quorum-cache.test.ts index 2d609c0875..401961cff6 100644 --- a/tests/routing/anthropic-quorum-cache.test.ts +++ b/tests/routing/anthropic-quorum-cache.test.ts @@ -12,8 +12,9 @@ * still visible once it expires, and a rotation invalidates immediately rather than answering the * next question from a pre-failure count. */ -import { afterEach, beforeEach, describe, expect, test } from "bun:test"; -import { mkdtempSync, statSync, utimesSync } from "node:fs"; +import { afterEach, beforeEach, describe, expect, spyOn, test } from "bun:test"; +import * as fs from "node:fs"; +import { mkdtempSync } from "node:fs"; import { tmpdir } from "node:os"; import { join } from "node:path"; import { @@ -29,15 +30,21 @@ import { removeTreeWithRetry } from "../helpers/remove-tree"; const originalHome = process.env.OPENCODEX_HOME; let home: string; +let readSpy: ReturnType | undefined; +let authReadsBefore = 0; beforeEach(() => { home = mkdtempSync(join(tmpdir(), "ocx-quorum-cache-")); process.env.OPENCODEX_HOME = home; + // Pass-through spy (no mockImplementation): records calls, the real read still happens. + readSpy = spyOn(fs, "readFileSync"); clearAnthropicAccountPoolState(); forgetAnthropicFailoverQuorum(); }); afterEach(() => { + readSpy?.mockRestore(); + readSpy = undefined; clearAnthropicAccountPoolState(); forgetAnthropicFailoverQuorum(); if (originalHome === undefined) delete process.env.OPENCODEX_HOME; @@ -59,28 +66,37 @@ async function seed(count: number, offset = 0): Promise { } /** - * Observe the store read without stubbing the module: `loadAuthStore` calls `readFileSync`, - * which updates atime. Pinning atime into the past and checking whether it moved is a direct - * observation of the syscall this cache exists to avoid. + * Observe the store read without stubbing the module: count `readFileSync` calls against + * THIS home's auth.json — the syscall this cache exists to avoid. + * + * The previous observer pinned atime into the past and checked whether the read moved it. + * On windows-latest NTFS last-access updates are disabled (fsutil DisableLastAccess = 3, + * measured in run 33929916059), so `readFileSync` left atime untouched: the three + * "invalidates immediately" cases could never see the read they assert on, and the + * "shares one read" case passed vacuously. The spy sees the same syscall where the + * platform cannot hide it. The path filter keeps refresh-intent files, lock snapshots and + * `peekAuthStore` out of the count; only the hardened store read can satisfy the cache. */ -function storePath(): string { - return join(home, "auth.json"); +function authReadCount(): number { + const target = join(home, "auth.json"); + return (readSpy?.mock.calls ?? []).filter(([path]) => String(path) === target).length; } function markStoreUnread(): void { - const stats = statSync(storePath()); - utimesSync(storePath(), new Date(Date.now() - 60_000), stats.mtime); + authReadsBefore = authReadCount(); } function storeWasRead(): boolean { - return statSync(storePath()).atimeMs > Date.now() - 30_000; + return authReadCount() > authReadsBefore; } describe("Anthropic failover quorum cache", () => { test("a burst of requests inside the TTL window shares one store read", async () => { const start = Date.now(); await seed(2); - // Prime the cache, then prove the next calls do not touch the file at all. + // Prime the cache, then prove the next calls do not touch the file at all. This asserts + // ZERO reads during hits, not one read per fill: a fill is getAccountSet plus up to two + // getAccountCredential calls through isPoolCredentialUsable, each a store read. expect(hasAnthropicFailoverQuorum(start)).toBe(true); markStoreUnread(); for (let i = 0; i < 25; i++) expect(hasAnthropicFailoverQuorum(start + i)).toBe(true);