From 999713197f94be04c4b8875b8a2ba6f586bfc2a8 Mon Sep 17 00:00:00 2001 From: sh940701 Date: Thu, 1 Oct 2026 13:41:49 +0900 Subject: [PATCH 1/3] fix(claude): log a stalled or over-cap passthrough stream as a 502 incomplete row tapAnthropicSseForLog ended a body stall or byte-cap overflow with an Anthropic error frame but finalized the row as status 200 with only closeReason body_stall / body_overflow. usage.jsonl persists failure diagnostics only for rows at status >= 400 or with a non-completed terminalStatus, so these cut-short turns reached it as plain 200 rows with no closeReason and no reason: anything reading usage.jsonl counted them as successes. The Responses relay logs the same events (a stall-timeout incomplete) as 502 with terminalStatus "incomplete"; httpStatusForRequestLogTerminal maps only a max_output_tokens incomplete to 200. The tap now does the same: 502, terminalStatus "incomplete", the existing closeReason, and the proxy's own message in upstreamError. A mid-stream reset stays 502 / failed, so the two differ only in terminalStatus. The client stream is unchanged. This settles the status split raised in the #6235 review. --- src/server/claude-messages.ts | 8 ++- structure/clients/claude-desktop.md | 2 +- .../claude-messages-endpoint.test.ts | 4 +- .../claude-native-passthrough.test.ts | 55 +++++++++++++++++++ .../messages-native.test.ts | 11 ++++ 5 files changed, 75 insertions(+), 5 deletions(-) diff --git a/src/server/claude-messages.ts b/src/server/claude-messages.ts index d4b0fe54178..701495c7d75 100644 --- a/src/server/claude-messages.ts +++ b/src/server/claude-messages.ts @@ -296,7 +296,7 @@ export interface PassthroughBodyGuard { } type PassthroughCloseReason = "terminal" | "client_cancel" | "body_stall" | "body_overflow"; -type PassthroughFinalizeMeta = { closeReason: PassthroughCloseReason; terminalStatus?: "failed" }; +type PassthroughFinalizeMeta = { closeReason: PassthroughCloseReason; terminalStatus?: "failed" | "incomplete" }; /** * Tap an Anthropic-vocabulary SSE stream for the request log (usage + terminal), @@ -370,7 +370,11 @@ export function tapAnthropicSseForLog( idle.cancel(); detachAbort(); recordUsage(); - finalize(200, { closeReason }); + // A cut-short turn, logged as the Responses relay logs a stall-timeout incomplete + // (httpStatusForRequestLogTerminal: only a max_output_tokens incomplete is a 200). A 200 + // row with no terminalStatus also lost its failure diagnostics in usage.jsonl. + logCtx.upstreamError = message.slice(0, 500); + finalize(502, { terminalStatus: "incomplete", closeReason }); closeWithErrorFrame(errType, message); reader.cancel(new DOMException(message, closeReason === "body_stall" ? "TimeoutError" : "QuotaExceededError")).catch(() => {}); }; diff --git a/structure/clients/claude-desktop.md b/structure/clients/claude-desktop.md index 4d433a3ab47..41ee9ad8944 100644 --- a/structure/clients/claude-desktop.md +++ b/structure/clients/claude-desktop.md @@ -487,7 +487,7 @@ Native Anthropic passthrough in `src/server/claude-messages.ts` forwards the cal ## Native passthrough stream terminals -`tapAnthropicSseForLog` in `src/server/claude-messages.ts` relays the streamed body of both the native passthrough and the managed native Messages lane (`src/server/messages-native.ts`). The response headers are already sent, so a stall, a byte-cap overflow, or an upstream read failure ends the body with an Anthropic `event: error` frame after a blank-line boundary and a clean close: `timeout_error` for an idle stall, `api_error` for the byte cap, and `api_error` when an upstream read fails mid-stream (a socket reset). The mid-stream reset is logged like the Responses relay's read error: status 502, `terminalStatus: "failed"`, `closeReason: "terminal"`, `transportPhase: "mid_stream"`, a synthetic terminal source, the attempt marked `streamAborted`, the redacted reason in `upstreamError`, and the usage seen before the reset. The non-streaming fold in the managed lane closes its row with the tap's meta for a reset, a stall or the byte cap, so its row matches the streaming lane's. The request is not replayed. The logged status is not uniform across these frames: a stall and the byte cap keep status 200 with `closeReason` `body_stall` or `body_overflow`, which classify as `incomplete`, while a reset is a 502 that classifies as `failed`. Some read failures are not upstream failures. When the cancel signal is already aborted, the rejection is a `499` client cancel, because Bun can reject the read before it dispatches the abort listener. The managed lane passes its upstream controller's signal, so shutdown and turn release count as cancels too. When `message_stop` or an upstream `error` event has been seen, including one still in the buffer without its blank-line delimiter, the turn is complete: it logs 200 and closes with no error frame. A terminal found only in that unterminated tail gets its blank line restored, because an SSE parser drops an event that EOF cuts off. A translator budget overflow is a local cap, so it still errors the stream, and the non-streaming fold answers it with 413. `tests/claude-integration/claude-native-passthrough.test.ts` and `tests/claude-integration/messages-native.test.ts` cover both lanes against an upstream that resets after a partial or a complete body, plus both cancel paths. +`tapAnthropicSseForLog` in `src/server/claude-messages.ts` relays the streamed body of both the native passthrough and the managed native Messages lane (`src/server/messages-native.ts`). The response headers are already sent, so a stall, a byte-cap overflow, or an upstream read failure ends the body with an Anthropic `event: error` frame after a blank-line boundary and a clean close: `timeout_error` for an idle stall, `api_error` for the byte cap, and `api_error` when an upstream read fails mid-stream (a socket reset). The mid-stream reset is logged like the Responses relay's read error: status 502, `terminalStatus: "failed"`, `closeReason: "terminal"`, `transportPhase: "mid_stream"`, a synthetic terminal source, the attempt marked `streamAborted`, the redacted reason in `upstreamError`, and the usage seen before the reset. The non-streaming fold in the managed lane closes its row with the tap's meta for a reset, a stall or the byte cap, so its row matches the streaming lane's. The request is not replayed. Every one of these frames logs status 502, as the Responses relay does for the same events: a stall or the byte cap is `terminalStatus: "incomplete"` with `closeReason` `body_stall` or `body_overflow` and the proxy's message in `upstreamError`, while a reset is `terminalStatus: "failed"`. Either way the row keeps its failure diagnostics in usage.jsonl. Some read failures are not upstream failures. When the cancel signal is already aborted, the rejection is a `499` client cancel, because Bun can reject the read before it dispatches the abort listener. The managed lane passes its upstream controller's signal, so shutdown and turn release count as cancels too. When `message_stop` or an upstream `error` event has been seen, including one still in the buffer without its blank-line delimiter, the turn is complete: it logs 200 and closes with no error frame. A terminal found only in that unterminated tail gets its blank line restored, because an SSE parser drops an event that EOF cuts off. A translator budget overflow is a local cap, so it still errors the stream, and the non-streaming fold answers it with 413. `tests/claude-integration/claude-native-passthrough.test.ts` and `tests/claude-integration/messages-native.test.ts` cover both lanes against an upstream that resets after a partial or a complete body, plus both cancel paths. A native passthrough answered without a stream records its reason in `upstreamError`, so the row and the failure diagnostics in usage.jsonl name the cause. An upstream error response (status 400 or above) is relayed verbatim; the stored diagnostic is `Provider error : ` only for a valid Anthropic error envelope with one of the closed types `invalid_request_error`, `authentication_error`, `permission_error`, `not_found_error`, `rate_limit_error`, `api_error`, `overloaded_error` or `request_too_large`. Upstream messages and arbitrary type strings never enter this diagnostic. Unknown or malformed envelopes, non-JSON bodies and bodies over 64 Ki characters log `Provider error `. Local header timeout, body stall, byte-cap overflow and cancel diagnostics contain fixed text plus validated guard limits. Fetch failures log the fixed reason `anthropic passthrough failed: upstream connection error`; the existing redacted client response is preserved. Classification uses these stored reasons and HTTP status, so a `permission_error` at 403 is `permission_denied` regardless of upstream message wording. `tests/claude-integration/claude-native-passthrough.test.ts` covers these cases and checks that echoed account identifiers and request content are absent from both history sinks. diff --git a/tests/claude-integration/claude-messages-endpoint.test.ts b/tests/claude-integration/claude-messages-endpoint.test.ts index 54809b653a0..6dbed427738 100644 --- a/tests/claude-integration/claude-messages-endpoint.test.ts +++ b/tests/claude-integration/claude-messages-endpoint.test.ts @@ -479,7 +479,7 @@ test("A1: stalled upstream body gets an Anthropic timeout_error tail and body_st expect(text).toContain("message_start"); // prior bytes preserved expect(text).toContain("\n\nevent: error\ndata: "); expect(text).toContain('"type":"timeout_error"'); - expect(calls).toEqual([{ status: 200, closeReason: "body_stall" }]); + expect(calls).toEqual([{ status: 502, closeReason: "body_stall" }]); }); test("A2: unbounded upstream body gets an api_error tail and body_overflow close reason", async () => { @@ -494,7 +494,7 @@ test("A2: unbounded upstream body gets an api_error tail and body_overflow close expect(text).toContain("\n\nevent: error\ndata: "); expect(text).toContain('"type":"api_error"'); expect(text).toContain("exceeded 120 bytes"); - expect(calls).toEqual([{ status: 200, closeReason: "body_overflow" }]); + expect(calls).toEqual([{ status: 502, closeReason: "body_overflow" }]); }); test("A3: client abort mid-body finalizes 499 client_cancel, not 200 terminal (misclassification regression)", async () => { diff --git a/tests/claude-integration/claude-native-passthrough.test.ts b/tests/claude-integration/claude-native-passthrough.test.ts index c15106a57e2..c9bd1cccfe1 100644 --- a/tests/claude-integration/claude-native-passthrough.test.ts +++ b/tests/claude-integration/claude-native-passthrough.test.ts @@ -1282,3 +1282,58 @@ test("a client that leaves while a non-stream body is pending logs the cancel as upstream.stop(); } }); + +// --- A stalled or over-cap stream is a visible incomplete turn, in the row and in usage.jsonl --- + +async function stalledStreamRow(upstream: { url: URL }, extraClaude: Record) { + const { clearRequestLogsForTests } = await import("../../src/server/request-log"); + clearRequestLogsForTests(); + saveConfig(cfg(upstream.url.toString().replace(/\/$/, ""), extraClaude)); + const server = startServer(0); + try { + const res = await fetch(new URL("/v1/messages?beta=true", server.url), { + method: "POST", + headers: OAUTH_HEADERS, + body: JSON.stringify(claudeBody()), + }); + const text = await res.text(); + const logs = logsFromApiBody<{ status?: number; terminalStatus?: string; closeReason?: string; upstreamError?: string }>( + await (await fetch(new URL("/api/logs?tail=1", server.url))).json(), + ); + expect(logs).toHaveLength(1); + return { res, text, row: logs[0]!, usage: readRecentUsageEntries(1)[0] }; + } finally { + await server.stop(true); + } +} + +test("a stalled native stream logs a 502 incomplete row and keeps its diagnostics in usage.jsonl", async () => { + const upstream = Bun.serve({ port: 0, fetch: () => new Response(new ReadableStream({ + start(controller) { controller.enqueue(new TextEncoder().encode(PARTIAL_TURN_SSE)); /* then silence */ }, + }), { headers: { "content-type": "text/event-stream" } }) }); + try { + const { res, text, row, usage } = await stalledStreamRow(upstream, { bodyStallSec: 1 }); + expect(res.status).toBe(200); + expect(text).toContain('"type":"timeout_error"'); + // Same row the Responses relay writes for a stall-timeout incomplete (httpStatusForRequestLogTerminal). + expect(row).toMatchObject({ status: 502, terminalStatus: "incomplete", closeReason: "body_stall" }); + expect(row.upstreamError).toBe("anthropic passthrough body stalled: no upstream bytes for 1s"); + // usage.jsonl keeps failure diagnostics only for failed or non-completed rows; a 200 row dropped them. + expect(usage).toMatchObject({ status: 502, terminalStatus: "incomplete", closeReason: "body_stall" }); + } finally { + upstream.stop(true); + } +}); + +test("a native stream over the byte cap logs a 502 incomplete row and keeps its diagnostics in usage.jsonl", async () => { + const upstream = Bun.serve({ port: 0, fetch: () => new Response(PARTIAL_TURN_SSE, { headers: { "content-type": "text/event-stream" } }) }); + try { + const { text, row, usage } = await stalledStreamRow(upstream, { bodyMaxBytes: 64 }); + expect(text).toContain("exceeded 64 bytes"); + expect(row).toMatchObject({ status: 502, terminalStatus: "incomplete", closeReason: "body_overflow" }); + expect(row.upstreamError).toBe("anthropic passthrough body exceeded 64 bytes"); + expect(usage).toMatchObject({ status: 502, terminalStatus: "incomplete", closeReason: "body_overflow" }); + } finally { + upstream.stop(true); + } +}); diff --git a/tests/claude-integration/messages-native.test.ts b/tests/claude-integration/messages-native.test.ts index 8deaabc5e68..2eab826b164 100644 --- a/tests/claude-integration/messages-native.test.ts +++ b/tests/claude-integration/messages-native.test.ts @@ -343,6 +343,17 @@ describe("managed native Messages", () => { expect(row.closeReason).toBe("body_overflow"); }); + test("a relayed stream over the byte cap is a 502 incomplete row, like the passthrough", async () => { + const config = fixtureConfig(startUpstream(ok), { claudeCode: { bodyMaxBytes: 64 } as OcxConfig["claudeCode"] }); + const { requestId, response, text } = await send(config, { ...SOURCE_BODY, stream: true }); + expect(response.status).toBe(200); + expect(text).toContain("exceeded 64 bytes"); + const row = rowFor(requestId); + expect(row.status).toBe(502); + expect(row.terminalStatus).toBe("incomplete"); + expect(row.closeReason).toBe("body_overflow"); + }); + test("a client that disconnects mid-stream is logged as a cancel, not an upstream failure", async () => { const config = fixtureConfig(startUpstream(hangingAfterPartialTurn)); const client = new AbortController(); From abf0b15e5623ec0611c3270568da73b16cf93420 Mon Sep 17 00:00:00 2001 From: sh940701 Date: Thu, 1 Oct 2026 13:55:39 +0900 Subject: [PATCH 2/3] fix(claude): treat a stall or overflow after message_stop as a finished turn Review follow-up. failBody did not check whether the turn's own terminal (message_stop or an upstream error event) had already gone through, unlike the read-error branch. An upstream that sent message_stop and then idled past bodyStallSec, or kept sending past the byte cap, got an error frame appended after message_stop and, with the 502 row, would have counted as a failed turn the client had fully received. It now logs 200 / terminal and closes without a frame. Tests: A1/A2 compare the full finalize meta; the managed lane gains a streaming stall case that checks terminalStatus and the tap's reason, and its fold test pins terminalStatus. The structure doc limits the Responses parity claim to the stall and describes the byte cap as matching the non-stream passthrough's 502. --- src/server/claude-messages.ts | 19 ++++++++---- structure/clients/claude-desktop.md | 2 +- .../claude-messages-endpoint.test.ts | 8 ++--- .../claude-native-passthrough.test.ts | 31 +++++++++++++++++++ .../messages-native.test.ts | 13 ++++++++ 5 files changed, 62 insertions(+), 11 deletions(-) diff --git a/src/server/claude-messages.ts b/src/server/claude-messages.ts index 701495c7d75..2cf47d255ff 100644 --- a/src/server/claude-messages.ts +++ b/src/server/claude-messages.ts @@ -370,12 +370,19 @@ export function tapAnthropicSseForLog( idle.cancel(); detachAbort(); recordUsage(); - // A cut-short turn, logged as the Responses relay logs a stall-timeout incomplete - // (httpStatusForRequestLogTerminal: only a max_output_tokens incomplete is a 200). A 200 - // row with no terminalStatus also lost its failure diagnostics in usage.jsonl. - logCtx.upstreamError = message.slice(0, 500); - finalize(502, { terminalStatus: "incomplete", closeReason }); - closeWithErrorFrame(errType, message); + if (terminalSeen) { + // The turn already ended (message_stop or an upstream error event): an upstream that then + // idles or keeps sending did not cut it short. Same rule as the read-error branch. + finalize(200, { closeReason: "terminal" }); + try { tapController?.close(); } catch { /* client already torn down */ } + } else { + // A cut-short turn, logged as the Responses relay logs a stall-timeout incomplete + // (httpStatusForRequestLogTerminal: only a max_output_tokens incomplete is a 200). A 200 + // row with no terminalStatus also lost its failure diagnostics in usage.jsonl. + logCtx.upstreamError = message.slice(0, 500); + finalize(502, { terminalStatus: "incomplete", closeReason }); + closeWithErrorFrame(errType, message); + } reader.cancel(new DOMException(message, closeReason === "body_stall" ? "TimeoutError" : "QuotaExceededError")).catch(() => {}); }; const idle = idleDeadline(guard?.stallMs ?? 0, () => { diff --git a/structure/clients/claude-desktop.md b/structure/clients/claude-desktop.md index 41ee9ad8944..4e2eb5c1968 100644 --- a/structure/clients/claude-desktop.md +++ b/structure/clients/claude-desktop.md @@ -487,7 +487,7 @@ Native Anthropic passthrough in `src/server/claude-messages.ts` forwards the cal ## Native passthrough stream terminals -`tapAnthropicSseForLog` in `src/server/claude-messages.ts` relays the streamed body of both the native passthrough and the managed native Messages lane (`src/server/messages-native.ts`). The response headers are already sent, so a stall, a byte-cap overflow, or an upstream read failure ends the body with an Anthropic `event: error` frame after a blank-line boundary and a clean close: `timeout_error` for an idle stall, `api_error` for the byte cap, and `api_error` when an upstream read fails mid-stream (a socket reset). The mid-stream reset is logged like the Responses relay's read error: status 502, `terminalStatus: "failed"`, `closeReason: "terminal"`, `transportPhase: "mid_stream"`, a synthetic terminal source, the attempt marked `streamAborted`, the redacted reason in `upstreamError`, and the usage seen before the reset. The non-streaming fold in the managed lane closes its row with the tap's meta for a reset, a stall or the byte cap, so its row matches the streaming lane's. The request is not replayed. Every one of these frames logs status 502, as the Responses relay does for the same events: a stall or the byte cap is `terminalStatus: "incomplete"` with `closeReason` `body_stall` or `body_overflow` and the proxy's message in `upstreamError`, while a reset is `terminalStatus: "failed"`. Either way the row keeps its failure diagnostics in usage.jsonl. Some read failures are not upstream failures. When the cancel signal is already aborted, the rejection is a `499` client cancel, because Bun can reject the read before it dispatches the abort listener. The managed lane passes its upstream controller's signal, so shutdown and turn release count as cancels too. When `message_stop` or an upstream `error` event has been seen, including one still in the buffer without its blank-line delimiter, the turn is complete: it logs 200 and closes with no error frame. A terminal found only in that unterminated tail gets its blank line restored, because an SSE parser drops an event that EOF cuts off. A translator budget overflow is a local cap, so it still errors the stream, and the non-streaming fold answers it with 413. `tests/claude-integration/claude-native-passthrough.test.ts` and `tests/claude-integration/messages-native.test.ts` cover both lanes against an upstream that resets after a partial or a complete body, plus both cancel paths. +`tapAnthropicSseForLog` in `src/server/claude-messages.ts` relays the streamed body of both the native passthrough and the managed native Messages lane (`src/server/messages-native.ts`). The response headers are already sent, so a stall, a byte-cap overflow, or an upstream read failure ends the body with an Anthropic `event: error` frame after a blank-line boundary and a clean close: `timeout_error` for an idle stall, `api_error` for the byte cap, and `api_error` when an upstream read fails mid-stream (a socket reset). The mid-stream reset is logged like the Responses relay's read error: status 502, `terminalStatus: "failed"`, `closeReason: "terminal"`, `transportPhase: "mid_stream"`, a synthetic terminal source, the attempt marked `streamAborted`, the redacted reason in `upstreamError`, and the usage seen before the reset. The non-streaming fold in the managed lane closes its row with the tap's meta for a reset, a stall or the byte cap, so its row matches the streaming lane's. The request is not replayed. Every one of these frames logs status 502. A stall is `terminalStatus: "incomplete"` with `closeReason: "body_stall"`, the status the Responses relay gives a stall-timeout incomplete. The byte cap is `incomplete` with `closeReason: "body_overflow"`, the same 502 the non-stream passthrough answers for it. Both carry the proxy's message in `upstreamError`, and a reset is `terminalStatus: "failed"`. Either way the row keeps its failure diagnostics in usage.jsonl. A stall or overflow after the turn's own terminal (`message_stop` or an upstream `error` event) is a finished turn: it logs 200 and closes without an error frame, as the read-error branch does. Some read failures are not upstream failures. When the cancel signal is already aborted, the rejection is a `499` client cancel, because Bun can reject the read before it dispatches the abort listener. The managed lane passes its upstream controller's signal, so shutdown and turn release count as cancels too. When `message_stop` or an upstream `error` event has been seen, including one still in the buffer without its blank-line delimiter, the turn is complete: it logs 200 and closes with no error frame. A terminal found only in that unterminated tail gets its blank line restored, because an SSE parser drops an event that EOF cuts off. A translator budget overflow is a local cap, so it still errors the stream, and the non-streaming fold answers it with 413. `tests/claude-integration/claude-native-passthrough.test.ts` and `tests/claude-integration/messages-native.test.ts` cover both lanes against an upstream that resets after a partial or a complete body, plus both cancel paths. A native passthrough answered without a stream records its reason in `upstreamError`, so the row and the failure diagnostics in usage.jsonl name the cause. An upstream error response (status 400 or above) is relayed verbatim; the stored diagnostic is `Provider error : ` only for a valid Anthropic error envelope with one of the closed types `invalid_request_error`, `authentication_error`, `permission_error`, `not_found_error`, `rate_limit_error`, `api_error`, `overloaded_error` or `request_too_large`. Upstream messages and arbitrary type strings never enter this diagnostic. Unknown or malformed envelopes, non-JSON bodies and bodies over 64 Ki characters log `Provider error `. Local header timeout, body stall, byte-cap overflow and cancel diagnostics contain fixed text plus validated guard limits. Fetch failures log the fixed reason `anthropic passthrough failed: upstream connection error`; the existing redacted client response is preserved. Classification uses these stored reasons and HTTP status, so a `permission_error` at 403 is `permission_denied` regardless of upstream message wording. `tests/claude-integration/claude-native-passthrough.test.ts` covers these cases and checks that echoed account identifiers and request content are absent from both history sinks. diff --git a/tests/claude-integration/claude-messages-endpoint.test.ts b/tests/claude-integration/claude-messages-endpoint.test.ts index 6dbed427738..0f799aec5d0 100644 --- a/tests/claude-integration/claude-messages-endpoint.test.ts +++ b/tests/claude-integration/claude-messages-endpoint.test.ts @@ -425,10 +425,10 @@ test("native Anthropic passthrough returns 502 when the upstream connection is r const sseEncoder = new TextEncoder(); function spyFinalize() { - const calls: Array<{ status: number; closeReason: string }> = []; + const calls: Array<{ status: number; closeReason: string; terminalStatus?: string }> = []; return { calls, - finalize: (status: number, meta: { closeReason: string }) => calls.push({ status, closeReason: meta.closeReason }), + finalize: (status: number, meta: { closeReason: string; terminalStatus?: string }) => calls.push({ status, ...meta }), }; } @@ -479,7 +479,7 @@ test("A1: stalled upstream body gets an Anthropic timeout_error tail and body_st expect(text).toContain("message_start"); // prior bytes preserved expect(text).toContain("\n\nevent: error\ndata: "); expect(text).toContain('"type":"timeout_error"'); - expect(calls).toEqual([{ status: 502, closeReason: "body_stall" }]); + expect(calls).toEqual([{ status: 502, closeReason: "body_stall", terminalStatus: "incomplete" }]); }); test("A2: unbounded upstream body gets an api_error tail and body_overflow close reason", async () => { @@ -494,7 +494,7 @@ test("A2: unbounded upstream body gets an api_error tail and body_overflow close expect(text).toContain("\n\nevent: error\ndata: "); expect(text).toContain('"type":"api_error"'); expect(text).toContain("exceeded 120 bytes"); - expect(calls).toEqual([{ status: 502, closeReason: "body_overflow" }]); + expect(calls).toEqual([{ status: 502, closeReason: "body_overflow", terminalStatus: "incomplete" }]); }); test("A3: client abort mid-body finalizes 499 client_cancel, not 200 terminal (misclassification regression)", async () => { diff --git a/tests/claude-integration/claude-native-passthrough.test.ts b/tests/claude-integration/claude-native-passthrough.test.ts index c9bd1cccfe1..18da4dd3e01 100644 --- a/tests/claude-integration/claude-native-passthrough.test.ts +++ b/tests/claude-integration/claude-native-passthrough.test.ts @@ -1337,3 +1337,34 @@ test("a native stream over the byte cap logs a 502 incomplete row and keeps its upstream.stop(true); } }); + +test("a turn that sent message_stop and then stalls is finished: 200 terminal, no error frame", async () => { + const source = new ReadableStream({ + start(controller) { controller.enqueue(new TextEncoder().encode(COMPLETE_TURN_SSE)); /* never closes */ }, + }); + const calls: unknown[] = []; + const logCtx: RequestLogContext = { model: "claude-fable-5", provider: "anthropic-native" }; + const tapped = tapAnthropicSseForLog(source, logCtx, (status, meta) => calls.push({ status, ...meta }), { stallMs: 30, maxBytes: 0 }); + const text = await new Response(tapped).text(); + expect(text).toBe(COMPLETE_TURN_SSE); + expect(calls).toEqual([{ status: 200, closeReason: "terminal" }]); + expect(logCtx.upstreamError).toBeUndefined(); +}); + +test("bytes past the cap after message_stop do not turn a finished turn into a failure", async () => { + let sent = false; + const source = new ReadableStream({ + pull(controller) { + if (!sent) { sent = true; controller.enqueue(new TextEncoder().encode(COMPLETE_TURN_SSE)); return; } + controller.enqueue(new TextEncoder().encode(": keepalive padding ".repeat(64))); + }, + }); + const calls: unknown[] = []; + const logCtx: RequestLogContext = { model: "claude-fable-5", provider: "anthropic-native" }; + const cap = new TextEncoder().encode(COMPLETE_TURN_SSE).byteLength + 16; + const tapped = tapAnthropicSseForLog(source, logCtx, (status, meta) => calls.push({ status, ...meta }), { stallMs: 0, maxBytes: cap }); + const text = await new Response(tapped).text(); + expect(text).toStartWith(COMPLETE_TURN_SSE); + expect(text).not.toContain("event: error"); + expect(calls).toEqual([{ status: 200, closeReason: "terminal" }]); +}); diff --git a/tests/claude-integration/messages-native.test.ts b/tests/claude-integration/messages-native.test.ts index 2eab826b164..389c2376b04 100644 --- a/tests/claude-integration/messages-native.test.ts +++ b/tests/claude-integration/messages-native.test.ts @@ -341,6 +341,7 @@ describe("managed native Messages", () => { const row = rowFor(requestId); expect(row.status).toBe(502); expect(row.closeReason).toBe("body_overflow"); + expect(row.terminalStatus).toBe("incomplete"); }); test("a relayed stream over the byte cap is a 502 incomplete row, like the passthrough", async () => { @@ -354,6 +355,18 @@ describe("managed native Messages", () => { expect(row.closeReason).toBe("body_overflow"); }); + test("a relayed stream that stalls is a 502 incomplete row with the tap's reason", async () => { + const config = fixtureConfig(startUpstream(hangingAfterPartialTurn), { claudeCode: { bodyStallSec: 1 } as OcxConfig["claudeCode"] }); + const { requestId, response, text } = await send(config, { ...SOURCE_BODY, stream: true }); + expect(response.status).toBe(200); + expect(text).toContain('"type":"timeout_error"'); + const row = rowFor(requestId); + expect(row.status).toBe(502); + expect(row.terminalStatus).toBe("incomplete"); + expect(row.closeReason).toBe("body_stall"); + expect(row.upstreamError).toBe("anthropic passthrough body stalled: no upstream bytes for 1s"); + }); + test("a client that disconnects mid-stream is logged as a cancel, not an upstream failure", async () => { const config = fixtureConfig(startUpstream(hangingAfterPartialTurn)); const client = new AbortController(); From 97254b530d41ba2e7bffd9046dfe341567df409c Mon Sep 17 00:00:00 2001 From: sh940701 Date: Thu, 1 Oct 2026 14:07:47 +0900 Subject: [PATCH 3/3] fix(claude): find passthrough SSE frames delimited by CRLF or CR CodeRabbit follow-up. The tap's inspection split frames on "\n\n" only, so a CRLF- or CR-delimited stream never had its frames seen: usage was not read, and with this PR's terminal check a finished turn that then stalled or overflowed would be logged as a 502 incomplete with an error frame after message_stop. The inspection copy is now normalized to LF (forwarded bytes untouched), holding a trailing CR until the next chunk so a CRLF split across chunks stays one line ending. The tail flush the read-error branch already did is now shared with failBody, so a terminal block still in the buffer (an upstream that went quiet right after it, or a held CR) counts there too; the blank line is restored only when the client has not received one. --- src/server/claude-messages.ts | 34 ++++++++++---- structure/clients/claude-desktop.md | 2 +- .../claude-native-passthrough.test.ts | 46 +++++++++++++++++++ 3 files changed, 72 insertions(+), 10 deletions(-) diff --git a/src/server/claude-messages.ts b/src/server/claude-messages.ts index 2cf47d255ff..f03dfc0d90e 100644 --- a/src/server/claude-messages.ts +++ b/src/server/claude-messages.ts @@ -340,6 +340,11 @@ export function tapAnthropicSseForLog( }; const inspect = (chunk: Uint8Array) => { buffer += decoder.decode(chunk, { stream: true }); + // SSE lines may end in CRLF, LF or CR. Normalize the inspection copy to LF (the forwarded + // bytes are untouched), holding a trailing CR until the next chunk shows whether an LF + // follows it, so a CRLF split across chunks stays one line ending. + const heldCr = buffer.endsWith("\r"); + buffer = (heldCr ? buffer.slice(0, -1) : buffer).replace(/\r\n?/g, "\n") + (heldCr ? "\r" : ""); let sep: number; while ((sep = buffer.indexOf("\n\n")) !== -1) { const frame = buffer.slice(0, sep); @@ -347,6 +352,17 @@ export function tapAnthropicSseForLog( inspectFrame(frame); } }; + // The last block can sit in the buffer without its blank line: an upstream that stopped after + // it, or a held trailing CR. Count it before deciding how the turn ended (the Responses relay + // flushes the same candidate). Returns true when this flush found the terminal in a block the + // client has not seen a blank line after, so the caller restores one. + const flushTail = (): boolean => { + const terminalBefore = terminalSeen; + const tail = (buffer + decoder.decode()).replace(/\r\n?/g, "\n"); + buffer = ""; + if (tail) inspectFrame(tail); + return terminalSeen && !terminalBefore && !tail.endsWith("\n\n"); + }; const reader = upstream.getReader(); let settled = false; let bodyBytes = 0; @@ -369,12 +385,17 @@ export function tapAnthropicSseForLog( settled = true; idle.cancel(); detachAbort(); + const terminalInTail = flushTail(); recordUsage(); if (terminalSeen) { // The turn already ended (message_stop or an upstream error event): an upstream that then - // idles or keeps sending did not cut it short. Same rule as the read-error branch. + // idles or keeps sending did not cut it short. Same rule as the read-error branch, + // including the restored blank line for a terminal found only in the tail. finalize(200, { closeReason: "terminal" }); - try { tapController?.close(); } catch { /* client already torn down */ } + try { + if (terminalInTail) tapController?.enqueue(encoder.encode("\n\n")); + tapController?.close(); + } catch { /* client already torn down */ } } else { // A cut-short turn, logged as the Responses relay logs a stall-timeout incomplete // (httpStatusForRequestLogTerminal: only a max_output_tokens incomplete is a 200). A 200 @@ -461,12 +482,7 @@ export function tapAnthropicSseForLog( settled = true; idle.cancel(); detachAbort(); - // A read error can follow the last SSE block before its blank-line delimiter. Count - // that block before deciding how the turn ended, as the Responses relay does. - const terminalBeforeTail = terminalSeen; - const tail = buffer + decoder.decode(); - buffer = ""; - if (tail) inspectFrame(tail); + const terminalInTail = flushTail(); recordUsage(); if (isTranslatorBudgetExceededError(err)) { // A local cap, not an upstream failure: the non-streaming native Messages fold @@ -482,7 +498,7 @@ export function tapAnthropicSseForLog( try { // An SSE parser drops an event that EOF cuts off before its blank line, so restore // the delimiter when the terminal was only found in that unterminated tail. - if (!terminalBeforeTail) controller.enqueue(encoder.encode("\n\n")); + if (terminalInTail) controller.enqueue(encoder.encode("\n\n")); controller.close(); } catch { /* torn down */ } reader.cancel(err).catch(() => {}); diff --git a/structure/clients/claude-desktop.md b/structure/clients/claude-desktop.md index 4e2eb5c1968..fccc462a137 100644 --- a/structure/clients/claude-desktop.md +++ b/structure/clients/claude-desktop.md @@ -487,7 +487,7 @@ Native Anthropic passthrough in `src/server/claude-messages.ts` forwards the cal ## Native passthrough stream terminals -`tapAnthropicSseForLog` in `src/server/claude-messages.ts` relays the streamed body of both the native passthrough and the managed native Messages lane (`src/server/messages-native.ts`). The response headers are already sent, so a stall, a byte-cap overflow, or an upstream read failure ends the body with an Anthropic `event: error` frame after a blank-line boundary and a clean close: `timeout_error` for an idle stall, `api_error` for the byte cap, and `api_error` when an upstream read fails mid-stream (a socket reset). The mid-stream reset is logged like the Responses relay's read error: status 502, `terminalStatus: "failed"`, `closeReason: "terminal"`, `transportPhase: "mid_stream"`, a synthetic terminal source, the attempt marked `streamAborted`, the redacted reason in `upstreamError`, and the usage seen before the reset. The non-streaming fold in the managed lane closes its row with the tap's meta for a reset, a stall or the byte cap, so its row matches the streaming lane's. The request is not replayed. Every one of these frames logs status 502. A stall is `terminalStatus: "incomplete"` with `closeReason: "body_stall"`, the status the Responses relay gives a stall-timeout incomplete. The byte cap is `incomplete` with `closeReason: "body_overflow"`, the same 502 the non-stream passthrough answers for it. Both carry the proxy's message in `upstreamError`, and a reset is `terminalStatus: "failed"`. Either way the row keeps its failure diagnostics in usage.jsonl. A stall or overflow after the turn's own terminal (`message_stop` or an upstream `error` event) is a finished turn: it logs 200 and closes without an error frame, as the read-error branch does. Some read failures are not upstream failures. When the cancel signal is already aborted, the rejection is a `499` client cancel, because Bun can reject the read before it dispatches the abort listener. The managed lane passes its upstream controller's signal, so shutdown and turn release count as cancels too. When `message_stop` or an upstream `error` event has been seen, including one still in the buffer without its blank-line delimiter, the turn is complete: it logs 200 and closes with no error frame. A terminal found only in that unterminated tail gets its blank line restored, because an SSE parser drops an event that EOF cuts off. A translator budget overflow is a local cap, so it still errors the stream, and the non-streaming fold answers it with 413. `tests/claude-integration/claude-native-passthrough.test.ts` and `tests/claude-integration/messages-native.test.ts` cover both lanes against an upstream that resets after a partial or a complete body, plus both cancel paths. +`tapAnthropicSseForLog` in `src/server/claude-messages.ts` relays the streamed body of both the native passthrough and the managed native Messages lane (`src/server/messages-native.ts`). The response headers are already sent, so a stall, a byte-cap overflow, or an upstream read failure ends the body with an Anthropic `event: error` frame after a blank-line boundary and a clean close: `timeout_error` for an idle stall, `api_error` for the byte cap, and `api_error` when an upstream read fails mid-stream (a socket reset). The mid-stream reset is logged like the Responses relay's read error: status 502, `terminalStatus: "failed"`, `closeReason: "terminal"`, `transportPhase: "mid_stream"`, a synthetic terminal source, the attempt marked `streamAborted`, the redacted reason in `upstreamError`, and the usage seen before the reset. The non-streaming fold in the managed lane closes its row with the tap's meta for a reset, a stall or the byte cap, so its row matches the streaming lane's. The request is not replayed. Every one of these frames logs status 502. A stall is `terminalStatus: "incomplete"` with `closeReason: "body_stall"`, the status the Responses relay gives a stall-timeout incomplete. The byte cap is `incomplete` with `closeReason: "body_overflow"`, the same 502 the non-stream passthrough answers for it. Both carry the proxy's message in `upstreamError`, and a reset is `terminalStatus: "failed"`. Either way the row keeps its failure diagnostics in usage.jsonl. A stall or overflow after the turn's own terminal (`message_stop` or an upstream `error` event) is a finished turn: it logs 200 and closes without an error frame, as the read-error branch does. The tap finds frames in a copy normalized to LF, because SSE lines may end in CRLF, LF or CR; it holds a trailing CR until the next chunk so a split CRLF stays one line ending, and forwards the original bytes unchanged. Some read failures are not upstream failures. When the cancel signal is already aborted, the rejection is a `499` client cancel, because Bun can reject the read before it dispatches the abort listener. The managed lane passes its upstream controller's signal, so shutdown and turn release count as cancels too. When `message_stop` or an upstream `error` event has been seen, including one still in the buffer without its blank-line delimiter, the turn is complete: it logs 200 and closes with no error frame. A terminal found only in that unterminated tail gets its blank line restored, because an SSE parser drops an event that EOF cuts off. A translator budget overflow is a local cap, so it still errors the stream, and the non-streaming fold answers it with 413. `tests/claude-integration/claude-native-passthrough.test.ts` and `tests/claude-integration/messages-native.test.ts` cover both lanes against an upstream that resets after a partial or a complete body, plus both cancel paths. A native passthrough answered without a stream records its reason in `upstreamError`, so the row and the failure diagnostics in usage.jsonl name the cause. An upstream error response (status 400 or above) is relayed verbatim; the stored diagnostic is `Provider error : ` only for a valid Anthropic error envelope with one of the closed types `invalid_request_error`, `authentication_error`, `permission_error`, `not_found_error`, `rate_limit_error`, `api_error`, `overloaded_error` or `request_too_large`. Upstream messages and arbitrary type strings never enter this diagnostic. Unknown or malformed envelopes, non-JSON bodies and bodies over 64 Ki characters log `Provider error `. Local header timeout, body stall, byte-cap overflow and cancel diagnostics contain fixed text plus validated guard limits. Fetch failures log the fixed reason `anthropic passthrough failed: upstream connection error`; the existing redacted client response is preserved. Classification uses these stored reasons and HTTP status, so a `permission_error` at 403 is `permission_denied` regardless of upstream message wording. `tests/claude-integration/claude-native-passthrough.test.ts` covers these cases and checks that echoed account identifiers and request content are absent from both history sinks. diff --git a/tests/claude-integration/claude-native-passthrough.test.ts b/tests/claude-integration/claude-native-passthrough.test.ts index 18da4dd3e01..b41ee40bf5b 100644 --- a/tests/claude-integration/claude-native-passthrough.test.ts +++ b/tests/claude-integration/claude-native-passthrough.test.ts @@ -1368,3 +1368,49 @@ test("bytes past the cap after message_stop do not turn a finished turn into a f expect(text).not.toContain("event: error"); expect(calls).toEqual([{ status: 200, closeReason: "terminal" }]); }); + +// SSE lines may end in CRLF, LF or CR. The tap forwards bytes untouched but must still see the frames. +function tapWithChunks(chunks: string[], guard: { stallMs: number; maxBytes: number }) { + let index = 0; + const source = new ReadableStream({ + pull(controller) { + if (index < chunks.length) controller.enqueue(new TextEncoder().encode(chunks[index++]!)); + // then silence (stall) or more bytes, per the test + }, + }); + const calls: unknown[] = []; + const logCtx: RequestLogContext = { model: "claude-fable-5", provider: "anthropic-native" }; + const tapped = tapAnthropicSseForLog(source, logCtx, (status, meta) => calls.push({ status, ...meta }), guard); + return { tapped, calls, logCtx }; +} + +for (const [label, eol] of [["CRLF", "\r\n"], ["CR", "\r"]] as const) { + test(`a ${label}-delimited turn that then stalls is finished, and its usage is read`, async () => { + const turn = COMPLETE_TURN_SSE.replace(/\n/g, eol); + const { tapped, calls, logCtx } = tapWithChunks([turn], { stallMs: 30, maxBytes: 0 }); + const text = await new Response(tapped).text(); + expect(text).toBe(turn); + expect(calls).toEqual([{ status: 200, closeReason: "terminal" }]); + expect(logCtx.usage).toEqual(expect.objectContaining({ inputTokens: 12, outputTokens: 5 })); + }); +} + +test("a CRLF delimiter split across chunks is one delimiter, not a frame boundary", async () => { + const turn = COMPLETE_TURN_SSE.replace(/\n/g, "\r\n"); + // Cut every frame between its CR and LF so each chunk ends in a lone CR. + const chunks = turn.split("\r\n").map((part, i, all) => (i < all.length - 1 ? `${part}\r` : part)).map((part, i) => (i === 0 ? part : `\n${part}`)); + expect(chunks.join("")).toBe(turn); + const { tapped, calls, logCtx } = tapWithChunks(chunks, { stallMs: 30, maxBytes: 0 }); + await new Response(tapped).text(); + expect(calls).toEqual([{ status: 200, closeReason: "terminal" }]); + expect(logCtx.usage).toEqual(expect.objectContaining({ inputTokens: 12, outputTokens: 5 })); +}); + +test("a CRLF turn followed by bytes past the cap is finished, not a failure", async () => { + const turn = COMPLETE_TURN_SSE.replace(/\n/g, "\r\n"); + const cap = new TextEncoder().encode(turn).byteLength + 16; + const { tapped, calls } = tapWithChunks([turn, ": padding ".repeat(64)], { stallMs: 0, maxBytes: cap }); + const text = await new Response(tapped).text(); + expect(text).not.toContain("event: error"); + expect(calls).toEqual([{ status: 200, closeReason: "terminal" }]); +});