net/http/httputil: TestDumpRequest failure

[alberts]

What steps will reproduce the problem?

We have been building and running the tests at tip (currently at 221d98ac4a51) with
GOMAXPROCS=16 for the past few days.

The following failure just popped out for the first time:

FAIL    net/http/httputil   0.015s
2012/01/16 10:41:29 Unsolicited response received on idle HTTP channel starting with
"H"; err=<nil>
throw: all goroutines are asleep - deadlock!

goroutine 1 [chan receive]:
testing.RunTests(0x400c00, 0x6dc0d8, 0x300000003, 0x1, 0x6d96c0, ...)
    /var/lib/jenkins/jobs/go/workspace/src/pkg/testing/testing.go:302 +0x795
testing.Main(0x400c00, 0x6dc0d8, 0x300000003, 0x6ed170, 0x0, ...)
    /var/lib/jenkins/jobs/go/workspace/src/pkg/testing/testing.go:237 +0x62
main.main()
    /tmp/go-build556240328/net/http/httputil/_test/_testmain.go:47 +0x91

goroutine 3 [chan receive]:
net/http.(*persistConn).roundTrip(0xf84005e0c0, 0xf8400178f0, 0x0, 0x0, 0x0, ...)
    /var/lib/jenkins/jobs/go/workspace/src/pkg/net/http/transport.go:642 +0x284
net/http.(*Transport).RoundTrip(0xf840033f80, 0xf8400189a0, 0xf840024360, 0x0, 0x0, ...)
    /var/lib/jenkins/jobs/go/workspace/src/pkg/net/http/transport.go:158 +0x333
net/http/httputil.DumpRequestOut(0xf8400189a0, 0x426b01, 0x0, 0x0, 0x0, ...)
    /var/lib/jenkins/jobs/go/workspace/src/pkg/net/http/httputil/dump.go:75 +0x1a1
net/http/httputil.TestDumpRequest(0xf840000c40, 0xb967de0)
    /var/lib/jenkins/jobs/go/workspace/src/pkg/net/http/httputil/dump_test.go:109 +0x356
testing.tRunner(0xf840000c40, 0x6dc0f0, 0x0, 0x0)
    /var/lib/jenkins/jobs/go/workspace/src/pkg/testing/testing.go:226 +0x5f
created by testing.RunTests
    /var/lib/jenkins/jobs/go/workspace/src/pkg/testing/testing.go:301 +0x772

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

6g

Which operating system are you using?

linux

Which revision are you using?  (hg identify)

tip

Please provide any additional information below.

GOMAXPROCS=16

[bradfitz]

Comment 1:

That's the first time that first byte ("H") was useful.  It suggests some HTTP response
is actually coming back.  I should make it read a bit more and log it in that case.
I'll try to reproduce with GOMAXPROCS=16 in a loop.

Owner changed to @bradfitz.

Status changed to Accepted.

[rsc]

Comment 2:

Labels changed: added priority-go1, removed priority-triage.

[bradfitz]

Comment 3:

I wouldn't be surprised if this bug was fixed by the same fix in
http://code.google.com/p/go/source/detail?r=f57165f82
I'm going to close this for now, but please re-open if you see this again!

Status changed to Duplicate.

[alberts]

Comment 4:

