Skip to content

feat(cf-workers): log the streamed PUT body pipe's rejection - #141

Draft
alukach wants to merge 1 commit into
fix/size-aws-chunked-streamed-putfrom
diag/log-streamed-put-pipe-rejection
Draft

feat(cf-workers): log the streamed PUT body pipe's rejection#141
alukach wants to merge 1 commit into
fix/size-aws-chunked-streamed-putfrom
diag/log-streamed-put-pipe-rejection

Conversation

@alukach

@alukach alukach commented Aug 31, 2026

Copy link
Copy Markdown
Member

Stacked on #140 — base that branch, not main. See below for why it cannot usefully stand alone.

Diagnostic for source-cooperative/data.source.coop#206. This changes no behaviour; it exists to discriminate between two competing explanations that current logging cannot separate.

What I'm changing

WorkerBackend::forward dropped the promise returned by stream.pipe_to(&transform.writable()). The existing reasoning is sound as far as it goes — a pipe failure also errors readable, so the awaited outbound fetch fails regardless. But the fetch only reports that it failed, never why the body stopped, and that is exactly the missing bit.

Production evidence on data.source.coop: ~0.6% of streamed PUTs die as a Cloudflare-minted 520 on the worker's egress leg, with S3 never answering. The rate is Poisson (CV of inter-failure gaps = 0.99) and independent of body size (failed p50 6.56 MB vs succeeded 6.76 MB), which makes it a per-request race rather than a protocol defect — a structural defect would fail ~100% of the time, not 0.6%.

The two candidate races sit on opposite sides of this promise:

observation conclusion
pipe rejects on a failing request body-side failure — the inbound stream broke, and #140 is irrelevant to this bug
pipe stays healthy, fetch still returns 520 connection-side failure — supports #140's replayability argument

Right now we cannot tell which, so we cannot tell whether #140 is a fix or a no-op.

Why this is stacked on #140 rather than independent

On main the pipe exists only in the Some(len) (FixedLengthStream) branch. fixed_body_length() returns None for aws-chunked, so those requests take init.set_body(stream) and never touch the pipe at all — and every failure in the 4,059-PUT production sample was aws-chunked.

So on main this handler instruments a path the dominant failure mode never takes, and would log nothing. #140 is what routes aws-chunked through the transform, which is what makes this promise observable for the requests that actually fail. Landing this on its own would produce silence and be misread as evidence.

A useful corollary: it also means the dropped pipe cannot be the cause of the aws-chunked 520s as they occur on main today — there is no pipe on that path. The pipe-race theory only ever applied to the plain-Content-Length shape.

How I did it

  • crates/cf-workers/src/backend.rs — bind the pipe promise, clone request.request_id for correlation, and spawn_local a task that logs a warn with the JsValue error if it rejects. The pipe is deliberately still not awaited inline: nothing drains readable until the fetch below runs, so awaiting it there would deadlock. Only the rejection is captured, so backpressure and streaming are unchanged.
  • Replaces the comment justifying the dropped promise with one explaining what the captured rejection distinguishes.

Side effect worth expecting: the unattributed TypeError: Can't read from request stream after responding with an exception already visible in Workers logs should now arrive as an attributed streamed PUT body pipe failed line carrying a request_id, instead of a bare unhandled rejection.

Test plan

  • cargo check -p multistore-cf-workers --target wasm32-unknown-unknown
  • cargo fmt, cargo clippy --all-targets, cargo check
  • No unit test: the behaviour is a runtime promise rejection in the Workers runtime, which the host-target test suite cannot exercise (crates/cf-workers is not in the workspace default-members). Verification is reading production logs after deploy.

How to read the result once deployed: filter Workers logs for streamed PUT body pipe failed and join to the existing server error response line on request_id. A 520 with a matching pipe rejection is body-side; a 520 with none is connection-side.

🤖 Generated with Claude Code

https://claude.ai/code/session_01B3x2KzUtojpwPvDKmSgvht

`WorkerBackend::forward` dropped the promise from
`stream.pipe_to(&transform.writable())`. The reasoning held — a pipe failure
also errors `readable`, so the awaited outbound fetch fails anyway — but the
fetch only reports *that* it failed, never why the body stopped, which leaves
no way to tell a body-side failure from a connection-side one.

That distinction is what the intermittent 520s on streamed PUTs turn on
(source-cooperative/data.source.coop#206): the failures are Poisson and
size-independent, so they are a per-request race, and the two candidate races
sit on opposite sides of this promise. If the pipe rejects on a failing
request the body is at fault; if it stays healthy while the fetch still
returns 520, the connection is.

The pipe is still not awaited inline — that would deadlock, since nothing
drains `readable` until the fetch runs. Only the rejection is captured, so
backpressure and streaming behaviour are unchanged.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01B3x2KzUtojpwPvDKmSgvht
@claude

claude Bot commented Aug 31, 2026

Copy link
Copy Markdown

Claude finished @alukach's task in 1m 41s —— View job


Review

  • Gather context (diff, CLAUDE.md)
  • Review diff for correctness/security/best-practice issues
  • Apply ponytail-review pass for over-engineering
  • Post final findings

✅ No blocking issues — safe to merge.

crates/cf-workers/src/backend.rs:107-121 — binds the previously-dropped pipe_to promise, clones request.request_id (needed since request is still used later via request.url/request.method, so it can't be borrowed into the 'static task), and logs the rejection via tracing::warn! in a spawn_local task. Notes:

  • The spawn_local pattern matches the one already used in fetch_connector.rs (both for sending requests and draining response bodies), so this isn't introducing a new concurrency idiom to the crate.
  • tracing and wasm-bindgen-futures are both already crate dependencies; no new imports needed beyond what's used.
  • The comment correctly explains why the promise still isn't awaited inline (nothing drains readable until the fetch runs, so an inline await would deadlock) — this is the right call and matches the existing backpressure-preserving design.
  • Attaching a handler to the promise also fixes the unattributed unhandled-rejection console noise mentioned in the PR description, as a side benefit of the diagnostic.
  • Minor (non-blocking) note: since there's no ctx.waitUntil() anywhere in this crate, the spawned log task's completion isn't formally guaranteed before the Workers runtime could tear down the execution context after the outer response promise resolves. In practice the pipe rejection causally precedes (and is a fast single-microtask hop before) the readable-driven fetch failure that the rest of forward() awaits through several more ticks, so the log should reliably land — but this is worth keeping in mind if the diagnostic logs turn out to be intermittently missing after deploy.

Simplify (ponytail)

Nothing to flag — the diff reuses the existing spawn_local/tracing conventions already present in this crate and is about as small as this diagnostic can be.


💰 Estimated review cost: $0.38 · 1m41s · 18 turns

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant