runtime: lock ordering problems #58277

bcmills · 2023-02-02T20:59:48Z

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

(Pulled out from #55167, because these issues tend to be easier to diagnose; CC @golang/runtime)

The text was updated successfully, but these errors were encountered:

gopherbot · 2023-02-02T21:19:03Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2023-01-17 19:55 linux-amd64-staticlockranking go@839c8425 runtime/trace.TestTraceFutileWakeup (log)

111172  ======
0 : hchan 15 0xc0000221d8
1 : hchan 15 0xc000022258
2 : traceStackTab 43 0x702a98
3 : wbufSpans 39 0x6fb6f0
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x5c3185?, 0x1?})
	/workdir/go/src/runtime/panic.go:1047 +0x5d fp=0x7fe0337fd9c0 sp=0x7fe0337fd990 pc=0x439a9d
...
	/workdir/go/src/runtime/proc.go:387
runtime.semacquire1(0xc00019c118, 0x20?, 0x1, 0x0, 0x71?)
	/workdir/go/src/runtime/sema.go:160 +0x214 fp=0xc000063d60 sp=0xc000063cf8 pc=0x44de34
sync.runtime_Semacquire(0xc0001cc040?)
	/workdir/go/src/runtime/sema.go:62 +0x27 fp=0xc000063d98 sp=0xc000063d60 pc=0x46a5c7
sync.(*WaitGroup).Wait(0x8?)
	/workdir/go/src/sync/waitgroup.go:116 +0x4b fp=0xc000063dc0 sp=0xc000063d98 pc=0x4769ab
runtime/trace_test.TestTraceFutileWakeup(0xc0001a9ba0)
	/workdir/go/src/runtime/trace/trace_test.go:556 +0x399 fp=0xc000063f70 sp=0xc000063dc0 pc=0x56ec39
testing.tRunner(0xc0001a9ba0, 0x5cd9e0)

— watchflakes

gopherbot · 2023-05-19T16:27:19Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2023-05-19 14:59 linux-amd64-staticlockranking go@251daf46 runtime.TestPinnerSimple (log)

67962  ======
0 : mspanSpecial 29 0x7f2c982bf700
1 : mheapSpecial 28 0xb70250
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x85c23c?, 0xc00007f0f8?})
	/workdir/go/src/runtime/panic.go:1077 +0x5c fp=0x7f2c2affcde0 sp=0x7f2c2affcdb0 pc=0x43e23c
runtime.checkRanks(0xc000703040, 0x0?, 0x7dada0?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f2c2affce40 sp=0x7f2c2affcde0 pc=0x40fbf6
runtime.lockWithRank.func1()
	/workdir/go/src/runtime/lockrank_on.go:87 +0x85 fp=0x7f2c2affce70 sp=0x7f2c2affce40 pc=0x40f845
runtime.systemstack()
	/workdir/go/src/runtime/asm_amd64.s:509 +0x4a fp=0x7f2c2affce80 sp=0x7f2c2affce70 pc=0x47a9ea

runtime.systemstack_switch()
	/workdir/go/src/runtime/asm_amd64.s:474 +0x8 fp=0xc000079db8 sp=0xc000079da8 pc=0x47a988
runtime.lockWithRank(0xc000079df8?, 0x40f7c0?)
	/workdir/go/src/runtime/lockrank_on.go:76 +0x85 fp=0xc000079df0 sp=0xc000079db8 pc=0x40f785
runtime.lock(...)
	/workdir/go/src/runtime/lock_futex.go:48
runtime.(*mheap).newPinnerBits(0x412225?)
	/workdir/go/src/runtime/pinner.go:176 +0x37 fp=0xc000079e28 sp=0xc000079df0 pc=0x43f6b7
runtime.setPinned(0xc00002a630, 0x1)
	/workdir/go/src/runtime/pinner.go:128 +0xf1 fp=0xc000079ec0 sp=0xc000079e28 pc=0x43f391
runtime.(*Pinner).Pin(0xc000079f40, {0x7b9580, 0xc00002a630})
	/workdir/go/src/runtime/pinner.go:41 +0x94 fp=0xc000079f20 sp=0xc000079ec0 pc=0x43eed4
runtime_test.TestPinnerSimple(0xc0002244e0)
	/workdir/go/src/runtime/pinner_test.go:57 +0x91 fp=0xc000079f70 sp=0xc000079f20 pc=0x7583b1
testing.tRunner(0xc0002244e0, 0x87e020)

2023-05-19 15:54 linux-amd64-staticlockranking go@f283cba3 runtime.TestPinnerSimple (log)

67768  ======
0 : mspanSpecial 29 0x7f7d1c6ea348
1 : mheapSpecial 28 0xb70250
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x85c23c?, 0xc000314a68?})
	/workdir/go/src/runtime/panic.go:1077 +0x5c fp=0x7f7cdaffcde0 sp=0x7f7cdaffcdb0 pc=0x43e23c
