Skip to content
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

net/http: Goroutine leak in http client/transport #9092

Closed
gopherbot opened this issue Nov 12, 2014 · 13 comments

Comments

Projects
None yet
3 participants
@gopherbot
Copy link

commented Nov 12, 2014

by ronee.9:

Go version 1.3 (checked latest 1.3.3, it seems no changes at http client/transport)

I write a server to send http request to other servers, and found out the go routine
keep increases, and there are thousands of go routines like:

goroutine 1803 [chan receive, 117 minutes]:
net/http.(*persistConn).readLoop(0xc208477080)
    /usr/local/go/src/pkg/net/http/transport.go:798 +0x30b
created by net/http.(*Transport).dialConn
    /usr/local/go/src/pkg/net/http/transport.go:600 +0x93f

Not sure why it blocks here.
I am sending the http request like this:

    content := "anystring"
    buf := bytes.NewBufferString(content)
    req, err = http.NewRequest("POST", "anyurl", buf)
    if err != nil {
        return
    }
    req.Header.Add("Content-type", "application/x-www-form-urlencoded")
    return
@gopherbot

This comment has been minimized.

Copy link
Author

commented Nov 12, 2014

Comment 1 by ronee.9:

My httpclient is like this
func NewTimeoutClient(connectTimeout time.Duration, responseHeaderTimeout time.Duration)
*http.Client {
    return &http.Client{
        Transport: &http.Transport{
            Dial: TimeoutDialer(connectTimeout),
            ResponseHeaderTimeout: responseHeaderTimeout,
        },
        Timeout : HTTP_TIMEOUT * time.Second,
    }
}
@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Nov 12, 2014

Comment 2:

Labels changed: added repo-main, release-go1.5.

@bradfitz

This comment has been minimized.

Copy link
Member

commented Nov 12, 2014

Comment 3:

You need to close your Response.Body io.ReadClosers. And don't create more than one
transport. Or if you want its cached idle connections to go away, call
CloseIdleConnections on it.

Status changed to WorkingAsIntended.

@gopherbot

This comment has been minimized.

Copy link
Author

commented Dec 3, 2014

Comment 4 by ronee.9:

Thanks bradfitz's replay and sorry for late feedback.
I have closed the Response.Body by call defer resp.Body.Close().
What do you mean by do not create more than one transport? I create the http client with
this code, and it has only one transport:
func NewTimeoutClient(connectTimeout time.Duration, responseHeaderTimeout time.Duration)
*http.Client {
    return &http.Client{
        Transport: &http.Transport{
            Dial: TimeoutDialer(connectTimeout),
            ResponseHeaderTimeout: responseHeaderTimeout,
        },
        Timeout : HTTP_TIMEOUT * time.Second,
    }
}
I also checked the number of tcp connections, it is OK. i.e. the tcp connection is
reused successfully and not increasing like the go routines.
I traced the code, the block place seems wired at transport.go
798 rc := <-pc.reqch
@bradfitz

This comment has been minimized.

Copy link
Member

commented Dec 3, 2014

Comment 5:

Do you call your NewTimeoutClient more than once? That's what I meant by not making more
than one Transport if you're not going to call CloseIdleConnections.
@gopherbot

This comment has been minimized.

Copy link
Author

commented Dec 3, 2014

Comment 6 by ronee.9:

Yes. I called it only once.
@bradfitz

This comment has been minimized.

Copy link
Member

commented Dec 3, 2014

Comment 7:

Please post a complete but minimal reproduction program.
@gopherbot

This comment has been minimized.

Copy link
Author

commented Dec 3, 2014

Comment 8 by ronee.9:

OK, i will try to do it.
@gopherbot

This comment has been minimized.

Copy link
Author

commented Dec 3, 2014

Comment 9 by ronee.9:

