fix(fallback)+docs(adr-0004): D16 — honor "usable chunks streamed" qualifier on SPAWN_FAILED

cold-audit catch from 2026-05-23

Cold-audit Finding 17 (P2 fallback correctness). ADR 0004 § Trigger
taxonomy Hard triggers bullet 3 says "Provider CLI exit code ≠ 0
**with no usable response chunks streamed**" — the qualifier was
not honored. Pre-D16 code in `collectAllChunks` re-raised SPAWN_FAILED
unconditionally, discarding any partial chunks. Concrete failure:
provider yields 1000 chars of completion then exits non-zero (e.g.,
post-stream cleanup error) → chunks dropped, fallback to next provider,
user pays double spawn cost and loses the original provider's output.

Coordinated change across two layers, single commit per the
ADR-with-code pattern (D11 / D15 precedent):

1. docs/adr/0004-fallback-engine.md — Amendment 1 (top of doc, matching
   D11/D15 placement convention):
   - Documents the "usable chunks streamed" semantics precisely
   - Behavior split: chunks.length > 0 + SPAWN_FAILED → synthesize stop
     + return (Case B); chunks.length === 0 + SPAWN_FAILED → re-throw
     (Case A, hard trigger fires as before)
   - finish_reason='length' rationale (4 reasons documented)
   - Streaming-path note: ADR 0004 first-chunk rule already handles the
     analogous case for D10's real-streaming branch; D16 applies to
     buffered path only
   - Cache behavior: write-through `getOrCompute` (preserves D4 singleflight
     during truncation event) then evict via `set(ttlMs=0)` (so future
     fresh callers re-spawn). `__truncated` non-enumerable marker
     travels with the chunks array for follower visibility

2. server.mjs `collectAllChunks` salvage path:
   - try/catch around the for-await loop
   - On SPAWN_FAILED with chunks.length > 0: synthesize stop chunk
     `{type:'stop', finish_reason:'length'}`, log warn event
     `spawn_failed_after_usable_chunks`, mark chunks array with
     non-enumerable `__truncated`, return (no re-throw)
   - On SPAWN_FAILED with chunks.length === 0 OR any other error:
     re-throw (preserves existing hard-trigger semantics)

3. server.mjs `executeHopFn` cache eviction:
   - After `cacheStore.getOrCompute(...)` returns, check `result.__truncated`
   - If truncated: `cacheStore.set(keyId, hopCacheKey, result, 0)` —
     ttlMs=0 causes `_isAlive` to treat the entry as expired on next
     read (verified in lib/cache/store.mjs)

4. test-features.mjs Suite 13 — 3 new tests:
   - Case A regression: SPAWN_FAILED at iter 0 + 2-hop chain → openai
     serves, X-OLP-Fallback-Hops: 1 (no behavior change)
   - Case B 2-hop: 2 deltas + SPAWN_FAILED → anthropic serves with
     synthesized stop, hops=0, finish_reason='length', content
     concatenates, openai NOT called
   - Case B single-hop: 1 delta + SPAWN_FAILED → HTTP 200 (not 502),
     finish_reason='length', partial content visible

Tests: 297 → 300 (+3). All pass on Node 20.

Pre-commit fold-ins (per evidence-first checkpoint #4 — fold-ins
themselves need second-pass review):

- **Error-chunk-in-chunks fold-in (sonnet flagged)**: pre-D12 code
  pushed error chunks BEFORE throwing. Post-D16's `chunks.length > 0`
  check would incorrectly include an error chunk and trigger Case B
  for a path that's actually Case A. Moved the `type === 'error'`
  check BEFORE the push, restoring the invariant that the chunks
  array contains only delta/stop chunks. Verified all 3 scenarios:
  (1) error at iter 0 → throws before push → length=0 → Case A
  (2) delta×2 + error at iter 3 → throws before push → length=2 → Case B
      with delta×2 + synthesized stop (no error chunk leaks)
  (3) delta + non-zero exit from outside loop → length=1 → Case B

- **ADR doc-code drift fold-in (D16 reviewer flagged)**: original
  Amendment 1 text said the salvaged result "bypasses
  cacheStore.getOrCompute and is returned directly, exactly as the
  cache-bypass path does." This was factually wrong — the code
  write-throughs via getOrCompute then evicts via ttlMs=0. The drift
  was ironic: D16 was about removing doc-code drift in ADR 0004
  bullet 3 itself, and the amendment was about to ship fresh drift.
  Corrected to accurately describe the write-then-evict pattern and
  the rationale (preserving D4 singleflight during truncation events).

