Skip to content

fix: two provider failures that arrive looking like successes - #230

Merged
kenforthewin merged 7 commits into
mainfrom
fix/gateway-padded-body-transport-errors
Aug 9, 2026
Merged

fix: two provider failures that arrive looking like successes#230
kenforthewin merged 7 commits into
mainfrom
fix/gateway-padded-body-transport-errors

Conversation

@kenforthewin

@kenforthewin kenforthewin commented Aug 9, 2026

Copy link
Copy Markdown
Owner

Two provider failures that reach us looking like successes, found from one bug report. Neither raises an error, neither is retried, and both end with work silently missing — an atom with no tags, a wiki article that never updated, duplicate tags that never merged.


1. A padded 200 is a truncated transfer, not a parse failure

The report: auto-tagging failing on google/gemma-4-26b-a4b-it with EOF while parsing a value at line 233 column 0, a blank body preview, and nothing at all in the user's OpenRouter dashboard.

What's on the wire

OpenRouter fronts slow upstreams with a Cloudflare Worker that must return a response object immediately, so it commits 200 OK + Transfer-Encoding: chunked before the upstream has produced anything, then keeps the connection alive with insignificant JSON whitespace:

t=0.320s   HTTP/1.1 200 OK   Transfer-Encoding: chunked   X-Generation-Id: gen-…
t=0.487s   16 bytes of whitespace
t=0.912s   16 bytes of whitespace        <- every ~425ms
   …
t=4.721s   the actual JSON, all at once

Whitespace works because RFC 8259 permits it before the top-level value — a compliant parser cannot see it. Once that status is committed it can't be retracted, so a late failure can only be an error object in the body or an ended stream. Ending it leaves a complete, well-formed 200 whose entire body is padding.

That's a transport failure wearing a parse error's clothes. We classified it permanent, so auto-tagging spent one attempt of a three-attempt budget and dropped the atom. The identical event cut a moment earlier arrives as Network and is retried — only the politely-terminated form was fatal.

Evidence

  • Padding on every non-streaming call observed (15/15), 6–112 newlines.
  • The JSON payload contains zero newlines, so every line in that serde error was padding. line 233 = 232 padding newlines.
  • Cadence 4.66 newlines/sec, stable from 4.5s calls to an 8-minute one ⇒ 232 newlines implies ~49.8s. The report's timestamps span 49.13s.
  • A real hang delivered 12288 bytes / 2235 newlines / no JSON over 8 minutes.
  • Not our 300s timeout: that would have cut at ~1400 newlines.

Why their dashboard was clean. Three deliberately abandoned calls came back finish_reason: stop, cancelled: false, fully billed. A generation record models the upstream generation, not delivery, so this failure class is invisible there and lands as a billable success. An absence of errors is a prediction of this diagnosis, not a contradiction. The failing body also carries no provider field, so the report's upstream_provider="DeepInfra" belongs to the previous, successful call — no upstream is implicated.

The fix

decode_error uses serde_json's Category::Eof as the line: input ran out (empty, all padding, or cut mid-JSON) ⇒ truncated transfer ⇒ retryable Network + Transient for schedulers. Syntax/Data mean bytes arrived and were wrong ⇒ still a permanent ParseError. Applied to both chat and both embedding paths, plus:

  • Both streaming parsers returned Ok with empty content when a stream carried no payload, persisting silence as if the model chose it. Guarded on "no SSE payload and no terminator", so a legitimately empty completion is untouched.
  • The chat path had no handling for a 200 carrying an error object — the gateway's other exit. choices is required, so it landed as a permanent parse failure. The embedding path's handling is now shared via upstream_error.
  • x-generation-id is captured into the error and log line. It arrives in the headers, so it survives the failures the body doesn't, and resolves via GET /api/v1/generation?id=… to provider, timings, finish reason and cost.
  • Previews are no longer logged raw — that's why the field was blank. Whitespace bodies are described (<2552 bytes of gateway padding, 232 newlines, no payload>), everything else escaped.
  • Tagging sent no max_tokens at all (with_params replaced the struct carrying the default). This changes routing — OpenRouter filters endpoints by max_completion_tokens, so an absent cap widens the pool and an oversized one empties it (pinned to DeepInfra: 32000 → 404 No endpoints found, 8192 → serves). call_structured now guarantees a cap; tagging sets 8192.