Following is the code, it sends 3 http request and it generate three chan receive blocks
as the profile shown after the code
package main
import (
    "fmt"
    "net/http"
    //"encoding/xml"
    "bytes"
    "io/ioutil"
    //"log"
    "net"
    "net/http/httputil"
    _ "net/http/pprof"
    "strconv"
    "time"
)
const (
    CONNECTION_TIMEOUT      = 20
    RESPONSE_HEADER_TIMEOUT = 60
    HTTP_TIMEOUT            = 90
)
func TimeoutDialer(connectTimeout time.Duration) func(net, addr string) (net.Conn,
error) {
    return func(network, address string) (net.Conn, error) {
        conn, err := net.DialTimeout(network, address, connectTimeout)
        return conn, err
    }
}
func NewDefaultTimeoutClient() *http.Client {
    return NewTimeoutClient(CONNECTION_TIMEOUT*time.Second, RESPONSE_HEADER_TIMEOUT*time.Second)
}
func NewTimeoutClient(connectTimeout time.Duration, responseHeaderTimeout time.Duration)
*http.Client {
    return &http.Client{
        Transport: &http.Transport{
            Dial: TimeoutDialer(connectTimeout),
            ResponseHeaderTimeout: responseHeaderTimeout,
        },
        Timeout: HTTP_TIMEOUT * time.Second,
    }
}
func main() {
    go http.ListenAndServe(":6168", nil) //profiling
    client := NewDefaultTimeoutClient()
    for i := 0; i < 3; i++ {
        fmt.Println("Test ", i)
        content := fmt.Sprintf("api_key=%s&api_secret=%s&from=%s&to=%s&text=test%d&status-report-req=1",
            "xxx", "xxx", "xxx", "1234", i)
        buf := bytes.NewBufferString(content)
        req, err := http.NewRequest("POST", "http://xxx", buf)
        if err == nil {
            req.Header.Add("Content-type", "application/x-www-form-urlencoded")
            req.Header.Add("Content-Length", strconv.Itoa(len(content)))
            output, _ := httputil.DumpRequestOut(req, true)
            fmt.Println("DEBUG: ", string(output))
            resp, err := client.Do(req)
            if err == nil {
                respStr, err := ioutil.ReadAll(resp.Body)
                if err == nil {
                    fmt.Println("resp: ", string(respStr))
                } else {
                    fmt.Println("ERROR: ", err)
                }
            } else {
                fmt.Println("ERROR: ", err)
            }
            resp.Body.Close()
        } else {
            fmt.Println("ERROR: ", err)
        }
        time.Sleep(30 * time.Second)
    }
    time.Sleep(600 * time.Second)
}
goroutine 35 [running]:
runtime/pprof.writeGoroutineStacks(0x382178, 0xc08203a140, 0x0, 0x0)
    D:/Go/src/pkg/runtime/pprof/pprof.go:511 +0x93
runtime/pprof.writeGoroutine(0x382178, 0xc08203a140, 0x2, 0x0, 0x0)
    D:/Go/src/pkg/runtime/pprof/pprof.go:500 +0x55
runtime/pprof.(*Profile).WriteTo(0x904e80, 0x382178, 0xc08203a140, 0x2, 0x0, 0x0)
    D:/Go/src/pkg/runtime/pprof/pprof.go:229 +0xda
net/http/pprof.handler.ServeHTTP(0xc08201ae51, 0x9, 0x3820f0, 0xc08203a140, 0xc08201edd0)
    D:/Go/src/pkg/net/http/pprof/pprof.go:165 +0x277
net/http/pprof.Index(0x3820f0, 0xc08203a140, 0xc08201edd0)
    D:/Go/src/pkg/net/http/pprof/pprof.go:177 +0x167
net/http.HandlerFunc.ServeHTTP(0x7e6368, 0x3820f0, 0xc08203a140, 0xc08201edd0)
    D:/Go/src/pkg/net/http/server.go:1235 +0x47
net/http.(*ServeMux).ServeHTTP(0xc08201a090, 0x3820f0, 0xc08203a140, 0xc08201edd0)
    D:/Go/src/pkg/net/http/server.go:1511 +0x1aa
net/http.serverHandler.ServeHTTP(0xc08200e5a0, 0x3820f0, 0xc08203a140, 0xc08201edd0)
    D:/Go/src/pkg/net/http/server.go:1673 +0x1a6
net/http.(*conn).serve(0xc082048600)
    D:/Go/src/pkg/net/http/server.go:1174 +0xa85
created by net/http.(*Server).Serve
    D:/Go/src/pkg/net/http/server.go:1721 +0x31a
