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.

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

tracer_test.go is flaky (and hard to reproduce) #2725

Open
10000TB opened this issue Jul 24, 2023 · 1 comment
Open

tracer_test.go is flaky (and hard to reproduce) #2725

10000TB opened this issue Jul 24, 2023 · 1 comment
Labels
Bug Stuff that's wrong

Comments

@10000TB
Copy link
Member

10000TB commented Jul 24, 2023

Describe the bug
tracer_test.go would fail opportunistically across a larger number of successful runs.

To Reproduce
Steps to reproduce the behavior:

Run the test via go test, but I haven't be able to reproduce it. The flaky run came from our automated continuous runs, that run every hour.

Expected behavior

Test pass w/o offending changes.

Additional context

ok  	github.com/u-root/u-root/pkg/spidev	0.011s	coverage: 91.4% of statements
coverage: 40.4% of statements
panic: test timed out after 10m0s

goroutine 37 [running]:
testing.(*M).startAlarm.func1()
	/usr/local/go/src/testing/testing.go:2029 +0x8e
created by time.goFunc
	/usr/local/go/src/time/sleep.go:176 +0x32

goroutine 1 [chan receive]:
testing.(*T).Run(0xc00011b1e0, {0x575e6c?, 0x4c6625?}, 0x5806d8)
	/usr/local/go/src/testing/testing.go:1487 +0x37a
testing.runTests.func1(0xc00011b1e0?)
	/usr/local/go/src/testing/testing.go:1839 +0x6e
testing.tRunner(0xc00011b1e0, 0xc0000fdca0)
	/usr/local/go/src/testing/testing.go:1439 +0x102
testing.runTests(0xc0000babe0?, {0x6895c0, 0x6, 0x6}, {0x7fc114c815b8?, 0x40?, 0x68f0a0?})
	/usr/local/go/src/testing/testing.go:1837 +0x457
testing.(*M).Run(0xc0000babe0)
	/usr/local/go/src/testing/testing.go:1719 +0x5d9
main.main()
	_testmain.go:121 +0x255

goroutine 34 [chan receive]:
github.com/u-root/u-root/pkg/strace.runAndCollectTrace(0xc0001ba000, 0xc0001cc000)
	/src/golang/src/github.com/u-root/u-root/pkg/strace/tracer_test.go:58 +0x1db
github.com/u-root/u-root/pkg/strace.TestMultiProcess(0x0?)
	/src/golang/src/github.com/u-root/u-root/pkg/strace/tracer_test.go:89 +0x92
testing.tRunner(0xc0001ba000, 0x5806d8)
	/usr/local/go/src/testing/testing.go:1439 +0x102
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:1486 +0x35f

goroutine 35 [syscall, locked to thread]:
syscall.Syscall6(0x3d, 0xffffffffffffffff, 0xc0000ddccc, 0x0, 0x0, 0x0, 0x0)
	/usr/local/go/src/syscall/asm_linux_amd64.s:43 +0x5
golang.org/x/sys/unix.wait4(0x546460?, 0xc000184af0?, 0x8?, 0xc0000ddd08?)
	/src/golang/src/golang.org/x/sys/unix/zsyscall_linux.go:224 +0x4e
golang.org/x/sys/unix.Wait4(0x1?, 0xc0000ddd04, 0xc0000ddfc0?, 0xc0000ddeb0?)
	/src/golang/src/golang.org/x/sys/unix/syscall_linux.go:362 +0x2b
github.com/u-root/u-root/pkg/strace.wait(0x54db40?)
	/src/golang/src/github.com/u-root/u-root/pkg/strace/tracer.go:31 +0x3a
github.com/u-root/u-root/pkg/strace.(*tracer).runLoop(0xc0000dde40)
	/src/golang/src/github.com/u-root/u-root/pkg/strace/tracer.go:301 +0x5a
github.com/u-root/u-root/pkg/strace.Trace(0x7fc0ec659198?, {0xc0001d4fc0, 0x2, 0x2})
	/src/golang/src/github.com/u-root/u-root/pkg/strace/tracer.go:240 +0x526
github.com/u-root/u-root/pkg/strace.runAndCollectTrace.func1()
	/src/golang/src/github.com/u-root/u-root/pkg/strace/tracer_test.go:53 +0xae
created by github.com/u-root/u-root/pkg/strace.runAndCollectTrace
	/src/golang/src/github.com/u-root/u-root/pkg/strace/tracer_test.go:52 +0x19d

goroutine 36 [IO wait]:
internal/poll.runtime_pollWait(0x7fc0ec6590a8, 0x72)
	/usr/local/go/src/runtime/netpoll.go:302 +0x89
internal/poll.(*pollDesc).wait(0xc0001c4120?, 0xc000160007?, 0x1)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:83 +0x32
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:88
internal/poll.(*FD).Read(0xc0001c4120, {0xc000160007, 0x5f9, 0x5f9})
	/usr/local/go/src/internal/poll/fd_unix.go:167 +0x25a
os.(*File).read(...)
	/usr/local/go/src/os/file_posix.go:31
os.(*File).Read(0xc0001aa018, {0xc000160007?, 0x65cfa0?, 0xc0001c06a0?})
	/usr/local/go/src/os/file.go:119 +0x5e
bytes.(*Buffer).ReadFrom(0xc00018e2a0, {0x5b7da0, 0xc0001aa018})
	/usr/local/go/src/bytes/buffer.go:204 +0x98
io.copyBuffer({0x5b7be0, 0xc00018e2a0}, {0x5b7da0, 0xc0001aa018}, {0x0, 0x0, 0x0})
	/usr/local/go/src/io/io.go:412 +0x14b
io.Copy(...)
	/usr/local/go/src/io/io.go:385
os/exec.(*Cmd).writerDescriptor.func1()
	/usr/local/go/src/os/exec/exec.go:311 +0x3a
os/exec.(*Cmd).Start.func1(0xc0001c07a0?)
	/usr/local/go/src/os/exec/exec.go:448 +0x25
created by os/exec.(*Cmd).Start
	/usr/local/go/src/os/exec/exec.go:447 +0x785
FAIL	github.com/u-root/u-root/pkg/strace	600.009s
ok  	github.com/u-root/u-root/pkg/strace/internal/abi	0.002s	coverage: 41.3% of statements
ok  	github.com/u-root/u-root/pkg/strace/internal/binary	0.002s	coverage: 0.0% of statements
ok  	github.com/u-root/u-root/pkg/syscallfilter	0.014s	coverage: 88.5% of statements
@10000TB 10000TB added the Bug Stuff that's wrong label Jul 24, 2023
@10000TB
Copy link
Member Author

10000TB commented Jul 24, 2023

Haven't been able to produce it manually. But I am pretty certain it happens once in every while.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug Stuff that's wrong
Projects
None yet
Development

No branches or pull requests

1 participant