From bedfeed54a7a80123c07f83c325a0bcfe5c43398 Mon Sep 17 00:00:00 2001 From: Michael Pratt Date: Fri, 7 Aug 2020 16:28:35 +0000 Subject: runtime,runtime/metrics: add metric to track scheduling latencies This change adds a metric to track scheduling latencies, defined as the cumulative amount of time a goroutine spends being runnable before running again. The metric is an approximations and samples instead of trying to record every goroutine scheduling latency. This change was primarily authored by mknyszek@google.com. Change-Id: Ie0be7e6e7be421572eb2317d3dd8dd6f3d6aa152 Reviewed-on: https://go-review.googlesource.com/c/go/+/308933 Trust: Michael Pratt Run-TryBot: Michael Pratt TryBot-Result: Go Bot Reviewed-by: Michael Knyszek --- src/runtime/proc.go | 41 +++++++++++++++++++++++++++++++++++++++++ 1 file changed, 41 insertions(+) (limited to 'src/runtime/proc.go') diff --git a/src/runtime/proc.go b/src/runtime/proc.go index 37c051634c..2f9818d9f1 100644 --- a/src/runtime/proc.go +++ b/src/runtime/proc.go @@ -697,6 +697,11 @@ func schedinit() { sigsave(&_g_.m.sigmask) initSigmask = _g_.m.sigmask + if offset := unsafe.Offsetof(sched.timeToRun); offset%8 != 0 { + println(offset) + throw("sched.timeToRun not aligned to 8 bytes") + } + goargs() goenvs() parsedebugvars() @@ -973,6 +978,37 @@ func casgstatus(gp *g, oldval, newval uint32) { nextYield = nanotime() + yieldDelay/2 } } + + // Handle tracking for scheduling latencies. + if oldval == _Grunning { + // Track every 8th time a goroutine transitions out of running. + if gp.trackingSeq%gTrackingPeriod == 0 { + gp.tracking = true + } + gp.trackingSeq++ + } + if gp.tracking { + now := nanotime() + if oldval == _Grunnable { + // We transitioned out of runnable, so measure how much + // time we spent in this state and add it to + // runnableTime. + gp.runnableTime += now - gp.runnableStamp + gp.runnableStamp = 0 + } + if newval == _Grunnable { + // We just transitioned into runnable, so record what + // time that happened. + gp.runnableStamp = now + } else if newval == _Grunning { + // We're transitioning into running, so turn off + // tracking and record how much time we spent in + // runnable. + gp.tracking = false + sched.timeToRun.record(gp.runnableTime) + gp.runnableTime = 0 + } + } } // casgstatus(gp, oldstatus, Gcopystack), assuming oldstatus is Gwaiting or Grunnable. @@ -4286,6 +4322,11 @@ func newproc1(fn *funcval, argp unsafe.Pointer, narg int32, callergp *g, callerp if isSystemGoroutine(newg, false) { atomic.Xadd(&sched.ngsys, +1) } + // Track initial transition? + newg.trackingSeq = uint8(fastrand()) + if newg.trackingSeq%gTrackingPeriod == 0 { + newg.tracking = true + } casgstatus(newg, _Gdead, _Grunnable) if _p_.goidcache == _p_.goidcacheend { -- cgit v1.3-5-g9baa