net/http: TestStreamingGet timeout on Windows 7 #2651

gopherbot · 2012-01-04T00:31:02Z

by reddooots:

What steps will reproduce the problem?
run "gotest -test.short -test.v -test.timeout=120 -test.run=TestStream" in
net/http

What is the expected output?
The test to pass

What do you see instead?
$ gotest -test.short -test.v -test.timeout=120 -test.run=TestStream
rm -f _test/net/http.a
rm -f _test/net/http.a
gopack grc _test/net/http.a _gotest_.8
=== RUN http_test.TestStreamingGet
panic: test timed out

goroutine 9 [running]:
testing.alarm()
        c:/Users/Jared/MinGW/go/src/pkg/testing/testing.go:362 +0x43
created by time.goFunc
        c:/Users/Jared/MinGW/go/src/pkg/time/sleep.go:94 +0x41

goroutine 1 [chan receive]:
testing.RunTests(0x401000, 0x715450, 0x5e, 0x5e, 0x1b1701, ...)
        c:/Users/Jared/MinGW/go/src/pkg/testing/testing.go:276 +0x663
testing.Main(0x401000, 0x715450, 0x5e, 0x5e, 0x704a84, ...)
        c:/Users/Jared/MinGW/go/src/pkg/testing/testing.go:211 +0x48
main.main()
        c:/Users/Jared/MinGW/go/src/pkg/net/http/_testmain.go:124 +0x50

goroutine 2 [timer goroutine (idle)]:
created by addtimer
        c:/Users/Jared/MinGW/go/src/pkg/runtime/ztime_386.c:68

