net/http: Transport leaks goroutines when request.ContentLength is explicitly short

[gopherbot]

by zarcardfly:

Before filing a bug, please check whether it has been fixed since the
latest release. Search the issue tracker and check that you're running the
latest version of Go:

Run "go version" and compare against
http://golang.org/doc/devel/release.html  If a newer version of Go exists,
install it and retry what you did to reproduce the problem.

Thanks.

What steps will reproduce the problem?
If possible, include a link to a program on play.golang.org.
  1. sample code: http://play.golang.org/p/IKPtSqNs53
  2. I call http.Client.Do with a http.Request whose ContentLength is unequal to the posted body's length.
  3. http.Client.Do failed as assume, but the readLoop() goruntine is still running, it hang up at : 558            rc := <-pc.reqch
  4. I check the net/http/transport.go code:
   669      pc.lk.Lock()
   670      pc.numExpectedResponses++
   671      pc.lk.Unlock()
   672  
   673      err = req.Request.write(pc.bw, pc.isProxy, req.extra)
   674      if err != nil {
   675          pc.close()
   676          return
   677      }
   678      pc.bw.Flush()
   679  
   680      ch := make(chan responseAndError, 1)
   681      pc.reqch <- requestAndChan{req.Request, ch, requestedGzip}
   682      re := <-ch
   683      pc.lk.Lock()
   684      pc.numExpectedResponses--
   685      pc.lk.Unlock() 
  when 673 failed, the function returned without dec numExpectedResponses.
   544          pb, err := pc.br.Peek(1)
   545  
   546          pc.lk.Lock()
   547          if pc.numExpectedResponses == 0 {
   548              pc.closeLocked()
   549              pc.lk.Unlock()
   550              if len(pb) > 0 {
   551                  log.Printf("Unsolicited response received on idle HTTP channel starting with %q; err=%v",
   552                      string(pb), err)
   553              }
   554              return
   555          }
   556          pc.lk.Unlock()
   557  
   558          rc := <-pc.reqch
  And the result of line 547 is false, and then the goroutine block in 558.

What is the expected output?
  the number of goroutine is a small number, such as 5.

What do you see instead?
  the number of goroutine is more than 20.

Which compiler are you using (5g, 6g, 8g, gccgo)?
  6g

Which operating system are you using?
  mac os x 10.8

Which version are you using?  (run 'go version')
  I found it in an old version go, but I check the 'http://golang.org/src/pkg/net/http/transport.go', it still being there.

Please provide any additional information below.
 Tell me if I miss something, thank you, and sorry for my poor english.

[bradfitz]

Comment 1:

You said:
> but I check the 'http://golang.org/src/pkg/net/http/transport.go', it still being
there.
But that is not the latest code.
Much has changed in this code.
Please try to reproduce with the tip version. "hg update default; cd src; ./all.bash",
etc.
See http://golang.org/doc/install/source

Status changed to WaitingForReply.

[gopherbot]

Comment 2 by zarcardfly:

hi, I try as your recommended:
    hg clone -u release https://code.google.com/p/go
    cd go
    hg update default
    cd src
    ./all.bash
I checked the code version:
~/hg/go $ hg summary
parent: 15135:7e135713451d tip
 src: gofmt -w -s
branch: default
commit: 1 modified
update: (current)
And I run my program ‘http://play.golang.org/p/IKPtSqNs53’, the problem still exists.
The number of goroutines is more than 40 now, and the connections are 'leaking' too.
I checked the code and debuged with gdb, here is my preliminary analysis:
There are two goroutines for a new created persistConn.
The reader goroutine is stuck in readLoop():559:
557 
558         for alive {
559                 pb, err := pc.br.Peek(1)
560 
561                 pc.lk.Lock()
The writer goroutine is stuck in writeLoop():661:
660         for {
661                 select {
662                 case wr := <-pc.writech:
In my code, line 667 returned a none nil err 'http: Request.ContentLength=3 with Body
length 5', the 'pc' was maked broken, and pc.bw was't flushed, so line 559 in reader
goroutine would never returned. The writer goroutine go back to line 661, and stuck
there. 
667                         err := wr.req.Request.write(pc.bw, pc.isProxy, wr.req.extra)
668                         if err == nil {
669                                 err = pc.bw.Flush()
670                         }
671                         if err != nil {
672                                 pc.markBroken()
673                         }       
674                         wr.ch <- err
Because the persistConn was new created or picked from Transport.idleConn, no one could
obtain it again, it was 'leaked', with two goroutines and one connection.

[bradfitz]

Comment 3:

Thanks for confirming with tip.
I've changed the summary of this bug.

Owner changed to @bradfitz.

Status changed to Accepted.

[bradfitz]

Comment 4:

Fix out for review: https://golang.org/cl/6937069

Status changed to Started.

[bradfitz]

Comment 5:

This issue was closed by revision 7c3577e.

Status changed to Fixed.

[gopherbot]

Comment 6 by ibilicc:

6842 @ 0x41a716 0x4080d4 0x407d22 0x488021 0x41a8e0
#   0x4080d4    selectgo+0x384              /usr/local/go/src/pkg/runtime/chan.c:996
#   0x407d22    runtime.selectgo+0x12           /usr/local/go/src/pkg/runtime/chan.c:840
#   0x488021    net/http.(*persistConn).writeLoop+0x271 /usr/local/go/src/pkg/net/http/transport.go:791
6811 @ 0x41a716 0x4072d2 0x407718 0x4879cf 0x41a8e0
#   0x4879cf    net/http.(*persistConn).readLoop+0x68f  /usr/local/go/src/pkg/net/http/transport.go:778
when my program runs several hours, there're thousands writeLoop and readLoop goroutings
dangling around, i think somewhere someplace transport still leaking...

[bradfitz]

Comment 7:

Old bugs are not the right place for discussion. Please ask on golang-nuts and I or
somebody else will answer your question.

[gopherbot]

Comment 8 by ibilicc:

I've posted a topic on go-nuts
https://groups.google.com/forum/#!topic/golang-nuts/FnJZ9iZ0i_g, thanks for your reply.