diff --git a/docs/adr/0004-fallback-engine.md b/docs/adr/0004-fallback-engine.md index e83cbdf..e7c0f98 100644 --- a/docs/adr/0004-fallback-engine.md +++ b/docs/adr/0004-fallback-engine.md @@ -5,6 +5,26 @@ - **Authors:** project maintainer (with AI drafting assistance) - **Related:** OLP v0.1 spec §4.3; ADR 0001 (project founding — fallback is OLP's core value proposition); ADR 0002 (plugin architecture); ADR 0003 (IR — fallback replays IR across chain hops) +## Amendments + +### Amendment 1 — 2026-05-24: Buffered-path SPAWN_FAILED with usable chunks must NOT trigger fallback (D16) + +- **Finding:** Cold-audit Finding 17 (P2 fallback correctness) — Hard triggers bullet 3 in the Decision section below reads: "Provider CLI exit code ≠ 0 **with no usable response chunks streamed**." The qualifier "with no usable response chunks streamed" is load-bearing. Pre-D16 code in `server.mjs` `collectAllChunks` had no catch block: if the provider generator threw `ProviderError(SPAWN_FAILED)` after yielding N>0 IR delta/stop chunks, the throw propagated out of the `for await` loop, discarding the accumulated chunks. The fallback engine then treated SPAWN_FAILED as a hard trigger unconditionally, advanced the chain, and served the next provider's response. The original provider's actual partial output — content the user had already paid for — was silently dropped. + +- **Clarification — "usable response chunks streamed":** A chunks array has usable chunks if `chunks.length > 0` where the counted chunks are IR delta or stop chunks (i.e., `type === 'delta'` or `type === 'stop'`). Chunks of `type === 'error'` are excluded from this count — they are failure signals, not usable content. In the buffered path (`collectAllChunks` in `server.mjs`), `type === 'error'` chunks cause an immediate throw before being pushed to the array (see existing code), so in practice `chunks.length > 0` after the loop implies the array contains only delta/stop chunks and the count correctly reflects usable content. The N=1 boundary is intentional: even a single non-empty delta chunk represents content the provider has committed and the user has paid for in quota; dropping it to serve an alternate provider's response is strict waste and potentially misleading (the second provider may produce different content for the same prompt). + +- **Behavior change (D16):** In the buffered path (`collectAllChunks` in `server.mjs`), when the provider generator throws `ProviderError` with `code === 'SPAWN_FAILED'` after yielding one or more chunks: + - If `chunks.length > 0`: synthesize a final stop chunk `{ type: 'stop', finish_reason: 'length' }`, push it to the chunks array, log a `warn` event `spawn_failed_after_usable_chunks`, and **return the chunks** (do not re-throw). The fallback engine sees a successful return value and does not advance the chain. The client receives the partial response with `finish_reason: 'length'`. `X-OLP-Fallback-Hops: 0` is emitted. + - If `chunks.length === 0`: the SPAWN_FAILED error propagates as before. The fallback engine fires the hard trigger and advances the chain (Case A — correct behavior unchanged). + - Any other error code (not SPAWN_FAILED): always re-thrown, behavior unchanged. + - **Cache behavior:** truncated responses (those produced by the SPAWN_FAILED salvage path) are NOT persistently cached. ADR 0005 § "Cache write conditions" item 1 requires "response completed successfully (no truncation, no error mid-stream)"; a salvaged partial response does not meet this condition. In `executeHopFn`, the salvaged result is written through `cacheStore.getOrCompute` normally so that concurrent inflight callers (D4 singleflight) share the spawn and all receive the partial response — then the entry is immediately evicted via `cacheStore.set(keyId, hopCacheKey, result, ttlMs=0)`, which causes `_isAlive` to treat the entry as expired on the next read. The write-then-evict pattern preserves D4 singleflight during the truncation event (the right behavior — concurrent callers should share the partial spawn rather than each triggering their own) while ensuring future fresh callers re-spawn the provider rather than serving cached truncated content. The salvage path uses a non-enumerable `__truncated` marker on the returned chunks array to signal the eviction; the marker does not appear in `JSON.stringify` or in any client-visible surface. + +- **finish_reason choice:** The synthesized stop chunk uses `finish_reason: 'length'` because: (a) it is in the OpenAI spec enum (`stop | length | tool_calls | content_filter | function_call | null`); (b) it semantically maps to "output was truncated due to resource constraints," which is the closest available enum value to "truncated because the provider process exited non-zero during cleanup after streaming output"; (c) `null` is inferior — some clients retry on `null` finish_reason expecting additional chunks, which would cause spurious re-requests; (d) `stop` would be misleading — it implies the model naturally terminated at a sentence boundary, which is false. Using `length` correctly signals to the client that the output was cut short and they may wish to re-request or continue. + +- **Streaming path note:** The D10 real-streaming branch (single-hop, `server.mjs` lines 401–510) already handles the analogous case correctly via ADR 0004's first-chunk rule: once `firstChunkEmitted === true`, any subsequent error truncates the response with `res.end()` (no re-throw, no fallback). This amendment applies specifically to the **buffered path** (`collectAllChunks` + multi-hop fallback chains). The streaming path is not changed by D16. + +- **Procedural mechanism:** CC 开发铁律 v1.6 § 10.x (Cold Audit). Diff-review reviewers on earlier passes focused on the first-chunk rule for the real-streaming path; the buffered path has its own truncation-vs-fallback decision point, which the cold-audit pass on 2026-05-23 identified as Finding 17. + ## Context A multi-provider proxy is only valuable if it fails over gracefully. Per spec §1, OLP's core value proposition is "your IDEs and family clients keep working as long as *any* of your subscriptions has quota left." If Anthropic returns 529 (overloaded), or OpenAI returns 429 with `insufficient_quota`, or `claude -p` exits non-zero, the client should not see an error; the client should see the next provider in the chain transparently take over. diff --git a/server.mjs b/server.mjs index 7d6a05f..fff5910 100644 --- a/server.mjs +++ b/server.mjs @@ -368,17 +368,54 @@ async function handleChatCompletions(req, res) { // Collect all chunks from this provider, throwing on error chunks. // Error semantics: ProviderError thrown here propagates to executeWithFallback // which decides whether to advance the chain. + // + // D16 (ADR 0004 Amendment 1): if the generator throws ProviderError SPAWN_FAILED + // after yielding one or more chunks, those chunks are usable content the provider + // committed — dropping them and falling back to the next hop is strict waste. + // In that case: synthesize a stop chunk with finish_reason='length', return the + // partial chunks, and do NOT re-throw (fallback engine sees a success, hops=0). + // If chunks.length===0 on SPAWN_FAILED, re-throw as before (hard trigger fires). + // Any other error code always re-throws unchanged. + // + // D16 cache note: truncated responses are NOT cached (ADR 0005 § cache write + // conditions item 1 requires no truncation). A non-enumerable __truncated marker + // is set on the returned array so executeHopFn can evict the cache entry below. async function collectAllChunks() { const chunks = []; - for await (const irChunk of hopProviderPlugin.spawn(irReq, authContext)) { - chunks.push(irChunk); - if (irChunk.type === 'error') { - throw new ProviderError( - irChunk.error ?? 'Provider emitted error chunk', - 'SPAWN_FAILED', - ); + try { + for await (const irChunk of hopProviderPlugin.spawn(irReq, authContext)) { + // D16: check error chunks BEFORE pushing — preserves the invariant that + // chunks array contains only delta/stop chunks. Without this, the catch + // block's `chunks.length > 0` would mistake a single error chunk for + // "usable content streamed" (Case B) and synthesize a stop + return, + // sending an empty body to the client when the correct behavior is to + // re-throw and let the fallback engine advance the chain. + if (irChunk.type === 'error') { + throw new ProviderError( + irChunk.error ?? 'Provider emitted error chunk', + 'SPAWN_FAILED', + ); + } + chunks.push(irChunk); + if (irChunk.type === 'stop') break; } - if (irChunk.type === 'stop') break; + } catch (spawnErr) { + if (spawnErr instanceof ProviderError && spawnErr.code === 'SPAWN_FAILED' && chunks.length > 0) { + // Case B (ADR 0004 Amendment 1): provider emitted usable chunks then exited + // non-zero. Synthesize a truncated stop and surface the partial response. + chunks.push({ type: 'stop', finish_reason: 'length' }); + logEvent('warn', 'spawn_failed_after_usable_chunks', { + chunks_count: chunks.length - 1, // exclude the synthesized stop + provider: hopProvider, + model: hopModel, + }); + // Mark as truncated so the caller can evict this entry from cache. + Object.defineProperty(chunks, '__truncated', { value: true, enumerable: false }); + return chunks; + } + // Case A (SPAWN_FAILED with no chunks) or any other error: re-throw. + // Fallback engine fires hard trigger and advances chain as before. + throw spawnErr; } return chunks; } @@ -398,7 +435,21 @@ async function handleChatCompletions(req, res) { // D4 singleflight + D1 per-key isolation per ADR 0005. // Each hop has its own (provider, model) key — cross-provider contamination // is structurally impossible (ADR 0005 § Per-model isolation). - return cacheStore.getOrCompute(keyId, hopCacheKey, collectAllChunks); + // + // D16: after getOrCompute returns, check if collectAllChunks used the salvage + // path (chunks.__truncated===true). If so, evict the just-written cache entry + // to satisfy ADR 0005 § "Cache write conditions" item 1 (no truncation). + // D4 singleflight is preserved: getOrCompute still deduplicates concurrent + // requests during the spawn; the eviction only affects persistent caching. + const result = await cacheStore.getOrCompute(keyId, hopCacheKey, collectAllChunks); + if (result.__truncated) { + // Evict the truncated entry so future requests get a fresh spawn. + // ADR 0005 § "Cache write conditions" item 1: truncated responses must not + // persist in cache. Overwrite with ttlMs=0 so any subsequent get/peek + // finds the entry already-expired and deletes it. + await cacheStore.set(keyId, hopCacheKey, result, 0); + } + return result; } // ── Execute with fallback (ADR 0004) ──────────────────────────────────── diff --git a/test-features.mjs b/test-features.mjs index a5c193c..9e095ba 100644 --- a/test-features.mjs +++ b/test-features.mjs @@ -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 ──────────────────────────────