2. Generative structured calls come off wire-level schema enforcement

Chasing the first bug surfaced DeepInfra returning {"tags": []} for content every other endpoint tagged fine — 8 completion tokens, finish_reason: stop, zero reasoning tokens, no error signal anywhere.

It generalises by the shape of the call, not the endpoint. Where the model decides how much to emit and an empty result is legal, a constrained decoder can take the shortest grammar-valid path and return nothing. That parses, satisfies the schema, fires no fallback, and is indistinguishable from a considered "nothing to do".

Measurements

Pinned to DeepInfra, gemma-4-26b-a4b-it, 6 calls per cell, on inputs whose correct answer is unambiguously non-empty (planted duplicates, planted new source material):

call wire-level prompt-only
tag extraction 5/6 empty 0/6
tag merge 2/6 empty 0/6
wiki section ops 3/6 no-op 0/6
tag consolidation 0/6 0/6

Pinning matters: an unpinned run showed almost none of this, because OpenRouter routes around the weak endpoint most of the time. That's also why it reaches users as rare, unreproducible gaps rather than as a bug.

The trade is a decoding guarantee for the tolerant parser, and the parser was measured never to be exercised — across gpt-5-nano, gemma-4-26b-a4b-it, gpt-5-mini and glm-5.2, all 24 prompt-mode replies parsed directly, no fences, no surrounding prose.

The change

SchemaEnforcement makes the transport explicit — Strict and Lenient send response_format, PromptOnly sends none. with_strict remains shorthand over the two wire-level modes so it can't silently reach a different transport. One policy constant, GENERATIVE_CALL_ENFORCEMENT, covers all five generative call sites.

Consolidation never degraded and moves anyway: one rule beats four, prompt-only measured zero cost, and "didn't collapse on one input" isn't immunity. Closed-shape calls are explicitly out of scope — one enum choice, fixed-arity object — where there's no volume for a decoder to shorten and constrained decoding is free.

This also corrects a claim in call_long_form_markdown's docs that short structured calls "genuinely benefit from constrained decoding". True of shaping, not of generating.

The instruction had to be fixed first

Prompt-only originally stated the contract as "reply with a JSON object matching this schema" followed by the JSON Schema. A schema is itself JSON, so that has a literal reading and small models take it: llama3.2 returned the schema, answer nested under properties, in half of replies.

schema_instruction now leads with a concrete example derived from the schema — leaves replaced by <placeholder> text from each field's description, enums rendered as their alternatives — keeping the schema behind it for constraints an example can't express. Placeholders rather than invented values on purpose: invented values get copied, and for an enum whose first variant is the do-nothing case (wiki_update_section_ops) a "realistic" example would point straight at the degenerate answer.

llama3.2, no grammar, first-attempt valid:
  schema document only    3–4 of 8
  example only            8 of 8
  example + schema        8 of 8

This improves every caller, not just the ones that moved: the prompt-based fallback is where wire-level calls land when a primary parse fails.


