Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

net/http: frequent timeouts on linux-amd64-wsl with goroutines blocked in checkConnErrorWriter.Write #60259

Open
bcmills opened this issue May 17, 2023 · 6 comments
Open

net/http: frequent timeouts on linux-amd64-wsl with goroutines blocked in checkConnErrorWriter.Write #60259

bcmills opened this issue May 17, 2023 · 6 comments
Labels
NeedsFix The path to resolution is known, but the work has not been done.
Milestone
Backlog

Comments

@bcmills
Copy link
Contributor

bcmills commented May 17, 2023 •
edited 

#!watchflakes
post <- builder ~ `.*-wsl` && log ~ `test timed out` && log ~ `^net/http.checkConnErrorWriter.Write`

(attn @golang/wsl; CC @qmuntal @neild)
@bcmills bcmills added this to the Backlog milestone May 17, 2023
@bcmills
Copy link
Contributor Author

bcmills commented May 17, 2023

https://build.golang.org/log/269049c7773455ebb4b1fbd7fbafa4a482b7b7e7:

2023/05/17 05:11:56 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc00028c980 127.0.0.1:64282 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m58s)
…
goroutine 7340 [IO wait, 2 minutes]:
runtime.gopark(0xc000c65348?, 0xb?, 0x1?, 0x0?, 0xc?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc000c65330 sp=0xc000c65310 pc=0x43bb2e
runtime.netpollblock(0x47ed7b?, 0x405466?, 0x0?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/netpoll.go:556 +0xf7 fp=0xc000c65368 sp=0xc000c65330 pc=0x434557
internal/poll.runtime_pollWait(0x7f0b2c59a5b8, 0x77)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/netpoll.go:335 +0x85 fp=0xc000c65388 sp=0xc000c65368 pc=0x467f45
internal/poll.(*pollDesc).wait(0xc000893900?, 0xc000807000?, 0x0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc000c653b0 sp=0xc000c65388 pc=0x49ebe7
internal/poll.(*pollDesc).waitWrite(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/internal/poll/fd_poll_runtime.go:93
internal/poll.(*FD).Write(0xc000893900, {0xc000807000, 0x1000, 0x1000})
	/tmp/workdir-host-linux-amd64-wsl/go/src/internal/poll/fd_unix.go:391 +0x2d6 fp=0xc000c65460 sp=0xc000c653b0 pc=0x49ff76
net.(*netFD).Write(0xc000893900, {0xc000807000?, 0x4d8516?, 0xc00040c340?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/fd_posix.go:96 +0x25 fp=0xc000c654a8 sp=0xc000c65460 pc=0x5e3585
net.(*conn).Write(0xc00028c980, {0xc000807000?, 0xc7a840?, 0x423045?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/net.go:191 +0x45 fp=0xc000c654f0 sp=0xc000c654a8 pc=0x5ee665
net.(*TCPConn).Write(0x1?, {0xc000807000?, 0x5fbd05?, 0x476c38?})
	<autogenerated>:1 +0x25 fp=0xc000c65520 sp=0xc000c654f0 pc=0x5fbd05
net/http.checkConnErrorWriter.Write({0xc000d2eff8?}, {0xc000807000?, 0xc000c655a8?, 0x4d230c?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:3597 +0x2d fp=0xc000c65570 sp=0xc000c65520 pc=0x6db26d
bufio.(*Writer).Flush(0xc000a61c00)
	/tmp/workdir-host-linux-amd64-wsl/go/src/bufio/bufio.go:642 +0x55 fp=0xc000c655b8 sp=0xc000c65570 pc=0x505575
bufio.(*Writer).Write(0xc000a61c00, {0xc000d2e000?, 0x8c2c13?, 0x4?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/bufio/bufio.go:686 +0xcd fp=0xc000c65618 sp=0xc000c655b8 pc=0x50578d
net/http.(*chunkWriter).Write(0xc0006d43c0, {0xc000d2e000, 0x8000, 0x8000})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:388 +0x106 fp=0xc000c65688 sp=0xc000c65618 pc=0x6ccd66
bufio.(*Writer).Write(0xc000a61c80, {0xc000d2e000?, 0xc000893900?, 0xc000807000?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/bufio/bufio.go:682 +0xea fp=0xc000c656e8 sp=0xc000c65688 pc=0x5057aa
net/http.(*response).write(0xc0006d4380, 0x8000, {0xc000d2e000, 0x8000, 0x8000}, {0x0, 0x0})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:1648 +0x22a fp=0xc000c657f0 sp=0xc000c656e8 pc=0x6d31aa
net/http.(*response).Write(0x850300?, {0xc000d2e000?, 0x1?, 0xc000d95e50?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:1606 +0x2a fp=0xc000c65838 sp=0xc000c657f0 pc=0x6d2eea
net/http.(*writerOnly).Write(0xc000c658d8?, {0xc000d2e000?, 0xc000d95e50?, 0xc000c658e8?})
	<autogenerated>:1 +0x29 fp=0xc000c65868 sp=0xc000c65838 pc=0x71aa89
io.copyBuffer({0x9902a0, 0xc000d95e50}, {0x9905a0, 0xc11fc8}, {0xc000d2e000, 0x8000, 0x8000})
	/tmp/workdir-host-linux-amd64-wsl/go/src/io/io.go:429 +0x1f4 fp=0xc000c658e8 sp=0xc000c65868 pc=0x498e74
io.CopyBuffer({0x9902a0?, 0xc000d95e50?}, {0x9905a0?, 0xc11fc8?}, {0xc000d2e000?, 0xc000198dcc?, 0x4?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/io/io.go:400 +0x36 fp=0xc000c65930 sp=0xc000c658e8 pc=0x498bf6
net/http.(*response).ReadFrom(0xc0006d4380, {0x9905a0?, 0xc11fc8})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:614 +0x2e5 fp=0xc000c65a08 sp=0xc000c65930 pc=0x6cd925
io.copyBuffer({0x9902c0, 0xc0006d4380}, {0x9905a0, 0xc11fc8}, {0x0, 0x0, 0x0})
	/tmp/workdir-host-linux-amd64-wsl/go/src/io/io.go:413 +0x147 fp=0xc000c65a88 sp=0xc000c65a08 pc=0x498dc7
io.Copy(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/io/io.go:386
net/http_test.testIssue4191_InfiniteGetToPutTimeout.func1({0x992e80?, 0xc0006d4380}, 0xc00056fb18?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/transport_test.go:2253 +0x4a fp=0xc000c65ad0 sp=0xc000c65a88 pc=0x7ee66a
net/http.HandlerFunc.ServeHTTP(0x443ce0?, {0x992e80?, 0xc0006d4380?}, 0x6cdde5?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:2134 +0x29 fp=0xc000c65af8 sp=0xc000c65ad0 pc=0x6d5529
net/http.(*ServeMux).ServeHTTP(0xc80c80?, {0x992e80, 0xc0006d4380}, 0xc000b26d00)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:2512 +0x142 fp=0xc000c65b48 sp=0xc000c65af8 pc=0x6d6e42
net/http.serverHandler.ServeHTTP({0xc000bd5470?}, {0x992e80?, 0xc0006d4380?}, 0x6?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:2936 +0x8e fp=0xc000c65b78 sp=0xc000c65b48 pc=0x6d826e
net/http.(*conn).serve(0xc000f23e60, {0x993ae0, 0xc000bd5170})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:2007 +0x5e5 fp=0xc000c65fb8 sp=0xc000c65b78 pc=0x6d4105
net/http.(*Server).Serve.func3()
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:3084 +0x28 fp=0xc000c65fe0 sp=0xc000c65fb8 pc=0x6d89e8
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc000c65fe8 sp=0xc000c65fe0 pc=0x46d8c1
created by net/http.(*Server).Serve in goroutine 7336
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/server.go:3084 +0x5cb

@bcmills
Copy link
Contributor Author

bcmills commented May 17, 2023

This same failure mode seems to also cause timeouts in net/http/cgi.TestCopyError. Retitling and updating watchflakes pattern.

@bcmills bcmills changed the title net/http: frequent timeouts in TestIssue4191_InfiniteGetToPutTimeout/h1 on linux-amd64-wsl net/http: frequent timeouts on linux-amd64-wsl with goroutines blocked in checkConnErrorWriter.Write May 17, 2023
@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-wsl` && `test timed out` && `^net/http.checkConnErrorWriter.Write`
2023-05-10 16:34 linux-amd64-wsl go@945a2b17 net/http.TestLinuxSendfile (log) 
2023/05/14 21:29:09 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000233ee8 127.0.0.1:53086 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m58s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m52s)
	TestLinuxSendfile (2m58s)

syscall.Syscall6(0xc0004254a0?, 0xc0004492e0?, 0xc000490c0e?, 0xc000490d30?, 0x5122ce?, 0xc000140b20?, 0xf?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/syscall/syscall_linux.go:91 +0x30 fp=0xc000490ba0 sp=0xc000490b18 pc=0x47fc90
os.(*Process).blockUntilWaitable(0xc00009f0b0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/wait_waitid.go:32 +0x76 fp=0xc000490c78 sp=0xc000490ba0 pc=0x4a9b16
os.(*Process).wait(0xc00009f0b0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec_unix.go:22 +0x25 fp=0xc000490cd8 sp=0xc000490c78 pc=0x4a3f65
os.(*Process).Wait(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec.go:132
os/exec.(*Cmd).Wait(0xc0004254a0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec/exec.go:890 +0x45 fp=0xc000490d40 sp=0xc000490cd8 pc=0x512ce5
os/exec.(*Cmd).Run(0x8bb3e0?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec/exec.go:590 +0x2d fp=0xc000490d60 sp=0xc000490d40 pc=0x5118cd
net/http_test.TestLinuxSendfile(0xc0004ff860)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/fs_test.go:1307 +0x30f fp=0xc000490f70 sp=0xc000490d60 pc=0x75692f
testing.tRunner(0xc0004ff860, 0x909550)
2023-05-15 15:42 linux-amd64-wsl go@e9f1bb96 net/http (log) 
2023/05/15 08:54:33 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc00049ed40 127.0.0.1:65246 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m55s)

goroutine 21613 [running]:
panic({0x82f6c0?, 0xc0018acb80?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc00064bf10 sp=0xc00064be60 pc=0x438a6c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc00064bfe0 sp=0xc00064bf10 pc=0x501bb9
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc00064bfe8 sp=0xc00064bfe0 pc=0x46d8a1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d
2023-05-15 19:12 linux-amd64-wsl go@ff3aefba net/http.TestLinuxSendfile (log) 
2023/05/15 12:30:59 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000570380 127.0.0.1:57037 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m55s)
	TestLinuxSendfile (2m59s)

syscall.Syscall6(0xc0003b0b00?, 0xc0004a5460?, 0xc00030bc0e?, 0xc00030bd30?, 0x511b2e?, 0xc000380fa0?, 0xf?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/syscall/syscall_linux.go:91 +0x30 fp=0xc00030bba0 sp=0xc00030bb18 pc=0x4805f0
os.(*Process).blockUntilWaitable(0xc0002ced80)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/wait_waitid.go:32 +0x76 fp=0xc00030bc78 sp=0xc00030bba0 pc=0x4aa6b6
os.(*Process).wait(0xc0002ced80)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec_unix.go:22 +0x25 fp=0xc00030bcd8 sp=0xc00030bc78 pc=0x4a4b05
os.(*Process).Wait(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec.go:132
os/exec.(*Cmd).Wait(0xc0003b0b00)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec/exec.go:890 +0x45 fp=0xc00030bd40 sp=0xc00030bcd8 pc=0x512545
os/exec.(*Cmd).Run(0x8c35b9?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec/exec.go:590 +0x2d fp=0xc00030bd60 sp=0xc00030bd40 pc=0x51112d
net/http_test.TestLinuxSendfile(0xc0001fb520)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/fs_test.go:1307 +0x30f fp=0xc00030bf70 sp=0xc00030bd60 pc=0x75dacf
testing.tRunner(0xc0001fb520, 0x9117b0)
2023-05-16 01:41 linux-amd64-wsl go@65306bcd net/http.TestLinuxSendfile (log) 
2023/05/15 21:31:36 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc00048c6a0 127.0.0.1:64130 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m58s)
	TestLinuxSendfile (2m59s)

runtime.gopark(0xc000bc3570?, 0x6?, 0x1c?, 0x53?, 0xc000bc3384?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc000bc3208 sp=0xc000bc31e8 pc=0x43bb2e
...
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:724 +0x912 fp=0xc000bc3ce0 sp=0xc000bc3ad0 pc=0x68cf12
net/http.(*Client).Do(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:590
net/http.(*Client).Post(0x8c80e8?, {0xc000b13320?, 0xc000bc3e70?}, {0x0, 0x0}, {0x0?, 0x0?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:857 +0x146 fp=0xc000bc3d60 sp=0xc000bc3ce0 pc=0x68e2c6
net/http.Post(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:834
net/http_test.TestLinuxSendfile(0xc000591380)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/fs_test.go:1340 +0xae5 fp=0xc000bc3f70 sp=0xc000bc3d60 pc=0x75e225
testing.tRunner(0xc000591380, 0x911708)
2023-05-16 18:01 linux-amd64-wsl go@6fc5e7d4 net/http.TestLinuxSendfile (log) 
2023/05/16 11:28:46 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc0003da720 127.0.0.1:49637 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m57s)
	TestLinuxSendfile (2m59s)

runtime.gopark(0xc0004cf570?, 0x6?, 0x1c?, 0x53?, 0xc0004cf384?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc0004cf208 sp=0xc0004cf1e8 pc=0x43bb2e
...
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:724 +0x912 fp=0xc0004cfce0 sp=0xc0004cfad0 pc=0x68cf12
net/http.(*Client).Do(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:590
net/http.(*Client).Post(0x8c80e8?, {0xc00050e120?, 0xc0004cfe70?}, {0x0, 0x0}, {0x0?, 0x0?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:857 +0x146 fp=0xc0004cfd60 sp=0xc0004cfce0 pc=0x68e2c6
net/http.Post(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:834
net/http_test.TestLinuxSendfile(0xc0005fab60)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/fs_test.go:1340 +0xae5 fp=0xc0004cff70 sp=0xc0004cfd60 pc=0x75e225
testing.tRunner(0xc0005fab60, 0x911708)
2023-05-16 19:16 linux-amd64-wsl go@4cf79e47 net/http.TestLinuxSendfile (log) 
2023/05/16 12:33:28 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000347180 127.0.0.1:52025 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m58s)
	TestLinuxSendfile (2m58s)

syscall.Syscall6(0xc0013a89a0?, 0xc0002d25a0?, 0xc00065ec0e?, 0xc00065ed30?, 0x511a04?, 0xc000b18690?, 0xf?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/syscall/syscall_linux.go:91 +0x30 fp=0xc00065eba0 sp=0xc00065eb18 pc=0x4805f0
os.(*Process).blockUntilWaitable(0xc000563200)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/wait_waitid.go:32 +0x76 fp=0xc00065ec78 sp=0xc00065eba0 pc=0x4aa616
os.(*Process).wait(0xc000563200)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec_unix.go:22 +0x25 fp=0xc00065ecd8 sp=0xc00065ec78 pc=0x4a4a85
os.(*Process).Wait(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec.go:132
os/exec.(*Cmd).Wait(0xc0013a89a0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec/exec.go:890 +0x45 fp=0xc00065ed40 sp=0xc00065ecd8 pc=0x512405
os/exec.(*Cmd).Run(0x8c35b9?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec/exec.go:590 +0x2d fp=0xc00065ed60 sp=0xc00065ed40 pc=0x510fcd
net/http_test.TestLinuxSendfile(0xc00045a9c0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/fs_test.go:1307 +0x30a fp=0xc00065ef70 sp=0xc00065ed60 pc=0x75da4a
testing.tRunner(0xc00045a9c0, 0x911708)
2023-05-16 21:37 linux-amd64-wsl go@51fe7062 net/http.TestLinuxSendfile (log) 
2023/05/17 01:41:00 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc0001a9ae0 127.0.0.1:57132 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m55s)
	TestLinuxSendfile (2m59s)

runtime.gopark(0xc0004f1570?, 0x6?, 0x1c?, 0x53?, 0xc0004f1384?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/proc.go:387 +0xce fp=0xc0004f1208 sp=0xc0004f11e8 pc=0x43bb2e
...
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:724 +0x912 fp=0xc0004f1ce0 sp=0xc0004f1ad0 pc=0x68cf12
net/http.(*Client).Do(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:590
net/http.(*Client).Post(0x8c80e8?, {0xc000c8dbc0?, 0xc0004f1e70?}, {0x0, 0x0}, {0x0?, 0x0?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:857 +0x146 fp=0xc0004f1d60 sp=0xc0004f1ce0 pc=0x68e2c6
net/http.Post(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/client.go:834
net/http_test.TestLinuxSendfile(0xc000254340)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/fs_test.go:1340 +0xae5 fp=0xc0004f1f70 sp=0xc0004f1d60 pc=0x75e225
testing.tRunner(0xc000254340, 0x911708)
2023-05-16 21:40 linux-amd64-wsl go@d29dd2ec net/http.TestLinuxSendfile (log) 
2023/05/16 14:56:20 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc0004d01b8 127.0.0.1:56116 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m57s)
	TestLinuxSendfile (2m59s)

syscall.Syscall6(0xc00100c2c0?, 0xc00146e020?, 0xc0000edc0e?, 0xc0000edd30?, 0x511a04?, 0xc0017c8190?, 0xf?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/syscall/syscall_linux.go:91 +0x30 fp=0xc0000edba0 sp=0xc0000edb18 pc=0x4805f0
os.(*Process).blockUntilWaitable(0xc0004da630)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/wait_waitid.go:32 +0x76 fp=0xc0000edc78 sp=0xc0000edba0 pc=0x4aa616
os.(*Process).wait(0xc0004da630)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec_unix.go:22 +0x25 fp=0xc0000edcd8 sp=0xc0000edc78 pc=0x4a4a85
os.(*Process).Wait(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec.go:132
os/exec.(*Cmd).Wait(0xc00100c2c0)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec/exec.go:890 +0x45 fp=0xc0000edd40 sp=0xc0000edcd8 pc=0x512405
os/exec.(*Cmd).Run(0x8c35b9?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/os/exec/exec.go:590 +0x2d fp=0xc0000edd60 sp=0xc0000edd40 pc=0x510fcd
net/http_test.TestLinuxSendfile(0xc000263a00)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/http/fs_test.go:1307 +0x30a fp=0xc0000edf70 sp=0xc0000edd60 pc=0x75da4a
testing.tRunner(0xc000263a00, 0x911708)
2023-05-16 23:01 linux-amd64-wsl go@099f5a98 net/http (log) 
2023/05/16 16:16:04 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000400158 127.0.0.1:59372 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m57s)

goroutine 22142 [running]:
panic({0x8306e0?, 0xc000096d50?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc0013d5f10 sp=0xc0013d5e60 pc=0x438a4c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc0013d5fe0 sp=0xc0013d5f10 pc=0x501a99
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc0013d5fe8 sp=0xc0013d5fe0 pc=0x46d8c1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d
2023-05-16 23:34 linux-amd64-wsl go@882cc4d5 net/http (log) 
2023/05/16 16:50:11 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc0001fb588 127.0.0.1:61379 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m58s)

goroutine 21409 [running]:
panic({0x8306e0?, 0xc000bc4900?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc001482f10 sp=0xc001482e60 pc=0x438a4c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc001482fe0 sp=0xc001482f10 pc=0x501a99
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc001482fe8 sp=0xc001482fe0 pc=0x46d8c1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d

— watchflakes

@qmuntal
Copy link
Contributor

qmuntal commented May 17, 2023

This failure module was not very common till a couple of days ago, and I don't see any commit that could have regressed the net package.. Is the builder healthy/has it enough space on disk?

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-wsl` && `test timed out` && `^net/http.checkConnErrorWriter.Write`
2023-05-17 04:58 linux-amd64-wsl go@547aed18 net/http (log) 
2023/05/16 22:18:08 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc0003e8018 127.0.0.1:52036 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m57s)

goroutine 22230 [running]:
panic({0x8306e0?, 0xc0012aaa20?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc000689f10 sp=0xc000689e60 pc=0x438a4c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc000689fe0 sp=0xc000689f10 pc=0x501a99
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc000689fe8 sp=0xc000689fe0 pc=0x46d8c1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d
2023-05-17 11:57 linux-amd64-wsl go@7bc32817 net/http (log) 
2023/05/17 05:11:56 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc00028c980 127.0.0.1:64282 in state active
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetToPutTimeout (2m59s)
	TestIssue4191_InfiniteGetToPutTimeout/h1 (2m58s)

goroutine 21548 [running]:
panic({0x8306e0?, 0xc000448a80?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc00071bf10 sp=0xc00071be60 pc=0x438a4c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc00071bfe0 sp=0xc00071bf10 pc=0x501a99
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc00071bfe8 sp=0xc00071bfe0 pc=0x46d8c1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d

— watchflakes

@heschi heschi added the NeedsFix The path to resolution is known, but the work has not been done. label May 17, 2023
@mengzhuo
Copy link
Contributor

This failure module was not very common till a couple of days ago, and I don't see any commit that could have regressed the net package.. Is the builder healthy/has it enough space on disk?

Sorry for these wsl related issues.

At first, The wsl-2.farm.mzh.io builder try to update to Win10 22H2 automatically and run out free disk. WSL became read only which triggered #60253

However after I resize disk the ESXi report disk failure so I had to make a new VM and reinstall Windows, which is default to WSL1 instead of WSL2 (causing #60295, #60258 )
Since it's a new VM, I forget to drop it's IPv6 (causing #60257 )

I'll backup all builders in the future and monitor free disk.

@qmuntal qmuntal mentioned this issue May 19, 2023
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
NeedsFix The path to resolution is known, but the work has not been done.
Projects
Test Flakes
Status: No status
Milestone
Backlog
Development

No branches or pull requests
5 participants
@mengzhuo @qmuntal @bcmills @gopherbot @heschi