fix: retry 504 GatewayTimeout and resume truncated source reads - #144
Merged
Conversation
Hetzner terminates a response mid-body with a clean TCP FIN while still
advertising the full Content-Length, so aiohttp raises ClientPayloadError with
only part of the payload delivered. All 327 occurrences captured during a live
backup were clean closes (no ConnectionError suffix), i.e. the sender ended the
response deliberately -- not a network fault, not socket starvation (8MB
AES-GCM decrypt measured at 1.9ms), not the memory governor (zero
MEMORY_BACKPRESSURE/REJECTED events).
Measured at ~0.5% per read (2 of 400 in a sustained 16-way probe against the
same object), always ending on a page boundary. Only two values ever appeared:
190 x received 4165632 of 8388636 (1017 x 4096)
137 x received 8331264 of 8388636 (2034 x 4096)
Re-requesting the identical range reproduces the identical truncation (9 of 12
retried ranges cut at the same offset every attempt), so plain retry cannot make
progress -- ~12% of reads never recovered regardless of attempt count. At ~572
reads per 4.7GB copy a large file had a ~94% chance of hitting at least one,
which is why main.companies failed nearly every run while smaller tables passed.
Keep what arrived and request only the remainder: a fresh request gets a fresh
response buffer. Same vendor behaviour COPY_SOURCE_STREAM_RESUME already handles
on the upload side; the source-read path never got it.
Reading must accumulate in bounded chunks off the StreamingBody: read() collects
blocks in a local list and discards them all when the stream raises mid-body.
Note `async with resp["Body"]` unwraps to the raw ClientResponse, whose read()
takes no size argument, so the chunk loop stays outside that context.
Verified against the production object that fails: truncating at the observed
prod offset and resuming yields bytes SHA-256 identical to an untruncated read.
aiobotocore's StreamingBody.__aenter__ returns the *wrapped* aiohttp.ClientResponse, whose read() takes no size argument -- so `async with body: body.read(n)` is a TypeError in production. The mock returned `self`, which kept the size-aware read() available and let that exact bug pass the whole unit suite while failing against the real backend. Reintroducing the bug now fails 24 tests instead of 0.
273 of 288 fatal copy failures in the 2026-07-29 capture were HTTP 504
GatewayTimeout on UploadPartCopy; another 17 on PutObject and 7 on GetObject.
The segment loop in copy.py already retries via is_retryable_source_error, but
504/GatewayTimeout was absent from _RETRYABLE_S3_ERROR_CODES -- which had 500,
502 and 503 but not 504 -- so it hit `raise` on first occurrence. That is why
only 4 UPLOAD_PART_COPY_SEGMENT_RETRY events were logged against 297 x 504.
Reproduced against the real object: 572 UploadPartCopy calls at 8-way
concurrency yielded 1 x 504 (0.17%), latency p50 1.14s / p90 3.31s / max 61.86s.
Latency is heavy-tailed, so a 504 is transient congestion when Hetzner's own
server-side copy exceeds an internal deadline -- not a permanent condition.
botocore does retry 504 (its _retry.json has a gateway_timeout policy) but all
its attempts fire inside the same congestion window and exhaust ("reached max
retries: 3" x297). Retrying here with SOURCE_READ_BACKOFF_SEC exponential
backoff gives the backend time to clear. UploadPartCopy is idempotent for a
given PartNumber+range, so the retry is safe -- the same argument #133 used.
At 0.17% per copy a 4.7GB file (572 copies) has a ~63% chance of hitting a 504,
and 10 nodes doing this concurrently approaches certainty, which is why
main.companies failed on 10 of 13 racks while smaller tables passed.
Also fixes MockS3Response.__aenter__ fidelity: aiobotocore's StreamingBody
returns the wrapped ClientResponse (no size-aware read()), so the mock returning
`self` let an `async with body: body.read(n)` TypeError pass the whole suite
while failing in production. Reintroducing that bug now fails 24 tests.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Two independent backend failure modes taking down the Scylla
main.companiesbackup, plus a test-fidelity fix that let one of them hide.1. Unretried 504 GatewayTimeout (the dominant cause)
Census of the 288 fatal copy failures captured live during a failing run:
copy.pyalready retries viais_retryable_source_error, but_RETRYABLE_S3_ERROR_CODEScontained500,502,503— and not504. So a 504 hitraiseon first occurrence. The smoking gun is the ratio in the logs:Reproduced against the real object: 572
UploadPartCopycalls at 8-way concurrency → 1 x 504 (0.17%), latency p50 1.14s / p90 3.31s / max 61.86s. Latency is heavy-tailed, so a 504 is transient congestion when Hetzner's own server-side copy exceeds an internal deadline.At 0.17% per copy, a 4.7GB file (572 copies) has a ~63% chance of hitting one; 10 nodes concurrently approaches certainty. That's why
companiesfailed on 10 of 13 racks while smaller tables passed.botocore does retry 504 (its
_retry.jsonhas agateway_timeoutpolicy) but all attempts fire inside the same congestion window and exhaust —"reached max retries: 3"appears 297 times. Retrying here withSOURCE_READ_BACKOFF_SECexponential backoff gives the backend time to clear.UploadPartCopyis idempotent for a given PartNumber+range, so the retry is safe — the same argument #133 used.2. Truncated source reads
Hetzner ends a response mid-body with a clean TCP FIN while still advertising the full
Content-Length. All 327 captured occurrences were clean closes — none carried theconnection_closed_cleanly=Falsesuffixaiohttp/client_proto.py:147adds for connection errors.Ruled out by measurement: network fault (clean FIN, not a reset), crypto blocking the loop (8MB AES-GCM decrypt = 1.9ms), memory governor (zero backpressure/rejection events), HAProxy (not on this hop — direct HTTPS), pod/node specific (all 28 pods, ~25 nodes, amd64 + arm64).
Truncation lands on a page boundary, only two values ever:
Re-requesting the identical range reproduces the identical truncation — 9 of 12 retried ranges cut at the same offset every attempt. So retry cannot make progress; resume can, because a fresh request gets a fresh response buffer. Same vendor behaviour
COPY_SOURCE_STREAM_RESUMEalready handles on the upload side.Implementation notes:
StreamingBody.read()collects blocks in a local list and discards them all if the stream raises mid-body.async with resp["Body"]unwraps to the rawClientResponse, whoseread()takes no size argument, so the chunk loop must stay outside that context.3. Mock fidelity
That second note was a real bug I shipped and only caught in end-to-end testing — the shared
MockS3Response.__aenter__returnedself, keeping a size-awareread()that production does not have. It now returns a wrapper without it, matching aiobotocore.Reintroducing that bug now fails 24 tests instead of 0.
Verification
Resume, against the production object that fails — truncate at the observed prod offset, resume, compare:
Resume returns exactly the missing bytes, 4 real prod-failing ranges:
ruff check/format --checkScope
MULTIPART_ABORTED(292) and theInvalidPartseen on an earlier run are consequences, not separate causes — 261 of 292 aborts directly follow a fatal copy failure, and orphaned multiparts are what a later completion rejects. Removing the 504s should remove both.Residual risk: with 4 attempts and exponential backoff, per-copy failure probability drops to roughly 0.17%^4 — negligible if 504s are independent. Measurement showed one isolated 504 in 572 calls rather than a burst, but independence under 10-node concurrent load is not proven.
Test mocks in
test_source_read_retry.pyneededread(n)signatures; those tests' behaviour is unchanged (8 passed).