net/http/httputil: all goroutines are asleep - deadlock

[alexbrainman]

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

go version devel +fca6ad45e25 Sun May 14 20:24:34 2017 +0000 windows/amd64

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

set GOARCH=amd64
set GOBIN=
set GOEXE=.exe
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOOS=windows
set GOPATH=d:\a
set GORACE=
set GOROOT=d:\a\go
set GOTOOLDIR=d:\a\go\pkg\tool\windows_amd64
set GCCGO=gccgo
set CC=gcc
set GOGCCFLAGS=-m64 -mthreads -fmessage-length=0 -fdebug-prefix-map=C:\Users\brainman\AppData\Local\Temp\1\go-build025530391=/tmp/go-build -gno-record-gcc-switches
set CXX=g++
set CGO_ENABLED=1
set CGO_CFLAGS=-g -O2
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-g -O2
set CGO_FFLAGS=-g -O2
set CGO_LDFLAGS=-g -O2
set PKG_CONFIG=pkg-config

What did you do?

I run

go test -short net/http/httputil

command.

What did you expect to see?

I expected test to PASS.

What did you see instead?

fatal error: all goroutines are asleep - deadlock!

goroutine 1 [chan receive]:
testing.(*T).Run(0xc0420fe000, 0x72d0ab, 0x10, 0x740778, 0x482701)
	d:/a/go/src/testing/testing.go:790 +0x303
testing.runTests.func1(0xc0420fe000)
	d:/a/go/src/testing/testing.go:1004 +0x73
testing.tRunner(0xc0420fe000, 0xc042057de8)
	d:/a/go/src/testing/testing.go:747 +0xd7
testing.runTests(0xc0420c0720, 0x8c15a0, 0xf, 0xf, 0x4)
	d:/a/go/src/testing/testing.go:1002 +0x1fd
testing.(*M).Run(0xc042057f20, 0xc042057f78)
	d:/a/go/src/testing/testing.go:921 +0x118
main.main()
	net/http/httputil/_test/_testmain.go:84 +0xe2

goroutine 27 [select]:
net/http.(*persistConn).roundTrip(0xc04207b9e0, 0xc0421788a0, 0x0, 0x0, 0x0)
	d:/a/go/src/net/http/transport.go:1962 +0x659
net/http.(*Transport).RoundTrip(0xc0420fe960, 0xc0420dd300, 0xc0420fe960, 0x0, 0x0)
	d:/a/go/src/net/http/transport.go:408 +0x853
net/http.send(0xc0420dd300, 0x88bf80, 0xc0420fe960, 0x0, 0x0, 0x0, 0xc042004108, 0x71f380, 0xc04202faa8, 0x1)
	d:/a/go/src/net/http/client.go:249 +0x1b0
net/http.(*Client).send(0xc042065920, 0xc0420dd300, 0x0, 0x0, 0x0, 0xc042004108, 0x0, 0x1, 0x41159f)
	d:/a/go/src/net/http/client.go:173 +0x10e
net/http.(*Client).Do(0xc042065920, 0xc0420dd300, 0xc04200a420, 0x23, 0x0)
	d:/a/go/src/net/http/client.go:598 +0x1fc
net/http/httputil.TestReverseProxy(0xc0420fe780)
	d:/a/go/src/net/http/httputil/reverseproxy_test.go:130 +0xce3
testing.tRunner(0xc0420fe780, 0x740778)
	d:/a/go/src/testing/testing.go:747 +0xd7
created by testing.(*T).Run
	d:/a/go/src/testing/testing.go:789 +0x2e5

goroutine 28 [IO wait]:
internal/poll.runtime_pollWait(0x27f4f00, 0x72, 0xc04207eb58)
	d:/a/go/src/runtime/netpoll.go:173 +0x77
internal/poll.(*pollDesc).wait(0xc04207ec98, 0x72, 0x88a400, 0x0, 0x0)
	d:/a/go/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x8c3c40, 0xc04207eb58, 0x72a763, 0x8, 0xc0420c1620, 0x2, 0x1, 0x0)
	d:/a/go/src/internal/poll/fd_windows.go:191 +0x126
internal/poll.(*FD).acceptOne(0xc04207eb40, 0xa0, 0xc0420c2540, 0x2, 0x2, 0xc04207eb58, 0x8, 0xc042115d28, 0x41159f, 0x10)
	d:/a/go/src/internal/poll/fd_windows.go:731 +0xc9
internal/poll.(*FD).Accept(0xc04207eb40, 0xc042031b90, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	d:/a/go/src/internal/poll/fd_windows.go:765 +0x14f
net.(*netFD).accept(0xc04207eb40, 0xc042115ea8, 0x40110e, 0xc04203cc60)
	d:/a/go/src/net/fd_windows.go:191 +0x88
net.(*TCPListener).accept(0xc042004088, 0x64c947, 0x459900, 0xc042115ef0)
	d:/a/go/src/net/tcpsock_posix.go:136 +0x35
net.(*TCPListener).Accept(0xc042004088, 0x740498, 0xc04203cbe0, 0x890800, 0xc042065c50)
	d:/a/go/src/net/tcpsock.go:228 +0x50
net/http.(*Server).Serve(0xc04206e2c0, 0x8900c0, 0xc042004088, 0x0, 0x0)
	d:/a/go/src/net/http/server.go:2656 +0x27b
net/http/httptest.(*Server).goServe.func1(0xc0421009a0)
	d:/a/go/src/net/http/httptest/server.go:277 +0x74
created by net/http/httptest.(*Server).goServe
	d:/a/go/src/net/http/httptest/server.go:275 +0x63

goroutine 46 [IO wait]:
internal/poll.runtime_pollWait(0x27f4d80, 0x72, 0x0)
	d:/a/go/src/runtime/netpoll.go:173 +0x77
internal/poll.(*pollDesc).wait(0xc04207fa18, 0x72, 0x88a400, 0x0, 0x0)
	d:/a/go/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x8c3c40, 0xc04207f8d8, 0x72a5a2, 0x7, 0x7402b0, 0x0, 0x0, 0x0)
	d:/a/go/src/internal/poll/fd_windows.go:191 +0x126
