From 52bd1c4d6cc691aa60c71513695dba03062deb59 Mon Sep 17 00:00:00 2001 From: Rhys Hiltner Date: Fri, 18 Feb 2022 10:56:16 -0800 Subject: [PATCH] runtime: decrease STW pause for goroutine profile MIME-Version: 1.0 Content-Type: text/plain; charset=utf8 Content-Transfer-Encoding: 8bit The goroutine profile needs to stop the world to get a consistent snapshot of all goroutines in the app. Leaving the world stopped while iterating over allgs leads to a pause proportional to the number of goroutines in the app (or its high-water mark). Instead, do only a fixed amount of bookkeeping while the world is stopped. Install a barrier so the scheduler confirms that a goroutine appears in the profile, with its stack recorded exactly as it was during the stop-the-world pause, before it allows that goroutine to execute. Iterate over allgs while the app resumes normal operations, adding each to the profile unless they've been scheduled in the meantime (and so have profiled themselves). Stop the world a second time to remove the barrier and do a fixed amount of cleanup work. This increases both the fixed overhead and per-goroutine CPU-time cost of GoroutineProfile. It also increases the wall-clock latency of the call to GoroutineProfile, since the scheduler may interrupt it to execute other goroutines. name old time/op new time/op delta GoroutineProfile/small/loaded-8 1.05ms ± 5% 4.99ms ±31% +376.85% (p=0.000 n=10+9) GoroutineProfile/sparse/loaded-8 1.04ms ± 4% 3.61ms ±27% +246.61% (p=0.000 n=10+10) GoroutineProfile/large/loaded-8 7.69ms ±17% 20.35ms ± 4% +164.50% (p=0.000 n=10+10) GoroutineProfile/small/idle 958µs ± 0% 1820µs ±23% +89.91% (p=0.000 n=10+10) GoroutineProfile/sparse/idle-8 1.00ms ± 3% 1.52ms ±17% +51.18% (p=0.000 n=10+10) GoroutineProfile/small/idle-8 1.01ms ± 4% 1.47ms ± 7% +45.28% (p=0.000 n=9+9) GoroutineProfile/sparse/idle 980µs ± 1% 1403µs ± 2% +43.22% (p=0.000 n=9+10) GoroutineProfile/large/idle-8 7.19ms ± 8% 8.43ms ±21% +17.22% (p=0.011 n=10+10) PingPongHog 511ns ± 8% 585ns ± 9% +14.39% (p=0.000 n=10+10) GoroutineProfile/large/idle 6.71ms ± 0% 7.58ms ± 3% +13.08% (p=0.000 n=8+10) PingPongHog-8 469ns ± 8% 509ns ±12% +8.62% (p=0.010 n=9+10) WakeupParallelSyscall/5µs 216µs ± 4% 229µs ± 3% +6.06% (p=0.000 n=10+9) WakeupParallelSyscall/5µs-8 147µs ± 1% 149µs ± 2% +1.12% (p=0.009 n=10+10) WakeupParallelSyscall/2µs-8 140µs ± 0% 142µs ± 1% +1.11% (p=0.001 n=10+9) WakeupParallelSyscall/50µs-8 236µs ± 0% 238µs ± 1% +1.08% (p=0.000 n=9+10) WakeupParallelSyscall/1µs-8 138µs ± 0% 140µs ± 1% +1.05% (p=0.013 n=10+9) Matmult 8.52ns ± 1% 8.61ns ± 0% +0.98% (p=0.002 n=10+8) WakeupParallelSyscall/10µs-8 157µs ± 1% 158µs ± 1% +0.58% (p=0.003 n=10+8) CreateGoroutinesSingle-8 328ns ± 0% 330ns ± 1% +0.57% (p=0.000 n=9+9) WakeupParallelSpinning/100µs-8 343µs ± 0% 344µs ± 1% +0.30% (p=0.015 n=8+8) WakeupParallelSyscall/20µs-8 178µs ± 0% 178µs ± 0% +0.18% (p=0.043 n=10+9) StackGrowthDeep-8 22.8µs ± 0% 22.9µs ± 0% +0.12% (p=0.006 n=10+10) StackGrowth 1.06µs ± 0% 1.06µs ± 0% +0.09% (p=0.000 n=8+9) WakeupParallelSpinning/0s 10.7µs ± 0% 10.7µs ± 0% +0.08% (p=0.000 n=9+9) WakeupParallelSpinning/5µs 30.7µs ± 0% 30.7µs ± 0% +0.04% (p=0.000 n=10+10) WakeupParallelSpinning/100µs 411µs ± 0% 411µs ± 0% +0.03% (p=0.000 n=10+9) WakeupParallelSpinning/2µs 18.7µs ± 0% 18.7µs ± 0% +0.02% (p=0.026 n=10+10) WakeupParallelSpinning/20µs-8 93.0µs ± 0% 93.0µs ± 0% +0.01% (p=0.021 n=9+10) StackGrowth-8 216ns ± 0% 216ns ± 0% ~ (p=0.209 n=10+10) CreateGoroutinesParallel-8 49.5ns ± 2% 49.3ns ± 1% ~ (p=0.591 n=10+10) CreateGoroutinesSingle 699ns ±20% 748ns ±19% ~ (p=0.353 n=10+10) WakeupParallelSpinning/0s-8 15.9µs ± 2% 16.0µs ± 3% ~ (p=0.315 n=10+10) WakeupParallelSpinning/1µs 14.6µs ± 0% 14.6µs ± 0% ~ (p=0.513 n=10+10) WakeupParallelSpinning/2µs-8 24.2µs ± 3% 24.1µs ± 2% ~ (p=0.971 n=10+10) WakeupParallelSpinning/10µs 50.7µs ± 0% 50.7µs ± 0% ~ (p=0.101 n=10+10) WakeupParallelSpinning/20µs 90.7µs ± 0% 90.7µs ± 0% ~ (p=0.898 n=10+10) WakeupParallelSpinning/50µs 211µs ± 0% 211µs ± 0% ~ (p=0.382 n=10+10) WakeupParallelSyscall/0s-8 137µs ± 1% 138µs ± 0% ~ (p=0.075 n=10+10) WakeupParallelSyscall/1µs 216µs ± 1% 219µs ± 3% ~ (p=0.065 n=10+9) WakeupParallelSyscall/2µs 214µs ± 7% 219µs ± 1% ~ (p=0.101 n=10+8) WakeupParallelSyscall/50µs 317µs ± 5% 326µs ± 4% ~ (p=0.123 n=10+10) WakeupParallelSyscall/100µs 450µs ± 9% 459µs ± 8% ~ (p=0.247 n=10+10) WakeupParallelSyscall/100µs-8 337µs ± 0% 338µs ± 1% ~ (p=0.089 n=10+10) WakeupParallelSpinning/5µs-8 32.2µs ± 0% 32.2µs ± 0% -0.05% (p=0.026 n=9+10) WakeupParallelSpinning/50µs-8 216µs ± 0% 216µs ± 0% -0.12% (p=0.004 n=10+10) WakeupParallelSpinning/1µs-8 20.6µs ± 0% 20.5µs ± 0% -0.22% (p=0.014 n=10+10) WakeupParallelSpinning/10µs-8 54.5µs ± 0% 54.2µs ± 1% -0.57% (p=0.000 n=10+10) CreateGoroutines-8 213ns ± 1% 211ns ± 1% -0.86% (p=0.002 n=10+10) CreateGoroutinesCapture 1.03µs ± 0% 1.02µs ± 0% -0.91% (p=0.000 n=10+10) CreateGoroutinesCapture-8 1.32µs ± 1% 1.31µs ± 1% -1.06% (p=0.001 n=10+9) CreateGoroutines 188ns ± 0% 186ns ± 0% -1.06% (p=0.000 n=9+10) CreateGoroutinesParallel 188ns ± 0% 186ns ± 0% -1.27% (p=0.000 n=8+10) WakeupParallelSyscall/0s 210µs ± 3% 207µs ± 3% -1.60% (p=0.043 n=10+10) StackGrowthDeep 121µs ± 1% 119µs ± 1% -1.70% (p=0.000 n=9+10) Matmult-8 1.82ns ± 3% 1.78ns ± 3% -2.16% (p=0.020 n=10+10) WakeupParallelSyscall/20µs 281µs ± 3% 269µs ± 4% -4.44% (p=0.000 n=10+10) WakeupParallelSyscall/10µs 239µs ± 3% 228µs ± 9% -4.70% (p=0.001 n=10+10) GoroutineProfile/sparse-nil/idle-8 485µs ± 2% 12µs ± 4% -97.56% (p=0.000 n=10+10) GoroutineProfile/small-nil/idle-8 484µs ± 2% 12µs ± 1% -97.60% (p=0.000 n=10+7) GoroutineProfile/small-nil/loaded-8 487µs ± 2% 11µs ± 3% -97.68% (p=0.000 n=10+10) GoroutineProfile/sparse-nil/loaded-8 507µs ± 4% 11µs ± 6% -97.78% (p=0.000 n=10+10) GoroutineProfile/large-nil/idle-8 709µs ± 2% 11µs ± 4% -98.38% (p=0.000 n=10+10) GoroutineProfile/large-nil/loaded-8 717µs ± 2% 11µs ± 3% -98.43% (p=0.000 n=10+10) GoroutineProfile/sparse-nil/idle 465µs ± 3% 1µs ± 1% -99.84% (p=0.000 n=10+10) GoroutineProfile/small-nil/idle 493µs ± 3% 1µs ± 0% -99.85% (p=0.000 n=10+9) GoroutineProfile/large-nil/idle 716µs ± 1% 1µs ± 2% -99.89% (p=0.000 n=7+10) name old alloc/op new alloc/op delta CreateGoroutinesCapture 144B ± 0% 144B ± 0% ~ (all equal) CreateGoroutinesCapture-8 144B ± 0% 144B ± 0% ~ (all equal) name old allocs/op new allocs/op delta CreateGoroutinesCapture 5.00 ± 0% 5.00 ± 0% ~ (all equal) CreateGoroutinesCapture-8 5.00 ± 0% 5.00 ± 0% ~ (all equal) name old p50-ns new p50-ns delta GoroutineProfile/small/loaded-8 1.01M ± 3% 3.87M ±45% +282.15% (p=0.000 n=10+10) GoroutineProfile/sparse/loaded-8 1.02M ± 3% 2.43M ±41% +138.42% (p=0.000 n=10+10) GoroutineProfile/large/loaded-8 7.43M ±16% 17.28M ± 2% +132.43% (p=0.000 n=10+10) GoroutineProfile/small/idle 956k ± 0% 1559k ±16% +63.03% (p=0.000 n=10+10) GoroutineProfile/small/idle-8 1.01M ± 3% 1.45M ± 7% +44.31% (p=0.000 n=10+9) GoroutineProfile/sparse/idle 977k ± 1% 1399k ± 2% +43.20% (p=0.000 n=10+10) GoroutineProfile/sparse/idle-8 1.00M ± 3% 1.41M ± 3% +40.47% (p=0.000 n=10+10) GoroutineProfile/large/idle-8 6.97M ± 1% 8.41M ±25% +20.54% (p=0.003 n=8+10) GoroutineProfile/large/idle 6.71M ± 1% 7.46M ± 4% +11.15% (p=0.000 n=10+10) GoroutineProfile/sparse-nil/idle-8 483k ± 3% 13k ± 3% -97.41% (p=0.000 n=10+9) GoroutineProfile/small-nil/idle-8 483k ± 2% 12k ± 1% -97.43% (p=0.000 n=10+8) GoroutineProfile/small-nil/loaded-8 484k ± 3% 10k ± 2% -97.93% (p=0.000 n=10+8) GoroutineProfile/sparse-nil/loaded-8 492k ± 2% 10k ± 4% -97.97% (p=0.000 n=10+8) GoroutineProfile/large-nil/idle-8 708k ± 2% 12k ±15% -98.36% (p=0.000 n=10+10) GoroutineProfile/large-nil/loaded-8 714k ± 2% 10k ± 2% -98.60% (p=0.000 n=10+8) GoroutineProfile/sparse-nil/idle 459k ± 1% 1k ± 1% -99.85% (p=0.000 n=10+10) GoroutineProfile/small-nil/idle 477k ± 1% 1k ± 0% -99.85% (p=0.000 n=10+9) GoroutineProfile/large-nil/idle 712k ± 1% 1k ± 1% -99.90% (p=0.000 n=7+10) name old p90-ns new p90-ns delta GoroutineProfile/small/loaded-8 1.13M ±10% 7.49M ±35% +562.07% (p=0.000 n=10+10) GoroutineProfile/sparse/loaded-8 1.10M ±12% 4.58M ±31% +318.02% (p=0.000 n=10+9) GoroutineProfile/large/loaded-8 8.78M ±24% 27.83M ± 2% +217.00% (p=0.000 n=10+10) GoroutineProfile/small/idle 967k ± 0% 2909k ±50% +200.91% (p=0.000 n=10+10) GoroutineProfile/sparse/idle-8 1.02M ± 3% 1.96M ±76% +92.99% (p=0.000 n=10+10) GoroutineProfile/small/idle-8 1.07M ±17% 1.55M ±12% +45.23% (p=0.000 n=10+10) GoroutineProfile/sparse/idle 992k ± 1% 1417k ± 3% +42.79% (p=0.000 n=9+10) GoroutineProfile/large/idle 6.73M ± 0% 7.99M ± 8% +18.80% (p=0.000 n=8+10) GoroutineProfile/large/idle-8 8.20M ±25% 9.18M ±25% ~ (p=0.315 n=10+10) GoroutineProfile/sparse-nil/idle-8 495k ± 3% 13k ± 1% -97.36% (p=0.000 n=10+9) GoroutineProfile/small-nil/idle-8 494k ± 2% 13k ± 3% -97.36% (p=0.000 n=10+10) GoroutineProfile/small-nil/loaded-8 496k ± 2% 13k ± 1% -97.41% (p=0.000 n=10+10) GoroutineProfile/sparse-nil/loaded-8 544k ±11% 13k ± 1% -97.62% (p=0.000 n=10+9) GoroutineProfile/large-nil/idle-8 724k ± 1% 13k ± 3% -98.20% (p=0.000 n=10+10) GoroutineProfile/large-nil/loaded-8 729k ± 3% 13k ± 2% -98.23% (p=0.000 n=10+10) GoroutineProfile/sparse-nil/idle 476k ± 4% 1k ± 1% -99.85% (p=0.000 n=9+10) GoroutineProfile/small-nil/idle 537k ±10% 1k ± 0% -99.87% (p=0.000 n=10+9) GoroutineProfile/large-nil/idle 729k ± 0% 1k ± 1% -99.90% (p=0.000 n=7+10) name old p99-ns new p99-ns delta GoroutineProfile/sparse/loaded-8 1.27M ±33% 20.49M ±17% +1514.61% (p=0.000 n=10+10) GoroutineProfile/small/loaded-8 1.37M ±29% 20.48M ±23% +1399.35% (p=0.000 n=10+10) GoroutineProfile/large/loaded-8 9.76M ±23% 39.98M ±22% +309.52% (p=0.000 n=10+8) GoroutineProfile/small/idle 976k ± 1% 3367k ±55% +244.94% (p=0.000 n=10+10) GoroutineProfile/sparse/idle-8 1.03M ± 3% 2.50M ±65% +142.30% (p=0.000 n=10+10) GoroutineProfile/small/idle-8 1.17M ±34% 1.70M ±14% +45.15% (p=0.000 n=10+10) GoroutineProfile/sparse/idle 1.02M ± 3% 1.45M ± 4% +42.64% (p=0.000 n=9+10) GoroutineProfile/large/idle 6.92M ± 2% 9.00M ± 7% +29.98% (p=0.000 n=8+9) GoroutineProfile/large/idle-8 8.74M ±23% 9.90M ±24% ~ (p=0.190 n=10+10) GoroutineProfile/sparse-nil/idle-8 508k ± 4% 16k ± 2% -96.90% (p=0.000 n=10+9) GoroutineProfile/small-nil/idle-8 508k ± 4% 16k ± 3% -96.91% (p=0.000 n=10+9) GoroutineProfile/small-nil/loaded-8 542k ± 5% 15k ±15% -97.15% (p=0.000 n=10+10) GoroutineProfile/sparse-nil/loaded-8 649k ±16% 15k ±18% -97.67% (p=0.000 n=10+10) GoroutineProfile/large-nil/idle-8 738k ± 2% 16k ± 2% -97.86% (p=0.000 n=10+10) GoroutineProfile/large-nil/loaded-8 765k ± 4% 15k ±17% -98.03% (p=0.000 n=10+10) GoroutineProfile/sparse-nil/idle 539k ±26% 1k ±17% -99.84% (p=0.000 n=10+10) GoroutineProfile/small-nil/idle 659k ±25% 1k ± 0% -99.84% (p=0.000 n=10+8) GoroutineProfile/large-nil/idle 760k ± 2% 1k ±22% -99.88% (p=0.000 n=9+10) Fixes #33250 For #50794 Change-Id: I862a2bc4e991cec485f21a6fce4fca84f2c6435b Reviewed-on: https://go-review.googlesource.com/c/go/+/387415 Reviewed-by: Michael Knyszek Reviewed-by: Than McIntosh Run-TryBot: Rhys Hiltner TryBot-Result: Gopher Robot --- src/runtime/mfinal.go | 7 +- src/runtime/mprof.go | 249 +++++++++++++++++++++++++++++++++++++ src/runtime/proc.go | 25 ++++ src/runtime/runtime2.go | 4 + src/runtime/sizeof_test.go | 2 +- 5 files changed, 284 insertions(+), 3 deletions(-) diff --git a/src/runtime/mfinal.go b/src/runtime/mfinal.go index bf537b417c..44174913de 100644 --- a/src/runtime/mfinal.go +++ b/src/runtime/mfinal.go @@ -166,13 +166,16 @@ func runfinq() { argRegs int ) + gp := getg() + lock(&finlock) + fing = gp + unlock(&finlock) + for { lock(&finlock) fb := finq finq = nil if fb == nil { - gp := getg() - fing = gp fingwait = true goparkunlock(&finlock, waitReasonFinalizerWait, traceEvGoBlock, 1) continue diff --git a/src/runtime/mprof.go b/src/runtime/mprof.go index 1edb5d6967..5137db2015 100644 --- a/src/runtime/mprof.go +++ b/src/runtime/mprof.go @@ -753,11 +753,260 @@ func runtime_goroutineProfileWithLabels(p []StackRecord, labels []unsafe.Pointer return goroutineProfileWithLabels(p, labels) } +const go119ConcurrentGoroutineProfile = true + // labels may be nil. If labels is non-nil, it must have the same length as p. func goroutineProfileWithLabels(p []StackRecord, labels []unsafe.Pointer) (n int, ok bool) { if labels != nil && len(labels) != len(p) { labels = nil } + + if go119ConcurrentGoroutineProfile { + return goroutineProfileWithLabelsConcurrent(p, labels) + } + return goroutineProfileWithLabelsSync(p, labels) +} + +var goroutineProfile = struct { + sema uint32 + active bool + offset atomic.Int64 + records []StackRecord + labels []unsafe.Pointer +}{ + sema: 1, +} + +// goroutineProfileState indicates the status of a goroutine's stack for the +// current in-progress goroutine profile. Goroutines' stacks are initially +// "Absent" from the profile, and end up "Satisfied" by the time the profile is +// complete. While a goroutine's stack is being captured, its +// goroutineProfileState will be "InProgress" and it will not be able to run +// until the capture completes and the state moves to "Satisfied". +// +// Some goroutines (the finalizer goroutine, which at various times can be +// either a "system" or a "user" goroutine, and the goroutine that is +// coordinating the profile, any goroutines created during the profile) move +// directly to the "Satisfied" state. +type goroutineProfileState uint32 + +const ( + goroutineProfileAbsent goroutineProfileState = iota + goroutineProfileInProgress + goroutineProfileSatisfied +) + +type goroutineProfileStateHolder atomic.Uint32 + +func (p *goroutineProfileStateHolder) Load() goroutineProfileState { + return goroutineProfileState((*atomic.Uint32)(p).Load()) +} + +func (p *goroutineProfileStateHolder) Store(value goroutineProfileState) { + (*atomic.Uint32)(p).Store(uint32(value)) +} + +func (p *goroutineProfileStateHolder) CompareAndSwap(old, new goroutineProfileState) bool { + return (*atomic.Uint32)(p).CompareAndSwap(uint32(old), uint32(new)) +} + +func goroutineProfileWithLabelsConcurrent(p []StackRecord, labels []unsafe.Pointer) (n int, ok bool) { + semacquire(&goroutineProfile.sema) + + ourg := getg() + + stopTheWorld("profile") + // Using gcount while the world is stopped should give us a consistent view + // of the number of live goroutines, minus the number of goroutines that are + // alive and permanently marked as "system". But to make this count agree + // with what we'd get from isSystemGoroutine, we need special handling for + // goroutines that can vary between user and system to ensure that the count + // doesn't change during the collection. So, check the finalizer goroutine + // in particular. + n = int(gcount()) + if fingRunning { + n++ + } + + if n > len(p) { + // There's not enough space in p to store the whole profile, so (per the + // contract of runtime.GoroutineProfile) we're not allowed to write to p + // at all and must return n, false. + startTheWorld() + semrelease(&goroutineProfile.sema) + return n, false + } + + // Save current goroutine. + sp := getcallersp() + pc := getcallerpc() + systemstack(func() { + saveg(pc, sp, ourg, &p[0]) + }) + ourg.goroutineProfiled.Store(goroutineProfileSatisfied) + goroutineProfile.offset.Store(1) + + // Prepare for all other goroutines to enter the profile. Aside from ourg, + // every goroutine struct in the allgs list has its goroutineProfiled field + // cleared. Any goroutine created from this point on (while + // goroutineProfile.active is set) will start with its goroutineProfiled + // field set to goroutineProfileSatisfied. + goroutineProfile.active = true + goroutineProfile.records = p + goroutineProfile.labels = labels + // The finializer goroutine needs special handling because it can vary over + // time between being a user goroutine (eligible for this profile) and a + // system goroutine (to be excluded). Pick one before restarting the world. + if fing != nil { + fing.goroutineProfiled.Store(goroutineProfileSatisfied) + } + if readgstatus(fing) != _Gdead && !isSystemGoroutine(fing, false) { + doRecordGoroutineProfile(fing) + } + startTheWorld() + + // Visit each goroutine that existed as of the startTheWorld call above. + // + // New goroutines may not be in this list, but we didn't want to know about + // them anyway. If they do appear in this list (via reusing a dead goroutine + // struct, or racing to launch between the world restarting and us getting + // the list), they will aleady have their goroutineProfiled field set to + // goroutineProfileSatisfied before their state transitions out of _Gdead. + // + // Any goroutine that the scheduler tries to execute concurrently with this + // call will start by adding itself to the profile (before the act of + // executing can cause any changes in its stack). + forEachGRace(func(gp1 *g) { + tryRecordGoroutineProfile(gp1, Gosched) + }) + + stopTheWorld("profile cleanup") + endOffset := goroutineProfile.offset.Swap(0) + goroutineProfile.active = false + goroutineProfile.records = nil + goroutineProfile.labels = nil + startTheWorld() + + // Restore the invariant that every goroutine struct in allgs has its + // goroutineProfiled field cleared. + forEachGRace(func(gp1 *g) { + gp1.goroutineProfiled.Store(goroutineProfileAbsent) + }) + + if raceenabled { + raceacquire(unsafe.Pointer(&labelSync)) + } + + if n != int(endOffset) { + // It's a big surprise that the number of goroutines changed while we + // were collecting the profile. But probably better to return a + // truncated profile than to crash the whole process. + // + // For instance, needm moves a goroutine out of the _Gdead state and so + // might be able to change the goroutine count without interacting with + // the scheduler. For code like that, the race windows are small and the + // combination of features is uncommon, so it's hard to be (and remain) + // sure we've caught them all. + } + + semrelease(&goroutineProfile.sema) + return n, true +} + +// tryRecordGoroutineProfileWB asserts that write barriers are allowed and calls +// tryRecordGoroutineProfile. +// +//go:yeswritebarrierrec +func tryRecordGoroutineProfileWB(gp1 *g) { + if getg().m.p.ptr() == nil { + throw("no P available, write barriers are forbidden") + } + tryRecordGoroutineProfile(gp1, osyield) +} + +// tryRecordGoroutineProfile ensures that gp1 has the appropriate representation +// in the current goroutine profile: either that it should not be profiled, or +// that a snapshot of its call stack and labels are now in the profile. +func tryRecordGoroutineProfile(gp1 *g, yield func()) { + if readgstatus(gp1) == _Gdead { + // Dead goroutines should not appear in the profile. Goroutines that + // start while profile collection is active will get goroutineProfiled + // set to goroutineProfileSatisfied before transitioning out of _Gdead, + // so here we check _Gdead first. + return + } + if isSystemGoroutine(gp1, true) { + // System goroutines should not appear in the profile. (The finalizer + // goroutine is marked as "already profiled".) + return + } + + for { + prev := gp1.goroutineProfiled.Load() + if prev == goroutineProfileSatisfied { + // This goroutine is already in the profile (or is new since the + // start of collection, so shouldn't appear in the profile). + break + } + if prev == goroutineProfileInProgress { + // Something else is adding gp1 to the goroutine profile right now. + // Give that a moment to finish. + yield() + continue + } + + // While we have gp1.goroutineProfiled set to + // goroutineProfileInProgress, gp1 may appear _Grunnable but will not + // actually be able to run. Disable preemption for ourselves, to make + // sure we finish profiling gp1 right away instead of leaving it stuck + // in this limbo. + mp := acquirem() + if gp1.goroutineProfiled.CompareAndSwap(goroutineProfileAbsent, goroutineProfileInProgress) { + doRecordGoroutineProfile(gp1) + gp1.goroutineProfiled.Store(goroutineProfileSatisfied) + } + releasem(mp) + } +} + +// doRecordGoroutineProfile writes gp1's call stack and labels to an in-progress +// goroutine profile. Preemption is disabled. +// +// This may be called via tryRecordGoroutineProfile in two ways: by the +// goroutine that is coordinating the goroutine profile (running on its own +// stack), or from the scheduler in preparation to execute gp1 (running on the +// system stack). +func doRecordGoroutineProfile(gp1 *g) { + if readgstatus(gp1) == _Grunning { + print("doRecordGoroutineProfile gp1=", gp1.goid, "\n") + throw("cannot read stack of running goroutine") + } + + offset := int(goroutineProfile.offset.Add(1)) - 1 + + if offset >= len(goroutineProfile.records) { + // Should be impossible, but better to return a truncated profile than + // to crash the entire process at this point. Instead, deal with it in + // goroutineProfileWithLabelsConcurrent where we have more context. + return + } + + // saveg calls gentraceback, which may call cgo traceback functions. When + // called from the scheduler, this is on the system stack already so + // traceback.go:cgoContextPCs will avoid calling back into the scheduler. + // + // When called from the goroutine coordinating the profile, we still have + // set gp1.goroutineProfiled to goroutineProfileInProgress and so are still + // preventing it from being truly _Grunnable. So we'll use the system stack + // to avoid schedule delays. + systemstack(func() { saveg(^uintptr(0), ^uintptr(0), gp1, &goroutineProfile.records[offset]) }) + + if goroutineProfile.labels != nil { + goroutineProfile.labels[offset] = gp1.labels + } +} + +func goroutineProfileWithLabelsSync(p []StackRecord, labels []unsafe.Pointer) (n int, ok bool) { gp := getg() isOK := func(gp1 *g) bool { diff --git a/src/runtime/proc.go b/src/runtime/proc.go index 2f2664f778..b28e97475d 100644 --- a/src/runtime/proc.go +++ b/src/runtime/proc.go @@ -2508,6 +2508,13 @@ func gcstopm() { func execute(gp *g, inheritTime bool) { _g_ := getg() + if goroutineProfile.active { + // Make sure that gp has had its stack written out to the goroutine + // profile, exactly as it was when the goroutine profiler first stopped + // the world. + tryRecordGoroutineProfile(gp, osyield) + } + // Assign gp.m before entering _Grunning so running Gs have an // M. _g_.m.curg = gp @@ -3767,6 +3774,16 @@ func exitsyscall() { oldp := _g_.m.oldp.ptr() _g_.m.oldp = 0 if exitsyscallfast(oldp) { + // When exitsyscallfast returns success, we have a P so can now use + // write barriers + if goroutineProfile.active { + // Make sure that gp has had its stack written out to the goroutine + // profile, exactly as it was when the goroutine profiler first + // stopped the world. + systemstack(func() { + tryRecordGoroutineProfileWB(_g_) + }) + } if trace.enabled { if oldp != _g_.m.p.ptr() || _g_.m.syscalltick != _g_.m.p.ptr().syscalltick { systemstack(traceGoStart) @@ -4134,6 +4151,14 @@ func newproc1(fn *funcval, callergp *g, callerpc uintptr) *g { if _g_.m.curg != nil { newg.labels = _g_.m.curg.labels } + if goroutineProfile.active { + // A concurrent goroutine profile is running. It should include + // exactly the set of goroutines that were alive when the goroutine + // profiler first stopped the world. That does not include newg, so + // mark it as not needing a profile before transitioning it from + // _Gdead. + newg.goroutineProfiled.Store(goroutineProfileSatisfied) + } } // Track initial transition? newg.trackingSeq = uint8(fastrand()) diff --git a/src/runtime/runtime2.go b/src/runtime/runtime2.go index e4b7bec926..63d8449358 100644 --- a/src/runtime/runtime2.go +++ b/src/runtime/runtime2.go @@ -489,6 +489,10 @@ type g struct { timer *timer // cached timer for time.Sleep selectDone uint32 // are we participating in a select and did someone win the race? + // goroutineProfiled indicates the status of this goroutine's stack for the + // current in-progress goroutine profile + goroutineProfiled goroutineProfileStateHolder + // Per-G GC state // gcAssistBytes is this G's GC assist credit in terms of diff --git a/src/runtime/sizeof_test.go b/src/runtime/sizeof_test.go index ebf544ad3b..9ce0a3afcd 100644 --- a/src/runtime/sizeof_test.go +++ b/src/runtime/sizeof_test.go @@ -21,7 +21,7 @@ func TestSizeof(t *testing.T) { _32bit uintptr // size on 32bit platforms _64bit uintptr // size on 64bit platforms }{ - {runtime.G{}, 236, 392}, // g, but exported for testing + {runtime.G{}, 240, 392}, // g, but exported for testing {runtime.Sudog{}, 56, 88}, // sudog, but exported for testing } -- 2.50.0