taodeng/ocp
1
0
Fork 0
mirror of https://github.com/dtzp555-max/ocp.git synced 2026-07-27 07:55:07 +00:00
Code Issues Packages Projects Releases Wiki Activity

test: harden and instrument the ltBoot integration tests (#203, #199) (#204)

Browse Source 
* test: harden and instrument the ltBoot integration tests (#203, #199)

I could NOT reproduce either flake, and this commit does not claim to have
root-caused them. Stating that plainly up front, because a "fix" for an
unreproduced fault is a placebo unless you say what it actually is.

What I tried, all negative:
  - 150 targeted runs of the #203 boot-gate scenario in isolation (25 rounds x
    3 cases, with and without 8 CPU hogs)  -> 0 failures
  - 6 consecutive full-suite runs                                -> 0 failures
  - a direct test of the exit-before-stdio-drain hypothesis (40 spawns writing
    a stderr burst then exiting)                                 -> 0 races
  - a direct test of the port-clash hypothesis: with the port already held, the
    boot gate still fires FIRST and stderr still carries the FATAL, so a clash
    cannot produce the observed empty-stderr signature

So instead of guessing a cause, this removes the mechanisms that were
individually defensible anyway, and makes the next occurrence self-diagnosing.

1. Wait for 'close', not 'exit', wherever a test reads buf.err/buf.out after
   the child terminates. 'exit' fires on process termination while its stdio
   pipes may still hold unread data; 'close' is the event that guarantees both
   are drained. I could not get this to race locally, but the ordering is
   simply correct and costs nothing — and it exactly matches #203's signature
   (non-zero exit, EMPTY stderr).

2. Stop gating on a proxy signal. The #199 test waited for "listening on" and
   then asserted a DIFFERENT line ("ignored in TUI mode") that is written
   independently — a race by construction. It now waits for the line actually
   under assertion, still bounded by the same timeout, with the boot markers
   kept in the predicate so a failed boot ends the wait immediately.

3. Every fixed port is gone. All 10 ltBoot sites and their 8 matching ltPost
   calls now use ltFreePort(). #193 already hit a fixed-port variant of this,
   and 39330+i in particular was shared across a 3-iteration loop.

4. ltBoot now tracks signal/closed/spawnErr, and an 'error' listener is
   attached — without one, a spawn error is re-thrown as an uncaught exception
   and takes down the whole runner instead of failing one test.

5. New ltDiag(buf) is used in every assertion message. The historical failure
   text was `expected a local-tools FATAL, got: ` — an empty string, which
   distinguishes nothing. Both mutations below now produce an immediately
   readable cause:

     gate neutered   -> "[non-loopback] process never closed — exit=undefined
                         signal=undefined closed=false | stderr(92B)=... |
                         stdout(1147B)=..."   (it booted; the gate is gone)
     warning renamed -> "no inert-flag warning appeared — ... stderr(295B)=
                         \"⚠ OCP_LOCAL_TOOLS=1 is SILENCED-FOR-MUTATION ...\""
                         (the text changed, and you can see the new text)

Both target tests remain mutation-proven: neutering the non-loopback branch of
localToolsSafetyError fails the boot-gate test, and renaming the TUI inert
warning fails the inert test.

Stability after the change: 4 sequential + 3 concurrent full-suite runs, all
457/0. That shows no regression was introduced; it does NOT show the flakes are
gone, since I never reproduced them. #203 and #199 should stay open until a
run passes through this instrumentation and reports what it saw.

Tests: 457 passed, 0 failed. No production code touched.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_017gbqUZ8HfBZpjjbzQ85oH8

* test: fix the adjacent race the first pass missed, plus four review corrections

The review's most valuable finding is that my SEARCH was incompetent, not just
inconclusive. test-features.mjs:39-58 makes `test()` fire-and-forget for async
bodies, so ~15 ltBoot integration tests run CONCURRENTLY inside one suite run.
My "150 targeted runs in isolation" therefore removed the only condition that
produces the race. Under full-suite x 4-way concurrency the reviewer measured
#199 at 6/200 pre-PR and 0/400 post-PR (Fisher p ~ 0.001).

HIGH — I fixed one race and left its twin one line away (:1092).
`Local tools: ON` is written 14 console.log calls AFTER `listening on`, so
gating on the boot marker and then asserting the announcement reads a buffer
that may hold only the first chunk. Identical shape to #199, same pipe this
time. Measured 9/200 before AND 9/200 after my first pass — my PR did not touch
it, leaving it as the suite's top flake, and it reddens with a message that
looks exactly like a real regression. Now waits for the line under assertion;
review measured the same fix at 0/200.

MED — ENOTEMPTY (4/200). child.kill("SIGKILL") kills server.mjs but not the
fake `claude` grandchildren, which can still be writing into `dir` while rmSync
walks it. New _ltRmRetry uses Node's maxRetries/retryDelay and never lets a
leaked temp dir fail a test. Applied to all 10 lt call sites.

LOW — boot-gate wait was `buf.closed` while the TUI one was
`... || buf.spawnErr`; made symmetric so a spawn failure cannot become a 9s
hang later. ltFreePort moved above its first use (it worked only via hoisting).

Two claims of mine that were wrong, corrected in the PR body:
  - "ltDiag is used in EVERY assertion message" — it is used in the two target
    tests, 7 sites. Overstatement in a PR whose whole argument is scope honesty.
  - "39330+i was shared across a 3-iteration loop" — it was not; i is 0/1/2 so
    the ports differ. The real fixed-port risk is CROSS-PROCESS, which the
    review's data confirms: 21/200 EADDRINUSE, all on 39360/39361/39364.

Linux experiment for #203, run on the Oracle VM against pre-PR main:
  #199 reproduced at 25/50 (vs ~3% on macOS) — platform-dependent stdout/stderr
  delivery, exactly the mechanism the review identified.
  #203 did NOT reproduce, but that result is NOT usable: Oracle runs Node 22,
  whose SQLite ExperimentalWarning broke ~23/50 runs with spurious "server did
  not start" failures. The noise floor was too high to conclude anything, and
  CI is Node 24. Reporting it as contaminated rather than as evidence.

Tests: 457 passed, 0 failed; 7 consecutive clean runs.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_017gbqUZ8HfBZpjjbzQ85oH8

* fix: correct the PR body, kill a comment I rotted, and get the counts right

The review's blocker was not in the code — it was that my PR body still carried
both retracted claims VERBATIM while my commit message asserted they had been
"corrected in the PR body". They had only been corrected in a trailing comment.
In a PR whose entire thesis is claim accuracy, that is the finding that matters.

The body is rewritten. Both claims now appear only as struck-through
corrections with the true values:
  - "ltDiag in EVERY assertion message"  -> 8 call sites, two target tests only
  - "39330+i was SHARED across a loop"   -> it wasn't; i is 0/1/2, ports differ.
    The real risk is cross-process, which the control arm's 246 EADDRINUSE shows.

Comment rot I introduced: test-features.mjs:1000 said "See ltAssertBoot below"
and no such function exists — grep returned exactly one hit, the comment itself.
Removed.

Counts corrected after re-measuring with the definition line excluded, which is
where my earlier numbers came from:
  ltDiag call sites   7  -> 8
  _ltRmRetry sites   10  -> 11

_ltRmRetry's catch now honours LT_DEBUG instead of being unconditionally
silent. It must still never throw — it runs in a finally, where a throw would
REPLACE the real assertion error and turn a flake into an apparent regression —
but an opt-in warn costs nothing and stops it swallowing genuine programming
errors too.

Recording the reviewer's control-arm numbers, since they are what actually
justifies this PR (full suite x 4 concurrent x 50 rounds, per arm):
                      main    this branch
  clean runs         42/200      200/200
  #199                    7            0
  :1092                   8            0
  EADDRINUSE            246            0
  ENOTEMPTY               1            0
  #203                    0            0

Tests: 457 passed, 0 failed.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_017gbqUZ8HfBZpjjbzQ85oH8

* test: land the comment fix that didn't, and size ltDiag's window to the banner

Two things, both caught by review of the previous commit.

1. The comment fix I claimed to have made never landed.

800800e's message said it corrected the console.log gap "14 -> 13". The diff has two
hunks (ltAssertBoot removal, LT_DEBUG catch) and never touches that line, so the
comment still read 14 — and 13 was wrong too, in units. Ground truth:

    server.mjs:3627  console.log(`... listening on ...`)
    server.mjs:3640  if (LOCAL_TOOLS_ACTIVE) console.log(`Local tools: ON ...`)
    strictly between: 12 console.log calls, of which :3635 (SYSTEM_PROMPT) and
    :3636 (MCP_CONFIG) are conditional and unset in this env -> 10 actually fire.

Now 12, with the conditional note. Also corrected 9/200 -> 8/200 on the same comment:
the control-arm table says 8, and the two disagreed.

2. ltDiag sampled stdout tail-only, which is the wrong end.

Review reversed its own earlier "leave it" with direct evidence: the mutation
diagnostic printed 1147B of tail and did NOT contain "Local tools: ON" — the single
most decisive string for "it booted instead of refusing". Fixed as head+tail.

Sizing is measured, not picked round. On this tree stdout is 1118B with the string at
byte 581, so:

    head=120  -> string lands in the elided middle. VERIFIED INSUFFICIENT.
    head=900  -> clears it with ~5 banner lines of margin.

900 is robust rather than merely bigger: the banner is emitted first and is bounded, so
however much request noise follows, byte 581 stays in the head. Demonstrated under the
gate mutation:

    stdout(1133B)="... Local tools: ON (OCP_LOCAL_TOOLS=1) — model told it may use
    local tools; single-user/loopback only ..."

Also folded in the two cheap #203 levers review listed, since the next step on that
issue is a Linux + Node 24 run:

- closeMs (stamped at 'close', not read at assertion time) separates "died before
  reaching the gate" from "ran, then gated" — exit=1 with empty stderr is equally
  consistent with both today. Prints "(still open)" when close never fired.
- node=${process.version} — exactly what would have flagged the Node 22 SQLite
  ExperimentalWarning before it cost 50 contaminated Oracle runs.

Mutation restored from a file backup, not `git checkout` — that command destroyed
uncommitted work earlier in this series.

server.mjs: unchanged (test-only; ALIGNMENT.md requires no cli.js citation).
Suite: 461 passed, 0 failed.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_017gbqUZ8HfBZpjjbzQ85oH8

* test: make ltHeadTail's head budget loud instead of silently degrading

Review's LOW on 75ac3e4, taken rather than deferred. Its failure mode is the reason:
the head budget is coupled to banner growth, and when it is exceeded ltDiag degrades
back to exactly the blind spot this PR fixed — with no test going red. Silent
degradation of a diagnostic is the same class of bug as the flakes this PR is about,
so a one-line guard is worth more here than the cycle it costs.

    const _ltOffset = buf.out.indexOf("Local tools: ON");
    assert.ok(_ltOffset < 900, "...it is now at byte ${_ltOffset}. The banner grew...");

Mutation-verified (budget 900 -> 400):

    ✗ ltHeadTail's head budget (900B) no longer reaches the local-tools announcement
      — it is now at byte 582. The banner grew. Raise the head in ltHeadTail, or
      ltDiag will silently stop showing the one line that distinguishes "booted"
      from "refused".

Margin is ~17 more models: `Models:` runs ~18B per entry, and the offset is 581 of a
1118B banner. Review independently measured 577/1117 — the delta is port-digit width.

Two micro-fixes it noted:
- `buf.t0 ? ... : "?"` was dead: t0 is always set in the literal and Date.now() is
  never 0. Removed rather than left as a branch that can't be reached.
- closeMs now declared in the buf literal alongside signal/closed/spawnErr.

Also acknowledging one change of mine that review found and my own summary omitted:
stderr sampling went 200 -> 240 chars, because the non-loopback FATAL body is ~180
chars before the "FATAL:" prefix and 200 was close to truncating the longest gate
message. Same size-to-the-content reasoning as the head; I just failed to list it.

server.mjs: unchanged (test-only; ALIGNMENT.md requires no cli.js citation).
Suite: 461 passed, 0 failed.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_017gbqUZ8HfBZpjjbzQ85oH8

---------

Co-authored-by: dtzp555 <dtzp555@gmail.com>
Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
dtzp555-max
2026-07-27 12:26:48 +10:00
committed by GitHub
co-authored by taodeng Claude Opus 5
parent c180987376
commit 7f15921f69
1 changed files with 132 additions and 49 deletions
Download Patch File Download Diff File Expand all files Collapse all files
test-features.mjs
+132 -49
View File
@@ -991,17 +991,70 @@ function ltBoot(env, dir, nodeArgs = []) {
CLAUDE_BIND: "127.0.0.1", CLAUDE_AUTH_MODE: "none", CLAUDE_CACHE_TTL: "0", CLAUDE_TIMEOUT: "4000", ...env }, CLAUDE_BIND: "127.0.0.1", CLAUDE_AUTH_MODE: "none", CLAUDE_CACHE_TTL: "0", CLAUDE_TIMEOUT: "4000", ...env },
stdio: ["ignore", "pipe", "pipe"], stdio: ["ignore", "pipe", "pipe"],
}); });
const buf = { out: "", err: "", exit: undefined }; const buf = { out: "", err: "", exit: undefined, signal: undefined, closed: false, closeMs: undefined, spawnErr: null, t0: Date.now() };
child.stdout.on("data", d => { buf.out += d; }); child.stdout.on("data", d => { buf.out += d; });
child.stderr.on("data", d => { buf.err += d; }); child.stderr.on("data", d => { buf.err += d; });
child.on("exit", code => { buf.exit = code; }); // 'exit' fires when the process terminates, but its stdio pipes may still hold unread data —
// 'close' is the one that guarantees both are drained. A test that terminates the child and
// then asserts on buf.err/buf.out must wait for `closed`, not `exit != null`, or it can read
// an empty buffer.
child.on("exit", (code, signal) => { buf.exit = code; buf.signal = signal; });
child.on("close", () => { buf.closed = true; buf.closeMs = Date.now() - buf.t0; });
// Without a listener, a spawn 'error' is re-thrown as an uncaught exception and takes down the
// whole runner instead of failing one test.
child.on("error", e => { buf.spawnErr = e; });
return { child, buf }; return { child, buf };
} }
// child.kill("SIGKILL") kills server.mjs but NOT the fake `claude` grandchildren it spawned, and
// those can still be writing sp.txt / spawns.txt into `dir` while rmSync walks it — which surfaced
// as an intermittent ENOTEMPTY (4/200 in review). Node's own retry loop handles the window.
function _ltRmRetry(dir) {
try { _ltRm(dir, { recursive: true, force: true, maxRetries: 5, retryDelay: 50 }); }
catch (e) {
// Never throw: this runs in a finally, so a throw here would REPLACE the real assertion
// error and make a flake look like a regression. LT_DEBUG surfaces it without that risk.
if (process.env.LT_DEBUG) console.warn(` [ltRmRetry] ${dir}: ${e.code || e.message}`);
}
}
// Every ltBoot assertion failure should be self-diagnosing. The historical failure text was
// `expected a local-tools FATAL, got: ` — an empty string, which says nothing about whether the
// child never wrote, wrote to the other stream, died on a signal, or was never spawned.
// stdout is sampled HEAD+TAIL, not tail-only. The decisive string for "it booted instead of
// refusing" is "Local tools: ON", and it lives in the boot banner — a tail-only sample answered
// the wrong question for exactly the tests this exists to diagnose.
//
// The head is sized to the BANNER, not picked round: measured on this tree, the banner runs 1118B
// with "Local tools: ON" at byte 581, so 900 clears it with ~5 banner lines of margin. That sizing
// is what makes it robust — the banner is emitted first and is bounded, so however much request
// noise follows, byte 581 stays in the head. A head of 120 does NOT reach it (verified: the string
// landed in the elided middle), which is why this is not the obvious small window.
// stderr stays head-only: a fatal is the first thing it writes.
function ltHeadTail(s, head = 900, tail = 160) {
return s.length <= head + tail ? s : `${s.slice(0, head)}…[${s.length - head - tail}B]…${s.slice(-tail)}`;
}
function ltDiag(buf) {
// closeMs disambiguates "died before reaching the gate" from "ran, then gated" — an exit=1
// with empty stderr is equally consistent with both, and they have unrelated root causes.
// node= is here because a Node-version-specific stderr warning (22's SQLite ExperimentalWarning)
// once masqueraded as "server did not start" for ~23 of 50 runs on a Linux box.
const ms = buf.closeMs !== undefined ? `${buf.closeMs}ms` : `${Date.now() - buf.t0}ms(still open)`;
return `exit=${buf.exit} signal=${buf.signal} closed=${buf.closed} closeMs=${ms} node=${process.version}` +
(buf.spawnErr ? ` spawnErr=${buf.spawnErr.code || buf.spawnErr.message}` : "") +
` | stderr(${buf.err.length}B)=${JSON.stringify(buf.err.slice(0, 240))}` +
` | stdout(${buf.out.length}B)=${JSON.stringify(ltHeadTail(buf.out))}`;
}
async function ltWait(cond, ms = 9000) { async function ltWait(cond, ms = 9000) {
const start = Date.now(); const start = Date.now();
while (Date.now() - start < ms) { if (cond()) return true; await new Promise(r => setTimeout(r, 40)); } while (Date.now() - start < ms) { if (cond()) return true; await new Promise(r => setTimeout(r, 40)); }
return false; return false;
} }
async function ltFreePort() {
const srv = _ltNetServer();
await new Promise(r => srv.listen(0, "127.0.0.1", r));
const p = srv.address().port;
await new Promise(r => srv.close(r));
return p;
}
async function ltPost(port, body) { async function ltPost(port, body) {
try { try {
await fetch(`http://127.0.0.1:${port}/v1/chat/completions`, { await fetch(`http://127.0.0.1:${port}/v1/chat/completions`, {
@@ -1015,29 +1068,31 @@ console.log("\nOCP_LOCAL_TOOLS integration (boot server.mjs):");
test("integration: OCP_LOCAL_TOOLS=1 → the -p spawn receives the POSITIVE wrapper (kills the no-op mutation)", async () => { test("integration: OCP_LOCAL_TOOLS=1 → the -p spawn receives the POSITIVE wrapper (kills the no-op mutation)", async () => {
if (!LT_POSIX) return; // sh fake — skip on Windows CI if (!LT_POSIX) return; // sh fake — skip on Windows CI
const dir = ltMkdir(); const cap = join(dir, "sp.txt"); const fake = ltFake(dir); const dir = ltMkdir(); const cap = join(dir, "sp.txt"); const fake = ltFake(dir);
const { child, buf } = ltBoot({ OCP_LOCAL_TOOLS: "1", CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: "39321", SP_CAPTURE: cap }, dir); const port = await ltFreePort();
const { child, buf } = ltBoot({ OCP_LOCAL_TOOLS: "1", CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: String(port), SP_CAPTURE: cap }, dir);
try { try {
assert.ok(await ltWait(() => buf.out.includes("listening on") || buf.exit != null), `server did not start: ${buf.err.slice(0,200)}`); assert.ok(await ltWait(() => buf.out.includes("listening on") || buf.exit != null), `server did not start: ${buf.err.slice(0,200)}`);
await ltPost(39321, { model: "sonnet", messages: [{ role: "user", content: "hi" }] }); await ltPost(port, { model: "sonnet", messages: [{ role: "user", content: "hi" }] });
assert.ok(await ltWait(() => _ltExists(cap)), "fake claude was spawned and captured --system-prompt"); assert.ok(await ltWait(() => _ltExists(cap)), "fake claude was spawned and captured --system-prompt");
const sp = _ltRead(cap, "utf8"); const sp = _ltRead(cap, "utf8");
assert.ok(sp.includes(LT_POS_MARK), `expected POSITIVE wrapper in --system-prompt, got: ${sp.slice(0,90)}`); assert.ok(sp.includes(LT_POS_MARK), `expected POSITIVE wrapper in --system-prompt, got: ${sp.slice(0,90)}`);
assert.ok(!sp.includes(LT_NEG_MARK), "positive wrapper must REPLACE the negative one, not append"); assert.ok(!sp.includes(LT_NEG_MARK), "positive wrapper must REPLACE the negative one, not append");
} finally { child.kill("SIGKILL"); _ltRm(dir, { recursive: true, force: true }); } } finally { child.kill("SIGKILL"); _ltRmRetry(dir); }
}); });
test("integration: flag OFF → the -p spawn receives the EXACT negative wrapper (default path byte-for-byte)", async () => { test("integration: flag OFF → the -p spawn receives the EXACT negative wrapper (default path byte-for-byte)", async () => {
if (!LT_POSIX) return; if (!LT_POSIX) return;
const dir = ltMkdir(); const cap = join(dir, "sp.txt"); const fake = ltFake(dir); const dir = ltMkdir(); const cap = join(dir, "sp.txt"); const fake = ltFake(dir);
const { child, buf } = ltBoot({ CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: "39322", SP_CAPTURE: cap }, dir); // OCP_LOCAL_TOOLS unset const port = await ltFreePort();
const { child, buf } = ltBoot({ CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: String(port), SP_CAPTURE: cap }, dir); // OCP_LOCAL_TOOLS unset
try { try {
assert.ok(await ltWait(() => buf.out.includes("listening on") || buf.exit != null), `server did not start: ${buf.err.slice(0,200)}`); assert.ok(await ltWait(() => buf.out.includes("listening on") || buf.exit != null), `server did not start: ${buf.err.slice(0,200)}`);
await ltPost(39322, { model: "sonnet", messages: [{ role: "user", content: "hi" }] }); await ltPost(port, { model: "sonnet", messages: [{ role: "user", content: "hi" }] });
assert.ok(await ltWait(() => _ltExists(cap)), "fake claude captured --system-prompt"); assert.ok(await ltWait(() => _ltExists(cap)), "fake claude captured --system-prompt");
const sp = _ltRead(cap, "utf8"); const sp = _ltRead(cap, "utf8");
// No system messages + no CLAUDE_SYSTEM_PROMPT → the wrapper is passed verbatim. // No system messages + no CLAUDE_SYSTEM_PROMPT → the wrapper is passed verbatim.
assert.equal(sp, `You are accessed via the OCP HTTP proxy. You do NOT have access to any local filesystem, working directory, shell, git status, or machine environment. Do not infer or invent such information from any context you observe. Respond only based on the conversation provided.`); assert.equal(sp, `You are accessed via the OCP HTTP proxy. You do NOT have access to any local filesystem, working directory, shell, git status, or machine environment. Do not infer or invent such information from any context you observe. Respond only based on the conversation provided.`);
} finally { child.kill("SIGKILL"); _ltRm(dir, { recursive: true, force: true }); } } finally { child.kill("SIGKILL"); _ltRmRetry(dir); }
}); });
test("integration: boot gate REFUSES each unsafe config (multi / non-loopback / anon key)", async () => { test("integration: boot gate REFUSES each unsafe config (multi / non-loopback / anon key)", async () => {
@@ -1049,25 +1104,47 @@ test("integration: boot gate REFUSES each unsafe config (multi / non-loopback /
{ label: "anon", env: { PROXY_ANONYMOUS_KEY: "pub" } }, { label: "anon", env: { PROXY_ANONYMOUS_KEY: "pub" } },
]; ];
try { try {
for (const [i, c] of cases.entries()) { for (const c of cases) {
const { child, buf } = ltBoot({ OCP_LOCAL_TOOLS: "1", CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: String(39330 + i), ...c.env }, dir); const port = await ltFreePort();
const { child, buf } = ltBoot({ OCP_LOCAL_TOOLS: "1", CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: String(port), ...c.env }, dir);
try { try {
assert.ok(await ltWait(() => buf.exit != null), `[${c.label}] expected the process to exit`); // Wait for `closed`, not `exit`: the assertion below reads buf.err, and stderr is only
assert.notEqual(buf.exit, 0, `[${c.label}] must exit non-zero`); // guaranteed drained at 'close'. This is the ordering #203 was filed for.
assert.ok(/FATAL[\s\S]*OCP_LOCAL_TOOLS/.test(buf.err), `[${c.label}] expected a local-tools FATAL, got: ${buf.err.slice(0,160)}`); assert.ok(await ltWait(() => buf.closed || buf.spawnErr), `[${c.label}] process never closed — ${ltDiag(buf)}`);
assert.notEqual(buf.exit, 0, `[${c.label}] must exit non-zero — ${ltDiag(buf)}`);
assert.ok(/FATAL[\s\S]*OCP_LOCAL_TOOLS/.test(buf.err), `[${c.label}] expected a local-tools FATAL — ${ltDiag(buf)}`);
} finally { child.kill("SIGKILL"); } } finally { child.kill("SIGKILL"); }
} }
} finally { _ltRm(dir, { recursive: true, force: true }); } } finally { _ltRmRetry(dir); }
}); });
test("integration: safe single-user config BOOTS past the gate and announces local tools", async () => { test("integration: safe single-user config BOOTS past the gate and announces local tools", async () => {
if (!LT_POSIX) return; if (!LT_POSIX) return;
const dir = ltMkdir(); const fake = ltFake(dir); const dir = ltMkdir(); const fake = ltFake(dir);
const { child, buf } = ltBoot({ OCP_LOCAL_TOOLS: "1", CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: "39340" }, dir); // loopback + none const port = await ltFreePort();
const { child, buf } = ltBoot({ OCP_LOCAL_TOOLS: "1", CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: String(port) }, dir); // loopback + none
try { try {
assert.ok(await ltWait(() => buf.out.includes("listening on")), `safe config must boot, got: ${buf.err.slice(0,200)}`); // Same race as #199, one line over: "Local tools: ON" (server.mjs:3640) is written 12
assert.ok(buf.out.includes("Local tools: ON"), "startup must announce local tools when active"); // console.log calls after "listening on" (:3627) — 10 of them in this env, since the
} finally { child.kill("SIGKILL"); _ltRm(dir, { recursive: true, force: true }); } // SYSTEM_PROMPT and MCP_CONFIG lines are conditional and unset here. Gating on the boot
// marker and then asserting the announcement can therefore read a buffer holding only the
// first chunk. Wait for the line actually under assertion. Measured by review at 8/200
// before this change and 0/200 after — it was the suite's top flake.
assert.ok(await ltWait(() => buf.out.includes("Local tools: ON") || buf.closed || buf.spawnErr),
`startup must announce local tools when active — ${ltDiag(buf)}`);
assert.ok(buf.out.includes("Local tools: ON"),
`startup must announce local tools when active — ${ltDiag(buf)}`);
// Nails ltHeadTail's head budget to the thing it exists to capture. Without this the
// coupling is silent: every added banner line pushes "Local tools: ON" later (Models:
// alone is ~18B per model), and the day it crosses 900 the diagnostic degrades back to
// the exact blind spot this PR fixed — with no test going red. Measured offset here is
// 581 of a 1118B banner, so the margin is ~17 more models.
const _ltOffset = buf.out.indexOf("Local tools: ON");
assert.ok(_ltOffset < 900,
`ltHeadTail's head budget (900B) no longer reaches the local-tools announcement — it is ` +
`now at byte ${_ltOffset}. The banner grew. Raise the head in ltHeadTail, or ltDiag will ` +
`silently stop showing the one line that distinguishes "booted" from "refused".`);
} finally { child.kill("SIGKILL"); _ltRmRetry(dir); }
}); });
test("integration: TUI mode → flag is announced INERT (not 'ON'), boot not refused", async () => { test("integration: TUI mode → flag is announced INERT (not 'ON'), boot not refused", async () => {
@@ -1075,12 +1152,22 @@ test("integration: TUI mode → flag is announced INERT (not 'ON'), boot not ref
const dir = ltMkdir(); const fake = ltFake(dir); const dir = ltMkdir(); const fake = ltFake(dir);
// Non-loopback would normally trip the local-tools gate; under TUI the flag is inert so the // Non-loopback would normally trip the local-tools gate; under TUI the flag is inert so the
// gate must NOT fire on its behalf. Use loopback here to isolate TUI's own guards from ours. // gate must NOT fire on its behalf. Use loopback here to isolate TUI's own guards from ours.
const { child, buf } = ltBoot({ OCP_LOCAL_TOOLS: "1", CLAUDE_TUI_MODE: "true", CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: "39341" }, dir); const port = await ltFreePort();
const { child, buf } = ltBoot({ OCP_LOCAL_TOOLS: "1", CLAUDE_TUI_MODE: "true", CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: String(port) }, dir);
try { try {
assert.ok(await ltWait(() => buf.out.includes("listening on") || buf.exit != null), `did not start: ${buf.err.slice(0,200)}`); // Wait for the line actually under assertion, not for a proxy signal. "listening on" and the
assert.ok(!buf.out.includes("Local tools: ON"), "must NOT claim local tools are ON in TUI mode (the wrapper is unused there)"); // inert-flag warning are written independently, so gating on the former and then asserting
assert.ok(/ignored in TUI mode/.test(buf.out + buf.err), "must warn that OCP_LOCAL_TOOLS is inert under TUI"); // the latter is a race — the flake #199 was filed for. Still bounded by the same timeout, and
} finally { child.kill("SIGKILL"); _ltRm(dir, { recursive: true, force: true }); } // the boot markers are kept in the predicate so a failed boot ends the wait immediately
// rather than burning it.
const ready = await ltWait(() => /ignored in TUI mode/.test(buf.out + buf.err)
|| buf.closed || buf.spawnErr);
assert.ok(ready, `no inert-flag warning appeared — ${ltDiag(buf)}`);
assert.ok(/ignored in TUI mode/.test(buf.out + buf.err),
`must warn that OCP_LOCAL_TOOLS is inert under TUI — ${ltDiag(buf)}`);
assert.ok(!buf.out.includes("Local tools: ON"),
`must NOT claim local tools are ON in TUI mode (the wrapper is unused there) — ${ltDiag(buf)}`);
} finally { child.kill("SIGKILL"); _ltRmRetry(dir); }
}); });
test("integration: toggling OCP_LOCAL_TOOLS invalidates the standard response cache (epoch fold)", async () => { test("integration: toggling OCP_LOCAL_TOOLS invalidates the standard response cache (epoch fold)", async () => {
@@ -1098,11 +1185,11 @@ test("integration: toggling OCP_LOCAL_TOOLS invalidates the standard response ca
} finally { child.kill("SIGKILL"); } } finally { child.kill("SIGKILL"); }
}; };
try { try {
const off = await bootOnce({}, 39350); // caches "OK" under epoch(negative) const off = await bootOnce({}, await ltFreePort()); // caches "OK" under epoch(negative)
const on = await bootOnce({ OCP_LOCAL_TOOLS: "1" }, 39351); // same DB, epoch(positive) → must MISS → re-spawn const on = await bootOnce({ OCP_LOCAL_TOOLS: "1" }, await ltFreePort()); // same DB, epoch(positive) → must MISS → re-spawn
assert.equal(off, 1, "first request (cache empty) must spawn claude"); assert.equal(off, 1, "first request (cache empty) must spawn claude");
assert.equal(on, 1, "after toggling the flag the identical request must NOT be served from the old cache (epoch differs → re-spawn)"); assert.equal(on, 1, "after toggling the flag the identical request must NOT be served from the old cache (epoch differs → re-spawn)");
} finally { _ltRm(dir, { recursive: true, force: true }); } } finally { _ltRmRetry(dir); }
}); });
// ── active-request counter is paired to the process lifecycle (#180 / #193) ── // ── active-request counter is paired to the process lifecycle (#180 / #193) ──
@@ -1138,13 +1225,6 @@ function ltSpreadThrowCount(stackKb) {
return Number(String(_ltExecFile(process.execPath, [`--stack-size=${stackKb}`, "-e", src], { encoding: "utf8" })).trim()) || 0; return Number(String(_ltExecFile(process.execPath, [`--stack-size=${stackKb}`, "-e", src], { encoding: "utf8" })).trim()) || 0;
} catch { return 0; } } catch { return 0; }
} }
async function ltFreePort() {
const srv = _ltNetServer();
await new Promise(r => srv.listen(0, "127.0.0.1", r));
const p = srv.address().port;
await new Promise(r => srv.close(r));
return p;
}
async function ltPostStatus(port, body) { async function ltPostStatus(port, body) {
try { try {
const r = await fetch(`http://127.0.0.1:${port}/v1/chat/completions`, { const r = await fetch(`http://127.0.0.1:${port}/v1/chat/completions`, {
@@ -1191,7 +1271,7 @@ test("integration: a synchronous pre-spawn throw must not leak stats.activeReque
const active = (await r.json()).requests.active; const active = (await r.json()).requests.active;
assert.equal(active, 0, assert.equal(active, 0,
`3 requests threw before their spawn; the counter must be back to 0, got ${active} (this is the #180 leak)`); `3 requests threw before their spawn; the counter must be back to 0, got ${active} (this is the #180 leak)`);
} finally { child.kill("SIGKILL"); _ltRm(dir, { recursive: true, force: true }); } } finally { child.kill("SIGKILL"); _ltRmRetry(dir); }
}); });
// ── Cache keys hash the RESOLVED model, not the alias string (#194) ────────── // ── Cache keys hash the RESOLVED model, not the alias string (#194) ──────────
@@ -1219,36 +1299,38 @@ console.log("\nCache key resolves the model alias (#194):");
test("integration: an alias and its canonical target share ONE cache slot (normal path)", async () => { test("integration: an alias and its canonical target share ONE cache slot (normal path)", async () => {
if (!LT_POSIX) return; if (!LT_POSIX) return;
const dir = ltMkdir(); const fake = ltFake(dir); const counter = join(dir, "spawns.txt"); const dir = ltMkdir(); const fake = ltFake(dir); const counter = join(dir, "spawns.txt");
const { child, buf } = ltBoot({ CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: "39360", CLAUDE_CACHE_TTL: "60000", SP_COUNTER: counter }, dir); const port = await ltFreePort();
const { child, buf } = ltBoot({ CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: String(port), CLAUDE_CACHE_TTL: "60000", SP_COUNTER: counter }, dir);
try { try {
assert.ok(await ltWait(() => buf.out.includes("listening on")), `did not start: ${buf.err.slice(0, 200)}`); assert.ok(await ltWait(() => buf.out.includes("listening on")), `did not start: ${buf.err.slice(0, 200)}`);
_ltWrite(counter, "0"); _ltWrite(counter, "0");
const msgs = [{ role: "user", content: "alias-resolution-probe" }]; const msgs = [{ role: "user", content: "alias-resolution-probe" }];
await ltPost(39360, { model: "sonnet", messages: msgs }); // miss → spawn await ltPost(port, { model: "sonnet", messages: msgs }); // miss → spawn
await ltWait(() => (Number(_ltRead(counter, "utf8")) || 0) >= 1, 3000); await ltWait(() => (Number(_ltRead(counter, "utf8")) || 0) >= 1, 3000);
await ltPost(39360, { model: "claude-sonnet-5", messages: msgs }); // same resolved model → HIT await ltPost(port, { model: "claude-sonnet-5", messages: msgs }); // same resolved model → HIT
await new Promise(r => setTimeout(r, 600)); await new Promise(r => setTimeout(r, 600));
assert.equal(Number(_ltRead(counter, "utf8")) || 0, 1, assert.equal(Number(_ltRead(counter, "utf8")) || 0, 1,
"the canonical id must hit the slot the alias populated — a 2nd spawn means the key still hashes the raw alias"); "the canonical id must hit the slot the alias populated — a 2nd spawn means the key still hashes the raw alias");
} finally { child.kill("SIGKILL"); _ltRm(dir, { recursive: true, force: true }); } } finally { child.kill("SIGKILL"); _ltRmRetry(dir); }
}); });
test("integration: an alias and its canonical target share ONE cache slot (STRUCTURED path)", async () => { test("integration: an alias and its canonical target share ONE cache slot (STRUCTURED path)", async () => {
if (!LT_POSIX) return; if (!LT_POSIX) return;
const dir = ltMkdir(); const fake = ltFakeJson(dir); const counter = join(dir, "spawns.txt"); const dir = ltMkdir(); const fake = ltFakeJson(dir); const counter = join(dir, "spawns.txt");
const { child, buf } = ltBoot({ CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: "39361", CLAUDE_CACHE_TTL: "60000", SP_COUNTER: counter }, dir); const port = await ltFreePort();
const { child, buf } = ltBoot({ CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: String(port), CLAUDE_CACHE_TTL: "60000", SP_COUNTER: counter }, dir);
try { try {
assert.ok(await ltWait(() => buf.out.includes("listening on")), `did not start: ${buf.err.slice(0, 200)}`); assert.ok(await ltWait(() => buf.out.includes("listening on")), `did not start: ${buf.err.slice(0, 200)}`);
_ltWrite(counter, "0"); _ltWrite(counter, "0");
const rf = { type: "json_schema", json_schema: { name: "probe", schema: LT_SCHEMA } }; const rf = { type: "json_schema", json_schema: { name: "probe", schema: LT_SCHEMA } };
const msgs = [{ role: "user", content: "structured-alias-probe" }]; const msgs = [{ role: "user", content: "structured-alias-probe" }];
await ltPost(39361, { model: "sonnet", messages: msgs, response_format: rf }); await ltPost(port, { model: "sonnet", messages: msgs, response_format: rf });
await ltWait(() => (Number(_ltRead(counter, "utf8")) || 0) >= 1, 4000); await ltWait(() => (Number(_ltRead(counter, "utf8")) || 0) >= 1, 4000);
await ltPost(39361, { model: "claude-sonnet-5", messages: msgs, response_format: rf }); await ltPost(port, { model: "claude-sonnet-5", messages: msgs, response_format: rf });
await new Promise(r => setTimeout(r, 600)); await new Promise(r => setTimeout(r, 600));
assert.equal(Number(_ltRead(counter, "utf8")) || 0, 1, assert.equal(Number(_ltRead(counter, "utf8")) || 0, 1,
"structured cache key must resolve the alias too — this is the path the epoch-only fix missed"); "structured cache key must resolve the alias too — this is the path the epoch-only fix missed");
} finally { child.kill("SIGKILL"); _ltRm(dir, { recursive: true, force: true }); } } finally { child.kill("SIGKILL"); _ltRmRetry(dir); }
}); });
// MODEL_MAP is models[] + aliases + legacyAliases, so resolving covers legacyAliases for free. // MODEL_MAP is models[] + aliases + legacyAliases, so resolving covers legacyAliases for free.
@@ -1257,18 +1339,19 @@ test("integration: an alias and its canonical target share ONE cache slot (STRUC
test("integration: a legacyAlias shares ONE cache slot with its canonical target", async () => { test("integration: a legacyAlias shares ONE cache slot with its canonical target", async () => {
if (!LT_POSIX) return; if (!LT_POSIX) return;
const dir = ltMkdir(); const fake = ltFake(dir); const counter = join(dir, "spawns.txt"); const dir = ltMkdir(); const fake = ltFake(dir); const counter = join(dir, "spawns.txt");
const { child, buf } = ltBoot({ CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: "39364", CLAUDE_CACHE_TTL: "60000", SP_COUNTER: counter }, dir); const port = await ltFreePort();
const { child, buf } = ltBoot({ CLAUDE_BIN: fake, CLAUDE_PROXY_PORT: String(port), CLAUDE_CACHE_TTL: "60000", SP_COUNTER: counter }, dir);
try { try {
assert.ok(await ltWait(() => buf.out.includes("listening on")), `did not start: ${buf.err.slice(0, 200)}`); assert.ok(await ltWait(() => buf.out.includes("listening on")), `did not start: ${buf.err.slice(0, 200)}`);
_ltWrite(counter, "0"); _ltWrite(counter, "0");
const msgs = [{ role: "user", content: "legacy-alias-probe" }]; const msgs = [{ role: "user", content: "legacy-alias-probe" }];
await ltPost(39364, { model: "claude-haiku-4-5", messages: msgs }); // legacyAlias await ltPost(port, { model: "claude-haiku-4-5", messages: msgs }); // legacyAlias
await ltWait(() => (Number(_ltRead(counter, "utf8")) || 0) >= 1, 3000); await ltWait(() => (Number(_ltRead(counter, "utf8")) || 0) >= 1, 3000);
await ltPost(39364, { model: "claude-haiku-4-5-20251001", messages: msgs }); // canonical await ltPost(port, { model: "claude-haiku-4-5-20251001", messages: msgs }); // canonical
await new Promise(r => setTimeout(r, 600)); await new Promise(r => setTimeout(r, 600));
assert.equal(Number(_ltRead(counter, "utf8")) || 0, 1, assert.equal(Number(_ltRead(counter, "utf8")) || 0, 1,
"legacyAliases live in MODEL_MAP too — resolving must collapse them onto the canonical slot"); "legacyAliases live in MODEL_MAP too — resolving must collapse them onto the canonical slot");
} finally { child.kill("SIGKILL"); _ltRm(dir, { recursive: true, force: true }); } } finally { child.kill("SIGKILL"); _ltRmRetry(dir); }
}); });
test("integration: a config change invalidates the STRUCTURED cache too (closes the #177 gap)", async () => { test("integration: a config change invalidates the STRUCTURED cache too (closes the #177 gap)", async () => {
@@ -1287,11 +1370,11 @@ test("integration: a config change invalidates the STRUCTURED cache too (closes
} finally { child.kill("SIGKILL"); } } finally { child.kill("SIGKILL"); }
}; };
try { try {
const off = await bootOnce({}, 39362); // caches under epoch(negative wrapper) const off = await bootOnce({}, await ltFreePort()); // caches under epoch(negative wrapper)
const on = await bootOnce({ OCP_LOCAL_TOOLS: "1" }, 39363); // same DB, epoch differs → must re-spawn const on = await bootOnce({ OCP_LOCAL_TOOLS: "1" }, await ltFreePort()); // same DB, epoch differs → must re-spawn
assert.equal(off, 1, "first structured request (cache empty) must spawn claude"); assert.equal(off, 1, "first structured request (cache empty) must spawn claude");
assert.equal(on, 1, "structured cache must honor CONFIG_EPOCH — before #194 it omitted the epoch entirely and served the stale answer"); assert.equal(on, 1, "structured cache must honor CONFIG_EPOCH — before #194 it omitted the epoch entirely and served the stale answer");
} finally { _ltRm(dir, { recursive: true, force: true }); } } finally { _ltRmRetry(dir); }
}); });
// ── Upgrade Tests ── // ── Upgrade Tests ──