Repository navigation
Fix request timeouts: retries, body reads, and the flaky timeout test - #31
Conversation
The test set a 1ms timeout against a 2ms mock delay. A context is only marked expired when its timer callback runs, so on a busy machine gock's 2ms timer could fire first, the mock replied 200 and MakeRequest returned no error. Reproduced locally under CPU load (13 failures in 6,000 runs). Use a 10ms timeout and a 10s delay: gock stops waiting as soon as the context is done, so the test is no slower. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
There was a problem hiding this comment.
🟢 Approval recommended
It is a small, self-contained, empirically validated test-only change whose comment accurately matches the surrounding code and gock v1.1.2 behavior, with no production code affected.
No open issues 🎉
What changed in this PR
This PR fixes a flaky unit test, TestRequestRetryTimeout, in the cli package. The test verifies that a request which exceeds the configured rsh-timeout fails with a "timed out" error. Previously it pitted a 1ms request timeout against a 2ms gock response delay; because a context is only marked expired when its own timer callback runs, a busy CI machine could fire gock's 2ms timer first and return a 200 before the context expired, causing the "An error is expected but got nil" failure. The fix widens the gap between the two timers so the ordering can no longer flip.
Changes:
- Raise
rsh-timeoutfrom 1ms to 10ms and the gock responseDelayfrom 2ms to 10s, so the timeout reliably wins (gock stops waiting once the request context is done, so the long delay doesn't slow the test). - Replace a copy-pasted comment that described
TestRequestRetryIn's header with an accurate explanation of why the delay must greatly exceed the timeout.
| File | Description |
|---|---|
| cli/request_test.go | Adjusts timeout/delay values in TestRequestRetryTimeout to remove timer-ordering flakiness and updates the explanatory comment. |
Review effort: Balanced
doRequestWithRetry derived each attempt's rsh-timeout context from req.Context(), but req had already been replaced with the previous attempt's request, so a retry after a timeout started with an expired context and failed immediately. Timeouts were never really retried. It also deferred every cancel until the function returned, which is before the caller reads the body. With -t set, any body larger than the transport's buffer was cut off with "context canceled" (4MB came back as 3,963 bytes). And with --rsh-retry 0 it returned early and skipped the timeout altogether. Each attempt now derives its timeout from the request's original context. A discarded attempt is released immediately, and the returned response's timeout is released when its body is closed. The retry loop also runs with no retries, so the timeout always applies. As a side effect, -v now logs the request and response with --rsh-retry 0 too. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
There was a problem hiding this comment.
🔵 Needs a closer look
It changes context, cancellation, and body-streaming semantics in the core request path for every command, and such subtle concurrency/timeout lifecycle changes warrant final human review despite the added tests.
No open issues 🎉
Review effort: Balanced
Summary
This started as a fix for the flaky
TestRequestRetryTimeout. Investigating it turned up three bugs in howdoRequestWithRetry(cli/request.go) appliesrsh-timeout(-t), so this PR fixes those as well.The flaky test
The test set a 1ms timeout against a gock mock that waits 2ms before replying. A context is only marked expired when its own timer callback runs, and gock's delay is a separate timer, so on a busy machine gock's timer can fire first.
ctx.Err()is then still nil, gock returns the 200, andMakeRequestsucceeds.Reproduced locally by running the test binary with
-test.count=3000 -test.cpu 1,2alongside 8yes > /dev/nullprocesses: 13 failures in 6,000 runs, each a 200 on the first attempt after about 2ms. The test now uses a 10ms timeout and a 10s delay. gock stops waiting as soon as the request context is done, so the long delay costs nothing.Timeout bugs fixed
req.Context(), butreqhad already been replaced with the previous attempt's request, which carried the expired context. Each attempt now derives its timeout from the request's original context.-tcut off response bodies. Every attempt'scancelwas deferred untildoRequestWithRetryreturned, which is before the caller reads the body. Any body larger than the transport's buffer failed withcontext canceled: a 4MB response came back as 3,963 bytes. The returned response's body is now wrapped so its timeout is released when the body is closed. An attempt that is thrown away for a retry has its body closed and its timeout released straight away.--rsh-retry 0ignored-t. That path returnedclient.Do(req)before any timeout was applied. The retry loop now also runs when there are no retries, so the timeout always applies. The request body is still only buffered when a retry might need to resend it.Behaviour changes beyond the fixes:
-vnow logs the request and response when--rsh-retry 0is set. That path used to skip logging.The remaining comment on the test ("delay seems to have a bug where subsequent requests…are still delayed") was describing bug 1, not gock. I replaced it with the reason the mock has to reply twice.
Testing
TestRequestRetryTimeoutnow also checks that the retry reaches the server and that two full timeouts elapse (at least 20ms).TestRequestTimeoutWithoutRetries:-tapplies with--rsh-retry 0.TestRequestTimeoutAllowsReadingBody: a 4MB body can be read in full afterMakeRequestreturns, with a timeout set.request.go(11ms elapsed instead of 20ms; no error after waiting the full 10s delay;context canceledwhile reading the body) and pass with the fix.-test.cpu 1,2, with no failures.go test -race ./...passes.🤖 Generated with Claude Code