runtime.checkRanks(0xc000582820, 0x0?, 0x7dada0?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f7cdaffce40 sp=0x7f7cdaffcde0 pc=0x40fbf6
runtime.lockWithRank.func1()
	/workdir/go/src/runtime/lockrank_on.go:87 +0x85 fp=0x7f7cdaffce70 sp=0x7f7cdaffce40 pc=0x40f845
runtime.systemstack()
	/workdir/go/src/runtime/asm_amd64.s:509 +0x4a fp=0x7f7cdaffce80 sp=0x7f7cdaffce70 pc=0x47a9ea

runtime.systemstack_switch()
	/workdir/go/src/runtime/asm_amd64.s:474 +0x8 fp=0xc000073db8 sp=0xc000073da8 pc=0x47a988
runtime.lockWithRank(0xc000073df8?, 0x40f7c0?)
	/workdir/go/src/runtime/lockrank_on.go:76 +0x85 fp=0xc000073df0 sp=0xc000073db8 pc=0x40f785
runtime.lock(...)
	/workdir/go/src/runtime/lock_futex.go:48
runtime.(*mheap).newPinnerBits(0x412225?)
	/workdir/go/src/runtime/pinner.go:176 +0x37 fp=0xc000073e28 sp=0xc000073df0 pc=0x43f6b7
runtime.setPinned(0xc0025a6678, 0x1)
	/workdir/go/src/runtime/pinner.go:128 +0xf1 fp=0xc000073ec0 sp=0xc000073e28 pc=0x43f391
runtime.(*Pinner).Pin(0xc000073f40, {0x7b9580, 0xc0025a6678})
	/workdir/go/src/runtime/pinner.go:41 +0x94 fp=0xc000073f20 sp=0xc000073ec0 pc=0x43eed4
runtime_test.TestPinnerSimple(0xc000674340)
	/workdir/go/src/runtime/pinner_test.go:57 +0x91 fp=0xc000073f70 sp=0xc000073f20 pc=0x7583b1
testing.tRunner(0xc000674340, 0x87e020)

— watchflakes

prattmic · 2023-05-19T21:18:03Z

cc @mknyszek these look related to pinning

mknyszek · 2023-05-19T21:20:34Z

They're fixed at HEAD. :) Forgot to reference the issue because the change landed before this issue was updated.

gopherbot · 2023-05-22T22:09:25Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2023-05-11 14:15 linux-amd64-staticlockranking go@e738f130 os/signal.TestSignalTrace (log)

79552  ======
0 : traceStrings 20 0x65d6f0
1 : fin 18 0x676750
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x54e56a?, 0x65d780?})
	/workdir/go/src/runtime/panic.go:1047 +0x5d fp=0x7f6459c6cb18 sp=0x7f6459c6cae8 pc=0x43a09d
runtime.checkRanks(0xc000006ea0, 0x65d760?, 0x65d760?)
	/workdir/go/src/runtime/lockrank_on.go:153 +0x205 fp=0x7f6459c6cb78 sp=0x7f6459c6cb18 pc=0x40dc65
...
	/workdir/go/src/runtime/sema.go:150 +0x20f fp=0xc00023be48 sp=0xc00023bde0 pc=0x44e1ef
runtime.semacquire(...)
	/workdir/go/src/runtime/sema.go:101
runtime.StopTrace()
	/workdir/go/src/runtime/trace.go:384 +0x27d fp=0xc00023be80 sp=0xc00023be48 pc=0x45cafd