goroutine 3 [chan receive]:
net/http.(*persistConn).roundTrip(0x124d44c0, 0x124df740, 0x0, 0x0, 0x0, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/transport.go:642 +0x220
net/http.(*Transport).RoundTrip(0x124d1420, 0x124f8720, 0x16, 0x0, 0x0, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/transport.go:158 +0x19f
net/http.send(0x124f8720, 0x124e2e40, 0x124d1420, 0x0, 0x0, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/client.go:128 +0x19c
net/http.(*Client).doFollowingRedirects(0x124f9240, 0x124f8720, 0x0, 0x0, 0x0, .
..)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/client.go:222 +0x43c
net/http.(*Client).Get(0x124f9240, 0x124f9200, 0x16, 0x124f90c0, 0x0, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/client.go:171 +0x85
c:/Users/Jared/MinGW/go/src/pkg/net/http/_xtest_.TestStreamingGet(0x124d4540, 0x
e)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/client_test.go:251 +0x103
testing.tRunner(0x124d4540, 0x7154a4, 0x0)
        c:/Users/Jared/MinGW/go/src/pkg/testing/testing.go:198 +0x45
created by testing.RunTests
        c:/Users/Jared/MinGW/go/src/pkg/testing/testing.go:275 +0x646

goroutine 4 [syscall]:
syscall.Syscall6(0x76ced38b, 0x5, 0xdc, 0x124d3a60, 0x124df7a8, ...)
        c:/Users/Jared/MinGW/go/src/pkg/runtime/zsyscall_windows_386.c:96 +0x49
syscall.GetQueuedCompletionStatus(0xdc, 0x124d3a60, 0x124df7a8, 0x124df7a0, 0xff
ffffff, ...)
        c:/Users/Jared/MinGW/go/src/pkg/syscall/zsyscall_windows_386.go:463 +0x7
6
net.(*resultSrv).Run(0x124df6e0, 0x0)
        c:/Users/Jared/MinGW/go/src/pkg/net/fd_windows.go:112 +0x86
created by net.startServer
        c:/Users/Jared/MinGW/go/src/pkg/net/fd_windows.go:209 +0xf1

goroutine 5 [select]:
net.(*ioSrv).ProcessRemoteIO(0x124df6e8, 0x0)
        c:/Users/Jared/MinGW/go/src/pkg/net/fd_windows.go:143 +0x183
created by net.startServer
        c:/Users/Jared/MinGW/go/src/pkg/net/fd_windows.go:214 +0x171

goroutine 6 [chan receive]:
net.(*ioSrv).ExecIO(0x124df6e8, 0x124f9c20, 0x124e0360, 0x0, 0x0, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/fd_windows.go:189 +0x349
net.(*netFD).accept(0x124e7c00, 0x4b79ed, 0x0, 0x0, 0x0, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/fd_windows.go:523 +0x24a
net.(*TCPListener).AcceptTCP(0x124df708, 0x410f41, 0x0, 0x0)
        c:/Users/Jared/MinGW/go/src/pkg/net/tcpsock_posix.go:268 +0x55
net.(*TCPListener).Accept(0x124df708, 0x0, 0x0, 0x0, 0x0, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/tcpsock_posix.go:278 +0x38
net/http/httptest.(*historyListener).Accept(0x124f91c0, 0x0, 0x0, 0x0, 0x0, ...)

        c:/Users/Jared/MinGW/go/src/pkg/net/http/httptest/server.go:38 +0x48
net/http.(*Server).Serve(0x124d17e0, 0x124f91e0, 0x124f91c0, 0x0, 0x0, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/server.go:983 +0x56
created by net/http/httptest.(*Server).Start
        c:/Users/Jared/MinGW/go/src/pkg/net/http/httptest/server.go:96 +0x173

goroutine 7 [chan receive]:
net.(*ioSrv).ExecIO(0x124df6e8, 0x124f9660, 0x124d1b70, 0x0, 0x0, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/fd_windows.go:189 +0x349
net.(*netFD).Read(0x124e7b80, 0x12501000, 0x1000, 0x1000, 0x0, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/fd_windows.go:360 +0x15f
net.(*TCPConn).Read(0x124df768, 0x12501000, 0x1000, 0x1000, 0x124df598, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/tcpsock_posix.go:74 +0x7a
bufio.(*Reader).fill(0x124d1990, 0x415bdb)
        c:/Users/Jared/MinGW/go/src/pkg/bufio/bufio.go:98 +0x114
bufio.(*Reader).Peek(0x124d1990, 0x1, 0x0, 0x0)
        c:/Users/Jared/MinGW/go/src/pkg/bufio/bufio.go:123 +0x8a
net/http.(*persistConn).readLoop(0x124d44c0, 0x0)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/transport.go:521 +0x77
created by net/http.(*Transport).getConn
        c:/Users/Jared/MinGW/go/src/pkg/net/http/transport.go:376 +0x417

goroutine 8 [chan receive]:
c:/Users/Jared/MinGW/go/src/pkg/net/http/_xtest_._func_003(0x124df6c8, 0x4234d5,
 0x124f99a0, 0x124fd150)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/client_test.go:243 +0x6f
net/http.HandlerFunc.ServeHTTP(0x124f90a0, 0x124f99a0, 0x124fd150, 0x12505000, 0
x124fd150, ...)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/server.go:688 +0x34
net/http.(*conn).serve(0x124fd1b0, 0x0)
        c:/Users/Jared/MinGW/go/src/pkg/net/http/server.go:654 +0x428
created by net/http.(*Server).Serve
        c:/Users/Jared/MinGW/go/src/pkg/net/http/server.go:1001 +0x216
gotest: "./8.out.exe -test.short=true -test.v=true -test.timeout=120 -test.run=T
estStream" failed: exit status 2

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

Which operating system are you using?
Windows 7 64-bit

Which revision are you using?  (hg identify)
4a8268927758 weekly/weekly.2011-12-22

Please provide any additional information below.
export USE_GO_TOOL=false was used to build go if it matters.

alexbrainman · 2012-01-04T01:05:27Z

Comment 1:

I just noticed, there are some reports:
https://golang.org/issue/2616
https://golang.org/issue/2645
that are similar to yours. I suggest you monitor these. I suspect they will help with
your problem.
Alex

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

Owner changed to @alexbrainman.

Status changed to Accepted.

rsc · 2012-01-24T05:02:26Z

Comment 2:

Dup of issue #2616?

rsc · 2012-01-24T06:04:24Z

Comment 3:

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

gopherbot · 2012-01-26T01:08:30Z

Comment 4 by reddooots:

Tested again after issue #2616 was fixed and testing net/http is still hanging on
TestStreamingGet.
$ hg id
7de66de3961c tip
Since the first report I have moved to 6g and using the go tool.

alexbrainman · 2012-02-02T06:28:55Z

Comment 5:

I can't reproduce your problem on the latest (hg id 4f4b60443318). I am using
windows-386, but I tried it on both 32bit and 64bit versions of Windows. Is it possible
for you to try it on different pc? Just build the test and copy it somewhere else and
run. If it works, perhaps you pc is configured in a particular way that triggers this
bug. It would be nice to know how.
I am also ccing Brad. Perhaps he has some ideas.
Alex

gopherbot · 2012-02-03T07:17:16Z

Comment 6 by reddooots:

I setup a fresh 32bit MinGW, got weekly.2012-01-27, and built the test on the Windows 7
box and ran it on a 32bit xp box and it ran fine.  The Windows 7 box got stuck at
TestStreamingGet.  I also updated to tip (hg id a3a707ba21f5) and tested the Windows 7
box again and it still gets stuck on TestStreamingGet (windows-386 again).
Before issue #2616 was fixed I had tried the normal windows trouble shooting steps,
update drivers, use an admin account, disable anti-virus and firewall, and probably some
stuff I forgot and every time I got stuck at TestStreamingGet.

gopherbot · 2012-02-05T07:44:37Z

Comment 7 by reddooots:

Well I decided to see if any other tests failed and commented out TestStreamingGet in
client_test.go.  Is there a better way to skip tests?
TestServerExpect times out
TestRoundTripGzip fails with "panic: runtime error: invalid memory address or nil
pointer dereference [recovered]"
and here is the output from go test after commenting out the above tests.
FAIL    net/http    3.115s
=== RUN TestChunk
--- PASS: TestChunk (0.00 seconds)
=== RUN TestWriteSetCookies
--- PASS: TestWriteSetCookies (0.00 seconds)
=== RUN TestSetCookie
--- PASS: TestSetCookie (0.00 seconds)
=== RUN TestAddCookie
--- PASS: TestAddCookie (0.00 seconds)
=== RUN TestReadSetCookies
--- PASS: TestReadSetCookies (0.00 seconds)
=== RUN TestReadCookies
--- PASS: TestReadCookies (0.00 seconds)
=== RUN TestHeaderWrite
--- PASS: TestHeaderWrite (0.00 seconds)
=== RUN TestSplitFieldValue
--- PASS: TestSplitFieldValue (0.00 seconds)
=== RUN TestUseProxy
--- PASS: TestUseProxy (0.00 seconds)
=== RUN TestParseRange
--- PASS: TestParseRange (0.00 seconds)
=== RUN TestReadRequest
--- PASS: TestReadRequest (0.00 seconds)
=== RUN TestRequestWrite
--- PASS: TestRequestWrite (0.01 seconds)
=== RUN TestRequestWriteClosesBody
--- PASS: TestRequestWriteClosesBody (0.00 seconds)
=== RUN TestReadResponse
--- PASS: TestReadResponse (0.00 seconds)
=== RUN TestReadResponseCloseInMiddle
--- PASS: TestReadResponseCloseInMiddle (0.14 seconds)
=== RUN TestLocationResponse
--- PASS: TestLocationResponse (0.00 seconds)
=== RUN TestResponseWrite
--- PASS: TestResponseWrite (0.00 seconds)
=== RUN TestClient
--- PASS: TestClient (0.02 seconds)
=== RUN TestClientHead
--- PASS: TestClientHead (0.00 seconds)
=== RUN TestGetRequestFormat
--- PASS: TestGetRequestFormat (0.00 seconds)
=== RUN TestPostRequestFormat
--- PASS: TestPostRequestFormat (0.00 seconds)
=== RUN TestPostFormRequestFormat
--- PASS: TestPostFormRequestFormat (0.00 seconds)
=== RUN TestRedirects
--- PASS: TestRedirects (0.18 seconds)
=== RUN TestRedirectCookiesOnRequest
--- PASS: TestRedirectCookiesOnRequest (0.00 seconds)
=== RUN TestRedirectCookiesJar
--- PASS: TestRedirectCookiesJar (0.09 seconds)
    client_test.go:308: Received cookies: [ChocolateChip=tasty First=Hit Second=Hit]
=== RUN TestClientWrites
--- PASS: TestClientWrites (0.00 seconds)
=== RUN TestClientInsecureTransport
--- PASS: TestClientInsecureTransport (0.08 seconds)
=== RUN TestClientErrorWithRequestURI
--- PASS: TestClientErrorWithRequestURI (0.00 seconds)
=== RUN TestFileTransport
--- PASS: TestFileTransport (0.03 seconds)
=== RUN TestServeFile
--- PASS: TestServeFile (0.01 seconds)
=== RUN TestFSRedirect
--- PASS: TestFSRedirect (0.08 seconds)
=== RUN TestFileServerCleans
--- PASS: TestFileServerCleans (0.00 seconds)
=== RUN TestFileServerImplicitLeadingSlash
--- PASS: TestFileServerImplicitLeadingSlash (0.08 seconds)
=== RUN TestDirJoin
--- PASS: TestDirJoin (0.00 seconds)
    fs_test.go:180: skipping test; no /etc/hosts file
=== RUN TestEmptyDirOpenCWD
--- PASS: TestEmptyDirOpenCWD (0.00 seconds)
=== RUN TestServeFileContentType
--- PASS: TestServeFileContentType (0.01 seconds)
=== RUN TestServeFileMimeType
--- PASS: TestServeFileMimeType (0.00 seconds)
=== RUN TestServeFileFromCWD
--- PASS: TestServeFileFromCWD (0.00 seconds)
=== RUN TestServeFileWithContentEncoding
--- FAIL: TestServeFileWithContentEncoding (0.01 seconds)
    fs_test.go:287: Content-Length mismatch: got 11, want -1
=== RUN TestServeIndexHtml
--- PASS: TestServeIndexHtml (0.08 seconds)
=== RUN TestQuery
--- PASS: TestQuery (0.00 seconds)
=== RUN TestPostQuery
--- PASS: TestPostQuery (0.00 seconds)
=== RUN TestParseFormUnknownContentType
--- PASS: TestParseFormUnknownContentType (0.00 seconds)
=== RUN TestMultipartReader
--- PASS: TestMultipartReader (0.00 seconds)
=== RUN TestRedirect
--- PASS: TestRedirect (0.00 seconds)
=== RUN TestSetBasicAuth
--- PASS: TestSetBasicAuth (0.00 seconds)
=== RUN TestMultipartRequest
--- PASS: TestMultipartRequest (0.00 seconds)
=== RUN TestMultipartRequestAuto
--- PASS: TestMultipartRequestAuto (0.00 seconds)
=== RUN TestEmptyMultipartRequest
--- PASS: TestEmptyMultipartRequest (0.00 seconds)
=== RUN TestRequestMultipartCallOrder
--- PASS: TestRequestMultipartCallOrder (0.00 seconds)
=== RUN TestConsumingBodyOnNextConn
--- PASS: TestConsumingBodyOnNextConn (0.00 seconds)
=== RUN TestHostHandlers
--- PASS: TestHostHandlers (0.01 seconds)
=== RUN TestMuxRedirectLeadingSlashes
--- PASS: TestMuxRedirectLeadingSlashes (0.00 seconds)
=== RUN TestServerTimeouts
--- PASS: TestServerTimeouts (0.26 seconds)
=== RUN TestIdentityResponse
--- PASS: TestIdentityResponse (0.01 seconds)
=== RUN TestServeHTTP10Close
--- PASS: TestServeHTTP10Close (0.00 seconds)
=== RUN TestHandlersCanSetConnectionClose11
--- PASS: TestHandlersCanSetConnectionClose11 (0.00 seconds)
=== RUN TestHandlersCanSetConnectionClose10
--- PASS: TestHandlersCanSetConnectionClose10 (0.00 seconds)
=== RUN TestSetsRemoteAddr
--- PASS: TestSetsRemoteAddr (0.00 seconds)
=== RUN TestChunkedResponseHeaders
--- FAIL: TestChunkedResponseHeaders (0.00 seconds)
    serve_test.go:468: expected ContentLength of -1; got 24
    serve_test.go:471: expected TransferEncoding of [chunked]; got []
    serve_test.go:474: Unexpected Content-Length
=== RUN Test304Responses
--- PASS: Test304Responses (0.00 seconds)
=== RUN TestHeadResponses
--- PASS: TestHeadResponses (0.00 seconds)
=== RUN TestTLSHandshakeTimeout
--- PASS: TestTLSHandshakeTimeout (0.30 seconds)
=== RUN TestTLSServer
--- PASS: TestTLSServer (0.08 seconds)
=== RUN TestServerUnreadRequestBodyLittle
--- PASS: TestServerUnreadRequestBodyLittle (0.00 seconds)
=== RUN TestServerUnreadRequestBodyLarge
--- PASS: TestServerUnreadRequestBodyLarge (0.00 seconds)
=== RUN TestTimeoutHandler
--- PASS: TestTimeoutHandler (0.08 seconds)
=== RUN TestRedirectMunging
--- PASS: TestRedirectMunging (0.00 seconds)
=== RUN TestZeroLengthPostAndResponse
--- PASS: TestZeroLengthPostAndResponse (0.01 seconds)
=== RUN TestHandlerPanic
--- PASS: TestHandlerPanic (0.01 seconds)
=== RUN TestHandlerPanicWithHijack
--- PASS: TestHandlerPanicWithHijack (0.01 seconds)
=== RUN TestNoDate
--- PASS: TestNoDate (0.00 seconds)
=== RUN TestStripPrefix
--- PASS: TestStripPrefix (0.00 seconds)
=== RUN TestRequestLimit
--- FAIL: TestRequestLimit (0.47 seconds)
    serve_test.go:991: Do: Get http://127.0.0.1:61369: WSARecv tcp 127.0.0.1:61370: An existing connection was forcibly closed by the remote host.
=== RUN TestRequestBodyLimit
--- PASS: TestRequestBodyLimit (0.06 seconds)
=== RUN TestClientWriteShutdown
--- PASS: TestClientWriteShutdown (0.00 seconds)
=== RUN TestServerBufferedChunking
--- PASS: TestServerBufferedChunking (0.00 seconds)
    serve_test.go:1088: Skipping known broken test; see issue #2357
=== RUN TestAcceptMaxFds
--- PASS: TestAcceptMaxFds (0.00 seconds)
=== RUN TestDetectContentType
--- PASS: TestDetectContentType (0.00 seconds)
=== RUN TestServerContentType
--- PASS: TestServerContentType (0.09 seconds)
=== RUN TestContentTypeWithCopy
--- PASS: TestContentTypeWithCopy (0.08 seconds)
=== RUN TestSniffWriteSize
--- PASS: TestSniffWriteSize (0.08 seconds)
=== RUN TestTransportKeepAlives
--- PASS: TestTransportKeepAlives (0.01 seconds)
=== RUN TestTransportConnectionCloseOnResponse
--- PASS: TestTransportConnectionCloseOnResponse (0.01 seconds)
=== RUN TestTransportConnectionCloseOnRequest
--- PASS: TestTransportConnectionCloseOnRequest (0.00 seconds)
=== RUN TestTransportIdleCacheKeys
--- PASS: TestTransportIdleCacheKeys (0.00 seconds)
=== RUN TestTransportMaxPerHostIdleConns
--- PASS: TestTransportMaxPerHostIdleConns (0.00 seconds)
=== RUN TestTransportServerClosingUnexpectedly
--- PASS: TestTransportServerClosingUnexpectedly (0.03 seconds)
=== RUN TestStressSurpriseServerCloses
--- PASS: TestStressSurpriseServerCloses (0.00 seconds)
    transport_test.go:311: skipping test in short mode
=== RUN TestTransportHeadResponses
--- PASS: TestTransportHeadResponses (0.00 seconds)
=== RUN TestTransportHeadChunkedResponse
--- PASS: TestTransportHeadChunkedResponse (0.01 seconds)
=== RUN TestTransportGzip
--- PASS: TestTransportGzip (0.40 seconds)
=== RUN TestTransportProxy
--- PASS: TestTransportProxy (0.00 seconds)
=== RUN TestTransportGzipRecursive
--- PASS: TestTransportGzipRecursive (0.08 seconds)
=== RUN TestTransportAltProto
--- PASS: TestTransportAltProto (0.00 seconds)
FAIL
I tried to figure out why TestStreamingGet was getting stuck but just got confused on
how it could be timing out but TestRedirects is passing.

alexbrainman · 2012-02-05T10:17:58Z

Comment 8:

If I want to disable TestStreamingGet test, I would rename it to testStreamingGet or
anything else that does not start with Test...
Can you please run TestRoundTripGzip test and send us stack trace.
I think, you approach of trying to find solution yourself is the best. :-) Since you can
reliably reproduce all these problems, you should be able to put fmt.Printf statements
to see why it is happening and get to the bottom of it. Start with one problem and go
slowly small steps at the time. Make sure you understand what is suppose to happens, and
verify that it does, every step of the way. If you do not understand the code, just ask
here.
Thank you.
Alex

gopherbot · 2012-02-06T06:58:24Z

Comment 9 by reddooots:

Here is the stack trace.
FAIL    net/http    0.364s
=== RUN TestRoundTripGzip
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
    panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xc0000005 code=0x0 addr=0x250 pc=0x4ea243]
goroutine 2 [running]:
io/ioutil._func_001(0x232db0, 0x232100, 0x232fdc)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/io/ioutil/ioutil.go:29 +0xb6
----- stack segment boundary -----
compress/gzip.(*Decompressor).Read(0x0, 0x12402c00, 0x200, 0x200, 0x414ade, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/compress/gzip/gunzip.go:201 +0x3f
bytes.(*Buffer).ReadFrom(0x1242a960, 0x1242c0e0, 0x0, 0x0, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/bytes/buffer.go:150 +0x225
io/ioutil.readAll(0x1242c0e0, 0x0, 0x200, 0x0, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/io/ioutil/ioutil.go:32 +0xf1
io/ioutil.ReadAll(0x1242c0e0, 0x0, 0x0, 0x1242c0e0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/io/ioutil/ioutil.go:38 +0x3b
net/http_test.TestRoundTripGzip(0x12404680, 0xe)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/http/transport_test.go:464 +0x323
testing.tRunner(0x12404680, 0x7440a4, 0x0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/testing/testing.go:254 +0x70
created by testing.RunTests
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/testing/testing.go:329 +0x689
goroutine 1 [runnable]:
testing.RunTests(0x401000, 0x743c48, 0x62, 0x62, 0x231701, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/testing/testing.go:330 +0x6a9
testing.Main(0x401000, 0x743c48, 0x62, 0x62, 0x732a18, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/testing/testing.go:265 +0x48
main.main()
    C:/Users/Jared/AppData/Local/Temp/go-build587349394/net/http/_test/_testmain.go:241 +0x50
goroutine 3 [syscall]:
syscall.Syscall6(0x75f5d38b, 0x5, 0xc0, 0x12403a00, 0x124101b8, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/runtime/zsyscall_windows_386.c:96 +0x49
syscall.GetQueuedCompletionStatus(0xc0, 0x12403a00, 0x124101b8, 0x12410180, 0xffffffff,
...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/syscall/zsyscall_windows_386.go:463 +0x76
net.(*resultSrv).Run(0x12410680, 0x0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/fd_windows.go:112 +0x86
created by net.startServer
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/fd_windows.go:215 +0xfc
goroutine 4 [select]:
net.(*ioSrv).ProcessRemoteIO(0x12410678, 0x0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/fd_windows.go:143 +0x183
created by net.startServer
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/fd_windows.go:220 +0x17c
goroutine 5 [chan receive]:
net.(*ioSrv).ExecIO(0x12410678, 0x1242c820, 0x12437000, 0x0, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/fd_windows.go:195 +0x4a1
net.(*netFD).accept(0x12409bd0, 0x4e00b3, 0x0, 0x0, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/fd_windows.go:528 +0x27b
net.(*TCPListener).AcceptTCP(0x12410160, 0x40f5ab, 0x0, 0x0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/tcpsock_posix.go:269 +0x55
net.(*TCPListener).Accept(0x12410160, 0x0, 0x0, 0x0, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/tcpsock_posix.go:279 +0x38
net/http/httptest.(*historyListener).Accept(0x1240cde0, 0x0, 0x0, 0x0, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/http/httptest/server.go:38 +0x48
net/http.(*Server).Serve(0x124013f0, 0x1240cdc0, 0x1240cde0, 0x0, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/http/server.go:984 +0x66
created by net/http/httptest.(*Server).Start
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/http/httptest/server.go:96 +0x17e
goroutine 6 [chan receive]:
net/http.(*persistConn).readLoop(0x12404580, 0x0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/http/transport.go:588 +0x5d9
created by net/http.(*Transport).getConn
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/http/transport.go:375 +0x590
goroutine 7 [chan receive]:
net.(*ioSrv).ExecIO(0x12410678, 0x1242c8a0, 0x12401570, 0x0, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/fd_windows.go:195 +0x4a1
net.(*netFD).Read(0x12434000, 0x12435000, 0x1000, 0x1000, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/fd_windows.go:365 +0x15f
net.(*TCPConn).Read(0x124109c0, 0x12435000, 0x1000, 0x1000, 0x2a, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/tcpsock_posix.go:75 +0x8a
io.(*LimitedReader).Read(0x12433050, 0x12435000, 0x1000, 0x1000, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/io/io.go:382 +0xfb
bufio.(*Reader).fill(0x1242f630, 0x0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/bufio/bufio.go:98 +0x114
bufio.(*Reader).ReadSlice(0x1242f630, 0xb57d0a, 0x0, 0x0, 0x0, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/bufio/bufio.go:274 +0x1f2
bufio.(*Reader).ReadLine(0x1242f630, 0x0, 0x0, 0x0, 0x32721500, ...)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/bufio/bufio.go:300 +0x42
net/textproto.(*Reader).readLineSlice(0x1242c5e0, 0x4086f9, 0x8)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/textproto/reader.go:55 +0x3f
net/textproto.(*Reader).ReadLine(0x1242c5e0, 0x1242e150, 0x1242c5e0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/textproto/reader.go:36 +0x28
net/http.ReadRequest(0x1242f630, 0x1242e150, 0x0, 0x0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/http/request.go:457 +0x9b
net/http.(*conn).readRequest(0x1242f600, 0x12432100, 0x0, 0x0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/http/server.go:239 +0xb9
net/http.(*conn).serve(0x1242f600, 0x0)
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/http/server.go:593 +0x11d
created by net/http.(*Server).Serve
    C:/Users/Jared/MinGW/msys/1.0/home/Jared/go/src/pkg/net/http/server.go:1002 +0x2bb
I will keep working on it.

alexbrainman · 2012-02-06T08:12:16Z

Comment 10:

What is your Go version? Please, run "hg id" and post displayed value here. Thank you.
Alex

gopherbot · 2012-02-07T04:07:17Z

Comment 11 by reddooots:

1107a7d3cb07 weekly/weekly.2012-01-27 and still using windows-386.

alexbrainman · 2012-02-07T06:00:33Z

Comment 12:

Getting somewhere.
It looks like we are not checking errors in TestRoundTripGzip. That is why you are
getting "panic: runtime error: invalid memory address ...". Please, change the program
to NOT IGNORE ERRORS. Here is my diff:
diff -r 1107a7d3cb07 src/pkg/net/http/transport_test.go
--- a/src/pkg/net/http/transport_test.go    Fri Jan 27 17:51:53 2012 +1100
+++ b/src/pkg/net/http/transport_test.go    Tue Feb 07 16:53:50 2012 +1100
@@ -441,7 +441,10 @@
        }
        if accept == "gzip" {
            rw.Header().Set("Content-Encoding", "gzip")
-           gz, _ := gzip.NewWriter(rw)
+           gz, e := gzip.NewWriter(rw)
+           if e != nil {
+               t.Error(e)
+           }
            gz.Write([]byte(responseBody))
            gz.Close()
        } else {
@@ -453,14 +456,20 @@
 
    for i, test := range roundTripTests {
        // Test basic request (no accept-encoding)
-       req, _ := NewRequest("GET", fmt.Sprintf("%s/?testnum=%d&expect_accept=%s", ts.URL, i,
test.expectAccept), nil)
+       req, e := NewRequest("GET", fmt.Sprintf("%s/?testnum=%d&expect_accept=%s", ts.URL, i,
test.expectAccept), nil)
+       if e != nil {
+           t.Error(e)
+       }
        if test.accept != "" {
            req.Header.Set("Accept-Encoding", test.accept)
        }
        res, err := DefaultTransport.RoundTrip(req)
        var body []byte
        if test.compressed {
-           gzip, _ := gzip.NewReader(res.Body)
+           gzip, e := gzip.NewReader(res.Body)
+           if e != nil {
+               t.Error(e)
+           }
            body, err = ioutil.ReadAll(gzip)
            res.Body.Close()
        } else {
and tell us what it prints. Thank you.
Alex

gopherbot · 2012-02-07T09:07:48Z

Comment 13 by reddooots:

I applied the patch and ran "go test -test.v -test.run TestRoundTripGzip" and only got
the stack trace again.  Attached the output in case there is something new in there.
hg diff shows the same as your diff and hg status shows "M
src\pkg\net\http\transport_test.go"

Attachments:

test.txt (5939 bytes)

gopherbot · 2012-02-07T09:44:14Z

Comment 14 by reddooots:

I just ran an all.bash to make sure everything was in sync since go test was telling me
about httptest and httputil being out date and noticed the following.
8c -FVw -DGOOS_windows -DGOARCH_386 -o "slice.8" slice.c
8c -FVw -DGOOS_windows -DGOARCH_386 -o "symtab.8" symtab.c
8a -DGOOS_windows -DGOARCH_386 sys_windows_386.s
signal_windows_386.c:12 not a member of struct/union: Eax
signal_windows_386.c:13 not a member of struct/union: Ebx
signal_windows_386.c:14 not a member of struct/union: Ecx
signal_windows_386.c:15 not a member of struct/union: Edx
signal_windows_386.c:16 not a member of struct/union: Edi
signal_windows_386.c:17 not a member of struct/union: Esi
signal_windows_386.c:18 not a member of struct/union: Ebp
signal_windows_386.c:19 not a member of struct/union: Esp
signal_windows_386.c:20 not a member of struct/union: Eip
signal_windows_386.c:40 not a member of struct/union: Eip
signal_windows_386.c:52 not a member of struct/union: Eip
too many errors
make: *** [signal_windows_386.8] Error 1
make: *** Waiting for unfinished jobs....
rm -f arch_GOARCH.h os_GOOS.h signals_GOOS.h defs_GOOS_GOARCH.h zasm_GOOS_GOARCH
.h  runtime_defs.go version*.go asm_*.h
rm -rf *.o *.a *.[568vq] [568vq].out *.so _obj _test _testmain.go *.exe _cgo* te
st.out build.out
This is the first time I have seen it but I usually pay little attention when all.bash
is running.
The tests are still giving the same results.  I also tried the experimental 386 build
and got the same test results.  All the files for go should be in GOROOT correct?

gopherbot · 2012-02-07T14:11:56Z

Comment 15 by reddooots:

Well it appears that for some reason sending data with net/http is buffered on this box.
 If I add "w.Write(make([]byte, 4000000))" before "w.(Flusher).Flush()" in the handler
TestStreamingGet can run.  I just started with 4000 and added zeros until c.Get(ts.URL)
successfully got some data.
Of course TestStreamingGet still fails with
--- FAIL: TestStreamingGet (0.18 seconds)
        client_test.go:357: Expected "i", got "\x00"
I am not sure where to go from here.

alexbrainman · 2012-02-08T05:59:18Z

Comment 16:

For TestRoundTripGzip I missed one more error check. Lets see if
DefaultTransport.RoundTrip fails too:
diff -r 1107a7d3cb07 src/pkg/net/http/transport_test.go
--- a/src/pkg/net/http/transport_test.go    Fri Jan 27 17:51:53 2012 +1100
+++ b/src/pkg/net/http/transport_test.go    Wed Feb 08 16:07:02 2012 +1100
@@ -441,7 +441,10 @@
        }
        if accept == "gzip" {
            rw.Header().Set("Content-Encoding", "gzip")
-           gz, _ := gzip.NewWriter(rw)
+           gz, e := gzip.NewWriter(rw)
+           if e != nil {
+               t.Error(e)
+           }
            gz.Write([]byte(responseBody))
            gz.Close()
        } else {
@@ -453,14 +456,23 @@
    for i, test := range roundTripTests {
        // Test basic request (no accept-encoding)
-       req, _ := NewRequest("GET", fmt.Sprintf("%s/?testnum=%d&expect_accept=%s", ts.URL, i,
test.expectAccept), nil)
+       req, e := NewRequest("GET", fmt.Sprintf("%s/?testnum=%d&expect_accept=%s", ts.URL, i,
test.expectAccept), nil)
+       if e != nil {
+           t.Fatal(e)
+       }
        if test.accept != "" {
            req.Header.Set("Accept-Encoding", test.accept)
        }
        res, err := DefaultTransport.RoundTrip(req)
+       if err != nil {
+           t.Fatal(err)
+       }
        var body []byte
        if test.compressed {
-           gzip, _ := gzip.NewReader(res.Body)
+           gzip, e := gzip.NewReader(res.Body)
+           if e != nil {
+               t.Fatal(e)
+           }
            body, err = ioutil.ReadAll(gzip)
            res.Body.Close()
        } else {
You applied diff correctly, because your stack trace matches my program source. So just
do it again please.
Do not worry about error you see when you run all.bash. It is known and has been fixed.
Do not need to run all.bash after changing files in net/http, just run
go test -test.v -test.run TestRoundTripGzip
like you did, and it will rebuild all that is required.
As to TestStreamingGet, you can't just add w.Write(make([]byte, 4000000)) in places you
like, because this will send 4000000 bytes of 0. Instead, lets put some debug print
statements to see what is happening:
diff -r 1107a7d3cb07 src/pkg/net/http/client_test.go
--- a/src/pkg/net/http/client_test.go   Fri Jan 27 17:51:53 2012 +1100
+++ b/src/pkg/net/http/client_test.go   Wed Feb 08 16:56:58 2012 +1100
@@ -326,22 +326,30 @@
 func TestStreamingGet(t *testing.T) {
    say := make(chan string)
    ts := httptest.NewServer(HandlerFunc(func(w ResponseWriter, r *Request) {
+       fmt.Printf("| flushing:\n")
        w.(Flusher).Flush()
+       fmt.Printf("| flushed:\n")
        for str := range say {
-           w.Write([]byte(str))
+           fmt.Printf("| sending: %s\n", str)
+           n, e := w.Write([]byte(str))
+           fmt.Printf("| sent: %d %v\n", n, e)
            w.(Flusher).Flush()
+           fmt.Printf("| flushed:\n")
        }
    }))
    defer ts.Close()
 
    c := &Client{}
+   fmt.Printf(". connecting: %s\n", ts.URL)
    res, err := c.Get(ts.URL)
    if err != nil {
        t.Fatal(err)
    }
+   fmt.Printf(". connected:\n")
    var buf [10]byte
    for _, str := range []string{"i", "am", "also", "known", "as", "comet"} {
        say <- str
+       fmt.Printf(". say <-: %v\n", str)
        n, err := io.ReadFull(res.Body, buf[0:len(str)])
        if err != nil {
            t.Fatalf("ReadFull on %q: %v", str, err)
@@ -353,6 +361,7 @@
        if got != str {
            t.Fatalf("Expected %q, got %q", str, got)
        }
+       fmt.Printf(". received: %v\n", got)
    }
    close(say)
    _, err = io.ReadFull(res.Body, buf[0:1])
Thank you.
Alex

gopherbot · 2012-02-08T07:57:47Z

Comment 17 by reddooots:

TestRoundTripGzip output
$ go test -test.v -test.run TestRoundTripGzip
FAIL    net/http        0.356s
=== RUN TestRoundTripGzip
--- FAIL: TestRoundTripGzip (0.18 seconds)
        transport_test.go:440: in handler, test 1: Accept-Encoding = "", want "f
oo"
        transport_test.go:492: 1. Content-Encoding = ""; want "foo"
        transport_test.go:474: invalid gzip header
FAIL
TestStreamingGet output
$ go test -test.v -test.run TestStream -test.timeout 30s
FAIL    net/http        30.229s
=== RUN TestStreamingGet
. connecting: http://127.0.0.1:54937
| flushing:
| flushed:
panic: test timed out
I have used prints all the way down c.Get(ts.URL) until presistConn.readLoop in
transport.go and it gets stuck at pb, err := pc.br.Peek(1).  The only ways I have found
to get past that point are to send a bunch of data like above or remove the for loop in
the handler and then as one would expect the test gets stuck on the first send to the
say channel.
Here is the output with the for loop removed in the handler and the patch applied
$ go test -test.v -test.run TestStream -test.timeout 30s
FAIL    net/http        30.155s
=== RUN TestStreamingGet
. connecting: http://127.0.0.1:54947
| flushing:
| flushed:
. connected:
panic: test timed out
The docs for http.Flusher say "Note that even for ResponseWriters that support Flush, if
the client is connected through an HTTP proxy, the buffered data may not reach the
client until the response completes."  I did some searching and as far as I can tell
this box is not setup to use a proxy so I doubt that is the problem but I guess it could
be.
Earlier I did a simple ping pong test with the net package over a tcp connection and it
did not hang so next on my list is to dig deeper into how the server and client for
net/http talk to each other and see if I can use the -httptest.serve flag and see if I
can get any data from TestStreamingGet using the net package.
If you have a better idea or more patches to run let me know.

bradfitz · 2012-02-08T10:14:00Z

Comment 18:

Is this Windows machine running some anti-virus software which intercepts all TCP
connections, scanning for HTTP/malware?

gopherbot · 2012-02-08T13:26:13Z

Comment 19 by reddooots:

Yep that was it, turns out to completely disable the scanner a dll had to be renamed... 
Oh well I got to learn some stuff so I guess it was not a complete loss.
Ran the new all.bat in the latest weekly and no errors.

rsc · 2012-02-08T15:25:01Z

Comment 20:

Wow, never would have guess that.  Nice call, Brad.

Status changed to Retracted.

gopherbot added retracted labels Feb 8, 2012

rsc added this to the Go1 milestone Apr 10, 2015

rsc removed the priority-go1 label Apr 10, 2015

golang locked and limited conversation to collaborators Jun 24, 2016

gopherbot added the FrozenDueToAge label Jun 24, 2016

This issue was closed.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

net/http: TestStreamingGet timeout on Windows 7 #2651

net/http: TestStreamingGet timeout on Windows 7 #2651

gopherbot commented Jan 4, 2012

alexbrainman commented Jan 4, 2012

rsc commented Jan 24, 2012

rsc commented Jan 24, 2012

gopherbot commented Jan 26, 2012

alexbrainman commented Feb 2, 2012

gopherbot commented Feb 3, 2012

gopherbot commented Feb 5, 2012

alexbrainman commented Feb 5, 2012

gopherbot commented Feb 6, 2012

alexbrainman commented Feb 6, 2012

gopherbot commented Feb 7, 2012

alexbrainman commented Feb 7, 2012

gopherbot commented Feb 7, 2012

gopherbot commented Feb 7, 2012

gopherbot commented Feb 7, 2012

alexbrainman commented Feb 8, 2012

gopherbot commented Feb 8, 2012

bradfitz commented Feb 8, 2012

gopherbot commented Feb 8, 2012

rsc commented Feb 8, 2012

net/http: TestStreamingGet timeout on Windows 7 #2651

net/http: TestStreamingGet timeout on Windows 7 #2651

Comments

gopherbot commented Jan 4, 2012

alexbrainman commented Jan 4, 2012

rsc commented Jan 24, 2012

rsc commented Jan 24, 2012

gopherbot commented Jan 26, 2012

alexbrainman commented Feb 2, 2012

gopherbot commented Feb 3, 2012

gopherbot commented Feb 5, 2012

alexbrainman commented Feb 5, 2012

gopherbot commented Feb 6, 2012

alexbrainman commented Feb 6, 2012

gopherbot commented Feb 7, 2012

alexbrainman commented Feb 7, 2012

gopherbot commented Feb 7, 2012

gopherbot commented Feb 7, 2012

gopherbot commented Feb 7, 2012

alexbrainman commented Feb 8, 2012

gopherbot commented Feb 8, 2012

bradfitz commented Feb 8, 2012

gopherbot commented Feb 8, 2012

rsc commented Feb 8, 2012