Authority:
- ADR 0004 § Trigger taxonomy Hard triggers bullet 3 (the qualifier
  this amendment makes load-bearing)
  https://github.com/dtzp555-max/olp/blob/main/docs/adr/0004-fallback-engine.md
- ADR 0005 § Cache write conditions item 1 — "response completed
  successfully (no truncation, no error mid-stream)"
- OpenAI Chat Completions finish_reason enum (stop|length|tool_calls|
  content_filter|function_call|null)
  https://platform.openai.com/docs/api-reference/chat/object
- ADR 0004 § Fallback safety — first-chunk rule (already governs the
  analogous case in the real-streaming path)
- ALIGNMENT.md Rule 2(c) spirit — ADR amendment + code change land
  in same merge (D11 / D15 precedent)
- CC 开发铁律 v1.6 § 10.x — Cold Audit caught this; diff-review
  passes focused on first-chunk rule for streaming missed the
  buffered path's truncation-vs-fallback decision point

Reviewer (Iron Rule v1.6 § 10.x Mode A, fresh-context opus, independent
of drafter): APPROVE_WITH_MINOR. Folded the ADR doc-code drift minor
before commit. Walked all 3 error-chunk scenarios against actual code
to verify the pre-commit fold-in is correct. Analyzed the eviction
race window (sub-ms post-inflight pre-eviction window where a fresh
caller could hit the truncated cache before eviction lands) and
concluded it's structurally bounded — one-shot leak per truncation
event; subsequent callers re-spawn. Acceptable as v0.1.

Follow-up items (reviewer's non-blocking suggestions, NOT in this PR):
- 4th test asserting second identical request triggers fresh spawn
  (defense-in-depth around the eviction; store.mjs ttlMs=0 semantics
  are independently established)
- `cacheStore.delete()` API (cleaner than set-with-ttlMs=0 — leaves
  no dead entry in the namespace map; future PR)
- `cache_evicted_truncated` log event for dashboard observability
- SPAWN_TIMEOUT salvage parity — same architectural argument as
  SPAWN_FAILED (user paid for partial content); deferred as a
  separate cold-audit finding for a future D-stage

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
This commit is contained in:
2026-05-24 11:40:52 +10:00
co-authored by Claude Opus 4.7
parent 8ae77c3ae3
commit bafa6d1991
3 changed files with 356 additions and 9 deletions
+276
View File
@@ -4153,6 +4153,282 @@ describe('Fallback engine — HTTP integration (D9)', () => {
}
});
// ── D16 tests: SPAWN_FAILED partial-response salvage (ADR 0004 Amendment 1) ─
it('D16/Case-A regression guard: SPAWN_FAILED with no chunks → hard fallback fires → openai serves (2-hop)', async () => {
// Case A: provider exits non-zero BEFORE emitting any content.
// Fallback engine must still advance the chain — this is the pre-D16 behavior
// that must remain unchanged. Emitting zero chunks then exit-1 must still trigger
// the hard fallback.
__clearCache();
const { writeFileSync, unlinkSync } = await import('node:fs');
const { tmpdir } = await import('node:os');
const { join: pathJoin } = await import('node:path');
const tmpAuthFile = pathJoin(tmpdir(), `olp-test-d16-caseA-auth-${Date.now()}.json`);
writeFileSync(tmpAuthFile, JSON.stringify({ accessToken: 'fake-d16-caseA-codex-token' }), 'utf8');
const savedCodexAuthPath = process.env.OPENAI_CODEX_AUTH_PATH;
process.env.OPENAI_CODEX_AUTH_PATH = tmpAuthFile;
__setFallbackConfig({
chains: {
'claude-sonnet-4-6': [
{ provider: 'anthropic', model: 'claude-sonnet-4-6' },
{ provider: 'openai', model: 'gpt-5.5' },
],
},
soft_triggers: {},
});
// Anthropic mock: emits NO stdout, exits with code 1 → SPAWN_FAILED with chunks=[]
// This is Case A — hard trigger must fire, chain must advance.
__setSpawnImpl(function (_bin, _args, _opts) {
const proc = new EventEmitter();
proc.stdout = new EventEmitter();
proc.stderr = new EventEmitter();
proc.stdin = {
write: () => {},
end: () => {
setImmediate(() => {
// No stdout data emitted before close
proc.stdout.emit('end');
proc.stderr.emit('end');
proc.emit('close', 1, null); // exit 1 → SPAWN_FAILED, no usable chunks
});
},
};
proc.killed = false;
proc.kill = () => {};
return proc;
});
// OpenAI (codex) mock: succeeds with a real response
codexSetSpawnImpl(function (_bin, _args, _opts) {
const proc = new EventEmitter();
proc.stdout = new EventEmitter();
proc.stderr = new EventEmitter();
proc.stdin = {
write: () => {},
end: () => {
setImmediate(() => {
proc.stdout.emit('data', Buffer.from('{"content":"D16-caseA-fallback-openai-response"}\n'));
proc.stdout.emit('data', Buffer.from('{"type":"stop"}\n'));
proc.stdout.emit('end');
proc.stderr.emit('end');
proc.emit('close', 0, null);
});
},
};
proc.killed = false;
proc.kill = () => {};
return proc;
});
try {
const r = await fetch({
port,
method: 'POST',
path: '/v1/chat/completions',
body: {
model: 'claude-sonnet-4-6',
messages: [{ role: 'user', content: 'Hi' }],
max_tokens: 10,
},
});
assert.equal(r.status, 200, `Expected 200 from openai fallback, got ${r.status}: ${r.body.slice(0, 300)}`);
// Hard trigger fired → chain advanced → openai served → hops=1
assert.equal(r.headers['x-olp-fallback-hops'], '1', `Expected fallback-hops=1 (Case A hard trigger), got: ${r.headers['x-olp-fallback-hops']}`);
assert.equal(r.headers['x-olp-provider-used'], 'openai', `Expected openai served, got: ${r.headers['x-olp-provider-used']}`);
} finally {
__resetFallbackConfig();
__resetSpawnImpl();
codexResetSpawnImpl();
if (savedCodexAuthPath !== undefined) {
process.env.OPENAI_CODEX_AUTH_PATH = savedCodexAuthPath;
} else {
delete process.env.OPENAI_CODEX_AUTH_PATH;
}
try { unlinkSync(tmpAuthFile); } catch { /* ignore */ }
}
});
it('D16/Case-B fix: SPAWN_FAILED after N chunks → fallback does NOT fire → anthropic partial response served (2-hop)', async () => {
// Case B (the D16 fix): provider emits content then exits non-zero.
// The partial chunks are usable — fallback must NOT advance to openai.
// Instead, the partial response is returned with finish_reason='length'.
// X-OLP-Fallback-Hops must be 0 (anthropic served, openai not called).
__clearCache();
const { writeFileSync, unlinkSync } = await import('node:fs');
const { tmpdir } = await import('node:os');
const { join: pathJoin } = await import('node:path');
const tmpAuthFile = pathJoin(tmpdir(), `olp-test-d16-caseB-auth-${Date.now()}.json`);
writeFileSync(tmpAuthFile, JSON.stringify({ accessToken: 'fake-d16-caseB-codex-token' }), 'utf8');
const savedCodexAuthPath = process.env.OPENAI_CODEX_AUTH_PATH;
process.env.OPENAI_CODEX_AUTH_PATH = tmpAuthFile;
let openaiMockCalled = false;
__setFallbackConfig({
chains: {
'claude-sonnet-4-6': [
{ provider: 'anthropic', model: 'claude-sonnet-4-6' },
{ provider: 'openai', model: 'gpt-5.5' },
],
},
soft_triggers: {},
});
// Anthropic mock: emits 2 raw text chunks then exits non-zero (cleanup error).
// The anthropic plugin processes raw stdout as text → IR delta chunks.
// exit code 1 after yielding content → Case B: SPAWN_FAILED with chunks.length>0.
__setSpawnImpl(function (_bin, _args, _opts) {
const proc = new EventEmitter();
proc.stdout = new EventEmitter();
proc.stderr = new EventEmitter();
proc.stdin = {
write: () => {},
end: () => {
setImmediate(() => {
// Emit 2 content chunks as raw text (anthropic --output-format text)
proc.stdout.emit('data', Buffer.from('Hello '));
proc.stdout.emit('data', Buffer.from('world'));
proc.stdout.emit('end');
proc.stderr.emit('end');
// Non-zero exit AFTER emitting content → SPAWN_FAILED, chunks.length=2
proc.emit('close', 1, null);
});
},
};
proc.killed = false;
proc.kill = () => {};
return proc;
});
// OpenAI mock: should NOT be called (D16 must prevent fallback here)
codexSetSpawnImpl(function (_bin, _args, _opts) {
openaiMockCalled = true;
const proc = new EventEmitter();
proc.stdout = new EventEmitter();
proc.stderr = new EventEmitter();
proc.stdin = {
write: () => {},
end: () => {
setImmediate(() => {
proc.stdout.emit('data', Buffer.from('{"content":"unexpected-openai-response"}\n'));
proc.stdout.emit('data', Buffer.from('{"type":"stop"}\n'));
proc.stdout.emit('end');
proc.stderr.emit('end');
proc.emit('close', 0, null);
});
},
};
proc.killed = false;
proc.kill = () => {};
return proc;
});
try {
const r = await fetch({
port,
method: 'POST',
path: '/v1/chat/completions',
body: {
model: 'claude-sonnet-4-6',
messages: [{ role: 'user', content: 'Hi' }],
max_tokens: 10,
},
});
// D16: anthropic partial response surfaced instead of falling back
assert.equal(r.status, 200, `Expected 200 with partial anthropic response, got ${r.status}: ${r.body.slice(0, 300)}`);
// No fallback should have fired — anthropic's partial chunks were usable
assert.equal(r.headers['x-olp-fallback-hops'], '0', `Expected fallback-hops=0 (no fallback, Case B), got: ${r.headers['x-olp-fallback-hops']}`);
assert.equal(r.headers['x-olp-provider-used'], 'anthropic', `Expected anthropic served, got: ${r.headers['x-olp-provider-used']}`);
// OpenAI mock must NOT have been invoked
assert.equal(openaiMockCalled, false, 'OpenAI mock should NOT have been called (D16 prevents fallback on Case B)');
// Verify finish_reason='length' (synthesized stop from D16 salvage path)
const body = JSON.parse(r.body);
assert.equal(body.choices?.[0]?.finish_reason, 'length', `Expected finish_reason='length' from D16 salvage, got: ${body.choices?.[0]?.finish_reason}`);
// Verify the 2 content chunks are present in the response
const content = body.choices?.[0]?.message?.content ?? '';
assert.ok(content.includes('Hello'), `Expected 'Hello' in partial content, got: '${content}'`);
assert.ok(content.includes('world'), `Expected 'world' in partial content, got: '${content}'`);
} finally {
__resetFallbackConfig();
__resetSpawnImpl();
codexResetSpawnImpl();
if (savedCodexAuthPath !== undefined) {
process.env.OPENAI_CODEX_AUTH_PATH = savedCodexAuthPath;
} else {
delete process.env.OPENAI_CODEX_AUTH_PATH;
}
try { unlinkSync(tmpAuthFile); } catch { /* ignore */ }
}
});
it('D16/Case-B single-hop: SPAWN_FAILED after 1 chunk → HTTP 200 with partial response + finish_reason=length (no fallback chain)', async () => {
// Case B single-hop variant: only one provider in the chain.
// Provider emits 1 content chunk then exits non-zero.
// D16 must surface the partial response (HTTP 200, not 502).
__clearCache();
__setFallbackConfig({
chains: {
'claude-sonnet-4-6': [
{ provider: 'anthropic', model: 'claude-sonnet-4-6' },
],
},
soft_triggers: {},
});
// Anthropic mock: emits 1 raw text chunk then exits non-zero
__setSpawnImpl(function (_bin, _args, _opts) {
const proc = new EventEmitter();
proc.stdout = new EventEmitter();
proc.stderr = new EventEmitter();
proc.stdin = {
write: () => {},
end: () => {
setImmediate(() => {
proc.stdout.emit('data', Buffer.from('Partial answer'));
proc.stdout.emit('end');
proc.stderr.emit('end');
proc.emit('close', 1, null); // exit 1 after content → Case B
});
},
};
proc.killed = false;
proc.kill = () => {};
return proc;
});
try {
const r = await fetch({
port,
method: 'POST',
path: '/v1/chat/completions',
body: {
model: 'claude-sonnet-4-6',
messages: [{ role: 'user', content: 'Hi' }],
max_tokens: 10,
},
});
// D16: must be 200 with the partial content, not 502
assert.equal(r.status, 200, `Expected 200 with partial response (not 502), got ${r.status}: ${r.body.slice(0, 300)}`);
assert.equal(r.headers['x-olp-fallback-hops'], '0', `Expected fallback-hops=0, got: ${r.headers['x-olp-fallback-hops']}`);
assert.equal(r.headers['x-olp-provider-used'], 'anthropic', `Expected anthropic served, got: ${r.headers['x-olp-provider-used']}`);
const body = JSON.parse(r.body);
// finish_reason='length' indicates truncation (D16 synthesized stop)
assert.equal(body.choices?.[0]?.finish_reason, 'length', `Expected finish_reason='length', got: ${body.choices?.[0]?.finish_reason}`);
// Partial content must be present
const content = body.choices?.[0]?.message?.content ?? '';
assert.ok(content.includes('Partial answer'), `Expected 'Partial answer' in content, got: '${content}'`);
} finally {
__resetFallbackConfig();
__resetSpawnImpl();
}
});
});
// ── Suite 14: providers.enabled config wiring ──────────────────────────────