[go] runtime/pprof: add counting profile and sampling
44 views
Skip to first unread message
Rhys Hiltner (Gerrit)
May 6, 2022, 8:16:45 PM5/6/22
to goph...@pubsubhelper.golang.org, Rhys Hiltner, golang-co...@googlegroups.com
Rhys Hiltner has uploaded this change for review.
runtime/pprof: add counting profile and sampling
A custom Profile may track active resources through pairs of calls to
Add and Remove made with unique tracking tokens. Add a new way to use
Profile: by calling Event to track an occurrence of an event with some
associated weight.
Using the Event method of a custom Profile gives results similar to some
built-in profiles: for time spent blocking, or for the amount of memory
allocated. It tracks a pair of monotonically increasing values for each
observed call stack, one for the number of sampled events and one for
their combined weight.
Allow sampling in custom Profiles through the SetSampleRate method. Use
a Poisson process (as the heap profile does) to select when to record a
call to Event or to Add.
Fixes #18454
Change-Id: Iec775b2e42c4f0ce41df8af5856211786f5e3eae
---
M src/runtime/pprof/pprof.go
M src/runtime/pprof/pprof_test.go
M src/runtime/pprof/runtime.go
3 files changed, 594 insertions(+), 82 deletions(-)
diff --git a/src/runtime/pprof/pprof.go b/src/runtime/pprof/pprof.go
index f0b25c1..9a98b48 100644
--- a/src/runtime/pprof/pprof.go
+++ b/src/runtime/pprof/pprof.go
@@ -78,6 +78,7 @@
"fmt"
"internal/abi"
"io"
+ "math"
"runtime"
"sort"
"strings"
@@ -131,11 +132,20 @@
// the StartCPUProfile and StopCPUProfile functions, because it streams
// output to a writer during profiling.
type Profile struct {
- name string
- mu sync.Mutex
- m map[any][]uintptr
- count func() int
- write func(io.Writer, int) error
+ name string
+ mu sync.Mutex
+ m map[any][]uintptr
+ events map[runtime.StackRecord]*eventCount
+ rate int
+ next float64
+ count func() int
+ write func(io.Writer, int) error
+}
+
+// eventCount tracks the total weight tracked by calls to Profile.Event.
+type eventCount struct {
+ count int64
+ weight float64
}
// profiles records all registered profiles.
@@ -215,8 +225,9 @@
panic("pprof: NewProfile name already in use: " + name)
}
p := &Profile{
- name: name,
- m: map[any][]uintptr{},
+ name: name,
+ m: map[any][]uintptr{},
+ events: map[runtime.StackRecord]*eventCount{},
}
profiles.m[name] = p
return p
@@ -255,6 +266,9 @@
if p.count != nil {
return p.count()
}
+ if l := len(p.events); l > 0 {
+ return l
+ }
return len(p.m)
}
@@ -275,6 +289,8 @@
//
// Passing skip=0 begins the stack trace at the call to Add inside rpc.NewClient.
// Passing skip=1 begins the stack trace at the call to NewClient inside mypkg.Run.
+//
+// A given Profile should be populated using Add/Remove or Event, but not both.
func (p *Profile) Add(value any, skip int) {
if p.name == "" {
panic("pprof: use of uninitialized Profile")
@@ -283,6 +299,10 @@
panic("pprof: Add called on built-in Profile " + p.name)
}
+ if !p.keepSample(1) {
+ return
+ }
+
stk := make([]uintptr, 32)
n := runtime.Callers(skip+1, stk[:])
stk = stk[:n]
@@ -301,12 +321,129 @@
// Remove removes the execution stack associated with value from the profile.
// It is a no-op if the value is not in the profile.
+//
+// A given Profile should be populated using Add/Remove or Event, but not both.
func (p *Profile) Remove(value any) {
p.mu.Lock()
defer p.mu.Unlock()
delete(p.m, value)
}
+// Event records an event with the given weight.
+//
+// For a simple event counter, weight should be 1. If events have different
+// expenses, weight can vary according to the expense.
+//
+// The skip parameter has the same meaning as Add's skip and controls where the
+// stack trace begins.
+//
+// A given Profile should be populated using Add/Remove or Event, but not both.
+func (p *Profile) Event(weight float64, skip int) {
+ if p.name == "" {
+ panic("pprof: use of uninitialized Profile")
+ }
+ if p.write != nil {
+ panic("pprof: Event called on built-in Profile " + p.name)
+ }
+
+ if !p.keepSample(weight) {
+ return
+ }
+
+ var stk runtime.StackRecord
+ n := runtime.Callers(skip+1, stk.Stack0[:])
+ if n == 0 {
+ // The value for skip is too large, and there's no stack trace to record.
+ stk.Stack0[0] = abi.FuncPCABIInternal(lostProfileEvent)
+ n = 1
+ }
+ for i := n; i < len(stk.Stack0); i++ {
+ stk.Stack0[i] = 0
+ }
+
+ p.mu.Lock()
+ defer p.mu.Unlock()
+
+ counts := p.events[stk]
+ if counts == nil {
+ counts = new(eventCount)
+ p.events[stk] = counts
+ }
+ counts.count++
+ counts.weight += weight
+}
+
+// SetSampleRate sets the profile to record a fraction of samples based on rate.
+// For a Profile populated using Add/Remove, each call to Add has weight 1. For
+// a Profile populated using Event, the sampling algorithm uses the weight
+// provided in each of those calls.
+//
+// When rate is 0, the Profile stores every sample. When rate is 1 or greater,
+// the Profile will collect samples based on their weight at with average
+// spacing between samples of rate.
+//
+// It must be called before any calls to Add, Remove, or Event.
+func (p *Profile) SetSampleRate(rate int) {
+ p.mu.Lock()
+ defer p.mu.Unlock()
+
+ p.rate = rate
+ p.next = nextSample(p.rate)
+}
+
+func (p *Profile) keepSample(weight float64) bool {
+ if weight < 0 {
+ return false
+ }
+
+ p.mu.Lock()
+ defer p.mu.Unlock()
+
+ if p.rate <= 0 {
+ return true
+ }
+
+ next := p.next - weight
+ if p.next == next && weight > 0 {
+ // We should make some progress, even if the weight is tiny relative
+ // to the sample rate.
+ next = math.Nextafter(p.next, 0)
+ }
+
+ if next > 0 {
+ p.next = next
+ return false
+ }
+ p.next = nextSample(p.rate)
+ return true
+}
+
+func nextSample(mean int) float64 {
+ if mean <= 0 {
+ return 0
+ }
+
+ // From runtime.fastexprand in src/runtime/malloc.go, but without the +1
+ // offset necessary for the int-based version:
+
+ // Take a random sample of the exponential distribution exp(-mean*x).
+ // The probability distribution function is mean*exp(-mean*x), so the CDF is
+ // p = 1 - exp(-mean*x), so
+ // q = 1 - p == exp(-mean*x)
+ // log_e(q) = -mean*x
+ // -log_e(q)/mean = x
+ // x = -log_e(q) * mean
+ // x = log_2(q) * (-log_e(2)) * mean ; Using log_2 for efficiency
+ const randomBitCount = 26
+ q := fastrandn(1<<randomBitCount) + 1
+ qlog := math.Log2(float64(q)) - randomBitCount
+ if qlog > 0 {
+ qlog = 0
+ }
+ const minusLog2 = -0.6931471805599453 // -ln(2)
+ return qlog * (minusLog2 * float64(mean))
+}
+
// WriteTo writes a pprof-formatted snapshot of the profile to w.
// If a write to w returns an error, WriteTo returns that error.
// Otherwise, WriteTo returns nil.
@@ -332,6 +469,47 @@
// Obtain consistent snapshot under lock; then process without lock.
p.mu.Lock()
+ if len(p.events) > 0 {
+ all := make([]runtime.BlockProfileRecord, 0, len(p.events))
+ for key, value := range p.events {
+ var rec runtime.BlockProfileRecord
+ rec.StackRecord = key
+ rec.Count = value.count
+ rec.Cycles = int64(value.weight) // TODO: keep as float64 until scaling is done
+ all = append(all, rec)
+ }
+ rate := int64(p.rate)
+ p.mu.Unlock()
+
+ for i := range all {
+ if count, weight := all[i].Count, all[i].Cycles; weight > 0 {
+ all[i].Count, all[i].Cycles = scaleHeapSample(count, weight, rate)
+ } else {
+ all[i].Count, _ = scaleHeapSample(count, 1, rate)
+ }
+ }
+
+ sort.Slice(all, func(i, j int) bool {
+ ri, rj := all[i], all[j]
+ if ri.Cycles != rj.Cycles {
+ return ri.Cycles > rj.Cycles
+ }
+ return ri.Count > rj.Count
+ })
+
+ values := []int64{0, 0}
+ br := &blockRecords{
+ records: all,
+ period: rate,
+ scale: func(r runtime.BlockProfileRecord) []int64 {
+ values[0], values[1] = r.Cycles, r.Count
+ return values
+ },
+ }
+
+ return printCountProfile(w, debug, p.name, br)
+ }
+
all := make([][]uintptr, 0, len(p.m))
for _, stk := range p.m {
all = append(all, stk)
@@ -355,6 +533,8 @@
type stackProfile [][]uintptr
func (x stackProfile) Len() int { return len(x) }
+func (x stackProfile) Period() int64 { return 1 }
+func (x stackProfile) Values(i int) []int64 { return countValues }
func (x stackProfile) Stack(i int) []uintptr { return x[i] }
func (x stackProfile) Label(i int) *labelMap { return nil }
@@ -364,38 +544,118 @@
// and obtain each trace in turn.
type countProfile interface {
Len() int
+ Period() int64
+ Values(i int) []int64 // slice must not be retained
Stack(i int) []uintptr
Label(i int) *labelMap
}
+type blockRecords struct {
+ records []runtime.BlockProfileRecord
+ scale func(runtime.BlockProfileRecord) []int64
+ period int64
+}
+
+func (x blockRecords) Len() int { return len(x.records) }
+func (x blockRecords) Period() int64 { return x.period }
+func (x blockRecords) Values(i int) []int64 { return x.scale(x.records[i]) }
+func (x blockRecords) Stack(i int) []uintptr { return x.records[i].Stack() }
+func (x blockRecords) Label(i int) *labelMap { return nil }
+
+type valueProfile struct {
+ length int
+ period int64
+ values func(i int) []int64
+ stacks func(i int) []uintptr
+ labels func(i int) *labelMap
+ textKey func(i int) string
+}
+
+func (x valueProfile) Len() int { return x.length }
+func (x valueProfile) Period() int64 { return x.period }
+func (x valueProfile) Values(i int) []int64 { return x.values(i) }
+func (x valueProfile) Stack(i int) []uintptr { return x.stacks(i) }
+func (x valueProfile) Label(i int) *labelMap { return x.labels(i) }
+
+var countValues = []int64{1}
+
+type profileFormat struct {
+ countName string
+ weightName string
+ weightUnit string
+ allFrames bool
+}
+
+// writeText prints a debug profile in the legacy format
+func (f *profileFormat) writeText(tw *tabwriter.Writer, p *valueProfile) error {
+ if f.countName != "" {
+ fmt.Fprintf(tw, "%s profile: total %d\n", f.countName, p.Len())
+ }
+ for i := 0; i < p.Len(); i++ {
+ for _, v := range p.values(i) {
+ fmt.Fprintf(tw, "%v ", v)
+ }
+ fmt.Fprintf(tw, "%s\n", p.textKey(i))
+ printStackRecord(tw, p.stacks(i), f.allFrames)
+ }
+ return tw.Flush()
+}
+
+func (f *profileFormat) writeProto(w io.Writer, p countProfile) error {
+ b := newProfileBuilder(w)
+ if f.weightName != "" {
+ b.pbValueType(tagProfile_SampleType, f.weightName, f.weightUnit)
+ }
+ b.pbValueType(tagProfile_PeriodType, f.countName, "count")
+ b.pb.int64Opt(tagProfile_Period, p.Period())
+ b.pbValueType(tagProfile_SampleType, f.countName, "count")
+
+ var locs []uint64
+ for i := 0; i < p.Len(); i++ {
+ // For count profiles, all stack addresses are
+ // return PCs, which is what appendLocsForStack expects.
+ locs = b.appendLocsForStack(locs[:0], p.Stack(i))
+ var labels func()
+ if label := p.Label(i); label != nil {
+ labels = func() {
+ for k, v := range *label {
+ b.pbLabel(tagSample_Label, k, v, 0)
+ }
+ }
+ }
+ b.pbSample(p.Values(i), locs, labels)
+ }
+ b.build()
+ return nil
+}
+
// printCountCycleProfile outputs block profile records (for block or mutex profiles)
// as the pprof-proto format output. Translations from cycle count to time duration
// are done because The proto expects count and time (nanoseconds) instead of count
// and the number of cycles for block, contention profiles.
// Possible 'scaler' functions are scaleBlockProfile and scaleMutexProfile.
func printCountCycleProfile(w io.Writer, countName, cycleName string, scaler func(int64, float64) (int64, float64), records []runtime.BlockProfileRecord) error {
- // Output profile in protobuf form.
- b := newProfileBuilder(w)
- b.pbValueType(tagProfile_PeriodType, countName, "count")
- b.pb.int64Opt(tagProfile_Period, 1)
- b.pbValueType(tagProfile_SampleType, countName, "count")
- b.pbValueType(tagProfile_SampleType, cycleName, "nanoseconds")
-
cpuGHz := float64(runtime_cyclesPerSecond()) / 1e9
-
values := []int64{0, 0}
- var locs []uint64
- for _, r := range records {
- count, nanosec := scaler(r.Count, float64(r.Cycles)/cpuGHz)
- values[0] = count
- values[1] = int64(nanosec)
- // For count profiles, all stack addresses are
- // return PCs, which is what appendLocsForStack expects.
- locs = b.appendLocsForStack(locs[:0], r.Stack())
- b.pbSample(values, locs, nil)
+
+ br := &blockRecords{
+ records: records,
+ period: 1, // TODO: find period
+ scale: func(r runtime.BlockProfileRecord) []int64 {
+ count, nanosec := scaler(r.Count, float64(r.Cycles)/cpuGHz)
+ values[0] = count
+ values[1] = int64(nanosec)
+ return values
+ },
}
- b.build()
- return nil
+
+ format := &profileFormat{
+ countName: countName,
+ weightName: cycleName,
+ weightUnit: "nanoseconds",
+ }
+
+ return format.writeProto(w, br)
}
// printCountProfile prints a countProfile at the specified debug level.
@@ -415,71 +675,66 @@
}
return buf.String()
}
- count := map[string]int{}
+ count := map[string][2]int64{}
index := map[string]int{}
var keys []string
n := p.Len()
+ var values []int64
for i := 0; i < n; i++ {
+ if i == 0 {
+ values = make([]int64, len(p.Values(i)))
+ }
k := key(p.Stack(i), p.Label(i))
- if count[k] == 0 {
+ prev, ok := count[k]
+ if !ok {
index[k] = i
keys = append(keys, k)
}
- count[k]++
+ for j, v := range p.Values(i) {
+ if j < len(prev) {
+ prev[j] += v
+ }
+ }
+ count[k] = prev
}
sort.Sort(&keysByCount{keys, count})
+ vp := &valueProfile{
+ length: len(keys),
+ period: p.Period(),
+ values: func(i int) []int64 { v := count[keys[i]]; copy(values, v[:]); return values },
+ stacks: func(i int) []uintptr { return p.Stack(index[keys[i]]) },
+ labels: func(i int) *labelMap { return p.Label(index[keys[i]]) },
+ textKey: func(i int) string { return keys[i] },
+ }
+
+ format := &profileFormat{
+ countName: name,
+ }
+ if len(values) == 2 {
+ format.weightName = name
+ format.weightUnit = "weight"
+ }
+
if debug > 0 {
- // Print debug profile in legacy format
- tw := tabwriter.NewWriter(w, 1, 8, 1, '\t', 0)
- fmt.Fprintf(tw, "%s profile: total %d\n", name, p.Len())
- for _, k := range keys {
- fmt.Fprintf(tw, "%d %s\n", count[k], k)
- printStackRecord(tw, p.Stack(index[k]), false)
- }
- return tw.Flush()
+ return format.writeText(tabwriter.NewWriter(w, 1, 8, 1, '\t', 0), vp)
}
- // Output profile in protobuf form.
- b := newProfileBuilder(w)
- b.pbValueType(tagProfile_PeriodType, name, "count")
- b.pb.int64Opt(tagProfile_Period, 1)
- b.pbValueType(tagProfile_SampleType, name, "count")
-
- values := []int64{0}
- var locs []uint64
- for _, k := range keys {
- values[0] = int64(count[k])
- // For count profiles, all stack addresses are
- // return PCs, which is what appendLocsForStack expects.
- locs = b.appendLocsForStack(locs[:0], p.Stack(index[k]))
- idx := index[k]
- var labels func()
- if p.Label(idx) != nil {
- labels = func() {
- for k, v := range *p.Label(idx) {
- b.pbLabel(tagSample_Label, k, v, 0)
- }
- }
- }
- b.pbSample(values, locs, labels)
- }
- b.build()
- return nil
+ return format.writeProto(w, vp)
}
// keysByCount sorts keys with higher counts first, breaking ties by key string order.
type keysByCount struct {
keys []string
- count map[string]int
+ count map[string][2]int64
}
func (x *keysByCount) Len() int { return len(x.keys) }
func (x *keysByCount) Swap(i, j int) { x.keys[i], x.keys[j] = x.keys[j], x.keys[i] }
func (x *keysByCount) Less(i, j int) bool {
ki, kj := x.keys[i], x.keys[j]
- ci, cj := x.count[ki], x.count[kj]
+ ci, cj := x.count[ki][0], x.count[kj][0]
if ci != cj {
return ci > cj
}
@@ -737,6 +992,8 @@
}
func (p *runtimeProfile) Len() int { return len(p.stk) }
+func (p *runtimeProfile) Period() int64 { return 1 }
+func (p *runtimeProfile) Values(i int) []int64 { return countValues }
func (p *runtimeProfile) Stack(i int) []uintptr { return p.stk[i].Stack() }
func (p *runtimeProfile) Label(i int) *labelMap { return (*labelMap)(p.labels[i]) }
@@ -877,31 +1134,38 @@
return printCountCycleProfile(w, "contentions", "delay", scaleProfile, p)
}
- b := bufio.NewWriter(w)
+ values := []int64{0, 0}
+ vp := &valueProfile{
+ length: len(p),
+ period: int64(runtime.SetMutexProfileFraction(-1)),
+ values: func(i int) []int64 {
+ values[0] = p[i].Cycles
+ values[1] = p[i].Count
+ return values
+ },
+ stacks: func(i int) []uintptr { return p[i].Stack() },
+ labels: func(i int) *labelMap { return nil },
+ textKey: func(i int) string {
+ var buf strings.Builder
+ fmt.Fprint(&buf, "@")
+ for _, pc := range p[i].Stack() {
+ fmt.Fprintf(&buf, " %#x", pc)
+ }
+ return buf.String()
+ },
+ }
+
tw := tabwriter.NewWriter(w, 1, 8, 1, '\t', 0)
w = tw
fmt.Fprintf(w, "--- %v:\n", name)
fmt.Fprintf(w, "cycles/second=%v\n", runtime_cyclesPerSecond())
if name == "mutex" {
- fmt.Fprintf(w, "sampling period=%d\n", runtime.SetMutexProfileFraction(-1))
- }
- for i := range p {
- r := &p[i]
- fmt.Fprintf(w, "%v %v @", r.Cycles, r.Count)
- for _, pc := range r.Stack() {
- fmt.Fprintf(w, " %#x", pc)
- }
- fmt.Fprint(w, "\n")
- if debug > 0 {
- printStackRecord(w, r.Stack(), true)
- }
+ fmt.Fprintf(w, "sampling period=%d\n", vp.period)
}
- if tw != nil {
- tw.Flush()
- }
- return b.Flush()
+ format := &profileFormat{allFrames: true}
+ return format.writeText(tw, vp)
}
func scaleMutexProfile(cnt int64, ns float64) (int64, float64) {
diff --git a/src/runtime/pprof/pprof_test.go b/src/runtime/pprof/pprof_test.go
index eeb7b27..4bbad28 100644
--- a/src/runtime/pprof/pprof_test.go
+++ b/src/runtime/pprof/pprof_test.go
@@ -1687,6 +1687,223 @@
}
}
+var customProfileTestRun int64
+
+func TestCustomProfile(t *testing.T) {
+ t.Parallel()
+
+ const (
+ rate = 10
+ iterations = 1000
+ )
+
+ checkPrefix := func(t *testing.T, profile, prefix string) {
+ t.Helper()
+ if !strings.HasPrefix(profile, prefix) {
+ t.Errorf("did not find prefix: %q", prefix)
+ }
+ }
+
+ countRecords := func(t *testing.T, profile string, frame string, count int) {
+ t.Helper()
+ if n := strings.Count(profile, frame); n != count {
+ t.Errorf("expected %q to appear in %d records, got %d", frame, count, n)
+ }
+ }
+
+ countProfRecords := func(t *testing.T, prof *profile.Profile, funcPrefix string, count int) {
+ var n int
+ for _, sam := range prof.Sample {
+ for _, loc := range sam.Location {
+ for _, line := range loc.Line {
+ if strings.HasPrefix(line.Function.Name, funcPrefix) {
+ n++
+ }
+ }
+ }
+ }
+ if n != count {
+ t.Errorf("expected %q as a function name prefix %d times, got %d", funcPrefix, count, n)
+ }
+ }
+
+ logFailure := func(t *testing.T, profile string) {
+ t.Helper()
+ if t.Failed() {
+ t.Fatalf("got:\n\t%q\n\n%s", profile, profile)
+ }
+ }
+
+ t.Run("AddRemove", func(t *testing.T) {
+ t.Parallel()
+
+ var buf bytes.Buffer
+ name := fmt.Sprintf("custom_profile_%d", atomic.AddInt64(&customProfileTestRun, 1))
+ p := NewProfile(name)
+
+ p.Add("foo", 0)
+ p.Add("bar", 1)
+ for i := 0; i < 10; i++ {
+ p.Add(i, 300)
+ }
+ p.WriteTo(&buf, 1)
+ got := buf.String()
+ buf.Reset()
+
+ if have, want := p.Count(), 12; have != want {
+ t.Errorf("p.Count; %d != %d", have, want)
+ }
+
+ checkPrefix(t, got, name+" profile: total 3\n")
+ countRecords(t, got, "runtime/pprof.Test", 2) // includes skip==0 and skip==1
+ countRecords(t, got, "runtime/pprof.(*Profile).Add", 1) // includes skip==0
+ countRecords(t, got, "runtime/pprof.lostProfileEvent", 1) // includes skip==300
+ logFailure(t, got)
+
+ p.Remove("foo")
+ p.Remove("bar")
+ for i := 0; i < 10; i++ {
+ p.Remove(i)
+ }
+ p.WriteTo(&buf, 1)
+ got = buf.String()
+ buf.Reset()
+
+ if have, want := p.Count(), 0; have != want {
+ t.Errorf("p.Count; %d != %d", have, want)
+ }
+
+ checkPrefix(t, got, name+" profile: total 0\n")
+ countRecords(t, got, "runtime/pprof.Test", 0)
+ countRecords(t, got, "runtime/pprof.(*Profile).Add", 0)
+ countRecords(t, got, "runtime/pprof.lostProfileEvent", 0)
+ logFailure(t, got)
+ })
+
+ t.Run("AddRemoveSampling", func(t *testing.T) {
+ t.Parallel()
+
+ var buf bytes.Buffer
+ name := fmt.Sprintf("custom_profile_%d", atomic.AddInt64(&customProfileTestRun, 1))
+ p := NewProfile(name)
+ p.SetSampleRate(rate)
+
+ for i := 0; i < iterations; i++ {
+ p.Add(0-i, 0)
+ p.Add(1+i, 1)
+ }
+
+ p.WriteTo(&buf, 1)
+ got := buf.String()
+ buf.Reset()
+
+ checkPrefix(t, got, name+" profile: total 2\n")
+ countRecords(t, got, "runtime/pprof.Test", 2) // includes skip==0 and skip==1
+ countRecords(t, got, "runtime/pprof.(*Profile).Add", 1) // includes skip==0
+ logFailure(t, got)
+
+ for i := 0; i < iterations; i++ {
+ p.Remove(0 - i)
+ p.Remove(1 + i)
+ }
+ p.WriteTo(&buf, 1)
+ got = buf.String()
+ buf.Reset()
+
+ checkPrefix(t, got, name+" profile: total 0\n")
+ countRecords(t, got, "runtime/pprof.Test", 0)
+ countRecords(t, got, "runtime/pprof.(*Profile).Add", 0)
+ logFailure(t, got)
+ })
+
+ t.Run("Event", func(t *testing.T) {
+ t.Parallel()
+
+ var buf bytes.Buffer
+ name := fmt.Sprintf("custom_profile_%d", atomic.AddInt64(&customProfileTestRun, 1))
+ p := NewProfile(name)
+
+ p.Event(3, 0)
+ for i := 0; i < 2; i++ {
+ p.Event(10, 1)
+ }
+ for i := 0; i < 4; i++ {
+ p.Event(0.3, 1)
+ }
+ for i := 0; i < 8; i++ {
+ var weight float64
+ if i == 0 {
+ weight = 1
+ }
+ p.Event(weight, 1)
+ }
+ for i := 0; i < 16; i++ {
+ p.Event(0, 1)
+ }
+ for i := 0; i < 32; i++ {
+ p.Event(1, 300)
+ }
+
+ p.WriteTo(&buf, 1)
+ got := buf.String()
+ buf.Reset()
+
+ if have, want := p.Count(), 6; have != want {
+ t.Errorf("p.Count; %d != %d", have, want)
+ }
+
+ checkPrefix(t, got, name+" profile: total 6\n")
+ countRecords(t, got, "runtime/pprof.Test", 5) // includes skip==0 and skip==1
+ countRecords(t, got, "runtime/pprof.(*Profile).Event", 1) // includes skip==0
+ countRecords(t, got, "runtime/pprof.lostProfileEvent", 1) // includes skip==300
+ countRecords(t, got, "\n3 1 @ ", 1)
+ countRecords(t, got, "\n20 2 @ ", 1)
+ countRecords(t, got, "\n1 4 @ ", 1)
+ countRecords(t, got, "\n1 8 @ ", 1)
+ countRecords(t, got, "\n0 16 @ ", 1)
+ countRecords(t, got, "\n32 32 @ ", 1)
+ logFailure(t, got)
+ })
+
+ t.Run("EventSampling", func(t *testing.T) {
+ t.Parallel()
+
+ var buf bytes.Buffer
+ name := fmt.Sprintf("custom_profile_%d", atomic.AddInt64(&customProfileTestRun, 1))
+ p := NewProfile(name)
+ p.SetSampleRate(rate)
+
+ for i := 0; i < iterations; i++ {
+ p.Event(1e6, 1) // weight much greater than weight, force a re-roll
+ p.Event(1, 0) // small weight, should still show up sometimes
+ }
+ p.WriteTo(&buf, 1)
+ got := buf.String()
+ buf.Reset()
+
+ p.WriteTo(&buf, 0)
+ prof, err := profile.Parse(&buf)
+ if err != nil {
+ t.Fatalf("profile.Parse; err = %v", err)
+ }
+ buf.Reset()
+
+ if prof.Period != rate {
+ t.Errorf("profile period; %d != %d", prof.Period, rate)
+ }
+
+ countProfRecords(t, prof, "runtime/pprof.Test", 2) // includes skip==0 and skip==1
+ countProfRecords(t, prof, "runtime/pprof.(*Profile).Event", 1) // includes skip==0
+
+ checkPrefix(t, got, name+" profile: total 2\n")
+ countRecords(t, got, "runtime/pprof.Test", 2) // includes skip==0 and skip==1
+ countRecords(t, got, "runtime/pprof.(*Profile).Event", 1) // includes skip==0
+
+ logFailure(t, prof.String())
+ logFailure(t, got)
+ })
+}
+
// stackContainsLabeled takes a spec like funcname;key=value and matches if the stack has that key
// and value and has funcname somewhere in the stack.
func stackContainsLabeled(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool {
diff --git a/src/runtime/pprof/runtime.go b/src/runtime/pprof/runtime.go
index dd2545b3..b7702e2 100644
--- a/src/runtime/pprof/runtime.go
+++ b/src/runtime/pprof/runtime.go
@@ -18,6 +18,11 @@
// runtime_getProfLabel is defined in runtime/proflabel.go.
func runtime_getProfLabel() unsafe.Pointer
+// fastrandn allows access to mild entropy without adding a dependency on math/rand.
+//
+//go:linkname fastrandn runtime.fastrandn
+func fastrandn(n uint32) uint32
+
// SetGoroutineLabels sets the current goroutine's labels to match ctx.
// A new goroutine inherits the labels of the goroutine that created it.
// This is a lower-level API than Do, which should be used instead when possible.
To view, visit change 404697. To unsubscribe, or for help writing mail filters, visit settings.
Rhys Hiltner (Gerrit)
May 7, 2022, 12:39:02 AM5/7/22
to Rhys Hiltner, goph...@pubsubhelper.golang.org, golang-co...@googlegroups.com
Attention is currently required from: Rhys Hiltner.
Rhys Hiltner uploaded patch set #2 to this change.
runtime/pprof: add counting profile and sampling
A custom Profile may track active resources through pairs of calls to
Add and Remove made with unique tracking tokens. Add a new way to use
Profile: by calling Event to track an occurrence of an event with some
associated weight.
Using the Event method of a custom Profile gives results similar to some
built-in profiles: for time spent blocking, or for the amount of memory
allocated. It tracks a pair of monotonically increasing values for each
observed call stack, one for the number of sampled events and one for
their combined weight.
Allow sampling in custom Profiles through the SetSampleRate method. Use
a Poisson process (as the heap profile does) to select when to record a
call to Event or to Add.
Fixes #18454
Change-Id: Iec775b2e42c4f0ce41df8af5856211786f5e3eae
---
A api/next/18454.txt
M src/runtime/pprof/pprof.go
M src/runtime/pprof/pprof_test.go
M src/runtime/pprof/runtime.go
4 files changed, 596 insertions(+), 82 deletions(-)
To view, visit change 404697. To unsubscribe, or for help writing mail filters, visit settings.
Rhys Hiltner (Gerrit)
May 11, 2022, 11:09:25 AM5/11/22
to Rhys Hiltner, goph...@pubsubhelper.golang.org, Gopher Robot, golang-co...@googlegroups.com
1 comment:
Patchset:
I don't think this should be part of the Go 1.19 release. The existing profile-formatting code needs cleanup before adding yet another profile type which means a lot of code motion, and the right interface (include counts? how does rate=1 interact with weight<1?) isn't completely clear to me. I'll update the issue to sort those out and plan to try again next cycle.
To view, visit change 404697. To unsubscribe, or for help writing mail filters, visit settings.
Reply all
Reply to author
Forward
0 new messages