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

runtime/pprof: test timed out in StartCPUProfile #60108

Closed
bcmills opened this issue May 10, 2023 · 20 comments
Closed

runtime/pprof: test timed out in StartCPUProfile #60108

bcmills opened this issue May 10, 2023 · 20 comments
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsFix The path to resolution is known, but the work has not been done. OS-Darwin
Milestone

Comments

@bcmills
Copy link
Contributor

bcmills commented May 10, 2023

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`

https://build.golang.org/log/e7671b5aac25301376187c735141b1a0dd33bbe0 (from #57995 (comment)):

SIGQUIT: quit
PC=0x7ff81b7a62be m=1 sigcode=0
…
goroutine 2 [running]:
	goroutine running on other thread; stack unavailable
created by runtime.init.6 in goroutine 1
	/tmp/buildlet/go/src/runtime/proc.go:310 +0x1a
…
goroutine 55 [running]:
	goroutine running on other thread; stack unavailable
created by testing.(*T).Run in goroutine 1
	/tmp/buildlet/go/src/testing/testing.go:1648 +0x836
…
goroutine 57 [syscall]:
runtime.notetsleepg(0x10bce3a?, 0xc000050ec8?)
	/tmp/buildlet/go/src/runtime/lock_sema.go:294 +0x31 fp=0xc000050e90 sp=0xc000050e48 pc=0x105c711
runtime.(*profBuf).read(0xc000138090, 0x0)
	/tmp/buildlet/go/src/runtime/profbuf.go:500 +0xa8 fp=0xc000050ee8 sp=0xc000050e90 pc=0x10978a8
runtime/pprof.readProfile()
	/tmp/buildlet/go/src/runtime/cpuprof.go:230 +0x4b fp=0xc000050f48 sp=0xc000050ee8 pc=0x10b6f4b
runtime/pprof.profileWriter({0x12eea60, 0xc000414000})
	/tmp/buildlet/go/src/runtime/pprof/pprof.go:810 +0x65 fp=0xc000050fb0 sp=0xc000050f48 pc=0x121d105
runtime/pprof.StartCPUProfile.func2()
	/tmp/buildlet/go/src/runtime/pprof/pprof.go:794 +0x45 fp=0xc000050fe0 sp=0xc000050fb0 pc=0x121d005
runtime.goexit()
	/tmp/buildlet/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc000050fe8 sp=0xc000050fe0 pc=0x10bd041
created by runtime/pprof.StartCPUProfile in goroutine 55
	/tmp/buildlet/go/src/runtime/pprof/pprof.go:794 +0x1af
…
*** Test killed with quit: ran too long (4m0s).
FAIL	runtime/pprof	240.037s
@bcmills bcmills added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. compiler/runtime Issues related to the Go compiler and/or runtime. labels May 10, 2023
@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2023-05-03 18:47 darwin-amd64-race go@ea9097c9 runtime/pprof (log)
SIGQUIT: quit
PC=0x7ff81b7a62be m=1 sigcode=0

goroutine 2 [running]:
	goroutine running on other thread; stack unavailable
created by runtime.init.6 in goroutine 1
	/tmp/buildlet/go/src/runtime/proc.go:310 +0x1a

goroutine 55 [running]:
	goroutine running on other thread; stack unavailable
...
r12    0x700000ea16a8
r13    0x0
r14    0x0
r15    0x700000ea1df0
rip    0x7ff81b7a62be
rflags 0x247
cs     0x7
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (4m0s).

watchflakes

@bcmills bcmills changed the title runtime/pprof: test timed out in StartCPUProfile runtime/pprof: test timed out in StartCPUProfile on darwin-amd64-race May 10, 2023
@mknyszek
Copy link
Contributor

Related to #59995?

@mknyszek mknyszek added this to the Go1.21 milestone May 17, 2023
@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2023-05-19 18:01 darwin-amd64-race go@b60db8f7 runtime/pprof (log)
SIGQUIT: quit
PC=0x7ff80031e3ea m=1 sigcode=0

goroutine 26 [running]:
	goroutine running on other thread; stack unavailable
created by testing.(*T).Run in goroutine 1
	/tmp/buildlet/go/src/testing/testing.go:1648 +0x82b

rax    0x104
rbx    0x70000188e000
rcx    0x70000188dc48
rdx    0x2b00
rdi    0xc000040388
rsi    0x187c0100187d00
rbp    0x70000188dcf0
rsp    0x70000188dc48
r8     0x0
r9     0xa0
r10    0x0
r11    0x246
r12    0x16
r13    0x0
r14    0x187c0100187d00
r15    0x2b00
rip    0x7ff80031e3ea
rflags 0x247
cs     0x7
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (4m0s).

watchflakes

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2023-05-24 14:43 darwin-amd64-race go@d9fd19a7 runtime/pprof (log)
SIGQUIT: quit
PC=0x7ff81f9d62be m=1 sigcode=0

goroutine 2 [running]:
	goroutine running on other thread; stack unavailable
created by runtime.init.6 in goroutine 1
	/tmp/buildlet/go/src/runtime/proc.go:310 +0x1a

goroutine 50 [running]:
	goroutine running on other thread; stack unavailable
...
r12    0x7000007b26a8
r13    0x0
r14    0x0
r15    0x7000007b2df0
rip    0x7ff81f9d62be
rflags 0x247
cs     0x7
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (4m0s).

watchflakes

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2023-06-03 00:53 darwin-amd64-race go@3fd867ce runtime/pprof (log)
SIGQUIT: quit
PC=0x7ff8156902be m=1 sigcode=0

goroutine 2 [running]:
	goroutine running on other thread; stack unavailable
created by runtime.init.6 in goroutine 1
	/tmp/buildlet/go/src/runtime/proc.go:310 +0x1a

goroutine 26 [running]:
	goroutine running on other thread; stack unavailable
...
r12    0x70000cbd56a8
r13    0x0
r14    0x0
r15    0x70000cbd5df0
rip    0x7ff8156902be
rflags 0x247
cs     0x7
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (7m0s).

watchflakes

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2023-05-04 17:28 darwin-amd64-race go@60c724c5 runtime/pprof.TestCPUProfileWithFork (log)
SIGQUIT: quit
PC=0x7ff8061563ea m=1 sigcode=0

rax    0x104
rbx    0x70000a473000
rcx    0x70000a472c48
rdx    0x1a00
rdi    0xc000040380
rsi    0xa1c01000a1d00
rbp    0x70000a472cf0
...
	/tmp/buildlet/go/src/runtime/chan.go:107 +0xe5 fp=0xc0000b9a88 sp=0xc0000b9a48 pc=0x1055c85
os/exec.(*Cmd).Start(0xc00013e000)
	/tmp/buildlet/go/src/os/exec/exec.go:706 +0xa0f fp=0xc0000b9ce0 sp=0xc0000b9a88 pc=0x117696f
os/exec.(*Cmd).Run(0x0?)
	/tmp/buildlet/go/src/os/exec/exec.go:587 +0x27 fp=0xc0000b9d20 sp=0xc0000b9ce0 pc=0x1175ee7
os/exec.(*Cmd).CombinedOutput(0xc00013e000)
	/tmp/buildlet/go/src/os/exec/exec.go:1005 +0x1f7 fp=0xc0000b9d98 sp=0xc0000b9d20 pc=0x1178df7
runtime/pprof.TestCPUProfileWithFork(0xc000082820)
	/tmp/buildlet/go/src/runtime/pprof/pprof_test.go:687 +0x338 fp=0xc0000b9e98 sp=0xc0000b9d98 pc=0x12339b8
testing.tRunner(0xc000082820, 0x12b3970)
2023-05-10 14:30 darwin-amd64-race go@8e8303e1 runtime/pprof.TestCPUProfileWithFork (log)
SIGQUIT: quit
PC=0x7ff81b1ed34e m=1 sigcode=0

rax    0x4
rbx    0x700007427628
rcx    0x700007427568
rdx    0x0
rdi    0x3
rsi    0x0
rbp    0x700007427570
...
	/tmp/buildlet/go/src/os/exec/exec.go:941 +0x349 fp=0xc00007bc18 sp=0xc00007bad0 pc=0x117c7c9
os/exec.(*Cmd).Wait(0xc0000006e0)
	/tmp/buildlet/go/src/os/exec/exec.go:908 +0x2d5 fp=0xc00007bce0 sp=0xc00007bc18 pc=0x117c275
os/exec.(*Cmd).Run(0x0?)
	/tmp/buildlet/go/src/os/exec/exec.go:590 +0x55 fp=0xc00007bd20 sp=0xc00007bce0 pc=0x117a175
os/exec.(*Cmd).CombinedOutput(0xc0000006e0)
	/tmp/buildlet/go/src/os/exec/exec.go:1005 +0x1f7 fp=0xc00007bd98 sp=0xc00007bd20 pc=0x117d057
runtime/pprof.TestCPUProfileWithFork(0xc000144000)
	/tmp/buildlet/go/src/runtime/pprof/pprof_test.go:687 +0x338 fp=0xc00007be98 sp=0xc00007bd98 pc=0x123a538
testing.tRunner(0xc000144000, 0x12bf8a0)
2023-05-10 21:44 darwin-amd64-race go@3f9521b2 runtime/pprof.TestCPUProfileWithFork (log)
SIGQUIT: quit
PC=0x7ff807b492be m=1 sigcode=0

rax    0x4
rbx    0x0
rcx    0x70000f5f6da8
rdx    0x1
rdi    0x1403
rsi    0x0
rbp    0x70000f5f6de0
...
	/tmp/buildlet/go/src/os/exec/exec.go:941 +0x349 fp=0xc0000b7c18 sp=0xc0000b7ad0 pc=0x117c549
os/exec.(*Cmd).Wait(0xc000194000)
	/tmp/buildlet/go/src/os/exec/exec.go:908 +0x2d5 fp=0xc0000b7ce0 sp=0xc0000b7c18 pc=0x117bff5
os/exec.(*Cmd).Run(0xc0000e4160?)
	/tmp/buildlet/go/src/os/exec/exec.go:590 +0x55 fp=0xc0000b7d20 sp=0xc0000b7ce0 pc=0x1179ef5
os/exec.(*Cmd).CombinedOutput(0xc000194000)
	/tmp/buildlet/go/src/os/exec/exec.go:1005 +0x1f7 fp=0xc0000b7d98 sp=0xc0000b7d20 pc=0x117cdd7
runtime/pprof.TestCPUProfileWithFork(0xc000083860)
	/tmp/buildlet/go/src/runtime/pprof/pprof_test.go:687 +0x338 fp=0xc0000b7e98 sp=0xc0000b7d98 pc=0x123a2b8
testing.tRunner(0xc000083860, 0x12bf1a0)

watchflakes

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2023-06-14 21:53 darwin-amd64-race go@b01cd41b runtime/pprof (log)
SIGQUIT: quit
PC=0x7ff80384c2be m=1 sigcode=0

goroutine 3 [running]:
	goroutine running on other thread; stack unavailable
created by runtime.gcenable in goroutine 1
	/tmp/buildlet/go/src/runtime/mgc.go:200 +0x66

goroutine 4 [running]:
	goroutine running on other thread; stack unavailable
...
r12    0x7000038e66a8
r13    0x0
r14    0x0
r15    0x7000038e6df0
rip    0x7ff80384c2be
rflags 0x247
cs     0x7
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (7m0s).

watchflakes

@bcmills
Copy link
Contributor Author

bcmills commented Jun 30, 2023

I wonder if this is related to #18717. Do we know if cgo_yield is non-nil on darwin when the race detector is enabled?

@bcmills
Copy link
Contributor Author

bcmills commented Jun 30, 2023

The answer as of https://go.dev/cl/451055 seems to be no.

So, that's my theory: the TSAN runtime is deferring signals as described in #18717, but the workaround added to the runtime package for #18717 is no longer in effect because runtime/race/race.go is no longer used on darwin, which causes runtime/cgo not to be linked in, which causes _cgo_yield to be nil.

@bcmills bcmills added the NeedsFix The path to resolution is known, but the work has not been done. label Jun 30, 2023
@gopherbot gopherbot removed the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jun 30, 2023
@bcmills
Copy link
Contributor Author

bcmills commented Jun 30, 2023

One possible fix, in the spirit of https://go.dev/cl/451055, would be to have runtime/race provide a libc-but-not-cgo definition of _cgo_yield.

@gopherbot
Copy link

Change https://go.dev/cl/507356 mentions this issue: runtime/pprof: use testenv.Command in tests instead of exec.Command

@bcmills
Copy link
Contributor Author

bcmills commented Jun 30, 2023

@cherrymui notes:

I think C TSAN intercepts signals but the Go race detector doesn't (when it bundles TSAN it doesn't include the signal interceptor code). So for non-cgo build it shouldn't matter?

But I wonder: since we're linking against libc on macOS, do we use our bundled TSAN implementation, or the one provided by the system C toolchain? 🤔

@cherrymui
Copy link
Member

I think we use the bundled TSAN implementation from the race syso files. I don't think the libc we use contains TSAN.

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2023-05-23 17:16 darwin-amd64-race go@4e679e26 runtime/pprof.TestCPUProfileWithFork (log)
SIGQUIT: quit
PC=0x7ff81dd952be m=1 sigcode=0

rax    0x4
rbx    0x0
rcx    0x70000b58eda8
rdx    0x1
rdi    0x1403
rsi    0x0
rbp    0x70000b58ede0
...
	/tmp/buildlet/go/src/os/exec/exec.go:941 +0x349 fp=0xc0000b5c18 sp=0xc0000b5ad0 pc=0x117c4a9
os/exec.(*Cmd).Wait(0xc00005a2c0)
	/tmp/buildlet/go/src/os/exec/exec.go:908 +0x2da fp=0xc0000b5ce0 sp=0xc0000b5c18 pc=0x117bf5a
os/exec.(*Cmd).Run(0x0?)
	/tmp/buildlet/go/src/os/exec/exec.go:590 +0x55 fp=0xc0000b5d20 sp=0xc0000b5ce0 pc=0x1179e55
os/exec.(*Cmd).CombinedOutput(0xc00005a2c0)
	/tmp/buildlet/go/src/os/exec/exec.go:1005 +0x1f7 fp=0xc0000b5d98 sp=0xc0000b5d20 pc=0x117cd57
runtime/pprof.TestCPUProfileWithFork(0xc0000824e0)
	/tmp/buildlet/go/src/runtime/pprof/pprof_test.go:687 +0x33f fp=0xc0000b5e98 sp=0xc0000b5d98 pc=0x123ed9f
testing.tRunner(0xc0000824e0, 0x12bf0c8)
2023-06-21 19:47 darwin-amd64-race go@b23cae80 runtime/pprof.TestCPUProfileWithFork (log)
SIGQUIT: quit
PC=0x7ff818f692be m=1 sigcode=0

rax    0x4
rbx    0x0
rcx    0x700009bb0da8
rdx    0x1
rdi    0x903
rsi    0x0
rbp    0x700009bb0de0
...
	/tmp/buildlet/go/src/os/exec/exec.go:941 +0x349 fp=0xc00007bc18 sp=0xc00007bad0 pc=0x117d309
os/exec.(*Cmd).Wait(0xc0001aa160)
	/tmp/buildlet/go/src/os/exec/exec.go:908 +0x2da fp=0xc00007bce0 sp=0xc00007bc18 pc=0x117cdba
os/exec.(*Cmd).Run(0x0?)
	/tmp/buildlet/go/src/os/exec/exec.go:590 +0x55 fp=0xc00007bd20 sp=0xc00007bce0 pc=0x117acb5
os/exec.(*Cmd).CombinedOutput(0xc0001aa160)
	/tmp/buildlet/go/src/os/exec/exec.go:1005 +0x1f7 fp=0xc00007bd98 sp=0xc00007bd20 pc=0x117dbb7
runtime/pprof.TestCPUProfileWithFork(0xc00018a680)
	/tmp/buildlet/go/src/runtime/pprof/pprof_test.go:687 +0x33f fp=0xc00007be98 sp=0xc00007bd98 pc=0x123ff3f
testing.tRunner(0xc00018a680, 0x12c0dd8)
2023-06-29 22:49 darwin-amd64-race go@683f51d3 runtime/pprof (log)
SIGQUIT: quit
PC=0x7ff8120fa2be m=1 sigcode=0

goroutine 2 [running]:
	goroutine running on other thread; stack unavailable
created by runtime.init.6 in goroutine 1
	/tmp/buildlet/go/src/runtime/proc.go:310 +0x1a

goroutine 49 [running]:
	goroutine running on other thread; stack unavailable
...
r12    0x700006aef6a8
r13    0x0
r14    0x0
r15    0x700006aefdf0
rip    0x7ff8120fa2be
rflags 0x247
cs     0x7
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (7m0s).

watchflakes

gopherbot pushed a commit that referenced this issue Jul 20, 2023
If the test is about to time out, testenv.Command sends SIGQUIT to the
child process. The runtime's SIGQUIT goroutine dump should help us to
determine whether the hangs observed in TestCPUProfileWithFork are a
symptom of #60108 or a separate bug.

For #59995.
Updates #60108.

Change-Id: I26342ca262b2b0772795c8be142cfcad8d90db30
Reviewed-on: https://go-review.googlesource.com/c/go/+/507356
Run-TryBot: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Reviewed-by: Cherry Mui <cherryyz@google.com>
Reviewed-by: Michael Knyszek <mknyszek@google.com>
Auto-Submit: Bryan Mills <bcmills@google.com>
@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2023-08-01 17:16 darwin-amd64-race go@b6898dde runtime/pprof.TestCPUProfileWithFork (log)
SIGQUIT: quit
PC=0x7ff8146fc2be m=1 sigcode=0

rax    0x4
rbx    0x0
rcx    0x700005d39da8
rdx    0x1
rdi    0x903
rsi    0x0
rbp    0x700005d39de0
...
	/tmp/buildlet/go/src/runtime/panic.go:442 +0x5f fp=0xc0000bda38 sp=0xc0000bd9a0 pc=0x108743f
os/exec.(*Cmd).Start(0xc000192000)
	/tmp/buildlet/go/src/os/exec/exec.go:718 +0xf99 fp=0xc0000bdca8 sp=0xc0000bda38 pc=0x1181bd9
os/exec.(*Cmd).Run(0x10c1b29?)
	/tmp/buildlet/go/src/os/exec/exec.go:587 +0x27 fp=0xc0000bdce8 sp=0xc0000bdca8 pc=0x1180bc7
os/exec.(*Cmd).CombinedOutput(0xc000192000)
	/tmp/buildlet/go/src/os/exec/exec.go:977 +0x1f7 fp=0xc0000bdd60 sp=0xc0000bdce8 pc=0x1183b37
runtime/pprof.TestCPUProfileWithFork(0xc000102680)
	/tmp/buildlet/go/src/runtime/pprof/pprof_test.go:691 +0x585 fp=0xc0000bdea0 sp=0xc0000bdd60 pc=0x1246c25
testing.tRunner(0xc000102680, 0x12c7e48)

watchflakes

@gopherbot gopherbot modified the milestones: Go1.21, Go1.22 Aug 8, 2023
@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2023-07-19 21:06 darwin-amd64-race go@03c7e96b runtime/pprof.TestCPUProfileWithFork (log)
SIGQUIT: quit
PC=0x7ff8049112be m=1 sigcode=0

rax    0x4
rbx    0x0
rcx    0x7000033ccda8
rdx    0x1
rdi    0x1403
rsi    0x0
rbp    0x7000033ccde0
...
	/tmp/buildlet/go/src/os/exec/exec.go:941 +0x349 fp=0xc0000b7c18 sp=0xc0000b7ad0 pc=0x117cea9
os/exec.(*Cmd).Wait(0xc0001a0580)
	/tmp/buildlet/go/src/os/exec/exec.go:908 +0x2da fp=0xc0000b7ce0 sp=0xc0000b7c18 pc=0x117c95a
os/exec.(*Cmd).Run(0x0?)
	/tmp/buildlet/go/src/os/exec/exec.go:590 +0x55 fp=0xc0000b7d20 sp=0xc0000b7ce0 pc=0x117a855
os/exec.(*Cmd).CombinedOutput(0xc0001a0580)
	/tmp/buildlet/go/src/os/exec/exec.go:1005 +0x1f7 fp=0xc0000b7d98 sp=0xc0000b7d20 pc=0x117d757
runtime/pprof.TestCPUProfileWithFork(0xc000082b60)
	/tmp/buildlet/go/src/runtime/pprof/pprof_test.go:687 +0x33f fp=0xc0000b7e98 sp=0xc0000b7d98 pc=0x123fadf
testing.tRunner(0xc000082b60, 0x12c0958)
2023-07-21 03:06 darwin-amd64-race go@2fabb143 runtime/pprof (log)
SIGQUIT: quit
PC=0x7ff80167b2be m=1 sigcode=0

goroutine 2 [running]:
	goroutine running on other thread; stack unavailable
created by runtime.init.6 in goroutine 1
	/tmp/buildlet/go/src/runtime/proc.go:310 +0x1a

goroutine 49 [running]:
	goroutine running on other thread; stack unavailable
...
r12    0x70000f0756a8
r13    0x0
r14    0x0
r15    0x70000f075df0
rip    0x7ff80167b2be
rflags 0x247
cs     0x7
fs     0x0
gs     0x0
*** Test killed with quit: ran too long (7m0s).

watchflakes

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2023-08-12 03:56 linux-arm-aws go@ac64a362 runtime/pprof.TestGoroutineSwitch (log)
SIGQUIT: quit
PC=0x8b498 m=0 sigcode=0

trap    0x0
error   0x0
oldmask 0x0
r0      0x308098
r1      0x80
r2      0x0
r3      0x0
...
pc      0x8b498
cpsr    0xa0800010
fault   0x0
*** Test killed with quit: ran too long (7m0s).

runtime.Gosched(...)
	/workdir/go/src/runtime/proc.go:338
runtime/pprof.TestGoroutineSwitch(0x2342000)
	/workdir/go/src/runtime/pprof/pprof_test.go:716 +0x178 fp=0x2026f94 sp=0x2026f5c pc=0x18665c
testing.tRunner(0x2342000, 0x1e4094)

watchflakes

@mknyszek
Copy link
Contributor

As of the resolution of #61768, I think this is also fixed. gopherbot will reopen it if not true, but we haven't seen any issues in a couple weeks.

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && log ~ `Test killed with quit` && log ~ `^runtime/pprof\.StartCPUProfile`
2024-04-03 15:35 go1.21-linux-arm release-branch.go1.21@d8392e69 runtime/pprof.TestEmptyCallStack [ABORT] (log)
=== RUN   TestEmptyCallStack
=== PAUSE TestEmptyCallStack
2024-04-03 15:35 go1.21-linux-arm release-branch.go1.21@d8392e69 runtime/pprof.TestLabelSystemstack [ABORT] (log)
=== RUN   TestLabelSystemstack
SIGQUIT: quit
PC=0x8b78c m=0 sigcode=0

goroutine 0 [idle]:
runtime.futex()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/sys_linux_arm.s:416 +0x1c fp=0xffab15a8 sp=0xffab15a8 pc=0x8b78c
runtime.futexsleep(0x3080d0, 0x0, 0xffffffffffffffff)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/os_linux.go:69 +0x60 fp=0xffab15d0 sp=0xffab15a8 pc=0x4b670
runtime.notesleep(0x3080d0)
...
r9      0x308750
r10     0x307b48
fp      0x6
ip      0x4
sp      0xffab15a8
lr      0x4b670
pc      0x8b78c
cpsr    0xa0800010
fault   0x0
*** Test killed with quit: ran too long (10m0s).

watchflakes

@gopherbot gopherbot reopened this Apr 18, 2024
@mknyszek mknyszek changed the title runtime/pprof: test timed out in StartCPUProfile on darwin-amd64-race runtime/pprof: test timed out in StartCPUProfile Apr 24, 2024
@mknyszek
Copy link
Contributor

Closing in favor of #67023.

@mknyszek mknyszek closed this as not planned Won't fix, can't repro, duplicate, stale Apr 24, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsFix The path to resolution is known, but the work has not been done. OS-Darwin
Projects
Status: Done
Development

No branches or pull requests

5 participants