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

runtime: TestProfBuf failures #56196

Open
gopherbot opened this issue Oct 13, 2022 · 10 comments
Open

runtime: TestProfBuf failures #56196

gopherbot opened this issue Oct 13, 2022 · 10 comments
Assignees
@prattmic
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Backlog

Comments

@gopherbot
Copy link
Contributor 

#!watchflakes
post <- pkg == "runtime" && test == "TestProfBuf"

Issue created automatically to collect these failures.

Example (log):

--- FAIL: TestProfBuf (0.74s)
    profbuf_test.go:62: myTags is 0x1230000
    --- FAIL: TestProfBuf/BlockingWriteRead (0.73s)
        profbuf_test.go:37: unexpected profile read:
            have data [0x5 0x63 0x0 0x0 0x1]
            want data [0x8 0x63 0x65 0x66 0xc9 0xca 0xcb 0xcc]
            have tags [0x0]
            want tags [0x1230002]
            have eof=false, want false

— watchflakes
@gopherbot gopherbot added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Oct 13, 2022
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime" && test == "TestProfBuf"
2022-10-06 04:37 openbsd-arm-jsing go@b314eea4 runtime.TestProfBuf (log) 
--- FAIL: TestProfBuf (0.74s)
    profbuf_test.go:62: myTags is 0x1230000
    --- FAIL: TestProfBuf/BlockingWriteRead (0.73s)
        profbuf_test.go:37: unexpected profile read:
            have data [0x5 0x63 0x0 0x0 0x1]
            want data [0x8 0x63 0x65 0x66 0xc9 0xca 0xcb 0xcc]
            have tags [0x0]
            want tags [0x1230002]
            have eof=false, want false

— watchflakes

@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Oct 13, 2022
@mknyszek
Copy link
Contributor

@prattmic notes that CPU profile is broken on openbsd-arm, so as long as we only see issues there, this is probably not worth tracking other than to skip these tests. Assigning to @prattmic who volunteered to do that.

@mknyszek mknyszek added this to the Backlog milestone Oct 19, 2022
@prattmic
Copy link
Member

Actually, this just tests the buffer itself, it doesn't do profiling. I'll take a closer look.

@prattmic
Copy link
Member

The failing case is this one https://cs.opensource.google/go/go/+/master:src/runtime/profbuf_test.go;l=144-146;drc=b788fd80e68addd181983ca589d28bc1075f4a36.

The timestamp (99/0x63) is correct, but the length (got 5 want 8) and header/stack data are incorrect. Nothing stands out here, I'd like to see more failures to see if this is a pattern.

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime" && test == "TestProfBuf"
2022-11-22 18:14 openbsd-amd64-71 go@793f1a13 runtime.TestProfBuf (log) 
SIGQUIT: quit
PC=0x2b622160a m=13 sigcode=0

rax    0x58
rbx    0x253c7e0c8
rcx    0x2b622160a
rdx    0x0
rdi    0xc0025e8b38
rsi    0x3
rbp    0x253c7e020
...
	/tmp/workdir/go/src/runtime/proc.go:381 +0xd6 fp=0xc000109da0 sp=0xc000109d80 pc=0x43e2d6
runtime.chanrecv(0xc0006fb9d0, 0xc000109e9f, 0x1)
	/tmp/workdir/go/src/runtime/chan.go:583 +0x49d fp=0xc000109e30 sp=0xc000109da0 pc=0x40949d
runtime.chanrecv1(0xac24e0?, 0x795020?)
	/tmp/workdir/go/src/runtime/chan.go:442 +0x18 fp=0xc000109e58 sp=0xc000109e30 pc=0x408f98
testing.(*T).Run(0xc000883ba0, {0x81b07d?, 0xc0003abf00?}, 0xc000070100)
	/tmp/workdir/go/src/testing/testing.go:1629 +0x405 fp=0xc000109f18 sp=0xc000109e58 pc=0x500945
runtime_test.TestProfBuf(0xc000883ba0)
	/tmp/workdir/go/src/runtime/profbuf_test.go:139 +0x44b fp=0xc000109f70 sp=0xc000109f18 pc=0x73640b
testing.tRunner(0xc000883ba0, 0x83ec20)
2022-12-08 03:52 openbsd-amd64-71 go@c8313d4f runtime.TestProfBuf (log) 
SIGQUIT: quit
PC=0x22b8beefa m=14 sigcode=0

