-
Notifications
You must be signed in to change notification settings - Fork 1.2k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Strange 'hanging' request in specific HTTP/2 request sequence #3828
Comments
@joanlopez / @mstoykov , since I happened to see you active on the other issue... I realise this issue is quite involved, but maybe you can at least answer the following quick question: I'm trying to force HTTP/1.1 because of this issue. On the CLI locally I can do that with:
because it will hit this code: Lines 255 to 271 in 011a6b4
But it doesn't seem to work if I run this code with Thanks in advance. Obviously I hope you are intrigued by this issue as well 😀 |
(I've updated the issue by referencing the vendored code inside this repository, since I just realised I was referencing the Golang HTTP client code directly instead. This makes it more clear.) |
Hi @aukevanleeuwen , thank you a lot for the awesome issue report 🙇 Reading the issue my instinct is that this is a Golang std lib thing that Cloudflare started to exhibit likely to some recent change. I would expect otherwise we would've gotten more reports or more people would have hit it somehow. k6 doesn't really do anything specific to the http stream, so it will be quite interesting if some option we set, not set hits this. There are number of issues that seem relevant on the golang issue tracker but are not 100% a hit, but can you:
Unfortunately the GODEBUG hack isn't supported in the cloud - unfortunately only an issue about documenting this exist. Please contact cloud support to see if we can figure out something else through the channel. |
Also if we can get the script that sends the requests even with the url and authentication obscured, that might point out to something. |
Just double checking, but I think you mean Akamai here right?
Sorry took some time to discuss this internally a bit. I think we can give you something that you can work with, but not publicly obviously. How can we get this to you privately? I need to strip some things in the script to just get to the core of it in the meantime. |
Well I did mean Cloudflare ... because I apparently I just read "one" cdn and then swapped it for the other 😓 I guess cloudflare have better marketing for me 😅 . This doesn't really change anything though - there are just as many strange issues around akamai as cloudflare. And just as many old cases where it ended up being "akamai has identified this as a bug and will be rolling out a fix".
No problem - I don't expect we will be able to fix this very fast to begin with, and we are on low capacity due to the vacation season. So I am sorry, but we likely won't be able to look into this super fast :(
I would prefer that you reach through the support as that seems like the most official way and will let us have access internally even if I go out on vacation.
Thank you 🙇 It will still be nice if we can have a public version if anybody else hits this or has ideas. The public version obviously should have no data, but might still point to a potential problem |
@aukevanleeuwen you also might want to try to see if you can get the real traffic that goes in and out through tcpdump/wireshark and SSLKEYLOGGER , please see grafana/k6-docs#754 and the linked issues and article for more details. It is particularly interesting what is beind send and received in that last call. Is the request being flushed at all, is the response received but not read |
Thanks @mstoykov, we were just looking into this. I haven't had time to work any further on it as I was in client meetings. |
Okay.. I figured it out with some Wiresharking¹. What I was accidentally doing was creating requests based on a request arguments object (basically this: https://github.com/DefinitelyTyped/DefinitelyTyped/blob/9378dc4325a341e0b0143a072ec53dda5d0a9849/types/k6/http.d.ts#L354-L366) that was accidentally carrying over the Object.assign(options1, options2); rather than Object.assign({}, options1, options2); Apparently Akamai doesn't like HTTP/2 Either way, fixing my code to not send Thanks for your help though! ¹ The fact that |
Great job figuring out! Glad it turned out we don't need to debug the sdlib http2 code 😅 . Have you tried this with another server? I guess when you said:
Means that this works if not for Akamai even with your reproduction program? if so it migth be worth reporting it to Akamai. Otherwise it migth be worth reporting it to golang. |
I've tried it against the origin directly indeed, and also against https://nghttp2.org/httpbin/, both of which seemed to be fine with this behaviour. |
I've informally asked Akamai, but didn't create an official issue there. Let's see what comes back. |
Brief summary
K6 'hangs' on specific sequence of requests. I cannot reproduce this behaviour with (for example)
curl
or the native golang http client.k6 version
v0.52.0, but tested as far back as v0.40.0
OS
macOS 14.5
Docker version and image (if applicable)
No response
Steps to reproduce the problem
I have a strange issue with K6. In one of my load test scenarios,
k6
was hanging on aPOST
request. Running the test with different configurations of VUs I've narrowed it down to a specific sequence of requests.GET https://example.com/some/path
GET https://example.com/some/path
POST https://example.com/some/path
with request body of 16K random stringGET https://example.com/some/path
GET https://example.com/some/path
POST https://example.com/some/path
with request body of 16K random string (this request hangs)This is quite hard for me to debug (and describe in this issue), so bear with me. I've tried to go through a bunch of things trying to pin it down to something specific.
These requests fail on an API that is behind Akamai (with HTTP/2 behaviour configured). Some observations:
GET
requests, or just thePOST
requests, it all runs fine. So it's only the alternation ofGET
s andPOST
s that triggers this issue. Weirder still. If I would half the request body size of thePOST
, the amount of iterations (2GET
s and 1POST
) doubles.curl
requests using--next
to make sure that we have connection reuse and trying to get as close as possible to whatever K6 is doing. It just works.In all of this testing, looking at logs from
GODEBUG=http2debug=2
and breaking inside the k6 and http client source code I've narrowed it down to this:While sending the POST data it enters this loop:
k6/vendor/golang.org/x/net/http2/transport.go
Lines 1841 to 1860 in 011a6b4
The first time around this is going fine because, the allowed length to send in this frame is
16384
, which is the entire buffer, remaining is[]
and it will send the frame withflags=END_STREAM
. All good. The secondPOST
request however will enter that same loop, but for some reason that is beyond my understanding,cs.awaitFlowControl(len(remain))
will return16383
, so one byte less. This frame is created (without theEND_STREAM
flag obviously) and sent, it will enter the next iteration of the loop because there is still one byte to send and hitcs.awaitFlowControl(len(remain))
again. However inside that method on this line:k6/vendor/golang.org/x/net/http2/transport.go
Line 1934 in 011a6b4
cs.flow.available()
will return0
and therefore will block on thecc.cond.Wait()
mutex (k6/vendor/golang.org/x/net/http2/transport.go
Line 1946 in 011a6b4
I wish I could explain this simpler to be honest, but I don't really. Following are the logs from both
k6
and my own small CLI tool ran withGODEBUG=http2debug=2
. Maybe it will help.This is the K6 output that is hanging.
So the strange behaviour is here (snippet from above):
The content length and the length of the data frame don't match up. The fact that this is in fact 16383 rather than 16384 is already strange, but stranger still is the fact that it doesn't send yet another data frame with the last byte afterwards.
Notice that the failed request is roughly halfway, afterwards it will issue yet another 2 (successful)
GET
requests, but fail on thePOST
again 🤷 .Expected behaviour
For
k6
not to hang on these requests.Actual behaviour
k6
hangs.The text was updated successfully, but these errors were encountered: