net/http: *http.Transport is never collected

[powerman]

Please answer these questions before submitting your issue. Thanks!

1. What version of Go are you using (go version)?

go version go1.6.2 linux/amd64

1. What operating system and processor architecture are you using (go env)?

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/powerman/gocode"
GORACE=""
GOROOT="/usr/lib/go"
GOTOOLDIR="/usr/lib/go/pkg/tool/linux_amd64"
GO15VENDOREXPERIMENT="1"
CC="x86_64-pc-linux-gnu-gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0"
CXX="x86_64-pc-linux-gnu-g++"
CGO_ENABLED="1"

1. What did you do?

package main

import (
    "fmt"
    "io"
    "io/ioutil"
    "net/http"
    "runtime"
    "time"
)

func main() {
    for {
        c := &http.Client{
            Transport: &http.Transport{
                ExpectContinueTimeout: 1 * time.Second, // A
            },
        }
        resp, err := c.Get("http://google.com")
        if resp != nil {
            io.Copy(ioutil.Discard, resp.Body) // B
            resp.Body.Close()                  // B
        }
        fmt.Printf("resp=%t, err=%v\n", resp != nil, err)
        time.Sleep(time.Second)
        c.Transport.(*http.Transport).CloseIdleConnections() // C
        runtime.SetFinalizer(c, func(interface{}) { fmt.Println("--- http.Client GONE") })
        runtime.SetFinalizer(c.Transport, func(interface{}) { fmt.Println("--- http.Transport GONE") })
        runtime.GC()
    }
}

1. What did you expect to see?

resp=true, err=<nil>
--- http.Client GONE
resp=true, err=<nil>
--- http.Client GONE
--- http.Transport GONE
resp=true, err=<nil>
--- http.Client GONE
--- http.Transport GONE
resp=true, err=<nil>
--- http.Client GONE
--- http.Transport GONE
resp=true, err=<nil>
^Csignal: interrupt

1. What did you see instead?

Provided program works correctly and gives output shown above. But if we'll comment any of lines marked // A or // B or // C then http.Transport won't be garbage-collected anymore and output became:

resp=true, err=<nil>
--- http.Client GONE
resp=true, err=<nil>
--- http.Client GONE
resp=true, err=<nil>
--- http.Client GONE
resp=true, err=<nil>
--- http.Client GONE
resp=true, err=<nil>
^Csignal: interrupt

I know it's recommended to share same http.Client for all application, but I'm developing load-testing application which simulate thousands of independent clients and thus require own simulated client to use own http.Client and own http.Transport objects to behave more like real independent clients.

[adg]

I'm not sure what you expect to happen here. All the code is working exactly as documented. In particular, you must always Close the response body when using http.Client.

You can turn off keepalives entirely in your custom http.Transport if you like. There are also configuration knobs on Client that you may wish to turn.

[powerman]

I expect to have this code working correctly without needs to manually call CloseIdleConnections().

I don't see any issues with needs to call Body.Close(), but relationship between this issue and ExpectContinueTimeout looks weird for me.

[adg]

I expect to have this code working correctly without needs to manually call CloseIdleConnections().

Unless you disable Keep-Alive connections in the Transport, then you should expect the Transport to maintain a pool of idle connections. If you don't close those connections or re-use the Transport, you will leak Transports.

relationship between this issue and ExpectContinueTimeout looks weird for me.

Hmm, well ExpectContinueTimeout disables http2 in the client, so maybe that's related. You're saying that you see Transports escaping even if you don't call CloseIdleConnections?

[powerman]

Unless you disable Keep-Alive connections in the Transport, then you should expect the Transport to maintain a pool of idle connections.

Sure. But also I expect Transport object to clean up after itself when it doesn't used anymore - i.e. when all references to that object is gone.

If you don't close those connections or re-use the Transport, you will leak Transports.

Is this mean only correct way to create own Transport is to manually make sure it will be garbage-collected when it doesn't needed anymore? For example, in simple case when this Transport isn't shared between multiple clients use something like this (untested)?

tr := &http.Transport{…}
client := &http.Client{Transport: tr}
runtime.SetFinalizer(client, func(c *http.Client){ c.Transport.CloseIdleConnections() })

If this is the case, then it probably should be noted in documentation with warning about leaking sockets and goroutines otherwise.

Hmm, well ExpectContinueTimeout disables http2 in the client, so maybe that's related. You're saying that you see Transports escaping even if you don't call CloseIdleConnections?

Without defining ExpectContinueTimeout it leaks no matter is I call CloseIdleConnections() or not.

[adg]

Sure. But also I expect Transport object to clean up after itself when it doesn't used anymore - i.e. when all references to that object is gone.

