net/http: go1.6beta1, nil pointer in http.Client

[karmeye]

panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x20 pc=0x58d4e8]

goroutine 39320 [running]:
net/http.(*persistConn).closeLocked(0xc8646c8840)
    /usr/local/go/src/net/http/transport.go:1451 +0x48
net/http.(*persistConn).close(0xc8646c8840)
    /usr/local/go/src/net/http/transport.go:1445 +0x7a
net/http.(*Transport).putIdleConn(0xc820386bb0, 0xc8646c8840, 0xc84fc4d788)
    /usr/local/go/src/net/http/transport.go:500 +0x434
net/http.(*Transport).getConn.func2.1(0xc841323aa0, 0xc820386bb0, 0x9db1c8)
    /usr/local/go/src/net/http/transport.go:629 +0x7f
created by net/http.(*Transport).getConn.func2
    /usr/local/go/src/net/http/transport.go:632 +0x70

Occurs sometimes under the following conditions

• Using TLS and HTTP/2
• Stress testing server with 500 http.Clients running in the same process.

Clients are running on OS X 10.11.2
Server is running on Linux

Looking at the source, it seems to be than conn is nil:

func (pc *persistConn) closeLocked() {
    pc.broken = true
    if !pc.closed {
        pc.conn.Close()    <---- conn nil?
        pc.closed = true
        close(pc.closech)
    }
    pc.mutateHeaderFunc = nil
}

[bradfitz]

Have you run your program with the race detector? http://blog.golang.org/race-detector

[bradfitz]

I just read the code again at the version you're using (https://github.com/golang/go/blob/8db371b3d58a1c139f0854738f9962de05ca5d7a/src/net/http/transport.go) and see no way for pc or pc.conn to be nil.

Except perhaps if you're using the Transport.Dial hook and returning (nil, nil) from it.

Is your code available somewhere for me to look at?

[bradfitz]

Alternatively, are you able to reproduce with the latest code in the master branch?

[karmeye]

Seems it was a race issue.

My stress test code is using a client library.
https://github.com/go-resty/resty/blob/master/client.go
In the execute() method, which is called concurrently, there were 2 issues:

// RACE 1, writing
if req.proxyURL != nil {
    c.transport.Proxy = http.ProxyURL(req.proxyURL)
} else if c.proxyURL != nil {
    c.transport.Proxy = http.ProxyURL(c.proxyURL)
} else {
    c.transport.Proxy = nil
}

// RACE 2, writing
c.httpClient.Transport = c.transport

// RACE reading transport/proxy ?
resp, err := c.httpClient.Do(req.RawRequest)

After protecting this whole section with a mutex I cannot reproduce the panic. (There were 2 other race conditions elsewhere as well but I think they were unrelated.)

A Dial hook is set in the method SetTimeout, but I was not calling it.

Is it possible that the GC can nil things if races occur?

Anyways, I'll close this issue 👍

[bradfitz]

Is it possible that the GC can nil things if races occur?

If you have races, anything is possible. Even very strange things. Regularly detecting races and fixing them should always be your top priority.

[karmeye]

This is still an issue.

This is most definitely related to unexpected connection shutdowns from the server. If the connection is being closed while the client is reading/writing.

For example, in the case above (using 1.6 beta1), it stopped appearing when extending the Read and Write deadlines on the server in ConnState http.StateActive as seen here #13925 (comment)

Now using latest using latest code in the master branch (771da53) it is still appearing even with the change above.

In this case it was when the server got Killed by the system (memory pressure). Probably the same thing again, the client expected the connection to be open and was reading/writing to it.

I had 3 programs running on 3 different machines with several clients running in goroutines, and they all got the same panic at the same time with exactly the same stack trace as above (although different line numbers now):

panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x20 pc=0x57aacc]

goroutine 1084538 [running]:
net/http.(*persistConn).closeLocked(0xc822551450, 0x7f95b1e55028, 0xc820010dd0)
    /usr/local/go/src/net/http/transport.go:1505 +0xac
net/http.(*persistConn).close(0xc822551450, 0x7f95b1e55028, 0xc820010dd0)
    /usr/local/go/src/net/http/transport.go:1496 +0x92
net/http.(*Transport).putOrCloseIdleConn(0xc8200ae2c0, 0xc822551450)
    /usr/local/go/src/net/http/transport.go:478 +0x5d
net/http.(*Transport).getConn.func2.1(0xc8214d3860, 0xc8200ae2c0, 0x98ec88)
    /usr/local/go/src/net/http/transport.go:656 +0x7f
created by net/http.(*Transport).getConn.func2
    /usr/local/go/src/net/http/transport.go:659 +0x70

I am now using a Transport.Dial hook which is wrapping and returning the values of net.DialTimeout(network, addr, ioTimeout).

[bradfitz]

I don't see how such a case is possible without data races or other bugs. Are you sure your DialTimeout hook isn't returning (nil, nil)? Can you share your code and instructions to reproduce?

[bradfitz]

Actually, I have a potential lead now.

[gopherbot]

CL https://golang.org/cl/18573 mentions this issue.