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: frequent timeouts in TestSplice/tcp-to-tcp on linux-amd64-wsl #60258

Closed
bcmills opened this issue May 17, 2023 · 4 comments
Closed

net: frequent timeouts in TestSplice/tcp-to-tcp on linux-amd64-wsl #60258

bcmills opened this issue May 17, 2023 · 4 comments
Labels
NeedsFix The path to resolution is known, but the work has not been done. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Milestone
Backlog

Comments

@bcmills
Copy link
Contributor

bcmills commented May 17, 2023 •
edited 

#!watchflakes
post <- pkg == "net" && builder ~ `.*-wsl` && log ~ `test timed out` && log ~ `TestSplice/tcp-to-tcp \(\d+m\d+s\)`

As far as I can tell this always co-occurs with #60257. That may be important.
It is often (but not always) the /big subtest that times out.

https://build.golang.org/log/a1e647502ffe3ced34891a80b7bc714aebdf2ab3:

--- FAIL: TestTCPListener (0.00s)
    listen_test.go:72: skipping tcp  test
    listen_test.go:72: skipping tcp 0.0.0.0 test
    listen_test.go:72: skipping tcp ::ffff:0.0.0.0 test
    listen_test.go:72: skipping tcp :: test
    listen_test.go:90: tcp 127.0.0.1 should fail
panic: test timed out after 3m0s
running tests:
	TestSplice (2m58s)
	TestSplice/tcp-to-tcp (2m58s)
	TestSplice/tcp-to-tcp/big (2m58s)
