diff --git a/src/runtime/mprof.go b/src/runtime/mprof.go index 1156329615..5235b898e4 100644 --- a/src/runtime/mprof.go +++ b/src/runtime/mprof.go @@ -133,7 +133,7 @@ func (a *memRecordCycle) add(b *memRecordCycle) { // A blockRecord is the bucket data for a bucket of type blockProfile, // which is used in blocking and mutex profiles. type blockRecord struct { - count int64 + count float64 cycles int64 } @@ -398,20 +398,23 @@ func blockevent(cycles int64, skip int) { if cycles <= 0 { cycles = 1 } - if blocksampled(cycles) { - saveblockevent(cycles, skip+1, blockProfile) + + rate := int64(atomic.Load64(&blockprofilerate)) + if blocksampled(cycles, rate) { + saveblockevent(cycles, rate, skip+1, blockProfile) } } -func blocksampled(cycles int64) bool { - rate := int64(atomic.Load64(&blockprofilerate)) +// blocksampled returns true for all events where cycles >= rate. Shorter +// events have a cycles/rate random chance of returning true. +func blocksampled(cycles, rate int64) bool { if rate <= 0 || (rate > cycles && int64(fastrand())%rate > cycles) { return false } return true } -func saveblockevent(cycles int64, skip int, which bucketType) { +func saveblockevent(cycles, rate int64, skip int, which bucketType) { gp := getg() var nstk int var stk [maxStack]uintptr @@ -422,8 +425,15 @@ func saveblockevent(cycles int64, skip int, which bucketType) { } lock(&proflock) b := stkbucket(which, 0, stk[:nstk], true) - b.bp().count++ - b.bp().cycles += cycles + + if which == blockProfile && cycles < rate { + // Remove sampling bias, see discussion on http://golang.org/cl/299991. + b.bp().count += float64(rate) / float64(cycles) + b.bp().cycles += rate + } else { + b.bp().count++ + b.bp().cycles += cycles + } unlock(&proflock) } @@ -454,7 +464,7 @@ func mutexevent(cycles int64, skip int) { // TODO(pjw): measure impact of always calling fastrand vs using something // like malloc.go:nextSample() if rate > 0 && int64(fastrand())%rate == 0 { - saveblockevent(cycles, skip+1, mutexProfile) + saveblockevent(cycles, rate, skip+1, mutexProfile) } } @@ -656,7 +666,12 @@ func BlockProfile(p []BlockProfileRecord) (n int, ok bool) { for b := bbuckets; b != nil; b = b.allnext { bp := b.bp() r := &p[0] - r.Count = bp.count + r.Count = int64(bp.count) + // Prevent callers from having to worry about division by zero errors. + // See discussion on http://golang.org/cl/299991. + if r.Count == 0 { + r.Count = 1 + } r.Cycles = bp.cycles if raceenabled { racewriterangepc(unsafe.Pointer(&r.Stack0[0]), unsafe.Sizeof(r.Stack0), getcallerpc(), funcPC(BlockProfile)) diff --git a/src/runtime/pprof/pprof_test.go b/src/runtime/pprof/pprof_test.go index 3423f8dc3d..7cbb4fc7ae 100644 --- a/src/runtime/pprof/pprof_test.go +++ b/src/runtime/pprof/pprof_test.go @@ -14,6 +14,7 @@ import ( "internal/profile" "internal/testenv" "io" + "math" "math/big" "os" "os/exec" @@ -24,6 +25,7 @@ import ( "sync/atomic" "testing" "time" + _ "unsafe" ) func cpuHogger(f func(x int) int, y *int, dur time.Duration) { @@ -895,6 +897,74 @@ func blockCond() { mu.Unlock() } +// See http://golang.org/cl/299991. +func TestBlockProfileBias(t *testing.T) { + rate := int(1000) // arbitrary value + runtime.SetBlockProfileRate(rate) + defer runtime.SetBlockProfileRate(0) + + // simulate blocking events + blockFrequentShort(rate) + blockInfrequentLong(rate) + + var w bytes.Buffer + Lookup("block").WriteTo(&w, 0) + p, err := profile.Parse(&w) + if err != nil { + t.Fatalf("failed to parse profile: %v", err) + } + t.Logf("parsed proto: %s", p) + + il := float64(-1) // blockInfrequentLong duration + fs := float64(-1) // blockFrequentShort duration + for _, s := range p.Sample { + for _, l := range s.Location { + for _, line := range l.Line { + if len(s.Value) < 2 { + t.Fatal("block profile has less than 2 sample types") + } + + if line.Function.Name == "runtime/pprof.blockInfrequentLong" { + il = float64(s.Value[1]) + } else if line.Function.Name == "runtime/pprof.blockFrequentShort" { + fs = float64(s.Value[1]) + } + } + } + } + if il == -1 || fs == -1 { + t.Fatal("block profile is missing expected functions") + } + + // stddev of bias from 100 runs on local machine multiplied by 10x + const threshold = 0.2 + if bias := (il - fs) / il; math.Abs(bias) > threshold { + t.Fatalf("bias: abs(%f) > %f", bias, threshold) + } else { + t.Logf("bias: abs(%f) < %f", bias, threshold) + } +} + +// blockFrequentShort produces 100000 block events with an average duration of +// rate / 10. +func blockFrequentShort(rate int) { + for i := 0; i < 100000; i++ { + blockevent(int64(rate/10), 1) + } +} + +// blockFrequentShort produces 10000 block events with an average duration of +// rate. +func blockInfrequentLong(rate int) { + for i := 0; i < 10000; i++ { + blockevent(int64(rate), 1) + } +} + +// Used by TestBlockProfileBias. +//go:linkname blockevent runtime.blockevent +func blockevent(cycles int64, skip int) + func TestMutexProfile(t *testing.T) { // Generate mutex profile