runtime/trace.Stop()
	/workdir/go/src/runtime/trace/trace.go:148 +0x8d fp=0xc00023beb8 sp=0xc00023be80 pc=0x4bbead
os/signal.TestSignalTrace(0xc000293040)
	/workdir/go/src/os/signal/signal_test.go:908 +0x21a fp=0xc00023bf70 sp=0xc00023beb8 pc=0x4df5ba
testing.tRunner(0xc000293040, 0x556e30)

— watchflakes

mknyszek · 2023-05-22T22:18:55Z

I don't understand this last failure because traceStrings < MALLOC < fin explicitly in the lock rank order...

bcmills · 2023-05-23T02:00:23Z

Commit e738f130 is on release-branch.go1.19 (https://go.googlesource.com/go/+/e738f130).

(I filed #59483 to request clearer output from watchflakes for the release branches.)

gopherbot · 2023-05-23T12:03:46Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2023-05-23 11:37 linux-amd64-staticlockranking go@c99d966c runtime.TestPinnerSimple (log)

246251  ======
0 : mspanSpecial 29 0x7fbe420e0708
1 : gcBitsArenas 27 0xb71f40
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x85c240?, 0x7fbdf953e348?})
	/workdir/go/src/runtime/panic.go:1077 +0x5c fp=0x7fbde17f9de0 sp=0x7fbde17f9db0 pc=0x43e15c
runtime.checkRanks(0xc000178b60, 0x0?, 0x7dae00?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7fbde17f9e40 sp=0x7fbde17f9de0 pc=0x40fb96
...
	/workdir/go/src/runtime/mheap.go:2153 +0xaa fp=0xc0002ace20 sp=0xc0002acdd8 pc=0x43014a
runtime.(*mspan).newPinnerBits(...)
	/workdir/go/src/runtime/pinner.go:233
runtime.setPinned(0xc00002b170, 0x1)
	/workdir/go/src/runtime/pinner.go:127 +0xe9 fp=0xc0002acec0 sp=0xc0002ace20 pc=0x43f2a9
runtime.(*Pinner).Pin(0xc0002acf40, {0x7b9600, 0xc00002b170})
	/workdir/go/src/runtime/pinner.go:40 +0x94 fp=0xc0002acf20 sp=0xc0002acec0 pc=0x43edf4
runtime_test.TestPinnerSimple(0xc0006ca4e0)
	/workdir/go/src/runtime/pinner_test.go:57 +0x91 fp=0xc0002acf70 sp=0xc0002acf20 pc=0x7582b1
testing.tRunner(0xc0006ca4e0, 0x87e0e8)

— watchflakes

mknyszek · 2023-05-23T15:42:32Z

Okay, this last one is my bad. Should've seen that coming.

gopherbot · 2023-05-23T17:20:28Z

Change https://go.dev/cl/497475 mentions this issue: runtime: add partial lock order between mspanSpecial and gcBitsArenas

CL 493275 started using gcBits for pinner bits. This means gcBits can be allocated while holding the mspanSpecial lock. This is safe because these were just parallel in the partial order, but now they need an explicit edge between them. For #58277. Change-Id: I37917730e12d59cf0580f198d732198413a56424 Reviewed-on: https://go-review.googlesource.com/c/go/+/497475 Run-TryBot: Michael Knyszek <mknyszek@google.com> TryBot-Result: Gopher Robot <gobot@golang.org> Reviewed-by: David Chase <drchase@google.com>

mknyszek · 2023-06-09T18:35:11Z

I don't think we have any new ones. Moving this to Backlog.

gopherbot · 2023-10-25T21:18:13Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2023-10-25 19:47 linux-amd64-staticlockranking go@a57c5736 runtime/trace.TestTraceFutileWakeup (log)

84254  ======
0 : traceStackTab 43 0x7265e0
1 : wbufSpans 38 0x71f0b0
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x5ce82a?, 0x0?})
	/workdir/go/src/runtime/panic.go:1016 +0x5c fp=0x7fd1da7fb850 sp=0x7fd1da7fb820 pc=0x43b4bc