…
goroutine 960 [syscall, 2 minutes]:
syscall.Syscall6(0x7fbac6abe808?, 0xc0000dbaf8?, 0x4673c5?, 0xc0000dbb08?, 0x405486?, 0xc0000dbb20?, 0x494747?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/syscall/syscall_linux.go:91 +0x30 fp=0xc0000dbad0 sp=0xc0000dba48 pc=0x47fef0
syscall.Splice(0xc0000ed480?, 0xc0002993e0?, 0xc0000dbb00?, 0x4f45f2?, 0x7fffe714db3f?, 0x46?)
	/tmp/workdir-host-linux-amd64-wsl/go/src/syscall/zsyscall_linux_amd64.go:1356 +0x45 fp=0xc0000dbb30 sp=0xc0000dbad0 pc=0x47ed25
internal/poll.splice(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/internal/poll/splice_linux.go:154
internal/poll.splicePump(0xc0000ed480, 0xc0000ed300?, 0x7000)
	/tmp/workdir-host-linux-amd64-wsl/go/src/internal/poll/splice_linux.go:129 +0x1a5 fp=0xc0000dbbd8 sp=0xc0000dbb30 pc=0x49c2a5
internal/poll.Splice(0xc0000dbcd8?, 0x40e9c5?, 0x7fffffffffffffff)
	/tmp/workdir-host-linux-amd64-wsl/go/src/internal/poll/splice_linux.go:59 +0x1f7 fp=0xc0000dbc70 sp=0xc0000dbbd8 pc=0x49bbd7
net.splice(0x0?, {0x6ee4c0?, 0xc0003d40d8?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/splice_linux.go:39 +0xdf fp=0xc0000dbcd0 sp=0xc0000dbc70 pc=0x5727df
net.(*TCPConn).readFrom(0xc0003d40f8, {0x6ee4c0, 0xc0003d40d8})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/tcpsock_posix.go:48 +0x28 fp=0xc0000dbd00 sp=0xc0000dbcd0 pc=0x574a48
net.(*TCPConn).ReadFrom(0xc0003d40f8, {0x6ee4c0?, 0xc0003d40d8?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/tcpsock.go:130 +0x30 fp=0xc0000dbd40 sp=0xc0000dbd00 pc=0x572e10
io.copyBuffer({0x6ee480, 0xc0003d40f8}, {0x6ee4c0, 0xc0003d40d8}, {0x0, 0x0, 0x0})
	/tmp/workdir-host-linux-amd64-wsl/go/src/io/io.go:413 +0x147 fp=0xc0000dbdc0 sp=0xc0000dbd40 pc=0x491ba7
io.Copy(...)
	/tmp/workdir-host-linux-amd64-wsl/go/src/io/io.go:386
net.spliceTestCase.test({{0x692331, 0x3}, {0x692331, 0x3}, 0x500000, 0x40000000, 0x0}, 0xc00041cb60)
	/tmp/workdir-host-linux-amd64-wsl/go/src/net/splice_test.go:89 +0x3e5 fp=0xc0000dbf20 sp=0xc0000dbdc0 pc=0x5ea125
net.spliceTestCase.test-fm(0xc000322760?)
	<autogenerated>:1 +0x3e fp=0xc0000dbf70 sp=0xc0000dbf20 pc=0x62289e
testing.tRunner(0xc00041cb60, 0xc0000cec00)
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:1595 +0xff fp=0xc0000dbfc0 sp=0xc0000dbf70 pc=0x4e5f1f
testing.(*T).Run.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:1648 +0x25 fp=0xc0000dbfe0 sp=0xc0000dbfc0 pc=0x4e6ea5
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc0000dbfe8 sp=0xc0000dbfe0 pc=0x46c6e1
created by testing.(*T).Run in goroutine 984
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:1648 +0x3ad

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

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && builder ~ `.*-wsl` && log ~ `test timed out` && log ~ `TestSplice/tcp-to-tcp \(\d+m\d+s\)`
2023-05-10 16:34 linux-amd64-wsl go@945a2b17 net.TestInterfaceMulticastAddrs (log) 
--- FAIL: TestInterfaceMulticastAddrs (0.00s)
    interface_test.go:158: num IPv6 multicast route clones = 0; want >0; summary: &{loop:1 other:1}, &{ipv4:2 ipv6:5}, &{ipv4:0 ipv6:0}
2023-05-15 15:42 linux-amd64-wsl go@e9f1bb96 net.TestInterfaceMulticastAddrs (log) 
--- FAIL: TestInterfaceMulticastAddrs (0.00s)
    interface_test.go:158: num IPv6 multicast route clones = 0; want >0; summary: &{loop:1 other:1}, &{ipv4:2 ipv6:5}, &{ipv4:0 ipv6:0}
2023-05-15 19:12 linux-amd64-wsl go@ff3aefba net.TestInterfaceMulticastAddrs (log) 
--- FAIL: TestInterfaceMulticastAddrs (0.00s)
    interface_test.go:158: num IPv6 multicast route clones = 0; want >0; summary: &{loop:1 other:1}, &{ipv4:2 ipv6:5}, &{ipv4:0 ipv6:0}
2023-05-16 01:41 linux-amd64-wsl go@65306bcd net.TestInterfaceMulticastAddrs (log) 
--- FAIL: TestInterfaceMulticastAddrs (0.00s)
    interface_test.go:158: num IPv6 multicast route clones = 0; want >0; summary: &{loop:1 other:1}, &{ipv4:2 ipv6:5}, &{ipv4:0 ipv6:0}

— watchflakes

@heschi heschi added the NeedsFix The path to resolution is known, but the work has not been done. label May 17, 2023
@mengzhuo mengzhuo mentioned this issue May 19, 2023
Open
@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && builder ~ `.*-wsl` && log ~ `test timed out` && log ~ `TestSplice/tcp-to-tcp \(\d+m\d+s\)`
2023-05-16 18:01 linux-amd64-wsl go@6fc5e7d4 net.TestTCPListener (log) 
--- FAIL: TestTCPListener (0.00s)
    listen_test.go:72: skipping tcp  test
    listen_test.go:72: skipping tcp 0.0.0.0 test
    listen_test.go:72: skipping tcp ::ffff:0.0.0.0 test
    listen_test.go:72: skipping tcp :: test
    listen_test.go:90: tcp 127.0.0.1 should fail
panic: test timed out after 3m0s
running tests:
	TestSplice (2m58s)
	TestSplice/tcp-to-tcp (2m58s)
	TestSplice/tcp-to-tcp/big (2m58s)

goroutine 1012 [running]:
panic({0x644740?, 0xc000476060?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc000158f10 sp=0xc000158e60 pc=0x43852c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc000158fe0 sp=0xc000158f10 pc=0x4ea139
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc000158fe8 sp=0xc000158fe0 pc=0x46c6e1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d
2023-05-16 19:16 linux-amd64-wsl go@4cf79e47 net.TestTCPListener (log) 
--- FAIL: TestTCPListener (0.00s)
    listen_test.go:72: skipping tcp  test
    listen_test.go:72: skipping tcp 0.0.0.0 test
    listen_test.go:72: skipping tcp ::ffff:0.0.0.0 test
    listen_test.go:72: skipping tcp :: test
    listen_test.go:90: tcp 127.0.0.1 should fail
panic: test timed out after 3m0s
running tests:
	TestSplice (2m58s)
	TestSplice/tcp-to-tcp (2m58s)
	TestSplice/tcp-to-tcp/big (2m58s)

goroutine 981 [running]:
panic({0x644740?, 0xc000098260?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc00013ef10 sp=0xc00013ee60 pc=0x43852c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc00013efe0 sp=0xc00013ef10 pc=0x4ea139
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc00013efe8 sp=0xc00013efe0 pc=0x46c6e1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d
2023-05-16 21:37 linux-amd64-wsl go@51fe7062 net.TestTCPListener (log) 
--- FAIL: TestTCPListener (0.00s)
    listen_test.go:72: skipping tcp  test
    listen_test.go:72: skipping tcp 0.0.0.0 test
    listen_test.go:72: skipping tcp ::ffff:0.0.0.0 test
    listen_test.go:72: skipping tcp :: test
    listen_test.go:90: tcp 127.0.0.1 should fail
panic: test timed out after 3m0s
running tests:
	TestSplice (2m57s)
	TestSplice/tcp-to-tcp (2m57s)
	TestSplice/tcp-to-tcp/big (2m57s)

goroutine 991 [running]:
panic({0x644740?, 0xc000306060?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc00004ff10 sp=0xc00004fe60 pc=0x43852c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc00004ffe0 sp=0xc00004ff10 pc=0x4ea139
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc00004ffe8 sp=0xc00004ffe0 pc=0x46c6e1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d
2023-05-16 21:40 linux-amd64-wsl go@d29dd2ec net.TestTCPListener (log) 
--- FAIL: TestTCPListener (0.00s)
    listen_test.go:72: skipping tcp  test
    listen_test.go:72: skipping tcp 0.0.0.0 test
    listen_test.go:72: skipping tcp ::ffff:0.0.0.0 test
    listen_test.go:72: skipping tcp :: test
    listen_test.go:90: tcp 127.0.0.1 should fail
panic: test timed out after 3m0s
running tests:
	TestSplice (2m58s)
	TestSplice/tcp-to-tcp (2m58s)
	TestSplice/tcp-to-tcp/big (2m58s)

goroutine 1000 [running]:
panic({0x644740?, 0xc000332060?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc00012ef10 sp=0xc00012ee60 pc=0x43852c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc00012efe0 sp=0xc00012ef10 pc=0x4ea139
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc00012efe8 sp=0xc00012efe0 pc=0x46c6e1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d
2023-05-16 23:01 linux-amd64-wsl go@099f5a98 net.TestTCPListener (log) 
--- FAIL: TestTCPListener (0.00s)
    listen_test.go:72: skipping tcp  test
    listen_test.go:72: skipping tcp 0.0.0.0 test
    listen_test.go:72: skipping tcp ::ffff:0.0.0.0 test
    listen_test.go:72: skipping tcp :: test
    listen_test.go:90: tcp 127.0.0.1 should fail
panic: test timed out after 3m0s
running tests:
	TestSplice (2m58s)
	TestSplice/tcp-to-tcp (2m58s)
	TestSplice/tcp-to-tcp/big (2m57s)

goroutine 1003 [running]:
panic({0x644740?, 0xc000026070?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc000233f10 sp=0xc000233e60 pc=0x43852c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc000233fe0 sp=0xc000233f10 pc=0x4ea139
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc000233fe8 sp=0xc000233fe0 pc=0x46c6e1
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.TestTCPListener (log) 
--- FAIL: TestTCPListener (0.00s)
    listen_test.go:72: skipping tcp  test
    listen_test.go:72: skipping tcp 0.0.0.0 test
    listen_test.go:72: skipping tcp ::ffff:0.0.0.0 test
    listen_test.go:72: skipping tcp :: test
    listen_test.go:90: tcp 127.0.0.1 should fail
panic: test timed out after 3m0s
running tests:
	TestSplice (2m58s)
	TestSplice/tcp-to-tcp (2m58s)
	TestSplice/tcp-to-tcp/big (2m58s)

goroutine 989 [running]:
panic({0x644740?, 0xc0003f6060?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc000050f10 sp=0xc000050e60 pc=0x43852c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc000050fe0 sp=0xc000050f10 pc=0x4ea139
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc000050fe8 sp=0xc000050fe0 pc=0x46c6e1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d
2023-05-17 04:58 linux-amd64-wsl go@547aed18 net.TestTCPListener (log) 
--- FAIL: TestTCPListener (0.00s)
    listen_test.go:72: skipping tcp  test
    listen_test.go:72: skipping tcp 0.0.0.0 test
    listen_test.go:72: skipping tcp ::ffff:0.0.0.0 test
    listen_test.go:72: skipping tcp :: test
    listen_test.go:90: tcp 127.0.0.1 should fail
panic: test timed out after 3m0s
running tests:
	TestSplice (2m58s)
	TestSplice/tcp-to-tcp (2m58s)
	TestSplice/tcp-to-tcp/big (2m58s)

goroutine 1010 [running]:
panic({0x644740?, 0xc0000260b0?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc0000b9f10 sp=0xc0000b9e60 pc=0x43852c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc0000b9fe0 sp=0xc0000b9f10 pc=0x4ea139
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc0000b9fe8 sp=0xc0000b9fe0 pc=0x46c6e1
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.TestTCPListener (log) 
--- FAIL: TestTCPListener (0.00s)
    listen_test.go:72: skipping tcp  test
    listen_test.go:72: skipping tcp 0.0.0.0 test
    listen_test.go:72: skipping tcp ::ffff:0.0.0.0 test
    listen_test.go:72: skipping tcp :: test
    listen_test.go:90: tcp 127.0.0.1 should fail
panic: test timed out after 3m0s
running tests:
	TestSplice (2m58s)
	TestSplice/tcp-to-tcp (2m58s)
	TestSplice/tcp-to-tcp/big (2m57s)

goroutine 878 [running]:
panic({0x644740?, 0xc000304060?})
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/panic.go:1017 +0x3ac fp=0xc00004df10 sp=0xc00004de60 pc=0x43852c
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-linux-amd64-wsl/go/src/testing/testing.go:2259 +0x3b9 fp=0xc00004dfe0 sp=0xc00004df10 pc=0x4ea139
runtime.goexit()
	/tmp/workdir-host-linux-amd64-wsl/go/src/runtime/asm_amd64.s:1622 +0x1 fp=0xc00004dfe8 sp=0xc00004dfe0 pc=0x46c6e1
created by time.goFunc
	/tmp/workdir-host-linux-amd64-wsl/go/src/time/sleep.go:176 +0x2d

— watchflakes

@bcmills
Copy link
Contributor Author

bcmills commented Jun 30, 2023

These seem to have stopped in May. Maybe fixed?

@bcmills bcmills added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Jun 30, 2023
@gopherbot
Copy link

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)

@gopherbot gopherbot closed this as not planned Won't fix, can't repro, duplicate, stale Jul 30, 2023
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. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
Test Flakes
Status: Done
Milestone
Backlog
Development

No branches or pull requests
3 participants
@bcmills @gopherbot @heschi