fix(claude): log a stalled or over-cap passthrough stream as a 502 incomplete row

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),
@@ -340,13 +340,29 @@ 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);
       buffer = buffer.slice(sep + 2);
       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,9 +385,25 @@ export function tapAnthropicSseForLog(
     settled = true;
     idle.cancel();
     detachAbort();
+    const terminalInTail = flushTail();
     recordUsage();
-    finalize(200, { 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,
+      // including the restored blank line for a terminal found only in the tail.
+      finalize(200, { closeReason: "terminal" });
+      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
+      // 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, () => {
@@ -450,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
@@ -471,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(() => {});

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. 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 <status>: <type>` 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 <status>`. 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.
 

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: 200, 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: 200, 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 () => {

tests/claude-integration/claude-native-passthrough.test.ts

@@ -1282,3 +1282,135 @@ 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<string, unknown>) {
+  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<Uint8Array>({
+    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);
+  }
+});
+
+test("a turn that sent message_stop and then stalls is finished: 200 terminal, no error frame", async () => {
+  const source = new ReadableStream<Uint8Array>({
+    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<Uint8Array>({
+    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" }]);
+});
+
+// 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<Uint8Array>({
+    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" }]);
+});