But that's not how things usually work in Go. I would expect to call some kind of Close method.

I would not recommend using SetFinalizer (at all, its inclusion in Go was a mistake IMO), but rather just calling CloseIdleConnections when you are done. Alternately, you can disable KeepAlives in the Transport and then you needn't worry about CloseIdleConnections.

The interaction between connection pooling (I assume) and ExpectContinueTimeout does surprise me. There might be something here. Leaving assigned to @bradfitz in case he has idaes.

[powerman]

I would not recommend using SetFinalizer

Can you please explain why? Or give a link if this was already explained somewhere? How it's differ from defer (in spirit) in this use case?

But that's not how things usually work in Go. I would expect to call some kind of Close method.

I agree, but I believe this is somewhat corner/subtle case and it's worth to be mentioned in http package documentation.

[adg]

Can you please explain why? Or give a link if this was already explained somewhere? How it's differ from defer (in spirit) in this use case?

There are no guarantees about if/when a finalizer will be executed. A finalizer may be silently replaced by a subsequent call to SetFinalizer, with no warning from the compiler or runtime. In short, they are not reliable enough to be broadly useful.

On the other hand, defer is well-defined and its behavior is deterministic. You know that all deferred functions were executed if a function call returns.

[bradfitz]

I actually don't see *http.Transport ever being collected with Go 1.6, Go 1.7, or tip, even ignoring the Expect100Continue logic.

Here's my version:

package main

import (
    "fmt"
    "io"
    "io/ioutil"
    "log"
    "net/http"
    "net/http/httptest"
    "runtime"
    "time"
)

func main() {
    ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        io.WriteString(w, "Hello")
    }))
    var ms runtime.MemStats
    for {
        runtime.ReadMemStats(&ms)
        log.Printf("Before request: %d goroutines, %d heapalloc, %d GC", runtime.NumGoroutine(), ms.HeapAlloc, ms.NumGC)

        doRequest(ts.URL)

        time.Sleep(500 * time.Millisecond)
        runtime.GC()
        runtime.GC()

        runtime.ReadMemStats(&ms)
        log.Printf(" After request: %d goroutines, %d heapalloc, %d GC", runtime.NumGoroutine(), ms.HeapAlloc, ms.NumGC)
    }
}

func doRequest(url string) {
    tr := &http.Transport{
        DisableKeepAlives: true,
    }
    c := &http.Client{Transport: tr}

    runtime.SetFinalizer(c, func(*http.Client) { fmt.Println("--- http.Client GONE") })
    runtime.SetFinalizer(tr, func(*http.Transport) { fmt.Println("--- http.Transport GONE") })

    resp, err := c.Get(url)
    if err != nil {
        log.Fatal(err)
    }
    fmt.Println("got response")

    io.Copy(ioutil.Discard, resp.Body)
    resp.Body.Close()

    // Pointless with DisableKeepAlives above, but:
    time.Sleep(10 * time.Millisecond)
    tr.CloseIdleConnections()
}

And the output:

2016/10/22 06:08:44 Before request: 3 goroutines, 298336 heapalloc, 0 GC
got response
2016/10/22 06:08:45  After request: 3 goroutines, 294680 heapalloc, 2 GC
2016/10/22 06:08:45 Before request: 3 goroutines, 295824 heapalloc, 2 GC
--- http.Client GONE
got response
2016/10/22 06:08:45  After request: 3 goroutines, 297464 heapalloc, 4 GC
--- http.Client GONE
2016/10/22 06:08:45 Before request: 3 goroutines, 298816 heapalloc, 4 GC
got response
2016/10/22 06:08:46  After request: 3 goroutines, 300552 heapalloc, 6 GC
2016/10/22 06:08:46 Before request: 3 goroutines, 301872 heapalloc, 6 GC
--- http.Client GONE
got response
--- http.Client GONE
2016/10/22 06:08:47  After request: 3 goroutines, 302392 heapalloc, 8 GC
2016/10/22 06:08:47 Before request: 3 goroutines, 303744 heapalloc, 8 GC
got response
2016/10/22 06:08:47  After request: 3 goroutines, 304760 heapalloc, 10 GC
--- http.Client GONE
2016/10/22 06:08:47 Before request: 3 goroutines, 306112 heapalloc, 10 GC
got response
--- http.Client GONE
2016/10/22 06:08:48  After request: 3 goroutines, 306552 heapalloc, 12 GC
2016/10/22 06:08:48 Before request: 3 goroutines, 307904 heapalloc, 12 GC
got response
2016/10/22 06:08:48  After request: 3 goroutines, 309304 heapalloc, 14 GC
--- http.Client GONE
2016/10/22 06:08:48 Before request: 3 goroutines, 310656 heapalloc, 14 GC
got response
2016/10/22 06:08:49  After request: 3 goroutines, 311592 heapalloc, 16 GC
--- http.Client GONE
2016/10/22 06:08:49 Before request: 3 goroutines, 312944 heapalloc, 16 GC
got response
2016/10/22 06:08:49  After request: 3 goroutines, 313240 heapalloc, 18 GC
--- http.Client GONE
2016/10/22 06:08:49 Before request: 3 goroutines, 314592 heapalloc, 18 GC
got response
--- http.Client GONE
2016/10/22 06:08:50  After request: 3 goroutines, 317480 heapalloc, 20 GC
2016/10/22 06:08:50 Before request: 3 goroutines, 318832 heapalloc, 20 GC
got response
2016/10/22 06:08:50  After request: 3 goroutines, 319400 heapalloc, 22 GC
--- http.Client GONE
2016/10/22 06:08:50 Before request: 3 goroutines, 320544 heapalloc, 22 GC
got response