internal/poll.(*FD).Read(0xc04207f8c0, 0xc04218f000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	d:/a/go/src/internal/poll/fd_windows.go:422 +0x285
net.(*netFD).Read(0xc04207f8c0, 0xc04218f000, 0x1000, 0x1000, 0x200000003, 0xc04201d800, 0xc042165a88)
	d:/a/go/src/net/fd_windows.go:150 +0x59
net.(*conn).Read(0xc042004110, 0xc04218f000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	d:/a/go/src/net/net.go:176 +0x74
net/http.(*persistConn).Read(0xc04207b9e0, 0xc04218f000, 0x1000, 0x1000, 0x0, 0x0, 0xc042165b68)
	d:/a/go/src/net/http/transport.go:1373 +0x147
bufio.(*Reader).fill(0xc042037e00)
	d:/a/go/src/bufio/bufio.go:97 +0x10f
bufio.(*Reader).Peek(0xc042037e00, 0x1, 0xc042039ec0, 0xc042165c80, 0x8c62c0, 0x8c62c0, 0x42fe51)
	d:/a/go/src/bufio/bufio.go:129 +0x53
net/http.(*persistConn).readLoop(0xc04207b9e0)
	d:/a/go/src/net/http/transport.go:1521 +0x189
created by net/http.(*Transport).dialConn
	d:/a/go/src/net/http/transport.go:1168 +0xa35

goroutine 50 [select]:
net/http/httputil.(*ReverseProxy).ServeHTTP.func1(0xc0420342a0, 0xc0420319b0, 0x890740, 0xc042033600)
	d:/a/go/src/net/http/httputil/reverseproxy.go:144 +0xf9
created by net/http/httputil.(*ReverseProxy).ServeHTTP
	d:/a/go/src/net/http/httputil/reverseproxy.go:143 +0xec4

goroutine 47 [select]:
net/http.(*persistConn).writeLoop(0xc04207b9e0)
	d:/a/go/src/net/http/transport.go:1751 +0x2ba
created by net/http.(*Transport).dialConn
	d:/a/go/src/net/http/transport.go:1169 +0xa5a

goroutine 29 [IO wait]:
internal/poll.runtime_pollWait(0x27f4e40, 0x72, 0xc04207ed98)
	d:/a/go/src/runtime/netpoll.go:173 +0x77
internal/poll.(*pollDesc).wait(0xc04207eed8, 0x72, 0x88a400, 0x0, 0x0)
	d:/a/go/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x8c3c40, 0xc04207ed98, 0x72a763, 0x8, 0xc0420c15c0, 0x2, 0x1, 0x0)
	d:/a/go/src/internal/poll/fd_windows.go:191 +0x126
internal/poll.(*FD).acceptOne(0xc04207ed80, 0xa4, 0xc0420c2460, 0x2, 0x2, 0xc04207ed98, 0x8, 0xc042113d28, 0x41159f, 0x10)
	d:/a/go/src/internal/poll/fd_windows.go:731 +0xc9
internal/poll.(*FD).Accept(0xc04207ed80, 0xc042031980, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	d:/a/go/src/internal/poll/fd_windows.go:765 +0x14f
net.(*netFD).accept(0xc04207ed80, 0xc042113ea8, 0x40110e, 0xc04203cbc0)
	d:/a/go/src/net/fd_windows.go:191 +0x88
net.(*TCPListener).accept(0xc042004090, 0x64c947, 0x459900, 0xc042113ef0)
	d:/a/go/src/net/tcpsock_posix.go:136 +0x35
net.(*TCPListener).Accept(0xc042004090, 0x740498, 0xc04203cb40, 0x890800, 0xc042065d10)
	d:/a/go/src/net/tcpsock.go:228 +0x50
net/http.(*Server).Serve(0xc04206e370, 0x8900c0, 0xc042004090, 0x0, 0x0)
	d:/a/go/src/net/http/server.go:2656 +0x27b
net/http/httptest.(*Server).goServe.func1(0xc042100a10)
	d:/a/go/src/net/http/httptest/server.go:277 +0x74
created by net/http/httptest.(*Server).goServe
	d:/a/go/src/net/http/httptest/server.go:275 +0x63

goroutine 48 [select]:
net/http.(*persistConn).roundTrip(0xc04207bb00, 0xc042178d20, 0x0, 0x0, 0x0)
	d:/a/go/src/net/http/transport.go:1962 +0x659
net/http.(*Transport).RoundTrip(0x8c1240, 0xc0420dd500, 0xf, 0xc04200eaf0, 0x9)
	d:/a/go/src/net/http/transport.go:408 +0x853
net/http/httputil.(*ReverseProxy).ServeHTTP(0xc042032c80, 0x890240, 0xc0421741c0, 0xc0420dd400)
	d:/a/go/src/net/http/httputil/reverseproxy.go:203 +0x2b9
net/http.serverHandler.ServeHTTP(0xc04206e370, 0x890240, 0xc0421741c0, 0xc0420dd400)
	d:/a/go/src/net/http/server.go:2580 +0xbb
net/http.(*conn).serve(0xc04203cb40, 0x890740, 0xc042033500)
	d:/a/go/src/net/http/server.go:1797 +0x6a8
created by net/http.(*Server).Serve
	d:/a/go/src/net/http/server.go:2681 +0x257

goroutine 49 [IO wait]:
internal/poll.runtime_pollWait(0x27f4cc0, 0x72, 0x0)
	d:/a/go/src/runtime/netpoll.go:173 +0x77
internal/poll.(*pollDesc).wait(0xc04207fc58, 0x72, 0x88a400, 0x0, 0x0)
	d:/a/go/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x8c3c40, 0xc04207fb18, 0x72a5a2, 0x7, 0x7402b0, 0x0, 0x0, 0x0)
	d:/a/go/src/internal/poll/fd_windows.go:191 +0x126
internal/poll.(*FD).Read(0xc04207fb00, 0xc042178ac1, 0x1, 0x1, 0x0, 0x0, 0x0)
	d:/a/go/src/internal/poll/fd_windows.go:422 +0x285
net.(*netFD).Read(0xc04207fb00, 0xc042178ac1, 0x1, 0x1, 0x0, 0x0, 0x0)
	d:/a/go/src/net/fd_windows.go:150 +0x59
net.(*conn).Read(0xc042004118, 0xc042178ac1, 0x1, 0x1, 0x0, 0x0, 0x0)
	d:/a/go/src/net/net.go:176 +0x74
net/http.(*connReader).backgroundRead(0xc042178ab0)
	d:/a/go/src/net/http/server.go:656 +0x69
created by net/http.(*connReader).startBackgroundRead
	d:/a/go/src/net/http/server.go:652 +0xdb

goroutine 55 [select]:
net/http.(*persistConn).writeLoop(0xc04207bb00)
	d:/a/go/src/net/http/transport.go:1751 +0x2ba
created by net/http.(*Transport).dialConn
	d:/a/go/src/net/http/transport.go:1169 +0xa5a

goroutine 54 [IO wait]:
internal/poll.runtime_pollWait(0x27f4c00, 0x72, 0x0)
	d:/a/go/src/runtime/netpoll.go:173 +0x77
internal/poll.(*pollDesc).wait(0xc04207fe98, 0x72, 0x88a400, 0x0, 0x0)
	d:/a/go/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x8c3c40, 0xc04207fd58, 0x72a5a2, 0x7, 0x7402b0, 0x200000003, 0xc04201de00, 0xc0421619c0)
	d:/a/go/src/internal/poll/fd_windows.go:191 +0x126