rax    0x58
rbx    0x23c37a928
rcx    0x22b8beefa
rdx    0x0
rdi    0xc0001f0f38
rsi    0x3
rbp    0x23c37a880
...

runtime.gopark(0x4465f1?, 0xc00030a650?, 0x20?, 0x66?, 0xc0000809b0?)
	/tmp/workdir/go/src/runtime/proc.go:381 +0xd6 fp=0xc00030a640 sp=0xc00030a620 pc=0x43e2d6
time.Sleep(0x989680)
	/tmp/workdir/go/src/runtime/time.go:195 +0x125 fp=0xc00030a680 sp=0xc00030a640 pc=0x474b05
runtime_test.TestProfBuf.func3(0xc00082cea0, 0xc0000f2510, {0x0, 0x0, 0x0}, {0x0, 0x0, 0x0})
	/tmp/workdir/go/src/runtime/profbuf_test.go:41 +0x125 fp=0xc00030a6a8 sp=0xc00030a680 pc=0x7573c5
runtime_test.TestProfBuf.func12(0x89c3e8?)
	/tmp/workdir/go/src/runtime/profbuf_test.go:151 +0x408 fp=0xc00030a770 sp=0xc00030a6a8 pc=0x734ac8
testing.tRunner(0xc00082cea0, 0xc000070100)

— watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime" && test == "TestProfBuf"
2023-08-16 21:01 linux-s390x-ibm go@14a3ffc3 runtime.TestProfBuf (log) 
--- FAIL: TestProfBuf (1.28s)
    profbuf_test.go:62: myTags is 0xc0000fa9a0
    --- FAIL: TestProfBuf/BlockingWriteRead (1.28s)
        profbuf_test.go:46: timeout waiting for blocked read

— watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime" && test == "TestProfBuf"
2023-09-11 20:26 linux-s390x-ibm go@94f24fd0 runtime.TestProfBuf (log) 
--- FAIL: TestProfBuf (1.34s)
    profbuf_test.go:62: myTags is 0xc0007404d0
    --- FAIL: TestProfBuf/BlockingWriteRead (1.34s)
        profbuf_test.go:46: timeout waiting for blocked read

— watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime" && test == "TestProfBuf"
2023-09-14 19:43 linux-s390x-ibm go@0b07bbd2 runtime.TestProfBuf (log) 
--- FAIL: TestProfBuf (1.63s)
    profbuf_test.go:62: myTags is 0xc000072540
    --- FAIL: TestProfBuf/BlockingWriteRead (1.63s)
        profbuf_test.go:46: timeout waiting for blocked read

— watchflakes

@gopherbot
Copy link
Contributor Author

Change https://go.dev/cl/528399 mentions this issue: runtime: remove an arbitrary timeout in TestProfBuf

gopherbot pushed a commit that referenced this issue Sep 15, 2023
runtime: remove an arbitrary timeout in TestProfBuf
98f0509 
The failure observed in
https://build.golang.org/log/766ad55d098ee1979ba1ae261e0813063567743e
appears to be spurious. If it is, this change will fix it.

If it is not, and somehow the Read has deadlocked,
then this change will help to diagnose it
(by causing the test to time out and dump its running goroutines).

For #56196.

Change-Id: Ic74f018384a64e95566a5b5d8126cbd59ab5e5fa
Reviewed-on: https://go-review.googlesource.com/c/go/+/528399
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Reviewed-by: Michael Pratt <mpratt@google.com>
Auto-Submit: Bryan Mills <bcmills@google.com>
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime" && test == "TestProfBuf"
2024-01-04 21:34 linux-s390x-ibm go@43818206 runtime.TestProfBuf (log) 
--- FAIL: TestProfBuf (1.40s)
    profbuf_test.go:62: myTags is 0xc0006063f0
    --- FAIL: TestProfBuf/BlockingWriteRead (1.40s)
        profbuf_test.go:46: timeout waiting for blocked read

— watchflakes

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@prattmic prattmic

Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
Go Compiler / Runtime
Status: Todo
Test Flakes
Status: No status
Milestone
Backlog
Development

No branches or pull requests
3 participants
@mknyszek @prattmic @gopherbot