runtime.checkRanks(0xc000105520, 0x0?, 0x0?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7fd1da7fb8b0 sp=0x7fd1da7fb850 pc=0x40e7b6
...
	/workdir/go/src/runtime/proc.go:406
runtime.semacquire1(0xc0000781e8, 0x0, 0x1, 0x0, 0x12)
	/workdir/go/src/runtime/sema.go:160 +0x22f fp=0xc000067d60 sp=0xc000067d00 pc=0x44fbcf
sync.runtime_Semacquire(0xc00008c060?)
	/workdir/go/src/runtime/sema.go:62 +0x25 fp=0xc000067d98 sp=0xc000067d60 pc=0x46c4e5
sync.(*WaitGroup).Wait(0x8?)
	/workdir/go/src/sync/waitgroup.go:116 +0x48 fp=0xc000067dc0 sp=0xc000067d98 pc=0x4782c8
runtime/trace_test.TestTraceFutileWakeup(0xc000324680)
	/workdir/go/src/runtime/trace/trace_test.go:558 +0x372 fp=0xc000067f70 sp=0xc000067dc0 pc=0x574e92
testing.tRunner(0xc000324680, 0x5d9648)

— watchflakes

gopherbot · 2023-12-01T19:56:46Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2023-12-01 19:20 linux-amd64-staticlockranking go@5a2161ce runtime (log)

79554  ======
0 : gscan 35 0x0
1 : profInsert 31 0xc51f70
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x8be74f?, 0x0?})
	/workdir/go/src/runtime/panic.go:1023 +0x5c fp=0x7f435fffe6c8 sp=0x7f435fffe698 pc=0x44383c
runtime.checkRanks(0xc000006ea0, 0x0?, 0xbc1c80?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f435fffe728 sp=0x7f435fffe6c8 pc=0x4129f6
...
runtime_test.TestGCTestMoveStackOnNextCall(0xc000d40000)
	/workdir/go/src/runtime/gc_test.go:211 +0x1c fp=0xc0007a0f70 sp=0xc0007a0f20 pc=0x74997c
testing.tRunner(0xc000d40000, 0x8e3380)
	/workdir/go/src/testing/testing.go:1689 +0xfb fp=0xc0007a0fc0 sp=0xc0007a0f70 pc=0x521e1b
testing.(*T).Run.gowrap1()
	/workdir/go/src/testing/testing.go:1742 +0x25 fp=0xc0007a0fe0 sp=0xc0007a0fc0 pc=0x522e45
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0007a0fe8 sp=0xc0007a0fe0 pc=0x486f61
created by testing.(*T).Run in goroutine 1
	/workdir/go/src/testing/testing.go:1742 +0x390

— watchflakes

gopherbot · 2023-12-08T20:40:35Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2023-12-06 17:59 linux-amd64-staticlockranking go@3f2bf706 runtime (log)

81122  ======
0 : gscan 35 0x0
1 : profInsert 31 0xc56110
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x8c0a0e?, 0x0?})
	/workdir/go/src/runtime/panic.go:1023 +0x5c fp=0x7f5fbfffe6c8 sp=0x7f5fbfffe698 pc=0x443f3c
runtime.checkRanks(0xc00022e680, 0x0?, 0xbc5c80?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f5fbfffe728 sp=0x7f5fbfffe6c8 pc=0x413236
...
runtime_test.TestNetpollWaiters(0xc000c9a1a0)
	/workdir/go/src/runtime/crash_test.go:893 +0x1f fp=0xc000a8c770 sp=0xc000a8c6f0 pc=0x73f23f
testing.tRunner(0xc000c9a1a0, 0x8e5d80)
	/workdir/go/src/testing/testing.go:1689 +0xfb fp=0xc000a8c7c0 sp=0xc000a8c770 pc=0x52289b
testing.(*T).Run.gowrap1()
	/workdir/go/src/testing/testing.go:1742 +0x25 fp=0xc000a8c7e0 sp=0xc000a8c7c0 pc=0x5238c5
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000a8c7e8 sp=0xc000a8c7e0 pc=0x4879e1
created by testing.(*T).Run in goroutine 1
	/workdir/go/src/testing/testing.go:1742 +0x390

— watchflakes

gopherbot · 2023-12-13T01:12:49Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2023-12-13 00:22 linux-amd64-staticlockranking go@400e24a8 runtime (log)

81226  ======
0 : gscan 35 0x0
1 : profInsert 31 0xc561d0
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x8c0cb9?, 0x0?})
	/workdir/go/src/runtime/panic.go:1023 +0x5c fp=0x7f875effc6c8 sp=0x7f875effc698 pc=0x443f1c