goroutine 16 [sleep, 3 minutes]:
time.Sleep(0x8bb2c97000)
    C:/Users/ADMINI~1/AppData/Local/Temp/2/makerelease686069423/go/src/pkg/runtime/time.goc:39 +0x38
main.main()
    D:/workspace/beetalk_server/go_projects/src/garena.com/TestSMS/TestSMS.go:75 +0x89c
goroutine 19 [finalizer wait, 7 minutes]:
runtime.park(0x4160d0, 0x910c78, 0x90e609)
    D:/Go/src/pkg/runtime/proc.c:1369 +0xac
runtime.parkunlock(0x910c78, 0x90e609)
    D:/Go/src/pkg/runtime/proc.c:1385 +0x42
runfinq()
    D:/Go/src/pkg/runtime/mgc0.c:2644 +0xdd
runtime.goexit()
    D:/Go/src/pkg/runtime/proc.c:1445
goroutine 24 [chan receive, 6 minutes]:
net/http.(*persistConn).readLoop(0xc08203e160)
    D:/Go/src/pkg/net/http/transport.go:798 +0x312
created by net/http.(*Transport).dialConn
    D:/Go/src/pkg/net/http/transport.go:600 +0x946
goroutine 21 [IO wait]:
net.runtime_pollWait(0x381dc0, 0x72, 0x0)
    C:/Users/ADMINI~1/AppData/Local/Temp/2/makerelease686069423/go/src/pkg/runtime/netpoll.goc:146 +0x6d
net.(*pollDesc).Wait(0xc082080170, 0x72, 0x0, 0x0)
    D:/Go/src/pkg/net/fd_poll_runtime.go:84 +0x4d
net.(*ioSrv).ExecIO(0xc082038078, 0xc082080060, 0x750910, 0x8, 0xc082000980,
0xc082080480, 0x0, 0x0)
    D:/Go/src/pkg/net/fd_windows.go:188 +0x242
net.(*netFD).acceptOne(0xc082080000, 0x7e6298, 0xc08205a1c0, 0x2, 0x2, 0xc082080060,
0x7167a0, 0x0, 0x0)
    D:/Go/src/pkg/net/fd_windows.go:539 +0x3c7
