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 <austin@google.com>
Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>

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 {

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

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

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

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() {