runtime.checkRanks(0xc0001a2fc0, 0x0?, 0xbc5c80?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f875effc728 sp=0x7f875effc6c8 pc=0x413236
...
runtime_test.TestPanicTraceback(0xc0000dbba0)
	/workdir/go/src/runtime/crash_test.go:496 +0x2a fp=0xc0007d7f70 sp=0xc0007d7e38 pc=0x73c62a
testing.tRunner(0xc0000dbba0, 0x8e6288)
	/workdir/go/src/testing/testing.go:1689 +0xfb fp=0xc0007d7fc0 sp=0xc0007d7f70 pc=0x52295b
testing.(*T).Run.gowrap1()
	/workdir/go/src/testing/testing.go:1742 +0x25 fp=0xc0007d7fe0 sp=0xc0007d7fc0 pc=0x523985
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0007d7fe8 sp=0xc0007d7fe0 pc=0x487aa1
created by testing.(*T).Run in goroutine 1
	/workdir/go/src/testing/testing.go:1742 +0x390

— watchflakes

prattmic · 2023-12-13T22:26:51Z

gscan -> profInsert split to #64706.

gopherbot · 2024-01-23T01:04:49Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2024-01-23 00:14 linux-amd64-staticlockranking go@4605ce2d os/signal (log)

76557  ======
0 : traceStackTab 48 0x6aa2f0
1 : wbufSpans 43 0x689270
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x56b26a?, 0x2c000360eb?})
	/workdir/go/src/runtime/panic.go:1011 +0x5c fp=0x7f01f77fdaa0 sp=0x7f01f77fda70 pc=0x43c73c
runtime.checkRanks(0xc0001021c0, 0x5adc39?, 0x1f?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f01f77fdb00 sp=0x7f01f77fdaa0 pc=0x40f076
...
	/workdir/go/src/runtime/trace2.go:885 +0x53 fp=0xc0001b7fe0 sp=0xc0001b7fb0 pc=0x462093
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0001b7fe8 sp=0xc0001b7fe0 pc=0x4765e1
created by runtime.(*traceAdvancerState).start in goroutine 119
	/workdir/go/src/runtime/trace2.go:877 +0x168

goroutine 95 gp=0xc0000d8a80 m=nil [running]:
	goroutine running on other thread; stack unavailable
created by runtime/trace.Start in goroutine 119
	/workdir/go/src/runtime/trace/trace.go:128 +0xd0

— watchflakes

prattmic · 2024-01-25T18:00:21Z

@mknyszek I think adding traceStackTab above WB would be OK?

Edit: oh, nevermind. I see #56554 now.

gopherbot · 2024-01-25T18:08:32Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2024-01-25 09:18 gotip-linux-amd64-staticlockranking go@cad66291 os/signal.TestNotifyContextNotifications (log)

=== RUN   TestNotifyContextNotifications
=== PAUSE TestNotifyContextNotifications

2024-01-25 09:18 gotip-linux-amd64-staticlockranking go@cad66291 os/signal.TestSignalTrace (log)

=== RUN   TestSignalTrace
748108  ======
0 : traceStackTab 48 0x6ad2f0
1 : wbufSpans 43 0x68c270
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x56b26a?, 0x6990000d5ac?})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:1011 +0x5c fp=0x7f58bfd7eaa0 sp=0x7f58bfd7ea70 pc=0x43c73c
runtime.checkRanks(0xc000006fc0, 0x45da6b?, 0x4bfc1?)
...
runtime.chansend(0xc00022c310, 0xc0003c8fc7, 0x1, 0xc0003c8fd0?)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/chan.go:259 +0x38d fp=0xc0003c8f80 sp=0xc0003c8f10 pc=0x40800d
runtime.chansend1(0x4478bd?, 0xc0002b0380?)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/chan.go:145 +0x17 fp=0xc0003c8fb0 sp=0xc0003c8f80 pc=0x407c77
runtime.(*traceAdvancerState).start.func1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/trace2.go:885 +0x53 fp=0xc0003c8fe0 sp=0xc0003c8fb0 pc=0x462093
runtime.goexit({})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0003c8fe8 sp=0xc0003c8fe0 pc=0x4765e1
created by runtime.(*traceAdvancerState).start in goroutine 56
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/trace2.go:877 +0x168

