chunked POST via callback regression in 8.7.X #13229
Comments
|
@icing it feels like a topic for you! |
|
I wrote up debugit.c in an attempt to reproduce, but I fail. |
|
@peff: as the difference between the working and the non-working command lines seems to be |
|
This bug report in Arch Linux might describe the same bug: https://gitlab.archlinux.org/archlinux/packaging/packages/curl/-/issues/6 |
|
I've played a bit around with that and it seems like for some repos it works and for others it does not:
I'm scratching my head now a bit whats the difference between the two as everything else stays the same. I can also confirm that the 8.6 release works as intended. |
That looks like curl gets a HTTP response code 400 back. It smells like a different issue and probably even in the server side. |
I have bisected the issue and landed on the same commit: Click to see bisect log |
|
@bagder I tried a very similar reproduction recipe, but couldn't convince it to fail. I'm not quite sure what Git is doing differently. Your question about |
|
@christian-heusel I think you're seeing the same problem. Whether you see the The root of the issue is that the But the root cause is the same: the client's POST was invalid, because curl didn't keep invoking our As for why the failure is seen with one repo or not the other: it is related to the size of the remote repository. It looks like you aren't setting But for a clone, we'll also follow that up by asking for all of the ref tips in another If you increase the buffer size (causing Git to buffer the whole request itself and then hand it to curl as a single pointer via |
|
@peff in the case where it stops after those first 14 bytes: can you check what happens in the next invocation of the callback? (since those 14 bytes are what is sent after the callback returns after the first invoke) If the next one returns a zero, then that would explain the issue - but something tells me that is not what is going on... |
|
@bagder Nope, we are only invoked once. If I instrument Git like this: diff --git a/remote-curl.c b/remote-curl.c
index 1161dc7fed..3aaf0c96cc 100644
--- a/remote-curl.c
+++ b/remote-curl.c
@@ -682,6 +682,8 @@ static size_t rpc_out(void *ptr, size_t eltsize,
size_t avail = rpc->len - rpc->pos;
enum packet_read_status status;
+ warning("in read func: %d bytes allowed by curl, we have %d ready",
+ (int)max, (int)avail);
if (!avail) {
rpc->initial_buffer = 0;
rpc->len = 0;
@@ -720,6 +722,7 @@ static size_t rpc_out(void *ptr, size_t eltsize,
avail = max;
memcpy(ptr, rpc->buf + rpc->pos, avail);
rpc->pos += avail;
+ warning("passed curl %d bytes", (int)avail);
return avail;
}
I get: It is interesting that curl is only offering us 4 bytes of space to write. This could be because a previous request sent only 4 bytes (in this case it is because before streaming, Git sends a "probe" request of just 4 bytes to make sure the endpoint works at all). And indeed, if I comment out that probe (in It's also possible that Git isn't correctly re-setting the handle between the requests, but we do reset POSTFIELDS and POSTFIELDSIZE to NULL/0. |
|
Interestingly, adding this seem to make it work, at least for kernel.org: diff --git a/remote-curl.c b/remote-curl.c
index 1161dc7fed..8f514e235c 100644
--- a/remote-curl.c
+++ b/remote-curl.c
@@ -962,6 +962,7 @@ static int post_rpc(struct rpc_state *rpc, int stateless_connect, int flush_rece
*/
headers = curl_slist_append(headers, "Transfer-Encoding: chunked");
rpc->initial_buffer = 1;
+ curl_easy_setopt(slot->curl, CURLOPT_POSTFIELDSIZE, -1L);
curl_easy_setopt(slot->curl, CURLOPT_READFUNCTION, rpc_out);
curl_easy_setopt(slot->curl, CURLOPT_INFILE, rpc);
curl_easy_setopt(slot->curl, CURLOPT_SEEKFUNCTION, rpc_seek);But it wasn't necessary with older curl. Should we have been setting that all along? Or is curl internally failing to treat a zero size along with a NULL Curiously it doesn't seem to fix the problem when hitting GitHub. It looks like maybe we are not sending the chunked encoding header then? So maybe one is not supposed to pass "-1" for that field. |
No, it should not be necessary. -1 is the presumed value/default if not set. This is a regression. |
|
I need to confer with @icing and decide on a way forward. I think he might be having an Easter time-off like we all should have! 😁 |
|
Here is an updated debugit.c that I believe reproduces the issue in the same style git does it: first a short POST then one using the read callback, but the callback post does not (if this example source is modified) reset the postfieldsize and then sends an aborted chunked stream. |
I agree. Just trying to understand how we manage that and where the regression came in:
There is no call to |
|
Please see #13257 for the fix on this. I verified with a git master checkout. Please report back if this works for you as well. |
|
As for the |
|
@icing Thanks, your patch seems to fix my stand-alone reproduction, and it makes my Curiously, though, trying the same thing against GitHub continues to fail. E.g.: The big difference there is that it is using HTTP/2. Looking at verbose output, it seems that in 8.6.0, we'd stream the input directly. But in 8.7.1 + your fix, we send chunked transfer-encoding. Here's a diff of two traces (preimage is 8.6.0, postimage is your PR): => Send header, 0000000260 bytes (0x00000104)
=> Send header: POST /git/git/git-upload-pack HTTP/2
=> Send header: Host: github.com
=> Send header: User-Agent: git/2.44.0.413.gd6fd04375f.dirty
=> Send header: Accept-Encoding: deflate, gzip
=> Send header: Content-Type: application/x-git-upload-pack-request
=> Send header: Accept: application/x-git-upload-pack-result
=> Send header: Git-Protocol: version=2
=> Send header:
-=> Send data, 0000000020 bytes (0x00000014)
-=> Send data: 0014command=ls-refs.
-=> Send data, 0000000042 bytes (0x0000002a)
-=> Send data: 002aagent=git/2.44.0.413.gd6fd04375f.dirty
-=> Send data, 0000000022 bytes (0x00000016)
-=> Send data: 0016object-format=sha1
-=> Send data, 0000000004 bytes (0x00000004)
-=> Send data: 0001
+=> Send data, 0000000026 bytes (0x0000001a)
+=> Send data: 14..0014command=ls-refs...
+=> Send data, 0000000048 bytes (0x00000030)
+=> Send data: 2a..002aagent=git/2.44.0.413.gd6fd04375f.dirty..
+=> Send data, 0000000028 bytes (0x0000001c)
+=> Send data: 16..0016object-format=sha1..
[etc...]I'm not sure if this is caused by the same commit or not. I'll see if I can bisect, applying your new fix on top of the intermediate states. |
|
@peff, ah, right. I amended the PR with the additional fix that suppresses chunked encoding completely for HTTP/2 and higher. |
Yeah, it is the same commit (though perhaps a different problem introduced by the same commit). If I build the parent of 9369c30, then the POST that diff --git a/lib/http.c b/lib/http.c
index 3f17f7cd9..56c60f9f9 100644
--- a/lib/http.c
+++ b/lib/http.c
@@ -2304,7 +2304,8 @@ CURLcode Curl_http_req_complete(struct Curl_easy *data,
}
else { /* we read the bytes from the callback */
Curl_pgrsSetUploadSize(data, http->postsize);
- result = Client_reader_set_fread(data, http->postsize);
+ bool chunked = !!Curl_checkheaders(data, STRCONST("Transfer-Encoding"));
+ result = Client_reader_set_fread(data, chunked? -1 : http->postsize);
}
http->sending = HTTPSEND_BODY;
break;curl will now read all of the input from the Switching Git to set |
|
@icing Ah, our comments just crossed. I just tried the fix you pushed up to the PR, and it works! I think that fixes all of the cases I've seen. |
|
I have applied the mentioned PR on top of 8.7.1 and sadly it does not fix the issue that I have mentioned in #13229 (comment) See the following gist for the debug log: Sadly its huge, so if you need anything more specific let me know, I'll happily provide more (useful) input. |
|
Did you try the PR in its latest revision? The last fix was for HTTP/2 which I see in the log. |
|
Yes, looking at the trace in #13229 (comment) it is sending the chunked encoding over HTTP/2, which would be consistent with using only the earlier version of the PR. The failing |
I have applied the following patch, which includes the changes added later I think: https://gist.github.com/christian-heusel/f4c1a95c29a36ad614f7fab368a8fdf1 |
|
The logs look, as @peff said, like the POST request body is sent using chunked encoding. This is exactly what the last addition to the patch fixed. Could you double check that the failure happens with the full patch active? Thanks! |
|
Sorry for the additonal noise, the later added changes also fixed it for me 👍🏻 I had the correct patchfile locally, but not on the build machine I used 😢 🤦🏻 I even double checked the local patchfile before posting #13229 (comment) (which ofc did not help) because I was fearing for this to happen 😆 Thanks for posting a fix so quickly! 🥳 ❤️ |
|
Thanks for clarifying. Such things happen to everyone, speaking from own experience.😌 |
|
Thank you everyone! |
In get_active_slot(), we return a CURL handle that may have been used
before (reusing them is good because it lets curl reuse the same
connection across many requests). We set a few curl options back to
defaults that may have been modified by previous requests.
We reset POSTFIELDS to NULL, but do not reset POSTFIELDSIZE (which
defaults to "-1"). This usually doesn't matter because most POSTs will
set both fields together anyway. But there is one exception: when
handling a large request in remote-curl's post_rpc(), we don't set
_either_, and instead set a READFUNCTION to stream data into libcurl.
This can interact weirdly with a stale POSTFIELDSIZE setting, because
curl will assume it should read only some set number of bytes from our
READFUNCTION. However, it has worked in practice because we also
manually set a "Transfer-Encoding: chunked" header, which libcurl uses
as a clue to set the POSTFIELDSIZE to -1 itself.
So everything works, but we're better off resetting the size manually
for a few reasons:
- there was a regression in curl 8.7.0 where the chunked header
detection didn't kick in, causing any large HTTP requests made by
Git to fail. This has since been fixed (but not yet released). In
the issue, curl folks recommended setting it explicitly to -1:
curl/curl#13229 (comment)
and it indeed works around the regression. So even though it won't
be strictly necessary after the fix there, this will help folks who
end up using the affected libcurl versions.
- it's consistent with what a new curl handle would look like. Since
get_active_slot() may or may not return a used handle, this reduces
the possibility of heisenbugs that only appear with certain request
patterns.
Note that the recommendation in the curl issue is to actually drop the
manual Transfer-Encoding header. Modern libcurl will add the header
itself when streaming from a READFUNCTION. However, that code wasn't
added until 802aa5ae2 (HTTP: use chunked Transfer-Encoding for HTTP_POST
if size unknown, 2019-07-22), which is in curl 7.66.0. We claim to
support back to 7.19.5, so those older versions still need the manual
header.
Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
In get_active_slot(), we return a CURL handle that may have been used
before (reusing them is good because it lets curl reuse the same
connection across many requests). We set a few curl options back to
defaults that may have been modified by previous requests.
We reset POSTFIELDS to NULL, but do not reset POSTFIELDSIZE (which
defaults to "-1"). This usually doesn't matter because most POSTs will
set both fields together anyway. But there is one exception: when
handling a large request in remote-curl's post_rpc(), we don't set
_either_, and instead set a READFUNCTION to stream data into libcurl.
This can interact weirdly with a stale POSTFIELDSIZE setting, because
curl will assume it should read only some set number of bytes from our
READFUNCTION. However, it has worked in practice because we also
manually set a "Transfer-Encoding: chunked" header, which libcurl uses
as a clue to set the POSTFIELDSIZE to -1 itself.
So everything works, but we're better off resetting the size manually
for a few reasons:
- there was a regression in curl 8.7.0 where the chunked header
detection didn't kick in, causing any large HTTP requests made by
Git to fail. This has since been fixed (but not yet released). In
the issue, curl folks recommended setting it explicitly to -1:
curl/curl#13229 (comment)
and it indeed works around the regression. So even though it won't
be strictly necessary after the fix there, this will help folks who
end up using the affected libcurl versions.
- it's consistent with what a new curl handle would look like. Since
get_active_slot() may or may not return a used handle, this reduces
the possibility of heisenbugs that only appear with certain request
patterns.
Note that the recommendation in the curl issue is to actually drop the
manual Transfer-Encoding header. Modern libcurl will add the header
itself when streaming from a READFUNCTION. However, that code wasn't
added until 802aa5ae2 (HTTP: use chunked Transfer-Encoding for HTTP_POST
if size unknown, 2019-07-22), which is in curl 7.66.0. We claim to
support back to 7.19.5, so those older versions still need the manual
header.
Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
I did this
(imported issued from https://marc.info/?l=git&m=171175679831214&w=2, authored by Jeff King (@peff))
I noticed some http-related failures in the test suite on my Debian
unstable system, which recently got an upgraded curl package. It looks
like it's related to cases where we use the remote-curl helper in
"connect" mode (i.e., protocol v2) and the http buffer is small
(requiring us to stream the data to curl). Besides just running t5551,
an easy reproduction is:
The error message comes from ls-remote itself, which was expecting a
FLUSH packet from the remote. Instead it gets the RESPONSE_END from
remote-curl (remember that in connect mode, remote-curl is just ferrying
bytes back and forth between ls-remote and the server).
It works with older versions of libcurl, but not 8.7.0 (or 8.7.1).
Bisecting in libcurl points to 9369c30 (lib: Curl_read/Curl_write
clarifications, 2024-02-15).
Running with
GIT_TRACE_CURL=1shows weirdness on the POST we send toissue the ls-refs command. With older curl, I see this:
But with the broken version, I get:
So we only get the first 4 bytes, and then we quit (the double mention
of 14 is confusing, but I think it is both the size of the pkt-line
("command=ls-refs\n") but also the length of the 4-byte string when
framed with chunked transfer-encoding). Those 4 bytes are the first
thing returned by rpc_out(), which we use as our
CURLOPT_READFUNCTION.It's possible that we're doing something wrong with our read/write
function callbacks. But I don't see how; we say "here's 4 bytes", but
then we never get called again. It's like curl is giving up on trying to
read the post input early for some reason.
I'm not sure how to dig further. That commit is pretty big and scary. I
did check that the tip of master in curl.git is still affected (I'd
hoped maybe the 0-length write fixes in b30d694 would be related,
but that's not it).
Ideas?
I expected the following
No response
curl/libcurl version
8.7.0 and 8.7.1
operating system
Linux, but probably not relevant
The text was updated successfully, but these errors were encountered: