net/http/cgi: TestCopyError failures due to unexpected child process

[gopherbot]

#!watchflakes
post <- goos == "darwin" && pkg == "net/http/cgi" && test == "TestCopyError" && `expected child to be gone`

Issue created automatically to collect these failures.

Example (log):

2022/12/08 14:53:02 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000228030 127.0.0.1:50046 in state active
2022/12/08 14:53:03 cgi: copy error: write tcp 127.0.0.1:50045->127.0.0.1:50046: write: broken pipe
--- FAIL: TestCopyError (21.17s)
    host_test.go:425: post-conn.Close, expected child to be gone
2022/12/08 14:53:03 cgi: copy error: past write limit
2022/12/08 14:53:03 cgi: no headers
2022/12/08 14:53:03 cgi: missing required Content-Type in headers
2022/12/08 14:53:03 cgi: no headers

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http/cgi" && test == "TestCopyError"

2022-12-08 18:29 darwin-amd64-12_0 go@f368abb4 net/http/cgi.TestCopyError (log)

2022/12/08 14:53:02 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000228030 127.0.0.1:50046 in state active
2022/12/08 14:53:03 cgi: copy error: write tcp 127.0.0.1:50045->127.0.0.1:50046: write: broken pipe
--- FAIL: TestCopyError (21.17s)
    host_test.go:425: post-conn.Close, expected child to be gone
2022/12/08 14:53:03 cgi: copy error: past write limit
2022/12/08 14:53:03 cgi: no headers
2022/12/08 14:53:03 cgi: missing required Content-Type in headers
2022/12/08 14:53:03 cgi: no headers

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http/cgi" && test == "TestCopyError"

2023-02-15 21:52 darwin-amd64-12_0 go@7b398b1f net/http/cgi.TestCopyError (log)

2023/02/16 00:25:31 cgi: copy error: write tcp 127.0.0.1:50013->127.0.0.1:50014: write: connection reset by peer
--- FAIL: TestCopyError (19.33s)
    host_test.go:425: post-conn.Close, expected child to be gone
2023/02/16 00:25:31 cgi: copy error: past write limit
2023/02/16 00:25:32 cgi: no headers
2023/02/16 00:25:32 cgi: missing required Content-Type in headers
2023/02/16 00:25:32 cgi: no headers

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http/cgi" && test == "TestCopyError"

2023-04-27 22:26 darwin-amd64-13 go@afe2d222 net/http/cgi.TestCopyError (log)

2023/04/27 18:40:28 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc00003e068 127.0.0.1:50048 in state active
2023/04/27 18:40:37 cgi: copy error: write tcp 127.0.0.1:50047->127.0.0.1:50048: write: broken pipe
--- FAIL: TestCopyError (29.13s)
    host_test.go:425: post-conn.Close, expected child to be gone
2023/04/27 18:40:38 cgi: copy error: past write limit
2023/04/27 18:40:38 cgi: no headers
2023/04/27 18:40:39 cgi: missing required Content-Type in headers
2023/04/27 18:40:39 cgi: no headers

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http/cgi" && test == "TestCopyError"

2023-05-11 19:07 darwin-amd64-13 go@a2737b1a net/http/cgi.TestCopyError (log)

2023/05/12 04:06:15 cgi: copy error: write tcp 127.0.0.1:50045->127.0.0.1:50046: write: broken pipe
--- FAIL: TestCopyError (28.73s)
    host_test.go:425: post-conn.Close, expected child to be gone
2023/05/12 04:06:16 cgi: copy error: past write limit
2023/05/12 04:06:16 cgi: no headers
2023/05/12 04:06:16 cgi: missing required Content-Type in headers
2023/05/12 04:06:16 cgi: no headers

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http/cgi" && test == "TestCopyError"

2023-05-16 18:01 linux-amd64-wsl go@6fc5e7d4 net/http/cgi.TestCopyError (log)

2023/05/16 11:28:59 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc00009a258 127.0.0.1:65346 in state active
panic: test timed out after 3m0s
running tests:
	TestCopyError (3m0s)

runtime.gopark(0xc0000f3bb0?, 0x675ef4?, 0x60?, 0x60?, 0x6d27a0?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc0000f3af8 sp=0xc0000f3ad8 pc=0x43b86e
runtime.goparkunlock(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:393
...
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:771 +0x1b8 fp=0xc0000f3ce8 sp=0xc0000f3ca8 pc=0x438198
runtime.Goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:523 +0x145 fp=0xc0000f3d58 sp=0xc0000f3ce8 pc=0x4378e5
testing.(*common).FailNow(0xc00010f860)
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:999 +0x4a fp=0xc0000f3db0 sp=0xc0000f3d58 pc=0x4e43aa
testing.(*common).Fatalf(0xc00010f860, {0x731e39?, 0xc000200000?}, {0x0?, 0x1388?, 0x1388?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:1083 +0x5e fp=0xc0000f3e08 sp=0xc0000f3db0 pc=0x4e4f3e
net/http/cgi.TestCopyError(0xc00010f860)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/cgi/host_test.go:425 +0x5f7 fp=0xc0000f3f70 sp=0xc0000f3e08 pc=0x693857
testing.tRunner(0xc00010f860, 0x7551f8)

2023-05-16 19:16 linux-amd64-wsl go@4cf79e47 net/http/cgi.TestCopyError (log)

2023/05/16 12:33:42 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000040060 127.0.0.1:51410 in state active
panic: test timed out after 3m0s
running tests:
	TestCopyError (3m0s)

runtime.gopark(0xc0000f3bb0?, 0x675ef4?, 0xc0?, 0x66?, 0x6d27a0?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc0000f3af8 sp=0xc0000f3ad8 pc=0x43b86e
runtime.goparkunlock(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:393
...
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:771 +0x1b8 fp=0xc0000f3ce8 sp=0xc0000f3ca8 pc=0x438198
runtime.Goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:523 +0x145 fp=0xc0000f3d58 sp=0xc0000f3ce8 pc=0x4378e5
testing.(*common).FailNow(0xc000007ba0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:999 +0x4a fp=0xc0000f3db0 sp=0xc0000f3d58 pc=0x4e43aa
testing.(*common).Fatalf(0xc000007ba0, {0x731e39?, 0xc0001ca000?}, {0x0?, 0x1388?, 0x1388?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:1083 +0x5e fp=0xc0000f3e08 sp=0xc0000f3db0 pc=0x4e4f3e
net/http/cgi.TestCopyError(0xc000007ba0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/cgi/host_test.go:425 +0x5f7 fp=0xc0000f3f70 sp=0xc0000f3e08 pc=0x693857
testing.tRunner(0xc000007ba0, 0x7551f8)

2023-05-16 21:37 linux-amd64-wsl go@51fe7062 net/http/cgi.TestCopyError (log)

2023/05/17 01:41:10 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc00009a1d8 127.0.0.1:56099 in state active
panic: test timed out after 3m0s
running tests:
	TestCopyError (3m0s)

runtime.gopark(0xc0000edbb0?, 0x675ef4?, 0x80?, 0x61?, 0x6d27a0?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc0000edaf8 sp=0xc0000edad8 pc=0x43b86e
runtime.goparkunlock(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:393
...
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:771 +0x1b8 fp=0xc0000edce8 sp=0xc0000edca8 pc=0x438198
runtime.Goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:523 +0x145 fp=0xc0000edd58 sp=0xc0000edce8 pc=0x4378e5
testing.(*common).FailNow(0xc000007d40)
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:999 +0x4a fp=0xc0000eddb0 sp=0xc0000edd58 pc=0x4e43aa
testing.(*common).Fatalf(0xc000007d40, {0x731e39?, 0xc000158000?}, {0x0?, 0x1388?, 0x1388?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:1083 +0x5e fp=0xc0000ede08 sp=0xc0000eddb0 pc=0x4e4f3e
net/http/cgi.TestCopyError(0xc000007d40)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/cgi/host_test.go:425 +0x5f7 fp=0xc0000edf70 sp=0xc0000ede08 pc=0x693857
testing.tRunner(0xc000007d40, 0x7551f8)

2023-05-16 21:40 linux-amd64-wsl go@d29dd2ec net/http/cgi.TestCopyError (log)

2023/05/16 14:56:32 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000040208 127.0.0.1:55389 in state active
panic: test timed out after 3m0s
running tests:
	TestCopyError (3m0s)

runtime.gopark(0xc00013fbb0?, 0x675ef4?, 0x80?, 0x44?, 0x6d27a0?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc00013faf8 sp=0xc00013fad8 pc=0x43b86e
runtime.goparkunlock(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:393
...
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:771 +0x1b8 fp=0xc00013fce8 sp=0xc00013fca8 pc=0x438198
runtime.Goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:523 +0x145 fp=0xc00013fd58 sp=0xc00013fce8 pc=0x4378e5
testing.(*common).FailNow(0xc000082820)
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:999 +0x4a fp=0xc00013fdb0 sp=0xc00013fd58 pc=0x4e43aa
testing.(*common).Fatalf(0xc000082820, {0x731e39?, 0xc0001a6000?}, {0x0?, 0x1388?, 0x1388?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:1083 +0x5e fp=0xc00013fe08 sp=0xc00013fdb0 pc=0x4e4f3e
net/http/cgi.TestCopyError(0xc000082820)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/cgi/host_test.go:425 +0x5f7 fp=0xc00013ff70 sp=0xc00013fe08 pc=0x693857
testing.tRunner(0xc000082820, 0x7551f8)

2023-05-16 23:34 linux-amd64-wsl go@882cc4d5 net/http/cgi.TestCopyError (log)

2023/05/16 16:50:24 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc0000be058 127.0.0.1:60900 in state active
panic: test timed out after 3m0s
running tests:
	TestCopyError (3m0s)

runtime.gopark(0xc00016bbb0?, 0x675ef4?, 0xc0?, 0x26?, 0x6d27a0?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc00016baf8 sp=0xc00016bad8 pc=0x43b86e
runtime.goparkunlock(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:393
...
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:771 +0x1b8 fp=0xc00016bce8 sp=0xc00016bca8 pc=0x438198
runtime.Goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:523 +0x145 fp=0xc00016bd58 sp=0xc00016bce8 pc=0x4378e5
testing.(*common).FailNow(0xc0000829c0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:999 +0x4a fp=0xc00016bdb0 sp=0xc00016bd58 pc=0x4e43aa
testing.(*common).Fatalf(0xc0000829c0, {0x731e39?, 0xc00020c000?}, {0x0?, 0x1388?, 0x1388?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:1083 +0x5e fp=0xc00016be08 sp=0xc00016bdb0 pc=0x4e4f3e
net/http/cgi.TestCopyError(0xc0000829c0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/cgi/host_test.go:425 +0x5f7 fp=0xc00016bf70 sp=0xc00016be08 pc=0x693857
testing.tRunner(0xc0000829c0, 0x7551f8)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http/cgi" && test == "TestCopyError"

2023-05-17 04:58 linux-amd64-wsl go@547aed18 net/http/cgi.TestCopyError (log)

2023/05/16 22:18:20 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000040048 127.0.0.1:51158 in state active
panic: test timed out after 3m0s
running tests:
	TestCopyError (3m0s)

runtime.gopark(0xc0000edbb0?, 0x675ef4?, 0x0?, 0xc0?, 0x6d27a0?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc0000edaf8 sp=0xc0000edad8 pc=0x43b86e
runtime.goparkunlock(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:393
...
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:771 +0x1b8 fp=0xc0000edce8 sp=0xc0000edca8 pc=0x438198
runtime.Goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:523 +0x145 fp=0xc0000edd58 sp=0xc0000edce8 pc=0x4378e5
testing.(*common).FailNow(0xc000007a00)
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:999 +0x4a fp=0xc0000eddb0 sp=0xc0000edd58 pc=0x4e43aa
testing.(*common).Fatalf(0xc000007a00, {0x731e39?, 0xc000224000?}, {0x0?, 0x1388?, 0x1388?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:1083 +0x5e fp=0xc0000ede08 sp=0xc0000eddb0 pc=0x4e4f3e
net/http/cgi.TestCopyError(0xc000007a00)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/cgi/host_test.go:425 +0x5f7 fp=0xc0000edf70 sp=0xc0000ede08 pc=0x693857
testing.tRunner(0xc000007a00, 0x7551f8)

2023-05-17 11:57 linux-amd64-wsl go@7bc32817 net/http/cgi.TestCopyError (log)

2023/05/17 05:12:09 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000040260 127.0.0.1:63681 in state active
panic: test timed out after 3m0s
running tests:
	TestCopyError (3m0s)

runtime.gopark(0xc00013fbb0?, 0x675ef4?, 0x60?, 0xe0?, 0x6d27a0?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc00013faf8 sp=0xc00013fad8 pc=0x43b86e
runtime.goparkunlock(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:393
...
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:771 +0x1b8 fp=0xc00013fce8 sp=0xc00013fca8 pc=0x438198
runtime.Goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:523 +0x145 fp=0xc00013fd58 sp=0xc00013fce8 pc=0x4378e5
testing.(*common).FailNow(0xc000182b60)
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:999 +0x4a fp=0xc00013fdb0 sp=0xc00013fd58 pc=0x4e43aa
testing.(*common).Fatalf(0xc000182b60, {0x731e39?, 0xc0000d6000?}, {0x0?, 0x1388?, 0x1388?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:1083 +0x5e fp=0xc00013fe08 sp=0xc00013fdb0 pc=0x4e4f3e
net/http/cgi.TestCopyError(0xc000182b60)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/cgi/host_test.go:425 +0x5f7 fp=0xc00013ff70 sp=0xc00013fe08 pc=0x693857
testing.tRunner(0xc000182b60, 0x7551f8)

— watchflakes

[bcmills]

This looks like another instance of #63937.

[gopherbot]

Change https://go.dev/cl/554075 mentions this issue: net/http/cgi: in TestCopyError, check for a Handler.ServeHTTP goroutine instead of a running PID

[bcmills]

This looks like another instance of #63937.

Hmm, maybe not. The test can also also fail spuriously if the CGI process's PID is quickly reused by another long-running process (such as another test running in parallel).