— watchflakes

gopherbot · 2024-02-21T22:04:55Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2024-02-21 21:27 linux-amd64-staticlockranking go@cdf3249d net/http/pprof (log)

73321  ======
0 : gscan 39 0x0
1 : profBlock 36 0xa73580
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x77a90c?, 0x0?})
	/workdir/go/src/runtime/panic.go:1021 +0x5c fp=0x7f7d61ffa878 sp=0x7f7d61ffa848 pc=0x43d87c
runtime.checkRanks(0xc0002261c0, 0x434179?, 0xc000598000?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f7d61ffa8d8 sp=0x7f7d61ffa878 pc=0x40f236
...
sync.(*Mutex).Lock(...)
	/workdir/go/src/sync/mutex.go:90 pc=0x6dddcd
net/http/pprof.mutexHog2(0xc0000f4160, 0xc0000f4168, {0x0?, 0x0?, 0xa0fbc0?}, 0x1312d00)
	/workdir/go/src/net/http/pprof/pprof_test.go:129 +0xe9 fp=0xc0004eaf80 sp=0xc0004eaf28 pc=0x6ddda9
net/http/pprof.mutexHog.func1()
	/workdir/go/src/net/http/pprof/pprof_test.go:151 +0x6d fp=0xc0004eafe0 sp=0xc0004eaf80 pc=0x6de0cd
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0004eafe8 sp=0xc0004eafe0 pc=0x477a61
created by net/http/pprof.mutexHog in goroutine 47
	/workdir/go/src/net/http/pprof/pprof_test.go:149 +0xae

— watchflakes

gopherbot · 2024-02-28T17:06:11Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2024-02-28 16:43 linux-amd64-staticlockranking go@3be36e9b net/http/pprof (log)

73427  ======
0 : gscan 39 0x0
1 : profBlock 36 0xa70520
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x77977b?, 0x0?})
	/workdir/go/src/runtime/panic.go:1021 +0x5c fp=0x7f840108a780 sp=0x7f840108a750 pc=0x43d77c
runtime.checkRanks(0xc0000a8380, 0x434079?, 0xc0000a8380?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f840108a7e0 sp=0x7f840108a780 pc=0x40f136
...
sync.(*Mutex).Lock(...)
	/workdir/go/src/sync/mutex.go:90 pc=0x6dc68d
net/http/pprof.mutexHog2(0xc000446140, 0xc000446148, {0x0?, 0x0?, 0xa0cb60?}, 0x1312d00)
	/workdir/go/src/net/http/pprof/pprof_test.go:129 +0xe9 fp=0xc00044a780 sp=0xc00044a728 pc=0x6dc669
net/http/pprof.mutexHog.func1()
	/workdir/go/src/net/http/pprof/pprof_test.go:151 +0x6d fp=0xc00044a7e0 sp=0xc00044a780 pc=0x6dc98d
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00044a7e8 sp=0xc00044a7e0 pc=0x477061
created by net/http/pprof.mutexHog in goroutine 30
	/workdir/go/src/net/http/pprof/pprof_test.go:149 +0xae

— watchflakes

gopherbot · 2024-03-08T22:51:03Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2024-03-08 22:34 linux-amd64-staticlockranking go@24fa7544 net/http/pprof (log)

75602  ======
0 : gscan 40 0x0
1 : profBlock 37 0xa70700
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x779d29?, 0x0?})
	/workdir/go/src/runtime/panic.go:1021 +0x5c fp=0x7f47afffe878 sp=0x7f47afffe848 pc=0x43d89c