internal/poll.(*FD).Read(0xc04207fd40, 0xc0421a0000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	d:/a/go/src/internal/poll/fd_windows.go:422 +0x285
net.(*netFD).Read(0xc04207fd40, 0xc0421a0000, 0x1000, 0x1000, 0x0, 0x0, 0x27f4b40)
	d:/a/go/src/net/fd_windows.go:150 +0x59
net.(*conn).Read(0xc042004120, 0xc0421a0000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	d:/a/go/src/net/net.go:176 +0x74
net/http.(*persistConn).Read(0xc04207bb00, 0xc0421a0000, 0x1000, 0x1000, 0x0, 0x0, 0xc042161b68)
	d:/a/go/src/net/http/transport.go:1373 +0x147
bufio.(*Reader).fill(0xc04219e120)
	d:/a/go/src/bufio/bufio.go:97 +0x10f
bufio.(*Reader).Peek(0xc04219e120, 0x1, 0xc04219c420, 0xc042161c80, 0x4126b2, 0xc042119048, 0x0)
	d:/a/go/src/bufio/bufio.go:129 +0x53
net/http.(*persistConn).readLoop(0xc04207bb00)
	d:/a/go/src/net/http/transport.go:1521 +0x189
created by net/http.(*Transport).dialConn
	d:/a/go/src/net/http/transport.go:1168 +0xa35
FAIL	net/http/httputil	0.104s

Sometimes test passes and sometimes it fails.

Alex

[alexbrainman]

Bisected to:

e4371fb179ad69cbd057f2430120843948e09f2f is the first bad commit
commit e4371fb179ad69cbd057f2430120843948e09f2f
Author: Russ Cox <rsc@golang.org>
Date:   Fri Feb 3 19:26:13 2017 -0500

    time: optimize Now on darwin, windows

    Fetch both monotonic and wall time together when possible.
    Avoids skew and is cheaper.

    Also shave a few ns off in conversion in package time.

    Compared to current implementation (after monotonic changes):

    name   old time/op  new time/op  delta
    Now    19.6ns ± 1%   9.7ns ± 1%  -50.63%  (p=0.000 n=41+49) darwin/amd64
    Now    23.5ns ± 4%  10.6ns ± 5%  -54.61%  (p=0.000 n=30+28) windows/amd64
    Now    54.5ns ± 5%  29.8ns ± 9%  -45.40%  (p=0.000 n=27+29) windows/386

    More importantly, compared to Go 1.8:

    name   old time/op  new time/op  delta
    Now     9.5ns ± 1%   9.7ns ± 1%   +1.94%  (p=0.000 n=41+49) darwin/amd64
    Now    12.9ns ± 5%  10.6ns ± 5%  -17.73%  (p=0.000 n=30+28) windows/amd64
    Now    15.3ns ± 5%  29.8ns ± 9%  +94.36%  (p=0.000 n=30+29) windows/386

    This brings time.Now back in line with Go 1.8 on darwin/amd64 and windows/am
d64.

    It's not obvious why windows/386 is still noticeably worse than Go 1.8,
    but it's better than before this CL. The windows/386 speed is not too
    important; the changes just keep the two architectures similar.

    Change-Id: If69b94970c8a1a57910a371ee91e0d4e82e46c5d
    Reviewed-on: https://go-review.googlesource.com/36428
    Run-TryBot: Russ Cox <rsc@golang.org>
    TryBot-Result: Gobot Gobot <gobot@golang.org>
    Reviewed-by: Ian Lance Taylor <iant@golang.org>

Alex

[odeke-em]

/cc @bradfitz @rsc

[felixge]

I am seeing a very similar error on a Win7 64Bit machine in a production app.

As you can see below, there are only 3 go routines running, and only one of them is directly on the stack of my application.

I have a production machine I can reliably reproduce this on, but unfortunately I had no luck in a VM so far.

So for now I'm just saying "me too", but hopefully I can provide some more information later on.

fatal error: all goroutines are asleep - deadlock!

goroutine 1 [select]:
net/http.(*persistConn).roundTrip(0xc042084b40, 0xc042078d50, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/http/transport.go:1970 +0x60f
net/http.(*Transport).RoundTrip(0x7de220, 0xc0420f0300, 0x7de220, 0x0, 0x0)
	/usr/local/go19/src/net/http/transport.go:413 +0x999
net/http.send(0xc0420f0200, 0x7acbc0, 0x7de220, 0x0, 0x0, 0x0, 0xc042064098, 0x100, 0xc0420618c8, 0x1)
	/usr/local/go19/src/net/http/client.go:249 +0x1b0
net/http.(*Client).send(0x7e1d80, 0xc0420f0200, 0x0, 0x0, 0x0, 0xc042064098, 0x0, 0x1, 0xf56308)
	/usr/local/go19/src/net/http/client.go:173 +0x104
net/http.(*Client).Do(0x7e1d80, 0xc0420f0200, 0xc, 0x68d46d, 0x10)
	/usr/local/go19/src/net/http/client.go:602 +0x294
net/http.(*Client).Post(0x7e1d80, 0xc0420fe070, 0x6f, 0x68d46d, 0x10, 0x7acec0, 0xc042064078, 0x9, 0xc0420465a0, 0xc0420ec310)
	/usr/local/go19/src/net/http/client.go:729 +0xff
net/http.Post(0xc0420fe070, 0x6f, 0x68d46d, 0x10, 0x7acec0, 0xc042064078, 0x9, 0x0, 0x0)
	/usr/local/go19/src/net/http/client.go:709 +0x7a
main.(*Daemon).postFile(0xc0420f4000, 0xc04206c140, 0x43, 0x0, 0x0)
	/github.com/org/project/cmd/project/daemon.go:108 +0x339
main.(*Daemon).processNext(0xc0420f4000, 0xc042038120, 0xdf8475800, 0xc0420d2700)
	/github.com/org/project/cmd/project/daemon.go:81 +0x5d
main.(*Daemon).Run(0xc0420f4000, 0xe, 0xc0420442e0)
	/github.com/org/project/cmd/project/daemon.go:50 +0x1ae
main.run(0xc042038058, 0x0)
	/github.com/org/project/cmd/project/main.go:22 +0x13e
main.main()
	/github.com/org/project/cmd/project/main.go:12 +0x2d

goroutine 4 [IO wait]:
internal/poll.runtime_pollWait(0x1b45048, 0x72, 0x0)
	/usr/local/go19/src/runtime/netpoll.go:173 +0x5e
internal/poll.(*pollDesc).wait(0xc042080c98, 0x72, 0x7ab200, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x7e0468, 0xc042080b58, 0x69de58, 0x0, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a
internal/poll.(*FD).Read(0xc042080b40, 0xc042110000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_windows.go:439 +0x266
net.(*netFD).Read(0xc042080b40, 0xc042110000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/fd_windows.go:151 +0x59
net.(*conn).Read(0xc042004010, 0xc042110000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/net.go:176 +0x74
net/http.(*persistConn).Read(0xc042084b40, 0xc042110000, 0x1000, 0x1000, 0x0, 0x0, 0xc042105b68)
	/usr/local/go19/src/net/http/transport.go:1391 +0x147
bufio.(*Reader).fill(0xc042036060)
	/usr/local/go19/src/bufio/bufio.go:97 +0x121
bufio.(*Reader).Peek(0xc042036060, 0x1, 0xc0421160c0, 0xc042105c80, 0x0, 0x0, 0x0)
	/usr/local/go19/src/bufio/bufio.go:129 +0x41
net/http.(*persistConn).readLoop(0xc042084b40)
	/usr/local/go19/src/net/http/transport.go:1539 +0x18c
created by net/http.(*Transport).dialConn
	/usr/local/go19/src/net/http/transport.go:1186 +0xa35

goroutine 5 [IO wait]:
internal/poll.runtime_pollWait(0x1b45048, 0x77, 0x0)
	/usr/local/go19/src/runtime/netpoll.go:173 +0x5e
internal/poll.(*pollDesc).wait(0xc042080c98, 0x77, 0x7ab200, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x7e0470, 0xc042080bf8, 0x69de68, 0x0, 0x8, 0x2)
	/usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a
internal/poll.(*FD).Write(0xc042080b40, 0xc042111000, 0x2, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_windows.go:613 +0x23a
net.(*netFD).Write(0xc042080b40, 0xc042111000, 0x2, 0x1000, 0x1b84118, 0x9f01000000, 0x1)
	/usr/local/go19/src/net/fd_windows.go:163 +0x59
net.(*conn).Write(0xc042004010, 0xc042111000, 0x2, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/net.go:188 +0x74
net/http.persistConnWriter.Write(0xc042084b40, 0xc042111000, 0x2, 0x1000, 0xc042032040, 0x68a5ce, 0x2)
	/usr/local/go19/src/net/http/transport.go:1202 +0x59
bufio.(*Writer).Flush(0xc042032040, 0xc042004018, 0x68a5ce)
	/usr/local/go19/src/bufio/bufio.go:567 +0x85
net/http/internal.(*chunkedWriter).Write(0xc042030090, 0xc042120000, 0x2667, 0x8000, 0x2667, 0x0, 0x0)
	/usr/local/go19/src/net/http/internal/chunked.go:215 +0x1de
io.copyBuffer(0x1b840a0, 0xc042030090, 0x7adcc0, 0xc04211c000, 0xc042120000, 0x8000, 0x8000, 0x644b00, 0x68cd00, 0x1b840a0)
	/usr/local/go19/src/io/io.go:394 +0x206
io.Copy(0x1b840a0, 0xc042030090, 0x7adcc0, 0xc04211c000, 0xc042030090, 0x59afc4, 0xc042111110)
	/usr/local/go19/src/io/io.go:362 +0x6f
net/http.(*transferWriter).WriteBody(0xc04211c000, 0x7ac600, 0xc042032040, 0x2, 0x2)
	/usr/local/go19/src/net/http/transfer.go:330 +0x172
net/http.(*Request).write(0xc0420f0300, 0x7ac600, 0xc042032040, 0x0, 0xc04210c060, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/http/request.go:618 +0x6f2
net/http.(*persistConn).writeLoop(0xc042084b40)
	/usr/local/go19/src/net/http/transport.go:1762 +0x208
created by net/http.(*Transport).dialConn
	/usr/local/go19/src/net/http/transport.go:1187 +0xa5a

[felixge]

Edit: The update below does not work reliable, see my comment further down.

I found a workaround. I changed my code from:

res, err := http.Post(url.String(), "application/json", file)

to

client := &http.Client{Timeout: 5 * time.Second}
res, err := client.Post(url.String(), "application/json", file)

I was planning to add a timeout here anyway, so that's good enough for me right now.

Hopefully the above will also point in the right direction for finding the root cause of the deadlock that occurs when no timeout is set.

[rsc]

I didn't see this when it came in, sorry. If this is still a problem we should think about backporting any fix to the next Go 1.9 point release, so I set the milestone to Go 1.9.3.

[felixge]

Turns out the workaround I posted above is not working reliably. It does prevent the deadlock panic, but sometimes the requests time out even so there is a response (as confirmed using tcpdump).

There seems to be some randomness to it, i.e. some runs the program experiences the timeouts all the times, other runs it seems to be fine.

I'll try to boil this down to a stand alone test case and report back any findings early next week.

[felixge]

I spent some more time debugging this today. I was able to reproduce the deadlock with a minimal test program that basically just executes a http GET request.

I ran the command in a loop and got the following results:

• go1.7.5: No deadlocks
• go1.8.4: No deadlocks (This means that the e4371fb aka go1.8beta2-389-ge4371fb179 commit mentioned above is probably not the root cause)
• go1.9.1: Lots of deadlocks, see example

Notes:

• I was able to consistently reproduce this in 64Bit Win7 VM with Cygwin. However, it doesn't happen for every run of the program, but 20-50% of the runs trigger the problem.
• I was not able to reproduce this in a local 64Bit Win7 Professional VM (also using Cygwin)

@rsc Please let me know if I can provide more information or otherwise help with getting this resolved.

[davecheney]

Hi Felix. Thanks for the work on this repro. I have a question, the issue is related to net/http/httputil but your repro, or the example panic you posted mentions that package either.

…

On 23 Oct 2017, at 19:53, Felix Geisendörfer ***@***.***> wrote: I spent some more time debugging this today. I was able to reproduce the deadlock with a minimal test program that basically just executes a http GET request. I ran the command in a loop and got the following results: go1.7.5: No deadlocks go1.8.4: No deadlocks (This means that e4371fb aka go1.8beta2-389-ge4371fb179 is probably not the root cause) go1.9.1: Lots of deadlocks, see example Notes: I was able to consistently reproduce this in Win7 VM with Cygwin. However, it doesn't happen for every run of the program, but 20-50% of the runs trigger the problem. I was not able to reproduce this in a local Win7 Professional VM (also using Cygwin) @rsc Please let me know if I can provide more information or otherwise help with getting this resolved. — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or mute the thread.

[felixge]

Hi @davecheney . That's correct. I came across this issue in production and searched the issue tracker for similar issues. This one seemed like a perfect match, so I decided to add my information here instead of creating a new issue.

If it turns out that there are two separate issues here, I'm happy to create a new issue as well.

FWIW I haven't been able to run go test -short net/http/httputil on the production machine, because it doesn't have Go installed. But I might be able to make that happen if it will help with resolving this issue.

[davecheney]

I’d appreciate it if you would create a new issue. Feel free to reference this one for context.

…

On 23 Oct 2017, at 21:21, Felix Geisendörfer ***@***.***> wrote: Hi @davecheney . That's correct. I came across this issue in production and searched the issue tracker for similar issues. This one seemed like a perfect match, so I decided to add my information here instead of creating a new issue. If it turns out that there are two separate issues here, I'm happy to create a new issue as well. FWIW I haven't been able to run go test -short net/http/httputil on the production machine, because it doesn't have Go installed. But I might be able to make that happen if it will help with resolving this issue. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

[felixge]

@davecheney I just realized that I can cross-compile the httputil test:

GOOS=windows GOARCH=amd64 go test -c -o httputil_test.exe net/http/httputil

I then executed it on the production machine and got the same results as the original author of this issue above (see below).

Please confirm if you still want me to open a separate issue, or if this is enough evidence to confirm that both issues are identical.

$ while ./httputil_test.exe -test.short; do :; done
fatal error: all goroutines are asleep - deadlock!

goroutine 1 [chan receive]:
testing.(*T).Run(0xc04211a000, 0x723c71, 0x10, 0x7374c8, 0x482901)
	/usr/local/go19/src/testing/testing.go:790 +0x303
testing.runTests.func1(0xc04211a000)
	/usr/local/go19/src/testing/testing.go:1004 +0x6b
testing.tRunner(0xc04211a000, 0xc042063de0)
	/usr/local/go19/src/testing/testing.go:746 +0xd7
testing.runTests(0xc0420da700, 0x8b1760, 0x11, 0x11, 0x10)
	/usr/local/go19/src/testing/testing.go:1002 +0x2df
testing.(*M).Run(0xc042063f18, 0xc042063f70)
	/usr/local/go19/src/testing/testing.go:921 +0x118
main.main()
	net/http/httputil/_test/_testmain.go:88 +0xe2

goroutine 40 [select]:
net/http.(*persistConn).roundTrip(0xc042095200, 0xc042079aa0, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/http/transport.go:1970 +0x60f
net/http.(*Transport).RoundTrip(0xc04211a960, 0xc0420f5100, 0xc04211a960, 0x0, 0x0)
	/usr/local/go19/src/net/http/transport.go:413 +0x999
net/http.send(0xc0420f5100, 0x87bf80, 0xc04211a960, 0x0, 0x0, 0x0, 0xc0420660a0, 0x100, 0xc042183a48, 0x1)
	/usr/local/go19/src/net/http/client.go:249 +0x1b0
net/http.(*Client).send(0xc042079920, 0xc0420f5100, 0x0, 0x0, 0x0, 0xc0420660a0, 0x0, 0x1, 0xc18fe0)
	/usr/local/go19/src/net/http/client.go:173 +0x104
net/http.(*Client).Do(0xc042079920, 0xc0420f5100, 0x7, 0x720711, 0x3)
	/usr/local/go19/src/net/http/client.go:602 +0x294
net/http/httputil.TestReverseProxy(0xc04211a780)
	/usr/local/go19/src/net/http/httputil/reverseproxy_test.go:91 +0x3c4
testing.tRunner(0xc04211a780, 0x7374c8)
	/usr/local/go19/src/testing/testing.go:746 +0xd7
created by testing.(*T).Run
	/usr/local/go19/src/testing/testing.go:789 +0x2e5

goroutine 41 [IO wait]:
internal/poll.runtime_pollWait(0xc1d5f0, 0x72, 0xc042098b58)
	/usr/local/go19/src/runtime/netpoll.go:173 +0x5e
internal/poll.(*pollDesc).wait(0xc042098c98, 0x72, 0x87a400, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x8b4640, 0xc042098b58, 0xc0420db160, 0x2, 0x1, 0x0)
	/usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a
internal/poll.(*FD).acceptOne(0xc042098b40, 0xd4, 0xc0420dc1c0, 0x2, 0x2, 0xc042098b58, 0xc042028380, 0xc042131d28, 0x41159f, 0x10)
	/usr/local/go19/src/internal/poll/fd_windows.go:748 +0xae
internal/poll.(*FD).Accept(0xc042098b40, 0xc04203d420, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/usr/local/go19/src/internal/poll/fd_windows.go:782 +0x171
net.(*netFD).accept(0xc042098b40, 0xc042131ea8, 0x4010ee, 0xc042041020)
	/usr/local/go19/src/net/fd_windows.go:192 +0x88
net.(*TCPListener).accept(0xc042066078, 0x64106f, 0x459aa0, 0xc042131ef0)
	/usr/local/go19/src/net/tcpsock_posix.go:136 +0x35
net.(*TCPListener).Accept(0xc042066078, 0x7371d0, 0xc042040fa0, 0x880840, 0xc042192090)
	/usr/local/go19/src/net/tcpsock.go:247 +0x50
net/http.(*Server).Serve(0xc04207ac30, 0x880100, 0xc042066078, 0x0, 0x0)
	/usr/local/go19/src/net/http/server.go:2695 +0x1b9
net/http/httptest.(*Server).goServe.func1(0xc04211c9a0)
	/usr/local/go19/src/net/http/httptest/server.go:280 +0x74
created by net/http/httptest.(*Server).goServe
	/usr/local/go19/src/net/http/httptest/server.go:278 +0x63

goroutine 4 [select]:
net/http.(*Transport).getConn(0x8b1280, 0xc0421923f0, 0x0, 0xc0420465e0, 0x4, 0xc04200e0e0, 0xf, 0x0, 0x0, 0x150)
	/usr/local/go19/src/net/http/transport.go:948 +0x5c6
net/http.(*Transport).RoundTrip(0x8b1280, 0xc0421a0400, 0xf, 0xc04200e070, 0x9)
	/usr/local/go19/src/net/http/transport.go:400 +0x6ad
net/http/httputil.(*ReverseProxy).ServeHTTP(0xc042044c40, 0x880280, 0xc0421aa000, 0xc0421a0200)
	/usr/local/go19/src/net/http/httputil/reverseproxy.go:201 +0x2e4
net/http.serverHandler.ServeHTTP(0xc04207ad00, 0x880280, 0xc0421aa000, 0xc0421a0200)
	/usr/local/go19/src/net/http/server.go:2619 +0xbb
net/http.(*conn).serve(0xc04219c000, 0x880780, 0xc042034180)
	/usr/local/go19/src/net/http/server.go:1801 +0x724
created by net/http.(*Server).Serve
	/usr/local/go19/src/net/http/server.go:2720 +0x28f

goroutine 47 [IO wait]:
internal/poll.runtime_pollWait(0xc1d230, 0x72, 0x0)
	/usr/local/go19/src/runtime/netpoll.go:173 +0x5e
internal/poll.(*pollDesc).wait(0xc042099358, 0x72, 0x87a400, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x8b4640, 0xc042099218, 0x736fe8, 0x410e11, 0xc042044e80, 0x40)
	/usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a
internal/poll.(*FD).Read(0xc042099200, 0xc04219f000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_windows.go:439 +0x266
net.(*netFD).Read(0xc042099200, 0xc04219f000, 0x1000, 0x1000, 0xc04212d8c8, 0x637ed2, 0x6f3440)
	/usr/local/go19/src/net/fd_windows.go:151 +0x59
net.(*conn).Read(0xc0420660b8, 0xc04219f000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/net.go:176 +0x74
net/http.(*connReader).Read(0xc042079e30, 0xc04219f000, 0x1000, 0x1000, 0x43760b, 0xc04212d970, 0x64d9ea)
	/usr/local/go19/src/net/http/server.go:753 +0x10c
bufio.(*Reader).fill(0xc04207d500)
	/usr/local/go19/src/bufio/bufio.go:97 +0x121
bufio.(*Reader).ReadSlice(0xc04207d500, 0xa, 0x5, 0x0, 0x8d5aa8, 0xc042028380, 0xbc06a8)
	/usr/local/go19/src/bufio/bufio.go:338 +0x33
bufio.(*Reader).ReadLine(0xc04207d500, 0x100, 0xf8, 0x715f00, 0xc04212da98, 0x220000402319, 0xf8)
	/usr/local/go19/src/bufio/bufio.go:367 +0x3b
net/textproto.(*Reader).readLineSlice(0xc0420789f0, 0xc04212db20, 0xc04212db20, 0x41159f, 0x100, 0x715f00)
	/usr/local/go19/src/net/textproto/reader.go:55 +0x77
net/textproto.(*Reader).ReadLine(0xc0420789f0, 0xc0420f5200, 0x0, 0xc04212db90, 0x48e0d9)
	/usr/local/go19/src/net/textproto/reader.go:36 +0x32
net/http.readRequest(0xc04207d500, 0x0, 0xc0420f5200, 0x0, 0x0)
	/usr/local/go19/src/net/http/request.go:925 +0xa0
net/http.(*conn).readRequest(0xc042040fa0, 0x880780, 0xc042044e00, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/http/server.go:933 +0x183
net/http.(*conn).serve(0xc042040fa0, 0x880780, 0xc042044e00)
	/usr/local/go19/src/net/http/server.go:1739 +0x515
created by net/http.(*Server).Serve
	/usr/local/go19/src/net/http/server.go:2720 +0x28f

goroutine 42 [IO wait]:
internal/poll.runtime_pollWait(0xc1d530, 0x72, 0xc042098d98)
	/usr/local/go19/src/runtime/netpoll.go:173 +0x5e
internal/poll.(*pollDesc).wait(0xc042098ed8, 0x72, 0x87a400, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x8b4640, 0xc042098d98, 0xc0420020c0, 0x2, 0x1, 0x0)
	/usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a
internal/poll.(*FD).acceptOne(0xc042098d80, 0xc4, 0xc0421980e0, 0x2, 0x2, 0xc042098d98, 0xc042028700, 0xc04212fd28, 0x41159f, 0x10)
	/usr/local/go19/src/internal/poll/fd_windows.go:748 +0xae
internal/poll.(*FD).Accept(0xc042098d80, 0xc042032060, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/usr/local/go19/src/internal/poll/fd_windows.go:782 +0x171
net.(*netFD).accept(0xc042098d80, 0xc04212fea8, 0x4010ee, 0xc04219c080)
	/usr/local/go19/src/net/fd_windows.go:192 +0x88
net.(*TCPListener).accept(0xc042066080, 0x64106f, 0x459aa0, 0xc04212fef0)
	/usr/local/go19/src/net/tcpsock_posix.go:136 +0x35
net.(*TCPListener).Accept(0xc042066080, 0x7371d0, 0xc04219c000, 0x880840, 0xc042079c80)
	/usr/local/go19/src/net/tcpsock.go:247 +0x50
net/http.(*Server).Serve(0xc04207ad00, 0x880100, 0xc042066080, 0x0, 0x0)
	/usr/local/go19/src/net/http/server.go:2695 +0x1b9
net/http/httptest.(*Server).goServe.func1(0xc04211ca10)
	/usr/local/go19/src/net/http/httptest/server.go:280 +0x74
created by net/http/httptest.(*Server).goServe
	/usr/local/go19/src/net/http/httptest/server.go:278 +0x63

goroutine 45 [IO wait]:
internal/poll.runtime_pollWait(0xc1d470, 0x72, 0x0)
	/usr/local/go19/src/runtime/netpoll.go:173 +0x5e
internal/poll.(*pollDesc).wait(0xc042099118, 0x72, 0x87a400, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x8b4640, 0xc042098fd8, 0x736fe8, 0x0, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a
internal/poll.(*FD).Read(0xc042098fc0, 0xc04217d000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_windows.go:439 +0x266
net.(*netFD).Read(0xc042098fc0, 0xc04217d000, 0x1000, 0x1000, 0xc042079401, 0x4656f9, 0x1)
	/usr/local/go19/src/net/fd_windows.go:151 +0x59
net.(*conn).Read(0xc0420660b0, 0xc04217d000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/net.go:176 +0x74
net/http.(*persistConn).Read(0xc042095200, 0xc04217d000, 0x1000, 0x1000, 0x0, 0x0, 0xc042133b68)
	/usr/local/go19/src/net/http/transport.go:1391 +0x147
bufio.(*Reader).fill(0xc04207d380)
	/usr/local/go19/src/bufio/bufio.go:97 +0x121
bufio.(*Reader).Peek(0xc04207d380, 0x1, 0xc04203b740, 0xc042133c80, 0x7378c8, 0xc042133c30, 0x42cf5f)
	/usr/local/go19/src/bufio/bufio.go:129 +0x41
net/http.(*persistConn).readLoop(0xc042095200)
	/usr/local/go19/src/net/http/transport.go:1539 +0x18c
created by net/http.(*Transport).dialConn
	/usr/local/go19/src/net/http/transport.go:1186 +0xa35

goroutine 46 [select]:
net/http.(*persistConn).writeLoop(0xc042095200)
	/usr/local/go19/src/net/http/transport.go:1759 +0x16c
created by net/http.(*Transport).dialConn
	/usr/local/go19/src/net/http/transport.go:1187 +0xa5a

goroutine 5 [IO wait]:
internal/poll.runtime_pollWait(0xc1d3b0, 0x72, 0x0)
	/usr/local/go19/src/runtime/netpoll.go:173 +0x5e
internal/poll.(*pollDesc).wait(0xc04219a158, 0x72, 0x87a400, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5
internal/poll.(*ioSrv).ExecIO(0x8b4640, 0xc04219a018, 0x736fe8, 0x0, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a
internal/poll.(*FD).Read(0xc04219a000, 0xc0421921f1, 0x1, 0x1, 0x0, 0x0, 0x0)
	/usr/local/go19/src/internal/poll/fd_windows.go:439 +0x266
net.(*netFD).Read(0xc04219a000, 0xc0421921f1, 0x1, 0x1, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/fd_windows.go:151 +0x59
net.(*conn).Read(0xc042004018, 0xc0421921f1, 0x1, 0x1, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/net.go:176 +0x74
net/http.(*connReader).backgroundRead(0xc0421921e0)
	/usr/local/go19/src/net/http/server.go:660 +0x69
created by net/http.(*connReader).startBackgroundRead
	/usr/local/go19/src/net/http/server.go:656 +0xdf

goroutine 6 [select]:
net/http/httputil.(*ReverseProxy).ServeHTTP.func1(0xc042036070, 0xc042032090, 0x880780, 0xc042034300)
	/usr/local/go19/src/net/http/httputil/reverseproxy.go:154 +0xf9
created by net/http/httputil.(*ReverseProxy).ServeHTTP
	/usr/local/go19/src/net/http/httputil/reverseproxy.go:153 +0xf23

goroutine 7 [IO wait]:
internal/poll.runtime_pollWaitCanceled(0xc1d2f0, 0x77)
	/usr/local/go19/src/runtime/netpoll.go:189 +0x40
internal/poll.(*pollDesc).waitCanceled(0xc04219a398, 0x77)
	/usr/local/go19/src/internal/poll/fd_poll_runtime.go:101 +0x4e
internal/poll.(*ioSrv).ExecIO(0x8b4648, 0xc04219a2f8, 0x736fe0, 0xc0421b3200, 0xc0421b3208, 0xc0421b31f8)
	/usr/local/go19/src/internal/poll/fd_windows.go:225 +0x238
internal/poll.(*FD).ConnectEx(0xc04219a240, 0x87c7c0, 0xc04200a540, 0xc0420383c0, 0xc04219a240)
	/usr/local/go19/src/internal/poll/fd_windows.go:738 +0x80
net.(*netFD).connect(0xc04219a240, 0x880800, 0xc0420383c0, 0x0, 0x0, 0x87c7c0, 0xc04200a540, 0x0, 0x0, 0x0, ...)
	/usr/local/go19/src/net/fd_windows.go:116 +0x243
net.(*netFD).dial(0xc04219a240, 0x880800, 0xc0420383c0, 0x881a80, 0x0, 0x881a80, 0xc042192570, 0xc0421b33f8, 0x542925)
	/usr/local/go19/src/net/sock_posix.go:142 +0xf3
net.socket(0x880800, 0xc0420383c0, 0x720741, 0x3, 0x2, 0x1, 0x0, 0x0, 0x881a80, 0x0, ...)
	/usr/local/go19/src/net/sock_posix.go:93 +0x1c1
net.internetSocket(0x880800, 0xc0420383c0, 0x720741, 0x3, 0x881a80, 0x0, 0x881a80, 0xc042192570, 0x1, 0x0, ...)
	/usr/local/go19/src/net/ipsock_posix.go:141 +0x158
net.doDialTCP(0x880800, 0xc0420383c0, 0x720741, 0x3, 0x0, 0xc042192570, 0x8d5aa8, 0x0, 0x0)
	/usr/local/go19/src/net/tcpsock_posix.go:62 +0xc0
net.dialTCP(0x880800, 0xc0420383c0, 0x720741, 0x3, 0x0, 0xc042192570, 0xbe739053c662aa9c, 0x6fc23ac00, 0x8b6420)
	/usr/local/go19/src/net/tcpsock_posix.go:58 +0xeb
net.dialSingle(0x880800, 0xc0420383c0, 0xc0421a4100, 0x87e740, 0xc042192570, 0x0, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/dial.go:547 +0x3e9
net.dialSerial(0x880800, 0xc0420383c0, 0xc0421a4100, 0xc042032180, 0x1, 0x1, 0x0, 0x0, 0x0, 0x0)
	/usr/local/go19/src/net/dial.go:515 +0x24e
net.(*Dialer).DialContext(0xc04207c0c0, 0x880780, 0xc042034300, 0x720741, 0x3, 0xc04200e0e0, 0xf, 0x0, 0x0, 0x0, ...)
	/usr/local/go19/src/net/dial.go:397 +0x6f5
net.(*Dialer).DialContext-fm(0x880780, 0xc042034300, 0x720741, 0x3, 0xc04200e0e0, 0xf, 0x0, 0xc042023998, 0x5e38f0, 0xc042034300)
	/usr/local/go19/src/net/http/transport.go:46 +0x7a
net/http.(*Transport).dial(0x8b1280, 0x880780, 0xc042034300, 0x720741, 0x3, 0xc04200e0e0, 0xf, 0xc042023a70, 0xc042028700, 0x65f1d0, ...)
	/usr/local/go19/src/net/http/transport.go:884 +0x22a
net/http.(*Transport).dialConn(0x8b1280, 0x880780, 0xc042034300, 0x0, 0xc0420465e0, 0x4, 0xc04200e0e0, 0xf, 0x1, 0x0, ...)
	/usr/local/go19/src/net/http/transport.go:1060 +0x1d69
net/http.(*Transport).getConn.func4(0x8b1280, 0x880780, 0xc042034300, 0xc042192420, 0xc0421a80c0)
	/usr/local/go19/src/net/http/transport.go:943 +0x7f
created by net/http.(*Transport).getConn
	/usr/local/go19/src/net/http/transport.go:942 +0x39a

goroutine 9 [chan receive]:
net.(*netFD).connect.func2(0x880800, 0xc0420383c0, 0xc04219a240, 0xc0421a8300)
	/usr/local/go19/src/net/fd_windows.go:110 +0x16a
created by net.(*netFD).connect
	/usr/local/go19/src/net/fd_windows.go:104 +0x218

[davecheney]

If the retro you created does not use net/http/httputil please raise a separate bug. It’s easy to address multiple issues with one change if necessary so there’s little cost in keeping potentially unrelated issues separate.

…

On 23 Oct 2017, at 22:00, Felix Geisendörfer ***@***.***> wrote: @davecheney I just realized that I can cross-compile the httputil test: GOOS=windows GOARCH=amd64 go test -c -o httputil_test.exe net/http/httputil I then executed it on the production machine and got the same results as the original author of this issue above (see below). Please confirm if you still want me to open a separate issue, or if this is enough evidence to confirm that both issues are identical. $ while ./httputil_test.exe -test.short; do :; done fatal error: all goroutines are asleep - deadlock! goroutine 1 [chan receive]: testing.(*T).Run(0xc04211a000, 0x723c71, 0x10, 0x7374c8, 0x482901) /usr/local/go19/src/testing/testing.go:790 +0x303 testing.runTests.func1(0xc04211a000) /usr/local/go19/src/testing/testing.go:1004 +0x6b testing.tRunner(0xc04211a000, 0xc042063de0) /usr/local/go19/src/testing/testing.go:746 +0xd7 testing.runTests(0xc0420da700, 0x8b1760, 0x11, 0x11, 0x10) /usr/local/go19/src/testing/testing.go:1002 +0x2df testing.(*M).Run(0xc042063f18, 0xc042063f70) /usr/local/go19/src/testing/testing.go:921 +0x118 main.main() net/http/httputil/_test/_testmain.go:88 +0xe2 goroutine 40 [select]: net/http.(*persistConn).roundTrip(0xc042095200, 0xc042079aa0, 0x0, 0x0, 0x0) /usr/local/go19/src/net/http/transport.go:1970 +0x60f net/http.(*Transport).RoundTrip(0xc04211a960, 0xc0420f5100, 0xc04211a960, 0x0, 0x0) /usr/local/go19/src/net/http/transport.go:413 +0x999 net/http.send(0xc0420f5100, 0x87bf80, 0xc04211a960, 0x0, 0x0, 0x0, 0xc0420660a0, 0x100, 0xc042183a48, 0x1) /usr/local/go19/src/net/http/client.go:249 +0x1b0 net/http.(*Client).send(0xc042079920, 0xc0420f5100, 0x0, 0x0, 0x0, 0xc0420660a0, 0x0, 0x1, 0xc18fe0) /usr/local/go19/src/net/http/client.go:173 +0x104 net/http.(*Client).Do(0xc042079920, 0xc0420f5100, 0x7, 0x720711, 0x3) /usr/local/go19/src/net/http/client.go:602 +0x294 net/http/httputil.TestReverseProxy(0xc04211a780) /usr/local/go19/src/net/http/httputil/reverseproxy_test.go:91 +0x3c4 testing.tRunner(0xc04211a780, 0x7374c8) /usr/local/go19/src/testing/testing.go:746 +0xd7 created by testing.(*T).Run /usr/local/go19/src/testing/testing.go:789 +0x2e5 goroutine 41 [IO wait]: internal/poll.runtime_pollWait(0xc1d5f0, 0x72, 0xc042098b58) /usr/local/go19/src/runtime/netpoll.go:173 +0x5e internal/poll.(*pollDesc).wait(0xc042098c98, 0x72, 0x87a400, 0x0, 0x0) /usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5 internal/poll.(*ioSrv).ExecIO(0x8b4640, 0xc042098b58, 0xc0420db160, 0x2, 0x1, 0x0) /usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a internal/poll.(*FD).acceptOne(0xc042098b40, 0xd4, 0xc0420dc1c0, 0x2, 0x2, 0xc042098b58, 0xc042028380, 0xc042131d28, 0x41159f, 0x10) /usr/local/go19/src/internal/poll/fd_windows.go:748 +0xae internal/poll.(*FD).Accept(0xc042098b40, 0xc04203d420, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /usr/local/go19/src/internal/poll/fd_windows.go:782 +0x171 net.(*netFD).accept(0xc042098b40, 0xc042131ea8, 0x4010ee, 0xc042041020) /usr/local/go19/src/net/fd_windows.go:192 +0x88 net.(*TCPListener).accept(0xc042066078, 0x64106f, 0x459aa0, 0xc042131ef0) /usr/local/go19/src/net/tcpsock_posix.go:136 +0x35 net.(*TCPListener).Accept(0xc042066078, 0x7371d0, 0xc042040fa0, 0x880840, 0xc042192090) /usr/local/go19/src/net/tcpsock.go:247 +0x50 net/http.(*Server).Serve(0xc04207ac30, 0x880100, 0xc042066078, 0x0, 0x0) /usr/local/go19/src/net/http/server.go:2695 +0x1b9 net/http/httptest.(*Server).goServe.func1(0xc04211c9a0) /usr/local/go19/src/net/http/httptest/server.go:280 +0x74 created by net/http/httptest.(*Server).goServe /usr/local/go19/src/net/http/httptest/server.go:278 +0x63 goroutine 4 [select]: net/http.(*Transport).getConn(0x8b1280, 0xc0421923f0, 0x0, 0xc0420465e0, 0x4, 0xc04200e0e0, 0xf, 0x0, 0x0, 0x150) /usr/local/go19/src/net/http/transport.go:948 +0x5c6 net/http.(*Transport).RoundTrip(0x8b1280, 0xc0421a0400, 0xf, 0xc04200e070, 0x9) /usr/local/go19/src/net/http/transport.go:400 +0x6ad net/http/httputil.(*ReverseProxy).ServeHTTP(0xc042044c40, 0x880280, 0xc0421aa000, 0xc0421a0200) /usr/local/go19/src/net/http/httputil/reverseproxy.go:201 +0x2e4 net/http.serverHandler.ServeHTTP(0xc04207ad00, 0x880280, 0xc0421aa000, 0xc0421a0200) /usr/local/go19/src/net/http/server.go:2619 +0xbb net/http.(*conn).serve(0xc04219c000, 0x880780, 0xc042034180) /usr/local/go19/src/net/http/server.go:1801 +0x724 created by net/http.(*Server).Serve /usr/local/go19/src/net/http/server.go:2720 +0x28f goroutine 47 [IO wait]: internal/poll.runtime_pollWait(0xc1d230, 0x72, 0x0) /usr/local/go19/src/runtime/netpoll.go:173 +0x5e internal/poll.(*pollDesc).wait(0xc042099358, 0x72, 0x87a400, 0x0, 0x0) /usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5 internal/poll.(*ioSrv).ExecIO(0x8b4640, 0xc042099218, 0x736fe8, 0x410e11, 0xc042044e80, 0x40) /usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a internal/poll.(*FD).Read(0xc042099200, 0xc04219f000, 0x1000, 0x1000, 0x0, 0x0, 0x0) /usr/local/go19/src/internal/poll/fd_windows.go:439 +0x266 net.(*netFD).Read(0xc042099200, 0xc04219f000, 0x1000, 0x1000, 0xc04212d8c8, 0x637ed2, 0x6f3440) /usr/local/go19/src/net/fd_windows.go:151 +0x59 net.(*conn).Read(0xc0420660b8, 0xc04219f000, 0x1000, 0x1000, 0x0, 0x0, 0x0) /usr/local/go19/src/net/net.go:176 +0x74 net/http.(*connReader).Read(0xc042079e30, 0xc04219f000, 0x1000, 0x1000, 0x43760b, 0xc04212d970, 0x64d9ea) /usr/local/go19/src/net/http/server.go:753 +0x10c bufio.(*Reader).fill(0xc04207d500) /usr/local/go19/src/bufio/bufio.go:97 +0x121 bufio.(*Reader).ReadSlice(0xc04207d500, 0xa, 0x5, 0x0, 0x8d5aa8, 0xc042028380, 0xbc06a8) /usr/local/go19/src/bufio/bufio.go:338 +0x33 bufio.(*Reader).ReadLine(0xc04207d500, 0x100, 0xf8, 0x715f00, 0xc04212da98, 0x220000402319, 0xf8) /usr/local/go19/src/bufio/bufio.go:367 +0x3b net/textproto.(*Reader).readLineSlice(0xc0420789f0, 0xc04212db20, 0xc04212db20, 0x41159f, 0x100, 0x715f00) /usr/local/go19/src/net/textproto/reader.go:55 +0x77 net/textproto.(*Reader).ReadLine(0xc0420789f0, 0xc0420f5200, 0x0, 0xc04212db90, 0x48e0d9) /usr/local/go19/src/net/textproto/reader.go:36 +0x32 net/http.readRequest(0xc04207d500, 0x0, 0xc0420f5200, 0x0, 0x0) /usr/local/go19/src/net/http/request.go:925 +0xa0 net/http.(*conn).readRequest(0xc042040fa0, 0x880780, 0xc042044e00, 0x0, 0x0, 0x0) /usr/local/go19/src/net/http/server.go:933 +0x183 net/http.(*conn).serve(0xc042040fa0, 0x880780, 0xc042044e00) /usr/local/go19/src/net/http/server.go:1739 +0x515 created by net/http.(*Server).Serve /usr/local/go19/src/net/http/server.go:2720 +0x28f goroutine 42 [IO wait]: internal/poll.runtime_pollWait(0xc1d530, 0x72, 0xc042098d98) /usr/local/go19/src/runtime/netpoll.go:173 +0x5e internal/poll.(*pollDesc).wait(0xc042098ed8, 0x72, 0x87a400, 0x0, 0x0) /usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5 internal/poll.(*ioSrv).ExecIO(0x8b4640, 0xc042098d98, 0xc0420020c0, 0x2, 0x1, 0x0) /usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a internal/poll.(*FD).acceptOne(0xc042098d80, 0xc4, 0xc0421980e0, 0x2, 0x2, 0xc042098d98, 0xc042028700, 0xc04212fd28, 0x41159f, 0x10) /usr/local/go19/src/internal/poll/fd_windows.go:748 +0xae internal/poll.(*FD).Accept(0xc042098d80, 0xc042032060, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /usr/local/go19/src/internal/poll/fd_windows.go:782 +0x171 net.(*netFD).accept(0xc042098d80, 0xc04212fea8, 0x4010ee, 0xc04219c080) /usr/local/go19/src/net/fd_windows.go:192 +0x88 net.(*TCPListener).accept(0xc042066080, 0x64106f, 0x459aa0, 0xc04212fef0) /usr/local/go19/src/net/tcpsock_posix.go:136 +0x35 net.(*TCPListener).Accept(0xc042066080, 0x7371d0, 0xc04219c000, 0x880840, 0xc042079c80) /usr/local/go19/src/net/tcpsock.go:247 +0x50 net/http.(*Server).Serve(0xc04207ad00, 0x880100, 0xc042066080, 0x0, 0x0) /usr/local/go19/src/net/http/server.go:2695 +0x1b9 net/http/httptest.(*Server).goServe.func1(0xc04211ca10) /usr/local/go19/src/net/http/httptest/server.go:280 +0x74 created by net/http/httptest.(*Server).goServe /usr/local/go19/src/net/http/httptest/server.go:278 +0x63 goroutine 45 [IO wait]: internal/poll.runtime_pollWait(0xc1d470, 0x72, 0x0) /usr/local/go19/src/runtime/netpoll.go:173 +0x5e internal/poll.(*pollDesc).wait(0xc042099118, 0x72, 0x87a400, 0x0, 0x0) /usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5 internal/poll.(*ioSrv).ExecIO(0x8b4640, 0xc042098fd8, 0x736fe8, 0x0, 0x0, 0x0) /usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a internal/poll.(*FD).Read(0xc042098fc0, 0xc04217d000, 0x1000, 0x1000, 0x0, 0x0, 0x0) /usr/local/go19/src/internal/poll/fd_windows.go:439 +0x266 net.(*netFD).Read(0xc042098fc0, 0xc04217d000, 0x1000, 0x1000, 0xc042079401, 0x4656f9, 0x1) /usr/local/go19/src/net/fd_windows.go:151 +0x59 net.(*conn).Read(0xc0420660b0, 0xc04217d000, 0x1000, 0x1000, 0x0, 0x0, 0x0) /usr/local/go19/src/net/net.go:176 +0x74 net/http.(*persistConn).Read(0xc042095200, 0xc04217d000, 0x1000, 0x1000, 0x0, 0x0, 0xc042133b68) /usr/local/go19/src/net/http/transport.go:1391 +0x147 bufio.(*Reader).fill(0xc04207d380) /usr/local/go19/src/bufio/bufio.go:97 +0x121 bufio.(*Reader).Peek(0xc04207d380, 0x1, 0xc04203b740, 0xc042133c80, 0x7378c8, 0xc042133c30, 0x42cf5f) /usr/local/go19/src/bufio/bufio.go:129 +0x41 net/http.(*persistConn).readLoop(0xc042095200) /usr/local/go19/src/net/http/transport.go:1539 +0x18c created by net/http.(*Transport).dialConn /usr/local/go19/src/net/http/transport.go:1186 +0xa35 goroutine 46 [select]: net/http.(*persistConn).writeLoop(0xc042095200) /usr/local/go19/src/net/http/transport.go:1759 +0x16c created by net/http.(*Transport).dialConn /usr/local/go19/src/net/http/transport.go:1187 +0xa5a goroutine 5 [IO wait]: internal/poll.runtime_pollWait(0xc1d3b0, 0x72, 0x0) /usr/local/go19/src/runtime/netpoll.go:173 +0x5e internal/poll.(*pollDesc).wait(0xc04219a158, 0x72, 0x87a400, 0x0, 0x0) /usr/local/go19/src/internal/poll/fd_poll_runtime.go:85 +0xb5 internal/poll.(*ioSrv).ExecIO(0x8b4640, 0xc04219a018, 0x736fe8, 0x0, 0x0, 0x0) /usr/local/go19/src/internal/poll/fd_windows.go:195 +0x13a internal/poll.(*FD).Read(0xc04219a000, 0xc0421921f1, 0x1, 0x1, 0x0, 0x0, 0x0) /usr/local/go19/src/internal/poll/fd_windows.go:439 +0x266 net.(*netFD).Read(0xc04219a000, 0xc0421921f1, 0x1, 0x1, 0x0, 0x0, 0x0) /usr/local/go19/src/net/fd_windows.go:151 +0x59 net.(*conn).Read(0xc042004018, 0xc0421921f1, 0x1, 0x1, 0x0, 0x0, 0x0) /usr/local/go19/src/net/net.go:176 +0x74 net/http.(*connReader).backgroundRead(0xc0421921e0) /usr/local/go19/src/net/http/server.go:660 +0x69 created by net/http.(*connReader).startBackgroundRead /usr/local/go19/src/net/http/server.go:656 +0xdf goroutine 6 [select]: net/http/httputil.(*ReverseProxy).ServeHTTP.func1(0xc042036070, 0xc042032090, 0x880780, 0xc042034300) /usr/local/go19/src/net/http/httputil/reverseproxy.go:154 +0xf9 created by net/http/httputil.(*ReverseProxy).ServeHTTP /usr/local/go19/src/net/http/httputil/reverseproxy.go:153 +0xf23 goroutine 7 [IO wait]: internal/poll.runtime_pollWaitCanceled(0xc1d2f0, 0x77) /usr/local/go19/src/runtime/netpoll.go:189 +0x40 internal/poll.(*pollDesc).waitCanceled(0xc04219a398, 0x77) /usr/local/go19/src/internal/poll/fd_poll_runtime.go:101 +0x4e internal/poll.(*ioSrv).ExecIO(0x8b4648, 0xc04219a2f8, 0x736fe0, 0xc0421b3200, 0xc0421b3208, 0xc0421b31f8) /usr/local/go19/src/internal/poll/fd_windows.go:225 +0x238 internal/poll.(*FD).ConnectEx(0xc04219a240, 0x87c7c0, 0xc04200a540, 0xc0420383c0, 0xc04219a240) /usr/local/go19/src/internal/poll/fd_windows.go:738 +0x80 net.(*netFD).connect(0xc04219a240, 0x880800, 0xc0420383c0, 0x0, 0x0, 0x87c7c0, 0xc04200a540, 0x0, 0x0, 0x0, ...) /usr/local/go19/src/net/fd_windows.go:116 +0x243 net.(*netFD).dial(0xc04219a240, 0x880800, 0xc0420383c0, 0x881a80, 0x0, 0x881a80, 0xc042192570, 0xc0421b33f8, 0x542925) /usr/local/go19/src/net/sock_posix.go:142 +0xf3 net.socket(0x880800, 0xc0420383c0, 0x720741, 0x3, 0x2, 0x1, 0x0, 0x0, 0x881a80, 0x0, ...) /usr/local/go19/src/net/sock_posix.go:93 +0x1c1 net.internetSocket(0x880800, 0xc0420383c0, 0x720741, 0x3, 0x881a80, 0x0, 0x881a80, 0xc042192570, 0x1, 0x0, ...) /usr/local/go19/src/net/ipsock_posix.go:141 +0x158 net.doDialTCP(0x880800, 0xc0420383c0, 0x720741, 0x3, 0x0, 0xc042192570, 0x8d5aa8, 0x0, 0x0) /usr/local/go19/src/net/tcpsock_posix.go:62 +0xc0 net.dialTCP(0x880800, 0xc0420383c0, 0x720741, 0x3, 0x0, 0xc042192570, 0xbe739053c662aa9c, 0x6fc23ac00, 0x8b6420) /usr/local/go19/src/net/tcpsock_posix.go:58 +0xeb net.dialSingle(0x880800, 0xc0420383c0, 0xc0421a4100, 0x87e740, 0xc042192570, 0x0, 0x0, 0x0, 0x0) /usr/local/go19/src/net/dial.go:547 +0x3e9 net.dialSerial(0x880800, 0xc0420383c0, 0xc0421a4100, 0xc042032180, 0x1, 0x1, 0x0, 0x0, 0x0, 0x0) /usr/local/go19/src/net/dial.go:515 +0x24e net.(*Dialer).DialContext(0xc04207c0c0, 0x880780, 0xc042034300, 0x720741, 0x3, 0xc04200e0e0, 0xf, 0x0, 0x0, 0x0, ...) /usr/local/go19/src/net/dial.go:397 +0x6f5 net.(*Dialer).DialContext-fm(0x880780, 0xc042034300, 0x720741, 0x3, 0xc04200e0e0, 0xf, 0x0, 0xc042023998, 0x5e38f0, 0xc042034300) /usr/local/go19/src/net/http/transport.go:46 +0x7a net/http.(*Transport).dial(0x8b1280, 0x880780, 0xc042034300, 0x720741, 0x3, 0xc04200e0e0, 0xf, 0xc042023a70, 0xc042028700, 0x65f1d0, ...) /usr/local/go19/src/net/http/transport.go:884 +0x22a net/http.(*Transport).dialConn(0x8b1280, 0x880780, 0xc042034300, 0x0, 0xc0420465e0, 0x4, 0xc04200e0e0, 0xf, 0x1, 0x0, ...) /usr/local/go19/src/net/http/transport.go:1060 +0x1d69 net/http.(*Transport).getConn.func4(0x8b1280, 0x880780, 0xc042034300, 0xc042192420, 0xc0421a80c0) /usr/local/go19/src/net/http/transport.go:943 +0x7f created by net/http.(*Transport).getConn /usr/local/go19/src/net/http/transport.go:942 +0x39a goroutine 9 [chan receive]: net.(*netFD).connect.func2(0x880800, 0xc0420383c0, 0xc04219a240, 0xc0421a8300) /usr/local/go19/src/net/fd_windows.go:110 +0x16a created by net.(*netFD).connect /usr/local/go19/src/net/fd_windows.go:104 +0x218 — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

[felixge]

@davecheney ok, np. Just opened #22394 .

Happy to provide more information in either issue. Just let me know how I can help : )