From 79c56addb680b04804e1c3553ba96760d0172d55 Mon Sep 17 00:00:00 2001 From: Austin Clements Date: Fri, 14 Apr 2017 13:52:27 -0400 Subject: [PATCH] runtime: make sweep trace events encompass entire sweep loop Currently, each individual span sweep emits a span to the trace. But sweeps are generally done in loops until some condition is satisfied, so this tracing is lower-level than anyone really wants any hides the fact that no other work is being accomplished between adjacent sweep events. This is also high overhead: enabling tracing significantly impacts sweep latency. Replace this with instead tracing around the sweep loops used for allocation. This is slightly tricky because sweep loops don't generally know if any sweeping will happen in them. Hence, we make the tracing lazy by recording in the P that we would like to start tracing the sweep *if* one happens, and then only closing the sweep event if we started it. This does mean we don't get tracing on every sweep path, which are legion. However, we get much more informative tracing on the paths that block allocation, which are the paths that matter. Change-Id: I73e14fbb250acb0c9d92e3648bddaa5e7d7e271c Reviewed-on: https://go-review.googlesource.com/40810 Run-TryBot: Austin Clements Reviewed-by: Hyang-Ah Hana Kim TryBot-Result: Gobot Gobot --- src/runtime/mcentral.go | 11 +++++++++++ src/runtime/mgcsweep.go | 13 +++++++++---- src/runtime/mheap.go | 6 ++++++ src/runtime/runtime2.go | 5 +++++ src/runtime/trace.go | 31 +++++++++++++++++++++++++++++-- 5 files changed, 60 insertions(+), 6 deletions(-) diff --git a/src/runtime/mcentral.go b/src/runtime/mcentral.go index be3820a9a5..8f9c529539 100644 --- a/src/runtime/mcentral.go +++ b/src/runtime/mcentral.go @@ -43,6 +43,10 @@ func (c *mcentral) cacheSpan() *mspan { deductSweepCredit(spanBytes, 0) lock(&c.lock) + traceDone := false + if trace.enabled { + traceGCSweepStart() + } sg := mheap_.sweepgen retry: var s *mspan @@ -92,6 +96,10 @@ retry: // all subsequent ones must also be either swept or in process of sweeping break } + if trace.enabled { + traceGCSweepDone() + traceDone = true + } unlock(&c.lock) // Replenish central list if empty. @@ -106,6 +114,9 @@ retry: // At this point s is a non-empty span, queued at the end of the empty list, // c is unlocked. havespan: + if trace.enabled && !traceDone { + traceGCSweepDone() + } cap := int32((s.npages << _PageShift) / s.elemsize) n := cap - int32(s.allocCount) if n == 0 || s.freeindex == s.nelems || uintptr(s.allocCount) == s.nelems { diff --git a/src/runtime/mgcsweep.go b/src/runtime/mgcsweep.go index bdd9e517d4..0c4a7ccc02 100644 --- a/src/runtime/mgcsweep.go +++ b/src/runtime/mgcsweep.go @@ -190,7 +190,7 @@ func (s *mspan) sweep(preserve bool) bool { } if trace.enabled { - traceGCSweepStart() + traceGCSweepSpan() } atomic.Xadd64(&mheap_.pagesSwept, int64(s.npages)) @@ -364,9 +364,6 @@ func (s *mspan) sweep(preserve bool) bool { // it on the swept in-use list. mheap_.sweepSpans[sweepgen/2%2].push(s) } - if trace.enabled { - traceGCSweepDone() - } return res } @@ -394,6 +391,10 @@ func deductSweepCredit(spanBytes uintptr, callerSweepPages uintptr) { return } + if trace.enabled { + traceGCSweepStart() + } + // Account for this span allocation. spanBytesAlloc := atomic.Xadd64(&mheap_.spanBytesAlloc, int64(spanBytes)) @@ -405,6 +406,10 @@ func deductSweepCredit(spanBytes uintptr, callerSweepPages uintptr) { break } } + + if trace.enabled { + traceGCSweepDone() + } } // reimburseSweepCredit records that unusableBytes bytes of a diff --git a/src/runtime/mheap.go b/src/runtime/mheap.go index 80d925cac6..e1b3b184e8 100644 --- a/src/runtime/mheap.go +++ b/src/runtime/mheap.go @@ -576,7 +576,13 @@ func (h *mheap) alloc_m(npage uintptr, sizeclass int32, large bool) *mspan { // If GC kept a bit for whether there were any marks // in a span, we could release these free spans // at the end of GC and eliminate this entirely. + if trace.enabled { + traceGCSweepStart() + } h.reclaim(npage) + if trace.enabled { + traceGCSweepDone() + } } // transfer stats from cache to global diff --git a/src/runtime/runtime2.go b/src/runtime/runtime2.go index 50e39acaa5..b16735ac46 100644 --- a/src/runtime/runtime2.go +++ b/src/runtime/runtime2.go @@ -490,6 +490,11 @@ type p struct { tracebuf traceBufPtr + // traceSweep indicates the next traceGCSweepSpan should emit + // a sweep start event. This is used to defer the sweep start + // event until a span has actually been swept. + traceSweep bool + palloc persistentAlloc // per-P to avoid mutex // Per-P GC state diff --git a/src/runtime/trace.go b/src/runtime/trace.go index 93d52a9844..375f0b76b7 100644 --- a/src/runtime/trace.go +++ b/src/runtime/trace.go @@ -932,12 +932,39 @@ func traceGCScanDone() { traceEvent(traceEvGCScanDone, -1) } +// traceGCSweepStart prepares to trace a sweep loop. This does not +// emit any events until traceGCSweepSpan is called. +// +// traceGCSweepStart must be paired with traceGCSweepDone and there +// must be no preemption points between these two calls. func traceGCSweepStart() { - traceEvent(traceEvGCSweepStart, 1) + // Delay the actual GCSweepStart event until the first span + // sweep. If we don't sweep anything, don't emit any events. + _p_ := getg().m.p.ptr() + if _p_.traceSweep { + throw("double traceGCSweepStart") + } + _p_.traceSweep = true +} + +// traceGCSweepSpan traces the sweep of a single page. +// +// This may be called outside a traceGCSweepStart/traceGCSweepDone +// pair; however, it will not emit any trace events in this case. +func traceGCSweepSpan() { + _p_ := getg().m.p.ptr() + if _p_.traceSweep { + traceEvent(traceEvGCSweepStart, 1) + _p_.traceSweep = false + } } func traceGCSweepDone() { - traceEvent(traceEvGCSweepDone, -1) + _p_ := getg().m.p.ptr() + if !_p_.traceSweep { + traceEvent(traceEvGCSweepDone, -1) + } + _p_.traceSweep = false } func traceGCMarkAssistStart() { -- 2.48.1