runtime.checkRanks(0xc0001021c0, 0x434139?, 0x0?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f47afffe8d8 sp=0x7f47afffe878 pc=0x40f196
...
sync.(*Mutex).Lock(...)
	/workdir/go/src/sync/mutex.go:90 pc=0x6dc87d
net/http/pprof.mutexHog2(0xc0003024c0, 0xc0003024c8, {0x3030303030306362?, 0x303020702d2d2d20?, 0xa0cd20?}, 0x1312d00)
	/workdir/go/src/net/http/pprof/pprof_test.go:130 +0x120 fp=0xc0001b2f80 sp=0xc0001b2f28 pc=0x6dc860
net/http/pprof.mutexHog.func1()
	/workdir/go/src/net/http/pprof/pprof_test.go:151 +0x6d fp=0xc0001b2fe0 sp=0xc0001b2f80 pc=0x6dcb4d
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0001b2fe8 sp=0xc0001b2fe0 pc=0x476f61
created by net/http/pprof.mutexHog in goroutine 68
	/workdir/go/src/net/http/pprof/pprof_test.go:149 +0xae

— watchflakes

gopherbot · 2024-03-25T19:46:34Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2024-03-25 19:21 linux-amd64-staticlockranking go@2c677361 net/http/pprof (log)

76677  ======
0 : gscan 42 0x0
1 : profBlock 39 0xa7f900
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x782ccf?, 0x0?})
	/workdir/go/src/runtime/panic.go:1021 +0x5c fp=0x7f8981698720 sp=0x7f89816986f0 pc=0x43db1c
runtime.checkRanks(0xc000006fc0, 0x434319?, 0x0?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f8981698780 sp=0x7f8981698720 pc=0x40f316
...
sync.(*Mutex).Lock(...)
	/workdir/go/src/sync/mutex.go:90
net/http/pprof.mutexHog2(0xc000216380, 0xc000216388, {0x662e73747365546e?, 0x6574103231636e75?, 0xa1bf40?}, 0x1312d00)
	/workdir/go/src/net/http/pprof/pprof_test.go:129 +0x10d fp=0xc0000bc780 sp=0xc0000bc728 pc=0x6e3d0d
net/http/pprof.mutexHog.func1()
	/workdir/go/src/net/http/pprof/pprof_test.go:151 +0x6d fp=0xc0000bc7e0 sp=0xc0000bc780 pc=0x6e400d
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0000bc7e8 sp=0xc0000bc7e0 pc=0x4779c1
created by net/http/pprof.mutexHog in goroutine 48
	/workdir/go/src/net/http/pprof/pprof_test.go:149 +0xae

— watchflakes

gopherbot · 2024-04-16T18:39:08Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2024-04-16 14:45 linux-amd64-staticlockranking go@f17b28de net/http/pprof (log)

78347  ======
0 : gscan 42 0x0
1 : profBlock 39 0xa47bd0
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x788642?, 0x7f6b5b752db0?})
	/workdir/go/src/runtime/panic.go:1021 +0x5c fp=0x7f6b5b752720 sp=0x7f6b5b7526f0 pc=0x43dc9c
runtime.checkRanks(0xc0000076c0, 0x434419?, 0x0?)
	/workdir/go/src/runtime/lockrank_on.go:162 +0x236 fp=0x7f6b5b752780 sp=0x7f6b5b752720 pc=0x40f236
...
sync.(*Mutex).Lock(...)
	/workdir/go/src/sync/mutex.go:90
net/http/pprof.mutexHog2(0xc00040c120, 0xc00040c128, {0x0?, 0x0?, 0xa24020?}, 0x1312d00)
	/workdir/go/src/net/http/pprof/pprof_test.go:129 +0x10d fp=0xc00011ff80 sp=0xc00011ff28 pc=0x6e80ed
net/http/pprof.mutexHog.func1()
	/workdir/go/src/net/http/pprof/pprof_test.go:151 +0x6d fp=0xc00011ffe0 sp=0xc00011ff80 pc=0x6e83ed
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00011ffe8 sp=0xc00011ffe0 pc=0x478221
created by net/http/pprof.mutexHog in goroutine 52
	/workdir/go/src/net/http/pprof/pprof_test.go:149 +0xae

— watchflakes

gopherbot · 2024-04-18T21:52:47Z

Found new dashboard test flakes for:

#!watchflakes
post <- builder ~ `.*-staticlockranking` && log ~ `lock ordering problem`

2024-04-15 20:09 gotip-linux-amd64-staticlockranking go@7418d419 net/http/pprof.TestDeltaProfile [ABORT] (log)

=== RUN   TestDeltaProfile
19699  ======
0 : gscan 42 0x0
1 : profBlock 39 0xa4cbd0
fatal error: lock ordering problem

