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

Jump to bottom

runtime/pprof: TestLabelSystemstack failure with labeled racecall on linux-amd64-race #50705

Closed
bcmills opened this issue Jan 20, 2022 · 3 comments
Closed

runtime/pprof: TestLabelSystemstack failure with labeled racecall on linux-amd64-race #50705

bcmills opened this issue Jan 20, 2022 · 3 comments
Assignees
@prattmic
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. RaceDetector release-blocker
Milestone
Go1.18

Comments

@bcmills
Copy link
Contributor

bcmills commented Jan 20, 2022 

--- FAIL: TestLabelSystemstack (0.22s)
    pprof_test.go:524: total 32 CPU profile samples collected:
        1: 0x40784f (_ZN6__tsan7MetaMap9FreeRangeEPNS_9ProcessorEmm:0) 0x473140 (runtime._System:4621) labels: map[]
        
        1: 0x49c30b (racecall:389) labels: map[key:[value]]
        
        1: 0x407712 (_ZN6__tsan7MetaMap9FreeRangeEPNS_9ProcessorEmm:0) 0x473140 (runtime._System:4621) labels: map[key:[value]]
        
        1: 0x40784f (_ZN6__tsan7MetaMap9FreeRangeEPNS_9ProcessorEmm:0) 0x473140 (runtime._System:4621) labels: map[key:[value]]
        
        3: 0x49d063 (runtime.futex:553) 0x463bb5 (runtime.futexwakeup:68) 0x43dbd2 (runtime.unlock2:120) 0x452ff8 (runtime.unlockWithRank:31 runtime.unlock:111 runtime.setGCPercent.func1:1232) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        2: 0x452f49 (runtime.(*gcControllerState).setGCPercent:1219) 0x452fc4 (runtime.setGCPercent.func1:1229) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        2: 0x43dbbc (runtime.unlock2:115) 0x452ff8 (runtime.unlockWithRank:31 runtime.unlock:111 runtime.setGCPercent.func1:1232) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        5: 0x49d1c7 (runtime.osyield:651) 0x43daab (runtime.lock2:97) 0x452fb1 (runtime.lockWithRank:22 runtime.lock:47 runtime.setGCPercent.func1:1228) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        7: 0x49a746 (runtime.procyield:733) 0x43da72 (runtime.lock2:87) 0x452fb1 (runtime.lockWithRank:22 runtime.lock:47 runtime.setGCPercent.func1:1228) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        1: 0x43da6e (runtime.lock2:87) 0x452fb1 (runtime.lockWithRank:22 runtime.lock:47 runtime.setGCPercent.func1:1228) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        2: 0x452e8f (runtime.(*gcControllerState).commit:1062) 0x452f55 (runtime.(*gcControllerState).setGCPercent:1219) 0x452fc4 (runtime.setGCPercent.func1:1229) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        1: 0x43dbe7 (runtime.unlock2:125) 0x452ff8 (runtime.unlockWithRank:31 runtime.unlock:111 runtime.setGCPercent.func1:1232) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        1: 0x45313e (runtime.gcPaceScavenger:133) 0x452fea (runtime.setGCPercent.func1:1231) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        1: 0x452d25 (runtime.(*gcControllerState).commit:999) 0x452f55 (runtime.(*gcControllerState).setGCPercent:1219) 0x452fc4 (runtime.setGCPercent.func1:1229) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        1: 0x452c9e (runtime.(*gcControllerState).commit:970) 0x452f55 (runtime.(*gcControllerState).setGCPercent:1219) 0x452fc4 (runtime.setGCPercent.func1:1229) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        1: 0x452d7e (runtime.(*gcControllerState).commit:1016) 0x452f55 (runtime.(*gcControllerState).setGCPercent:1219) 0x452fc4 (runtime.setGCPercent.func1:1229) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
        1: 0x49a744 (runtime.procyield:732) 0x43da72 (runtime.lock2:87) 0x452fb1 (runtime.lockWithRank:22 runtime.lock:47 runtime.setGCPercent.func1:1228) 0x498968 (runtime.systemstack:469) 0x495325 (runtime/debug.setGCPercent:1227) 0x5fead9 (runtime/debug.SetGCPercent:92 runtime/pprof.labelHog:1521) 0x5fed92 (runtime/pprof.parallelLabelHog.func1:1534) labels: map[key:[value]]
        
    pprof_test.go:595: runtime.systemstack;key=value: 28
    pprof_test.go:1504: Sample labeled got true want false:  0x49c30b (racecall:389)
FAIL
FAIL	runtime/pprof	8.766s

greplogs --dashboard -md -l -e 'Sample labeled got true want false.*racecall' --since=2021-06-01

2022-01-19T21:14:18-c1296af/linux-amd64-race

(CC @prattmic @felixge; see previously #48577, #50007.)
@bcmills
Copy link
Contributor Author

bcmills commented Jan 20, 2022

Marking as release-blocker for Go 1.18 because this test is new in 1.18.

If I'm reading correctly this failure mode is likely specific to race-detector-enabled builds, so if nothing else it could probably be unblocked by skipping the test under the race detector. (But a fix to the underlying problem would be preferable. 😅)

@bcmills bcmills added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. RaceDetector release-blocker labels Jan 20, 2022
@bcmills bcmills added this to the Go1.18 milestone Jan 20, 2022
@prattmic
Copy link
Member

I just need to add racecall here. I figured we'd miss a few of these.

@prattmic prattmic self-assigned this Jan 20, 2022
@bcmills bcmills added the NeedsFix The path to resolution is known, but the work has not been done. label Jan 20, 2022
@gopherbot gopherbot removed the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jan 20, 2022
@gopherbot
Copy link

Change https://golang.org/cl/379834 mentions this issue: runtime/pprof: allow labels on racecall in TestLabelSystemstack

jproberts pushed a commit to jproberts/go that referenced this issue Jun 21, 2022
@prattmic @jproberts
runtime/pprof: allow labels on racecall in TestLabelSystemstack
bac2c79 
Fixes golang#50705.

Change-Id: I85857f836cbe58447625df6cd56756d3a69880ff
Reviewed-on: https://go-review.googlesource.com/c/go/+/379834
Trust: Michael Pratt <mpratt@google.com>
Run-TryBot: Michael Pratt <mpratt@google.com>
Reviewed-by: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
@prattmic prattmic self-assigned this Jun 24, 2022
@golang golang locked and limited conversation to collaborators Jun 24, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@prattmic prattmic

Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. RaceDetector release-blocker
Projects
None yet
Milestone
Go1.18
Development

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