So it's not a goroutine leak at least.

I really wish there were an API like 'runtime.ShowMePathsFromRootsetTo(mem uintptr)` so I could debug retentions like this.

Not sure whether our heapdump/heapview tooling is good enough for this yet.

I also suspected that maybe *http.Transport was on the stack which is why I never saw it finalized, but go tool compile -m says:

bug16005-garbage.go:36: &http.Transport literal escapes to heap

Go team, any help?

/cc @randall77 @mdempsky @matloob @aclements

[aclements]

I really wish there were an API like 'runtime.ShowMePathsFromRootsetTo(mem uintptr)` so I could debug retentions like this.

While that would be nice, it takes as much space as the heap itself (or, strictly speaking, as all of the pointers in the heap) to compute that and I don't think the runtime itself could give you any type information (just a chain of pointers and offsets).

The heap dump is the way to do this, but I'm not sure what its status is.

[aclements]

it takes as much space as the heap itself

I suppose that's not strictly true. We could do it with less space, but it would take O(|heap| * |path length|) time.

runtime.SetFinalizer(tr, func(*http.Transport) { fmt.Println("--- http.Transport GONE") })

Is it possible tr is involved in a cycle? If so, the finalizer itself will prevent it from being collected.

[aclements]

I toyed with solving this using GDB's Python API, and actually got quite far, but eventually slammed into the same problem the heap dumper has run into: I have only DWARF type information for global and stack roots, but only Go type information for interface values. Right now I don't think we have a reliable way to map from a Go type to a DWARF type. We'll probably have to fix that for the heap dumper to be robust.

[aclements]

Found it. The fact that the http.Transport is not collected in this program is not a bug.

The only reason the Transport isn't being collected is because of the finalizer. If you remove the finalizer, it will be collected (you can see this clearly by setting GODEBUG=allocfreetrace=1).

In general, you should never set a finalizer on an object you didn't implement because you don't know if it may participate in a cycle, or if the internal implementation already uses a finalizer. In this case, setting the finalizer causes it not to be freed because it participates in a cycle where Transport.h2transport points to an http2Transport object and http2Transport.t1 points right back at the Transport. (Awful GDB script for finding the path from a GC root to an object here.)

[bradfitz]

That's more disappointing than I was expecting.

Is that documented anywhere? I'm also not even sure I understand why cycles matter here. If that finalizer's func was doing something with the transport I could believe it, but where is the cycle?

I understand that Transport internally has cycles, but cycles don't preclude things being collected. So why do internal cycles + finalizers matter?

[quentinmit]

The GC guarantees that an object and all its references will be live when the finalizer is called. If you have a cycle, there's no object that can be collected "first" without making it impossible to run the other object's finalizer.

[aclements]

Is that documented anywhere?

"If a cyclic structure includes a block with a finalizer, that cycle is not guaranteed to be garbage collected and the finalizer is not guaranteed to run, because there is no ordering that respects the dependencies." -- https://godoc.org/runtime#SetFinalizer

In principle we could run the finalizer if exactly one block in the cycle has a finalizer, but I have no idea how to implement that efficiently and then it would just break down in an even subtler way if you happened to have two finalizers in the cycle.

Don't use finalizers.

[bradfitz]

Okay, I should've re-read the finalizer docs. I thought I'd still remembered them. Apparently not, thanks.

Don't use finalizers.

Fair enough.

Got that, @powerman?

[powerman]

Thanks for the explanation!

[mikedanese]

http.Transport seems to only get collected if there are no connections in flight and all idle connections are closed. I would have expected the gc to garbage collect http.Transport when there are no references from my code even if the idle connection map still has entries. Is that a bad assumption?