runtime stack:
runtime.throw({0x788402?, 0x0?})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:1021 +0x5c fp=0x7f477dc80780 sp=0x7f477dc80750 pc=0x43dc9c
runtime.checkRanks(0xc0005421c0, 0x434419?, 0x0?)
...
sync.(*Mutex).Lock(...)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/sync/mutex.go:90
net/http/pprof.mutexHog2(0xc000314080, 0xc000314088, {0x0?, 0x0?, 0xa29020?}, 0x1312d00)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/net/http/pprof/pprof_test.go:129 +0x10d fp=0xc0004b9f80 sp=0xc0004b9f28 pc=0x6e814d
net/http/pprof.mutexHog.func1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/net/http/pprof/pprof_test.go:151 +0x6d fp=0xc0004b9fe0 sp=0xc0004b9f80 pc=0x6e844d
runtime.goexit({})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0004b9fe8 sp=0xc0004b9fe0 pc=0x478221
created by net/http/pprof.mutexHog in goroutine 98
	/home/swarming/.swarming/w/ir/x/w/goroot/src/net/http/pprof/pprof_test.go:149 +0xae

— watchflakes

gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Feb 2, 2023

bcmills mentioned this issue Feb 2, 2023

runtime: corruption in tests #55167

Open

bcmills added this to the Go1.21 milestone Feb 2, 2023

This comment was marked as outdated.

Sign in to view

mknyszek added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Feb 2, 2023

mknyszek self-assigned this Feb 8, 2023

mknyszek modified the milestones: Go1.21, Backlog Jun 9, 2023

mknyszek removed their assignment Jun 16, 2023

rsc mentioned this issue Mar 9, 2024

runtime: lock ordering problem: gscan, profBlock #66004

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

runtime: lock ordering problems #58277

runtime: lock ordering problems #58277

bcmills commented Feb 2, 2023 •

edited

This comment was marked as outdated.

gopherbot commented Feb 2, 2023

gopherbot commented May 19, 2023

prattmic commented May 19, 2023

mknyszek commented May 19, 2023

gopherbot commented May 22, 2023

mknyszek commented May 22, 2023

bcmills commented May 23, 2023

gopherbot commented May 23, 2023

mknyszek commented May 23, 2023

gopherbot commented May 23, 2023

mknyszek commented Jun 9, 2023

gopherbot commented Oct 25, 2023

gopherbot commented Dec 1, 2023

gopherbot commented Dec 8, 2023

gopherbot commented Dec 13, 2023

prattmic commented Dec 13, 2023

gopherbot commented Jan 23, 2024

prattmic commented Jan 25, 2024 •

edited

gopherbot commented Jan 25, 2024

gopherbot commented Feb 21, 2024

gopherbot commented Feb 28, 2024

gopherbot commented Mar 8, 2024

gopherbot commented Mar 25, 2024

gopherbot commented Apr 16, 2024

gopherbot commented Apr 18, 2024

runtime: lock ordering problems #58277

runtime: lock ordering problems #58277

Comments

bcmills commented Feb 2, 2023 • edited

This comment was marked as outdated.

gopherbot commented Feb 2, 2023

gopherbot commented May 19, 2023

prattmic commented May 19, 2023

mknyszek commented May 19, 2023

gopherbot commented May 22, 2023

mknyszek commented May 22, 2023

bcmills commented May 23, 2023

gopherbot commented May 23, 2023

mknyszek commented May 23, 2023

gopherbot commented May 23, 2023

mknyszek commented Jun 9, 2023

gopherbot commented Oct 25, 2023

gopherbot commented Dec 1, 2023

gopherbot commented Dec 8, 2023

gopherbot commented Dec 13, 2023

prattmic commented Dec 13, 2023

gopherbot commented Jan 23, 2024

prattmic commented Jan 25, 2024 • edited

gopherbot commented Jan 25, 2024

gopherbot commented Feb 21, 2024

gopherbot commented Feb 28, 2024

gopherbot commented Mar 8, 2024

gopherbot commented Mar 25, 2024

gopherbot commented Apr 16, 2024

gopherbot commented Apr 18, 2024

bcmills commented Feb 2, 2023 •

edited

prattmic commented Jan 25, 2024 •

edited