net.(*netFD).accept(0xc082080000, 0x7e6298, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/net/fd_windows.go:566 +0x187
net.(*TCPListener).AcceptTCP(0xc0820380d8, 0x45e0ca, 0x0, 0x0)
    D:/Go/src/pkg/net/tcpsock_posix.go:234 +0x64
net/http.tcpKeepAliveListener.Accept(0xc0820380d8, 0x0, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/net/http/server.go:1947 +0x52
net/http.(*Server).Serve(0xc08200e5a0, 0x381f48, 0xc0820380d8, 0x0, 0x0)
    D:/Go/src/pkg/net/http/server.go:1698 +0x98
net/http.(*Server).ListenAndServe(0xc08200e5a0, 0x0, 0x0)
    D:/Go/src/pkg/net/http/server.go:1688 +0x154
net/http.ListenAndServe(0x7325f0, 0x5, 0x0, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/net/http/server.go:1778 +0x80
created by main.main
    D:/workspace/beetalk_server/go_projects/src/garena.com/TestSMS/TestSMS.go:45 +0x59
goroutine 45 [IO wait]:
net.runtime_pollWait(0x381e70, 0x72, 0x0)
    C:/Users/ADMINI~1/AppData/Local/Temp/2/makerelease686069423/go/src/pkg/runtime/netpoll.goc:146 +0x6d
net.(*pollDesc).Wait(0xc0820802f0, 0x72, 0x0, 0x0)
    D:/Go/src/pkg/net/fd_poll_runtime.go:84 +0x4d
net.(*ioSrv).ExecIO(0xc082038078, 0xc0820801e0, 0x73ab90, 0x7, 0x7e6228, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/net/fd_windows.go:188 +0x242
net.(*netFD).Read(0xc082080180, 0xc082070000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/net/fd_windows.go:451 +0x156
net.(*conn).Read(0xc082038060, 0xc082070000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/net/net.go:122 +0xee
net/http.(*liveSwitchReader).Read(0xc0820482a8, 0xc082070000, 0x1000, 0x1000, 0x0, 0x0,
0x0)
    D:/Go/src/pkg/net/http/server.go:206 +0xb6
io.(*LimitedReader).Read(0xc0820053a0, 0xc082070000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/io/io.go:399 +0xd7
bufio.(*Reader).fill(0xc08200ee40)
    D:/Go/src/pkg/bufio/bufio.go:97 +0x1ba
bufio.(*Reader).ReadSlice(0xc08200ee40, 0xc08203e00a, 0x0, 0x0, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/bufio/bufio.go:298 +0x233
bufio.(*Reader).ReadLine(0xc08200ee40, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/bufio/bufio.go:326 +0x70
net/textproto.(*Reader).readLineSlice(0xc08201ae10, 0x0, 0x0, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/net/textproto/reader.go:55 +0xa4
net/textproto.(*Reader).ReadLine(0xc08201ae10, 0x0, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/net/textproto/reader.go:36 +0x55
net/http.ReadRequest(0xc08200ee40, 0xc08201ef70, 0x0, 0x0)
    D:/Go/src/pkg/net/http/request.go:556 +0xce
net/http.(*conn).readRequest(0xc082048280, 0x0, 0x0, 0x0)
    D:/Go/src/pkg/net/http/server.go:577 +0x27d
net/http.(*conn).serve(0xc082048280)
    D:/Go/src/pkg/net/http/server.go:1132 +0x625
created by net/http.(*Server).Serve
    D:/Go/src/pkg/net/http/server.go:1721 +0x31a
goroutine 33 [chan receive, 6 minutes]:
net/http.(*persistConn).readLoop(0xc08203e420)
    D:/Go/src/pkg/net/http/transport.go:798 +0x312
created by net/http.(*Transport).dialConn
    D:/Go/src/pkg/net/http/transport.go:600 +0x946
goroutine 39 [chan receive, 3 minutes]:
net/http.(*persistConn).readLoop(0xc08203e6e0)
    D:/Go/src/pkg/net/http/transport.go:798 +0x312
created by net/http.(*Transport).dialConn
    D:/Go/src/pkg/net/http/transport.go:600 +0x946
@bradfitz

This comment has been minimized.

Copy link
Member

commented Dec 4, 2014

Comment 10:

That is neither complete, nor minimal. I can't run it and see the problem because it's
not complete. And it has a bunch of unrelated stuff still in it.
I suggest taking this to the golang-nuts@ mailing list where others can help you debug.
This feels like the wrong venue.
@gopherbot

This comment has been minimized.

Copy link
Author

commented Dec 5, 2014

Comment 11 by ronee.9:

Sorry for that. I cannot provide a runnable code, because it is related to a commercial
account. And I only see this problem when I am post msg to this remote site (which is
provide by other company). I will try to reproduce this problem by building a simple
client and server and talking this to golang-nuts. Thanks for the reply
@gopherbot

This comment has been minimized.

Copy link
Author

commented Dec 5, 2014

Comment 12 by ronee.9:

OK, finally find out the reason: it is caused by
this code: output, _ := httputil.DumpRequestOut(req, true). I guess there is some issue
while this function reads from the Reader. We should only use this in debug, not in
product:)
when I comment out this code, the problem solved.
@gopherbot

This comment has been minimized.

Copy link
Author

commented Dec 5, 2014

Comment 13 by ronee.9:

Yes, confirmed, it is a leak in httputil.DumpRequestOut. This issue is claimed been
closed by revision 490c2d4fda2b.
However, it still exist in latest go version, and that is the exact reason for my
problem. The test code is here: http://play.golang.org/p/D77HaPiS_3
we can see 10 can receive block at
0x9f920 net/http.(*persistConn).readLoop+0x420  /tmp/sandbox/go/src/pkg/net/http/transport.go:798
We can continue this issue at https://golang.org/issue/7869

@bradfitz bradfitz modified the milestone: Go1.5 Dec 16, 2014

@bradfitz bradfitz removed the release-go1.5 label Dec 16, 2014

@golang golang locked and limited conversation to collaborators Jun 25, 2016

This issue was closed.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
You can’t perform that action at this time.