[BUG] Rewind the curl request body with a seek callback - #4557
Conversation
The curl client installs CURLOPT_READFUNCTION but no CURLOPT_SEEKFUNCTION. When libcurl restarts an upload it already began, which happens when a connection it reused is closed before the response arrives, it has no way to rewind the body and fails the transfer with CURLE_SEND_FAIL_REWIND. IsRetryable() then declines to retry, because it also requires last_curl_result_ == CURLE_OK, so the export batch is dropped. The request body is a fully buffered span owned by the caller, so an absolute seek inside it is a move of the read cursor. Other origins, a negative offset, or an offset past the end are refused with CURL_SEEKFUNC_CANTSEEK rather than approximated, so libcurl fails cleanly instead of resuming from the wrong place. Fixes open-telemetry#4549
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #4557 +/- ##
==========================================
- Coverage 86.42% 86.41% -0.00%
==========================================
Files 524 524
Lines 20421 20435 +14
==========================================
+ Hits 17646 17657 +11
- Misses 2775 2778 +3
🚀 New features to boost your workflow:
|
Thank you both for the cooperation on this issue. Please clarify which author or co author line we should use when merging this, so you get proper credits. |
|
Closing this so @meastp can own it. The report, the diagnosis and the reproducer are his, and he worked out that error 65 needs connection reuse rather than any premature close. The branch is at |
|
I'm most happy to get this fix in - if you can reopen this PR and perhaps set me as coauthor, that's ok, I don't mind. :) @mateenali66 |
Codecov flagged the callback body as uncovered, since no test invoked it. Expose it through HttpOperationTestPeer, following HttpClientTestPeer in the same header and ReservoirCellTestPeer in the metrics SDK, and cover the reposition, the in-range boundary at exactly the body size, a negative offset, an offset past the end, SEEK_CUR, SEEK_END and a null user pointer. The refused cases assert the read cursor is left where it was, so a future change cannot move it and then report that it could not seek. Co-authored-by: Mats Taraldsvik <1156416+meastp@users.noreply.github.com>
|
Reopened, thanks. Added you as co-author on the commit. @marcalff the lines are Also pushed a second commit with a unit test for the callback, after codecov flagged the body as uncovered. It exercises the reposition, the boundary at exactly the body size, a negative offset, an offset past the end, SEEK_CUR, SEEK_END and a null user pointer, through a test peer following |
|
Ran the reproducer against this branch. It fixes the rewind path, and the batch is not merely Built ( For the baseline I did not compare against All runs: 8 requests, 64 KB body, retry policy on at the OTLP defaults (5 attempts, 1s initial
Three things worth drawing out:
On the change itself, one thing I checked since the placement depends on it: |
|
Deleting only the registration is a better baseline than diffing against Agreed on the two registrations. They are only correct together, and what makes the current placement complete is that |
iwyu failed on three configs. The new seek test uses curl_off_t and CURL_SEEKFUNC_* outside the ENABLE_OTLP_RETRY_PREVIEW guard, where curl/curl.h was only included inside it, and it uses SEEK_SET with nothing providing it. Move curl/curl.h out of the guard and add cstdio, matching http_operation_curl.cc. Verified both arms build and pass, 28 tests with OTELCPP_WITH_OTLP_RETRY_PREVIEW=ON and 25 with it OFF.
One sentence was left dangling, and the same rationale was restated in three places. State it once on the declaration and let the tests say what they cover.
| // move of the read cursor. Anything else is refused rather than approximated, because reporting | ||
| // success without repositioning would resume the upload from the wrong offset and send a | ||
| // truncated or misaligned body. | ||
| if (origin != SEEK_SET || offset < 0 || static_cast<size_t>(offset) > self->request_body_.size()) |
There was a problem hiding this comment.
nit- Could we check the offset before casting to size_t? On 32-bit systems, a large offset can wrap to zero and incorrectly pass this check.
There was a problem hiding this comment.
The offset < 0 check runs before the cast, so negatives are covered, but an offset of 2^32 or more still wraps on 32-bit. Follow-up coming that compares in curl_off_t.
There was a problem hiding this comment.
Still the same shape on main at f77c1a5c, ext/src/http/client/curl/http_operation_curl.cc:350:
if (origin != SEEK_SET || offset < 0 || static_cast<size_t>(offset) > self->request_body_.size())I went looking for a case that reaches it and could not build one. The offset libcurl hands a seek callback comes from its own position in the upload, and the upload is the body this code gave it. On a build where size_t is 32 bits that body cannot be 4 GB to begin with, so the wrap needs an offset larger than any body the process can hold. If someone sees a path that produces one I would like to know, because I could not.
So it reads to me as the check having the wrong shape rather than a case waiting to happen, which is how the original note was phrased anyway. Comparing before narrowing costs nothing and removes the question:
if (origin != SEEK_SET || offset < 0 ||
offset > static_cast<curl_off_t>(self->request_body_.size()))@mateenali66 is the follow-up still on your list? No rush from me, and I am happy to send it instead if you would rather not carry it.
There was a problem hiding this comment.
Still mine, it's up at #4630. Same comparison you wrote.
Agreed on reachability, I couldn't build a case either. The offset comes from libcurl's own position in the upload, and a 32 bit process can't hold a body big enough to get past the size_t range.
The test case I added doesn't catch anything on a 64 bit build, both forms refuse it, so it's only pinning the contract.
| // Send a body large enough to span several read callbacks and check it arrives whole, so a mistake | ||
| // in either CURLOPT_READFUNCTION or the seek callback registered beside it shows up as a corrupted | ||
| // or short upload. | ||
| TEST_F(BasicCurlHttpTests, SendPostRequestWithMultiChunkBody) |
There was a problem hiding this comment.
Could we add the reproducer as a functional test in a follow-up? These tests still pass if the seek callback registration is removed, since neither exercises a rewind through libcurl.
There was a problem hiding this comment.
True, neither test reaches a rewind. @meastp offered to land his reproducer as a functional test. Mats, still want to? Otherwise I'll take it.
There was a problem hiding this comment.
@mateenali66 you go ahead, I became a bit busy after the bug report/PR :)
There was a problem hiding this comment.
Taking it, no problem.
Nothing in the suite makes libcurl call the seek callback during a real transfer, so the rewind path is still uncovered. Yours got there through connection reuse, which a unit test on the callback can't reach.
The question is whether the test server can close a reused connection mid body. If it can, this lands as a functional test. If not, it isn't worth faking. Separate PR either way, the offset one is #4630.
There was a problem hiding this comment.
Measured the server side, and it splits the question in two.
A handler cannot close mid body. It runs once the connection reaches Processing, which only happens after ReceivingBody has finished, so the body is already in by the time the handler is called. What a handler does have is return -1, which processRequest turns into RequestOutcome::CloseConnection and applies after the request. There is no per-connection close from outside a handler either.
The part I did not expect is that this may not be the blocker. HttpOperation::PerformCurlMessage rewinds the body itself when it retries:
// Rewind request data so that read callback can re-transfer the payload
request_nwrite_ = 0;That sits inside the is_retryable branch. request_nwrite_ is repositioned in exactly two places, that one and SeekCallback, on separate paths; the read callback only advances it with +=. So the transport's own retry does not go through the seek callback. I measured that rather than leaving it as a reading: a counter at the rewind and a counter in SeekCallback, then RetryPolicyEnabled, which POSTs to /retry/ and gets a 429.
PROBE-RETRY rewinds observed: 1
PROBE-SEEK calls observed: 0
The retry demonstrably happened and the callback took no part in it, which matches what @lalitb found by removing the registration: a test that makes the transport retry does not reach it either.
What would reach it is a rewind libcurl decides on by itself. I tried three shapes against a socket server, with the option set the client uses, POSTFIELDS null plus READFUNCTION and SEEKFUNCTION: a pooled keep-alive connection dropped between requests, a connection dropped part way through the body, and a 401 Digest challenge. None called the callback.
I would not lean on all three equally. Checking my own probes afterwards, the first reset the read cursor by hand and so did libcurl's job for it, and the 401 one handed over exactly one body's worth of bytes, meaning it never replayed. The control is sound: CURLOPT_RESUME_FROM_LARGE on an upload calls the callback once and the cursor lands at the offset, so the wiring is right and the zeros are not a broken probe.
Untested from here: a 307 redirect under FOLLOWLOCATION, Expect: 100-continue negotiation, and NTLM or Negotiate auth.
So before building the functional test it may be worth settling whether the callback is reachable at all in this configuration. If only libcurl-internal rewinds use it, the test has to provoke one of those, and nothing the embedded server does will get there.
Edited twice. I first wrote that the member has two assignments, which is wrong if you count the += in the read callback: two repositions, three mutations. And the claim about the retry not reaching the callback started as a reading of the code, so I went and measured it.
Fixes #4549
Changes
The curl client sets
CURLOPT_READFUNCTIONbut neverCURLOPT_SEEKFUNCTION. When libcurl restarts an upload it has already begun, it asks the application to rewind the body, and with no seek callback it cannot, so the transfer ends inCURLE_SEND_FAIL_REWIND(65).IsRetryable()requireslast_curl_result_ == CURLE_OK(http_operation_curl.cc:602), so the operation falls through toCleanup()at:1631-1635and the export batch is gone.This registers a seek callback next to
CURLOPT_READDATAin the POST branch, which is the only branch that installs a read callback.request_body_is aconst Body &(http_operation_curl.h:338) andReadMemoryCallbackcopies out of it while advancingrequest_nwrite_(:321-334), so the body is fully buffered and an absolute seek is a move of the read cursor. Other origins, a negative offset, or an offset past the end returnCURL_SEEKFUNC_CANTSEEKrather than being approximated, so libcurl fails cleanly instead of resuming from the wrong place and sending a truncated body.This is the first of the two fixes the issue describes. The
IsRetryable()gate is deliberately not touched here, because widening the set ofCURLcodes that may be replayed on a non-idempotent POST is a policy decision that deserves its own thread.Testing
SendPostRequestWithMultiChunkBodysends a 263,175 byte body, not a round number so an off-by-one in the read cursor cannot land on a chunk boundary, and asserts the server received it byte for byte. It guards the read and seek registration: with a one byte corruption injected intoReadMemoryCallbackthe test fails, without it the suite is 27 of 27 green.It does not exercise the rewind path itself, and I would rather say so than imply otherwise. Reaching that path needs a peer that accepts one request on a connection and then half closes the reused connection on the next, which the in-tree test server cannot do, and
CURLOPT_FOLLOWLOCATIONis never set so a redirect cannot be used to force a rewind either.@meastp built a deterministic reproducer for exactly this and measured error 65 at 3 of 8 requests with connection reuse and 0 of 8 without, against an unmodified library. He has offered to run it against this branch and to contribute it as a functional test. That seems the better home for it than this PR.
CHANGELOG.mdupdated for non-trivial changesSetup())