This is still happening with tip:
2012/02/01 04:02:15 Unsolicited response received on idle HTTP channel starting with
"H"; err=<nil>
throw: all goroutines are asleep - deadlock!
goroutine 1 [chan receive]:
testing.RunTests(0x400c00, 0x6e30e8, 0x300000003, 0x1, 0x6e06b0, ...)
go/workspace/src/pkg/testing/testing.go:330 +0x791
testing.Main(0x400c00, 0x6e30e8, 0x300000003, 0x6f41a0, 0x0, ...)
go/workspace/src/pkg/testing/testing.go:265 +0x62
main.main()
/tmp/go-build326991940/net/http/httputil/_test/_testmain.go:47 +0x91
goroutine 3 [chan receive]:
net/http.(*persistConn).roundTrip(0xf84005e120, 0xf8400178f0, 0x0, 0x0, 0x0, ...)
go/workspace/src/pkg/net/http/transport.go:641 +0x33a
net/http.(*Transport).RoundTrip(0xf84002af80, 0xf840019f00, 0xf84001b360, 0x0, 0x0, ...)
go/workspace/src/pkg/net/http/transport.go:158 +0x32f
net/http/httputil.DumpRequestOut(0xf840019f00, 0x427101, 0x0, 0x0, 0x0, ...)
go/workspace/src/pkg/net/http/httputil/dump.go:76 +0x1a1
net/http/httputil.TestDumpRequest(0xf840055000, 0x5ae9318)
go/workspace/src/pkg/net/http/httputil/dump_test.go:109 +0x356
testing.tRunner(0xf840055000, 0x6e3100, 0x0, 0x0)
go/workspace/src/pkg/testing/testing.go:254 +0x6f
created by testing.RunTests
go/workspace/src/pkg/testing/testing.go:329 +0x76e
FAIL    net/http/httputil   0.053s

[bradfitz]

Comment 5:

Okay, I can reproduce on Linux now.
bradfitz@gopher:~/go/src/pkg/net/http/httputil$ export GOMAXPROCS=16
bradfitz@gopher:~/go/src/pkg/net/http/httputil$ while go test -v; do echo pass; done
....
=== RUN TestDumpRequest-16
2012/02/01 10:13:33 Unsolicited response received on idle HTTP channel starting with
"H"; err=<nil>
throw: all goroutines are asleep - deadlock!
goroutine 1 [chan receive]:
testing.RunTests(0x400c00, 0x6e30e8, 0x300000003, 0x1, 0x6e06b0, ...)
    /usr/local/google/home/bradfitz/go/src/pkg/testing/testing.go:330 +0x791
testing.Main(0x400c00, 0x6e30e8, 0x300000003, 0x6f41a0, 0x0, ...)
    /usr/local/google/home/bradfitz/go/src/pkg/testing/testing.go:265 +0x62
main.main()
    /tmp/go-build710017555/net/http/httputil/_test/_testmain.go:47 +0x91
goroutine 3 [chan receive]:
net/http.(*persistConn).roundTrip(0xf84005d120, 0xf8400178f0, 0x0, 0x0, 0x0, ...)
    /usr/local/google/home/bradfitz/go/src/pkg/net/http/transport.go:641 +0x33a
net/http.(*Transport).RoundTrip(0xf840033340, 0xf840019f00, 0xf84001b360, 0x0, 0x0, ...)
    /usr/local/google/home/bradfitz/go/src/pkg/net/http/transport.go:158 +0x32f
net/http/httputil.DumpRequestOut(0xf840019f00, 0x427101, 0x0, 0x0, 0x0, ...)
    /usr/local/google/home/bradfitz/go/src/pkg/net/http/httputil/dump.go:76 +0x1a1
net/http/httputil.TestDumpRequest(0xf840000cb0, 0x13bbc5e8)
    /usr/local/google/home/bradfitz/go/src/pkg/net/http/httputil/dump_test.go:109 +0x356
testing.tRunner(0xf840000cb0, 0x6e3100, 0x0, 0x0)
    /usr/local/google/home/bradfitz/go/src/pkg/testing/testing.go:254 +0x6f
created by testing.RunTests
    /usr/local/google/home/bradfitz/go/src/pkg/testing/testing.go:329 +0x76e
exit status 2
FAIL    net/http/httputil   0.010s
I'll look into this.

Status changed to Accepted.

[bradfitz]

Comment 6:

Fix:
http://golang.org/cl/5614043

Status changed to Started.

[bradfitz]

Comment 7:

This issue was closed by revision b293533.

Status changed to Fixed.