Partial pipelined request blocks outstanding responses #1043
Comments
|
So I did some step debugging and I found this: Which looks like this is a known (and intentional?) behavior. Would you accept a PR to make this behavior configurable? Or perhaps, add a very short timer event (a few ms, maybe?) to allow response packing without waiting for the unfinished request to arrive indefinitely? |
|
A bit of context about how we discovered this, might provide a little motivation for why this behavior is undesirable. A buggy client was setting a Content-Length header that was too small on a PUT request with a JSON body. The extra few bytes are interpreted by the server as the beginning of the next HTTP request. Rather than responding right away with a 400 when our callback failed to parse the PUT body, the server response hangs until ReadTimeout is reached. |
|
That's a tricky case you found here, thank you for the report. While it sounds like we have to provide a way to fix this, I'm not sure how we can do that while keeping fasthttp behavior backward compatible. I would appreciate a PR, let's see if we can fix that |
|
So I know how I'd fix this in C. I'd do a non-blocking read of the socket, and if I got EAGAIN, I'd know that the OS was still waiting on packets from the network. That'd be an easy way to tell the difference between "waiting on network" and "there are more pipelined requests in the buffer". It seems that Go doesn't have a non-blocking way to do this and the buffer peek operation is always blocking. If you know a good way to do this in Go, I'd love to hear it. If we can't do some version of the above, then perhaps adding a very short (like ~1-10ms ?) timer event to flush the buffer if the unfinished pipelined request still hasn't arrived yet? That might give us a window to pack in a few pipelined responses without costing an entire round trip, or more in time to first byte on the first request? Does this sound sane? Third option would be to add a configurable "FlushBufferAfterPipelinedRequests" option, or something like that, which would just flush the buffer every time for users that care more about time to first byte rather than packing more responses into a TCP packet. |
|
EAGAIN is not an indicator that more data is coming so its impossible to use that. I would prefer to have an option, I don't see any way to automatically fix this. @wcs1only what I'm confused about is why you have to wait for ReadTimeout in your case. Unless the extra few bytes happen to be a correct start of a HTTP request the parser should give an error and return a response immediately. |
What EAGAIN would tell you, is that the kernel hasn't processed any more bytes from the network. It doesn't need to know that no more data is coming, just so long as all of your pipelined requests fit within the first congestion window, it is reasonable to expect that all of them would be received within the window of servicing the first response, thus not regressing on the benchmark. That's the hypothesis anyway. If I knew how to do that in Go, we wouldn't have to speculate, we could run the benchmark in question and see if it regresses.
My experimentation suggests otherwise. The parser does not seem to bail early with an error. It remains hung until it gets an You can repeat my experiment with the following code: // socket client for golang
// https://golangr.com
package main
import "net"
import "fmt"
import "bufio"
import "time"
func main() {
// connect to server
conn, _ := net.Dial("tcp", "127.0.0.1:8080")
reader := bufio.NewReader(conn)
go func () {
for {
message, _ := reader.ReadString('\n')
if len(message) > 0 {
fmt.Printf("%s reply from server: %s", time.Now(), message)
}
}
} ()
payload := "GET / HTTP/1.1\r\nhost: localhost\r\n\r\nasdklfjhsdjfh@(#$*$&WSEJVHBSDFasldkfjlskdjflkjsdflkjsdkfjkhasdkfjhjkhasdfkjhsdjfhksjdhfkjshdfkjh"
fmt.Fprintf(conn, payload)
fmt.Printf("%s client sent: %s", time.Now(), payload)
time.Sleep(10 * time.Second)
payload = "\r\n"
fmt.Fprintf(conn, payload)
fmt.Printf("%s client sent: %s", time.Now(), payload)
time.Sleep(10 * time.Second)
}Running this code gives the following: |
|
I think this is largely due to the fact that the parser seems to accept any string as an HTTP verb, and any string as a URL. In fact, the only way that I could get it to even generate a 400 at all is if I didn't include a space before Basically the fix would look something like this. Disclaimer: I don't think this patch is safe as written, but it illustrates the fix I am thinking: diff --git a/server.go b/server.go
index 82eeef7..6d3b68a 100644
--- a/server.go
+++ b/server.go
@@ -2280,6 +2280,14 @@ func (s *Server) serveConn(c net.Conn) (err error) {
if err != nil {
break
}
+ } else if br.Buffered() != 0 {
+ flushTimer := time.NewTimer(10 * time.Millisecond)
+ go func () {
+ <-flushTimer.C
+ if bw != nil {
+ bw.Flush()
+ }
+ }()
}
if connectionClose {
break |
|
You're right it waits for the Lines 2290 to 2292 in 6233fbc In theory we could read a couple of bytes and see if they are ASCII as the method is the first token and should be all ASCII. I get what you want with EAGAIN and I think we could do this. Lines 1503 to 1507 in 6233fbc When we get an errNeedMore here we don't want to keep reading in a loop, instead we want to break out to here: Line 2095 in 6233fbc Where we can flush the send buffer if needed and then retry the Header.Read.But this will require some bigger changes I think. I don't have time for this right now but I will have in the near future. |
Don't wait for the next request as this can take some time, instead flush the outstanding responses already. Fixes #1043
|
@erikdubbelboer Awesome, this does seem to fix the issue and deliver the desired behavior for most cases. There is still an outstanding case when the buffer contains <4 bytes, it seems to get blocked here: Line 2059 in 34275a5 Code to reproduce: // socket client for golang
// https://golangr.com
package main
import "net"
import "fmt"
import "bufio"
import "time"
func main() {
// connect to server
conn, _ := net.Dial("tcp", "127.0.0.1:8080")
reader := bufio.NewReader(conn)
go func () {
for {
message, _ := reader.ReadString('\n')
if len(message) > 0 {
fmt.Printf("%s reply from server: %s", time.Now(), message)
}
}
} ()
payload := "GET / HTTP/1.1\r\nhost: localhost\r\n\r\na "
fmt.Fprintf(conn, payload)
fmt.Printf("%s client sent: %s", time.Now(), payload)
time.Sleep(100 * time.Second)
payload = "fooo\r\n\r\n"
fmt.Fprintf(conn, payload)
fmt.Printf("%s client sent: %s", time.Now(), payload)
time.Sleep(10 * time.Second)
} |
Don't wait for the next request as this can take some time, instead flush the outstanding responses already. Fixes #1043
|
You're right, I have fixed it in my pull. I'm going to merge it on Monday and do a new release on Wednesday. |
* Flush buffered responses if we have to wait for the next request Don't wait for the next request as this can take some time, instead flush the outstanding responses already. Fixes #1043 * Only peek 1 byte Make sure old clients that send bogus \r\n still work. See: golang/go@bf5e19f
If N pipelined requests are sent in the same packet, with the N+1th request split across a packet boundary. All replies are blocked until the N+1th request is finally sent. You can reproduce this behavior with the following client (run against helloworldserver example):
I would expect the first request to respond immediately, instead it is blocked until the second request is fully parsed. I confirmed via tcpdump that no response packet is sent for a full 10 seconds.
Output for the above is the following:
The text was updated successfully, but these errors were encountered: