Skip to content

fix(cf-workers): log the request-body pipe's rejection instead of dropping it - #135

Draft
alukach wants to merge 1 commit into
mainfrom
fix/capture-body-pipe-rejection
Draft

fix(cf-workers): log the request-body pipe's rejection instead of dropping it#135
alukach wants to merge 1 commit into
mainfrom
fix/capture-body-pipe-rejection

Conversation

@alukach

@alukach alukach commented Jul 28, 2026

Copy link
Copy Markdown
Member

What I'm changing

WorkerBackend::forward pipes a streamed PUT body into a FixedLengthStream and discards the pipe_to promise. The comment justified it: a pipe failure also errors readable, so the awaited outbound fetch would surface the error.

It does not. Chasing a persistent ~0.1% failure rate on PutObject/UploadPart in a downstream proxy, the observed sequence is:

  1. the pipe fails early — within ~80–140 ms, a few hundred KB into a multi-MB body;
  2. the origin receives a truncated request and closes without sending any HTTP response;
  3. the runtime turns that into a Cloudflare-minted error code: 520server: cloudflare, a subrequest cf-ray, text/plain, 16 bytes, no origin request id and no error document;
  4. GatewayResponse::Forward relays that status faithfully, so the caller gets a 520 whose body no AWS SDK can deserialize.

Every trace of why the pipe failed is gone, because the only object that carried it was dropped on the floor. That is the gap this closes. It does not fix the failure — it makes the failure legible.

Confirmed from production logs across two independent invocations (4.9 MB PutObject and 16 MiB UploadPart), both showing the identical Cloudflare-origin signature with zero x-amz-* headers.

How I did it

  • crates/cf-workers/src/backend.rs — new log_pipe_rejection(pipe, declared_len). Observes the pipe_to promise on wasm_bindgen_futures::spawn_local and logs the rejection at WARN with the declared Content-Length. Spawned rather than awaited: forward must still return as soon as the outbound response headers arrive, and the pipe is driven by that fetch's backpressure. The task only observes a promise — it issues no I/O and does not extend the request's lifetime.
  • Replaced let _ = stream.pipe_to(...) with the call, and rewrote the comment: the old one asserted behaviour that production contradicts, which is worse than no comment.
  • The doc comment names the causes that are indistinguishable downstream but distinct here: inbound body short of or past the declared Content-Length (either errors the FixedLengthStream), the inbound stream erroring, or the outbound fetch cancelling readable.
  • Cargo.lock — was stale on main at the workspace's previous version; the pre-commit clippy hook regenerates it on every run, so it is included rather than fought.

Diagnostic only. No behaviour change, and the None (aws-chunked) branch is untouched — it has no pipe to observe.

Test plan

  • cargo fmt --check
  • cargo clippy --fix -p multistore-cf-workers --target wasm32-unknown-unknown
  • cargo check
  • cargo check -p multistore-cf-workers --target wasm32-unknown-unknown
  • pre-commit hooks (fmt, clippy --fix, check, check-wasm) all pass

No test accompanies this. The crate has no wasm test harness — the only cfg(test) module is a host-side one in cors.rs — and the behaviour needs a live ReadableStream under a real Workers runtime to exercise. Flagging that rather than papering over it: the repo convention is a failing test first, and I could not write one that would actually fail.

Follow-up

Once the rejection reason is visible, the real fix follows. If the pipe is failing on a length mismatch, the outbound request should fail with a proper ProxyError rather than letting a truncated body reach the origin and turn into an opaque 520.

…pping it

`forward` piped the inbound body into a FixedLengthStream and discarded the
`pipe_to` promise, on the reasoning that a pipe failure also errors `readable`
so the awaited outbound fetch would surface it.

Production says otherwise. When the pipe fails the origin sees a truncated
request and closes without replying; the runtime turns that into a
Cloudflare-minted `error code: 520` -- a 16-byte text/plain body with no origin
request id and no error document. The proxy relays that status faithfully, so
the caller gets a 520 that no AWS SDK can deserialize, and the reason the pipe
failed is gone.

Observe the promise on a spawned task and log the rejection. The distinct
causes -- inbound body short of or past the declared Content-Length (either
errors the FixedLengthStream), the inbound stream erroring, the outbound fetch
cancelling `readable` -- are indistinguishable downstream but named here.

Diagnostic only: no behaviour change, and `forward` still returns as soon as
the outbound response headers arrive.

Cargo.lock is included because it was stale on main at the workspace's previous
version; the pre-commit clippy hook regenerates it on every run.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@alukach
alukach deployed to preview July 28, 2026 23:08 — with GitHub Actions Active
@claude

claude Bot commented Jul 28, 2026

Copy link
Copy Markdown

Claude finished @alukach's task in 2m 39s —— View job


Review complete

  • Gather context (PR body, diff, custom instructions)
  • Read changed files
  • Correctness / security / best-practice review
  • Ponytail over-engineering pass
  • Post final review

✅ No blocking issues — safe to merge.

The change is diagnostic-only, matches the stated scope, and doesn't touch the None (aws-chunked) path. js_sys/wasm-bindgen-futures are already workspace deps and already used in this file, so nothing new is pulled in.

One non-blocking robustness note:

  • crates/cf-workers/src/backend.rs:76-87log_pipe_rejection fires the log from a bare spawn_local task with no ctx.waitUntil() (the entry point's Context in examples/cf-workers/src/lib.rs:56 is _ctx, unused). Cloudflare Workers can tear down a request's execution context once the response finishes streaming to the client if pending work isn't registered with waitUntil(). In the traced failure mode this is likely benign in practice — the pipe rejection appears to precede (or coincide with) the edge minting the 520 response that forward()'s .send().await resolves with, so the spawned task's microtask probably completes before forward() even returns. But it's not guaranteed by anything in this diff, and losing the log in the exact scenario it exists to capture would be a silent failure. Worth a follow-up (plumbing ExecutionContext through to WorkerBackend so this can ctx.waitUntil()) rather than blocking this PR on it, since it's strictly additive over the status quo (no log at all).

Simplify (ponytail)

Nothing to cut — single-purpose helper, no new dependency, no speculative abstraction. (Minor, not worth a line item: the rationale for why the pipe rejection matters is written out twice — once in log_pipe_rejection's doc comment and again in the call-site comment at backend.rs:131-143 — so a future edit to one story needs to remember the other.)


💰 Estimated review cost: $0.80 · 2m39s · 23 turns

@github-actions github-actions Bot added the fix label Jul 28, 2026
@github-actions

Copy link
Copy Markdown

🚀 Latest commit deployed to https://multistore-proxy-pr-135.development-seed.workers.dev

  • Date: 2026-07-28T23:08:50Z
  • Commit: a9cf07d

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