SlyMarbo / spdy

[deprecated] A full-featured SPDY library for the Go language.
BSD 2-Clause "Simplified" License
116 stars 13 forks source link

Response status missing #48

Closed rnapier closed 10 years ago

rnapier commented 10 years ago

On some machines, I'm occasionally seeing a mismatch in the StatusCode and the headers. The fact that this happens only intermittently is making me think race condition. Here is the calling code:

resp, err := conn.RequestResponse(req, nil, DefaultSpdyPriority)
resp.Body.Close()
if resp.StatusCode != http.StatusCreated && resp.StatusCode != http.StatusNoContent {
    log.WithField("resp", resp).Warn("Unexpected result while setting KUID")
    return errors.New("Bad result while reading KUID")
}

From this, I'm getting the following log:

2014-05-23.12:08:41-07:00|WARN |kuid.go:58:SetKuid                      | Unexpected result while setting KUID|{"resp":{"Status":"0 ","StatusCode":0,"Proto":"HTTP/1.1","ProtoMajor":1,"ProtoMinor":1,"Header":{":status":["201"],":version":["HTTP/1.1"]},"Body":{"Reader":{}},"ContentLength":0,"TransferEncoding":null,"Close":true,"Trailer":{},"Request":{"Method":"PUT","URL":{"Scheme":"https","Opaque":"","User":null,"Host":"..konea..","Path":"/agent/kuid","RawQuery":"","Fragment":""},"Proto":"HTTP/1.1","ProtoMajor":1,"ProtoMinor":1,"Header":{":host":["..konea.."],":method":["PUT"],":path":["/agent/kuid"],":scheme":["https"],":version":["HTTP/1.1"],"Content-Length":["36"]},"Body":{"Reader":{}},"ContentLength":36,"TransferEncoding":null,"Close":false,"Host":"..konea..","Form":null,"PostForm":null,"MultipartForm":null,"Trailer":null,"RemoteAddr":"","RequestURI":"","TLS":null}}}

Notice that StatusCode is 0, but the :status header is "201" (which is correct). Most of the time, this code works fine. But sometimes (usually during the production test run), I get this mismatch. I'm investigating further whether this is a race condition on the response.

The output from the race detector on this test case is available at https://gist.github.com/rnapier/2ef6f20ab89684aadccb

Notice the races between spdy.(*response).Response() and spdy.(*response).ReceiveHeader(). This is exactly the kind of race that I would suspect.

I have several other test cases that are intermittently failing in similar ways. By "intermittent" I mean that at least some tests fail on at several of the build servers during most builds, so it's quite often (but I haven't reproduced it on my desktop).