Testing

  • 535 tests pass across 11 suites; workspace checks clean.
  • Clippy and rustfmt verified per file against main — zero new diffs. structured.rs carries 8 rustfmt diffs and wiki/mod.rs one clippy warning that both pre-date this branch; left alone rather than buried in the diff.
  • gateway_truncated_response_tests.rs — 5 tests built from captured wire bytes and real chunked framing, including the padding unit verbatim. Covers: padded body is transient; both framings agree; a payload-less stream fails instead of returning empty; a padded first attempt recovers on retry; every structured call sends a cap.
  • Unit tests pin that PromptOnly puts no response_format on the wire, states the shape before the schema, never names a single enum variant, and absorbs a fenced reply without spending the fallback.
  • Live end-to-end across all three provider families: gemma-4-26b-a4b-it and gpt-5-nano via OpenRouter, llama3.2 via native Ollama (8/8 first-attempt valid), and the OpenAI-compatible provider against Ollama's /v1 surface (6/6, no empty extractions).

One test-side consequence worth knowing: MockAiServer routed by wire schema name, so removing response_format made 8 tests fall through to {}. It now sniffs the schema stated in the prompt, with consolidation checked before extraction since both carry parent_name.

Not addressed

  • The 300s client timeout is untouched — nothing in the evidence implicates it.
  • What tipped that specific request over is unknown and not determinable from the log, which is exactly what capturing the generation id fixes for next time.
  • An empty extraction still records tagging_status = complete, so if a provider does return nothing the atom is silently untagged and never retried. Change 2 removes the cause we measured, not the blind spot. Worth a follow-up that records empties distinctly — tagging_status is plain TEXT with no CHECK constraint, so no migration needed.

🤖 Generated with Claude Code

kenforthewin and others added 2 commits August 9, 2026 12:33
A gateway fronting a slow upstream commits `200 OK` before the work is
done, then holds the connection open with insignificant JSON whitespace
(OpenRouter writes a newline-and-spaces heartbeat every ~425ms, legal
because RFC 8259 allows whitespace before the top-level value). Once the
status is committed it cannot be retracted, so a late failure can only
be an error body or an ended stream. When the stream ends, the client
gets a complete, well-formed 200 whose entire body is padding.

We classified that as a permanent ParseError. Auto-tagging therefore
spent one attempt of a three-attempt budget and dropped the atom — on a
fault a retry fixes, and one OpenRouter records as a success and bills
for. The identical event cut a moment earlier arrived as Network and was
retried; only the politely-terminated form was fatal.

serde_json draws the line: Category::Eof means the input ran out (empty,
all padding, or cut mid-JSON) and is always a truncated transfer, while
Syntax/Data mean bytes arrived and were wrong. `decode_error` applies it
across both chat and both embedding paths.

Also fixed, same class:

- Both streaming parsers returned Ok with empty content when the stream
  carried no payload at all, persisting the silence as if the model had
  chosen it. Guarded on "no SSE payload and no terminator" so a
  legitimately empty completion is untouched.
- The chat path had no handling for a 200 carrying an error object — the
  gateway's other exit. `choices` is required, so it landed as a
  permanent parse failure. The embedding path's handling is now shared
  via `upstream_error` in openrouter/mod.rs.
- `x-generation-id` arrives in the headers, before the body, so it
  survives exactly the failures the body doesn't. Captured into the
  error and log line; it resolves to provider, timings, finish reason
  and cost via GET /api/v1/generation.
- Response previews were logged raw, so a padded body printed as a blank
  field — the diagnostic went dark precisely when the body mattered.
  `body_for_log` describes whitespace bodies and escapes everything else.
- Tagging sent no max_tokens at all: StructuredCall::new sets a default
  and with_params replaced the struct wholesale. That changes routing —
  OpenRouter filters endpoints by max_completion_tokens. call_structured
  now guarantees a cap, and tagging sets 8192 explicitly (32k prunes
  real endpoints from the pool; 8192 clears the worst observed
  generation, 3091 tokens, with room to spare).

Verified against live OpenRouter traffic on google/gemma-4-26b-a4b-it:
padding is present on every non-streaming call, the JSON payload has
zero newlines (so `line 233` in the report was 232 padding newlines),
and the measured 4.66 newlines/sec cadence independently reproduces the
report's 49.13s gap. Regression tests are built from those captured
bytes and the real chunked framing.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
`response_format` puts the endpoint's constrained-decoding implementation
in the path, and implementations vary. Measured on
`google/gemma-4-26b-a4b-it` via OpenRouter, DeepInfra's schema-enforced
endpoint returned a valid-but-empty `{"tags": []}` on roughly one call in
three — 8 completion tokens, finish_reason stop, zero reasoning tokens,
no error signal anywhere — and schema-mode tag counts swung 5 to 13 on
identical input. The decoder took the shortest grammar-valid path instead
of doing the task.

Empty-but-valid is the worst failure shape available. It parses, so
`call_structured`'s prompt-based fallback never fires, and it reaches the
pipeline looking like an answer: the atom is recorded tagged with
nothing, `tagging_status = complete`, and never reconsidered.

Tag extraction is generative — the model decides how many tags to emit —
so a decoder that shortens the output changes the answer, not just its
shape. Schema now goes in the prompt for that call, parsed tolerantly.

The trade is a decoding guarantee for the tolerant parser, and the parser
was measured never to be exercised: across openai/gpt-5-nano,
google/gemma-4-26b-a4b-it, openai/gpt-5-mini and z-ai/glm-5.2, all 24
prompt-mode replies parsed directly — no fences, no surrounding prose.
Prompt mode also matched or beat schema mode on tag count for three of
the four models and was consistently less erratic.

`SchemaEnforcement` makes the choice explicit rather than implied by a
bool: Strict and Lenient both send `response_format`, PromptOnly sends
none. `with_strict` remains as shorthand over the two wire-level modes,
so it can never silently reach a different transport. Only tag extraction
moves; tag consolidation stays on constrained decoding because the
degradation was not measured for its prompt and output shape.

This also corrects the claim in `call_long_form_markdown`'s docs that
short structured calls "genuinely benefit from constrained decoding" —
true of shaping, not of generating.

The mock AI server routes schema-less requests by sniffing the schema
stated in the prompt; extraction and consolidation both carry
`parent_name`, so consolidation is tested first.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@kenforthewin kenforthewin changed the title fix: a padded 200 is a truncated transfer, not a parse failure fix: two provider failures that arrive looking like successes Aug 9, 2026
kenforthewin and others added 5 commits August 9, 2026 13:53
The previous commit took tag extraction off wire-level structured output
globally. That was right for OpenRouter and wrong for Ollama, which sends
the schema as a llama.cpp grammar to models small enough that
instruction-following is the weaker link.

Measured, same content and task:

  OpenRouter (gemma-4-26b-a4b-it -> DeepInfra)
    schema on the wire   {"tags": []} on ~1 call in 3; counts swing 5-13
    schema in the prompt 7-8 tags, 8 of 8

  Ollama (llama3.2, 3B, local)
    schema as grammar    2 tags, 6 of 6
    schema in the prompt EMPTY on 3 of 6

The dependence runs in opposite directions, so a single constant regresses
one deployment whichever value it takes. What actually differs is whether
the decoder is knowable: OpenRouter routes to whichever endpoint it likes,
we cannot see or test that implementation, and it changes without notice —
so the schema guarantee is a dependency on the worst decoder in the pool.
Ollama is one local implementation we can characterize, carrying a model
that needs the help.

OpenAI-compatible servers keep the wire-level default: unmeasured, so the
status quo rather than a guess.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The measurement behind the previous commit was wrong. It reported prompt
mode "empty on 3 of 6" for llama3.2; the harness only read obj["tags"] and
scored anything else as zero. The model was not returning nothing — it was
echoing the *schema*, nesting real tags under `properties`:

  {"type":"object","properties":{"tags":[{"name":"Machine Learning",...}]},
   "required":["tags"],"additionalProperties":false}

That shape deserializes as neither variant of ExtractionResult, so the real
pipeline rejects it, the prompt-based fallback re-asks, and the retry
succeeds — 6 of 6 end to end. A loud, recoverable failure, not a silent
empty one.

So the split stands but for a different reason. Both transports are correct
on Ollama; the grammar merely avoids a fallback round-trip on about half of
calls. Only the OpenRouter arm is load-bearing, because only there does the
failure arrive looking like an answer.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The prompt-level contract was stated as "reply with a JSON object matching
this schema", followed by the JSON Schema document. That is ambiguous
input: a schema is itself JSON, so "match this" has a literal reading, and
small models take it. On llama3.2, 4-5 replies in 8 came back as the
*schema*, with the extracted tags nested under `properties`.

`schema_instruction` now leads with a concrete example of the output shape,
derived from the schema — leaves replaced by <placeholder> text drawn from
each field's description, enums rendered as their alternatives — and keeps
the schema behind it for the constraints an example cannot express.
Placeholders rather than invented values on purpose: invented values get
copied, and for an enum whose first variant is the do-nothing case
(wiki_update_section_ops) a "realistic" example would point the model
straight at the degenerate answer.

Measured on llama3.2, no grammar, first-attempt valid replies:

  schema document only    3-4 of 8
  example only            8 of 8
  example + schema        8 of 8

and 8 of 8 through the real pipeline with the shipped instruction.

That removes the last basis for the provider split. It had been justified
first by a bad measurement (prompt mode "emptying" extractions — actually
the schema echo above), then by the fallback round-trip that echo caused.
With the round-trip gone, both transports are equivalent on Ollama and only
one is correct on OpenRouter, so tagging uses one transport everywhere.

The instruction change also improves every wire-level caller: the
prompt-based fallback is where they land when a primary parse fails.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Re-ran the pinned comparison with the example-led instruction. The collapse
is not specific to tag extraction — it follows the shape of the call.
Pinned to DeepInfra, gemma-4-26b-a4b-it, 6 calls per cell, on inputs whose
correct answer is unambiguously non-empty:

                    wire-level      prompt-only
  tag extraction    5/6 empty       0/6
  tag merge         2/6 empty       0/6
  wiki section ops  3/6 no-op       0/6
  tag consolidation 0/6             0/6

An earlier unpinned run showed none of this: OpenRouter routes around the
weak endpoint most of the time, which is also why it reaches users as rare,
unreproducible gaps rather than as a bug.

The common shape is a generative call whose empty result is legal, so a
decoder taking the shortest grammar-valid path returns "nothing to do" and
the work is silently skipped — no merges, no wiki update, no tags.
Consolidation never degraded and moves anyway: one rule beats four, and
prompt-only measured zero degenerate results and zero replies needing even
fence-stripping across 24 calls.

The policy now lives in one place (GENERATIVE_CALL_ENFORCEMENT) rather than
being restated per call site.

Also trims the comments added across this branch. The measurements belong in
the PR; the code needs to say what the decision is and what it prevents.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Taking the generative calls off wire-level enforcement removed the field
three harnesses used to identify a request. Each one silently stopped
recognising the call rather than failing at the point of the change:

- The shared mock routed by `response_format.json_schema.name`. Extraction
  and consolidation already had prompt-sniffing arms; merge did not, so
  `get_merge_suggestions` got `{}` and the atomic-server compaction e2e
  failed with "compaction must succeed".
- `section_ops_system_prompts` in the wiki e2e filtered on the same field
  and matched nothing, so an assertion about issuing one section-ops call
  saw zero.
- atomic-bench's mock had the same assumption and would have benchmarked
  against an empty response.

All three now fall back to the schema stated in the prompt, using the same
markers: `after_heading` for section ops, `winner_name` for merge,
`tags_to_remove` before `parent_name` so consolidation is not claimed by
the extraction arm. Each marker appears in exactly one schema.

Found by CI, which runs atomic-server; the earlier local runs were scoped
to atomic-core.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@kenforthewin
kenforthewin merged commit f7a988d into main Aug 9, 2026
4 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant