1
0
mirror of https://github.com/golang/go synced 2024-09-29 12:24:31 -06:00

runtime/pprof: consume tag for first CPU record

profBuf.write uses an index in b.tags for each entry, even if that entry
has no tag (that slice entry just remains 0). profBuf.read similarly
returns a tags slice with exactly as many entries as there are records
in data.

profileBuilder.addCPUData iterates through the tags in lockstep with the
data records. Except in the special case of the first record, where it
forgets to increment tags. Thus the first read of profiling data has all
tags off-by-one.

To help avoid regressions, addCPUData is changed to assert that tags
contains exactly the correct number of tags.

For #50007.

Change-Id: I5f32f93003297be8d6e33ad472c185d924a63256
Reviewed-on: https://go-review.googlesource.com/c/go/+/369741
Reviewed-by: Austin Clements <austin@google.com>
Trust: Michael Pratt <mpratt@google.com>
Run-TryBot: Michael Pratt <mpratt@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
This commit is contained in:
Michael Pratt 2021-12-06 16:05:55 -05:00
parent cf1ec17360
commit a3ae45ebe1
4 changed files with 37 additions and 13 deletions

View File

@ -200,6 +200,8 @@ func runtime_pprof_runtime_cyclesPerSecond() int64 {
// If profiling is turned off and all the profile data accumulated while it was // If profiling is turned off and all the profile data accumulated while it was
// on has been returned, readProfile returns eof=true. // on has been returned, readProfile returns eof=true.
// The caller must save the returned data and tags before calling readProfile again. // The caller must save the returned data and tags before calling readProfile again.
// The returned data contains a whole number of records, and tags contains
// exactly one entry per record.
// //
//go:linkname runtime_pprof_readProfile runtime/pprof.readProfile //go:linkname runtime_pprof_readProfile runtime/pprof.readProfile
func runtime_pprof_readProfile() ([]uint64, []unsafe.Pointer, bool) { func runtime_pprof_readProfile() ([]uint64, []unsafe.Pointer, bool) {

View File

@ -1608,6 +1608,7 @@ func TestTryAdd(t *testing.T) {
testCases := []struct { testCases := []struct {
name string name string
input []uint64 // following the input format assumed by profileBuilder.addCPUData. input []uint64 // following the input format assumed by profileBuilder.addCPUData.
count int // number of records in input.
wantLocs [][]string // ordered location entries with function names. wantLocs [][]string // ordered location entries with function names.
wantSamples []*profile.Sample // ordered samples, we care only about Value and the profile location IDs. wantSamples []*profile.Sample // ordered samples, we care only about Value and the profile location IDs.
}{{ }{{
@ -1617,6 +1618,7 @@ func TestTryAdd(t *testing.T) {
3, 0, 500, // hz = 500. Must match the period. 3, 0, 500, // hz = 500. Must match the period.
5, 0, 50, inlinedCallerStack[0], inlinedCallerStack[1], 5, 0, 50, inlinedCallerStack[0], inlinedCallerStack[1],
}, },
count: 2,
wantLocs: [][]string{ wantLocs: [][]string{
{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}, {"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"},
}, },
@ -1633,6 +1635,7 @@ func TestTryAdd(t *testing.T) {
7, 0, 10, inlinedCallerStack[0], inlinedCallerStack[1], inlinedCallerStack[0], inlinedCallerStack[1], 7, 0, 10, inlinedCallerStack[0], inlinedCallerStack[1], inlinedCallerStack[0], inlinedCallerStack[1],
5, 0, 20, inlinedCallerStack[0], inlinedCallerStack[1], 5, 0, 20, inlinedCallerStack[0], inlinedCallerStack[1],
}, },
count: 3,
wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}}, wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
wantSamples: []*profile.Sample{ wantSamples: []*profile.Sample{
{Value: []int64{10, 10 * period}, Location: []*profile.Location{{ID: 1}, {ID: 1}}}, {Value: []int64{10, 10 * period}, Location: []*profile.Location{{ID: 1}, {ID: 1}}},
@ -1646,6 +1649,7 @@ func TestTryAdd(t *testing.T) {
// entry. The "stk" entry is actually the count. // entry. The "stk" entry is actually the count.
4, 0, 0, 4242, 4, 0, 0, 4242,
}, },
count: 2,
wantLocs: [][]string{{"runtime/pprof.lostProfileEvent"}}, wantLocs: [][]string{{"runtime/pprof.lostProfileEvent"}},
wantSamples: []*profile.Sample{ wantSamples: []*profile.Sample{
{Value: []int64{4242, 4242 * period}, Location: []*profile.Location{{ID: 1}}}, {Value: []int64{4242, 4242 * period}, Location: []*profile.Location{{ID: 1}}},
@ -1664,6 +1668,7 @@ func TestTryAdd(t *testing.T) {
5, 0, 30, inlinedCallerStack[0], inlinedCallerStack[0], 5, 0, 30, inlinedCallerStack[0], inlinedCallerStack[0],
4, 0, 40, inlinedCallerStack[0], 4, 0, 40, inlinedCallerStack[0],
}, },
count: 3,
// inlinedCallerDump shows up here because // inlinedCallerDump shows up here because
// runtime_expandFinalInlineFrame adds it to the stack frame. // runtime_expandFinalInlineFrame adds it to the stack frame.
wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump"}, {"runtime/pprof.inlinedCallerDump"}}, wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump"}, {"runtime/pprof.inlinedCallerDump"}},
@ -1677,6 +1682,7 @@ func TestTryAdd(t *testing.T) {
3, 0, 500, // hz = 500. Must match the period. 3, 0, 500, // hz = 500. Must match the period.
9, 0, 10, recursionStack[0], recursionStack[1], recursionStack[2], recursionStack[3], recursionStack[4], recursionStack[5], 9, 0, 10, recursionStack[0], recursionStack[1], recursionStack[2], recursionStack[3], recursionStack[4], recursionStack[5],
}, },
count: 2,
wantLocs: [][]string{ wantLocs: [][]string{
{"runtime/pprof.recursionChainBottom"}, {"runtime/pprof.recursionChainBottom"},
{ {
@ -1700,6 +1706,7 @@ func TestTryAdd(t *testing.T) {
5, 0, 50, inlinedCallerStack[0], inlinedCallerStack[1], 5, 0, 50, inlinedCallerStack[0], inlinedCallerStack[1],
4, 0, 60, inlinedCallerStack[0], 4, 0, 60, inlinedCallerStack[0],
}, },
count: 3,
wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}}, wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
wantSamples: []*profile.Sample{ wantSamples: []*profile.Sample{
{Value: []int64{50, 50 * period}, Location: []*profile.Location{{ID: 1}}}, {Value: []int64{50, 50 * period}, Location: []*profile.Location{{ID: 1}}},
@ -1712,6 +1719,7 @@ func TestTryAdd(t *testing.T) {
4, 0, 70, inlinedCallerStack[0], 4, 0, 70, inlinedCallerStack[0],
5, 0, 80, inlinedCallerStack[0], inlinedCallerStack[1], 5, 0, 80, inlinedCallerStack[0], inlinedCallerStack[1],
}, },
count: 3,
wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}}, wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
wantSamples: []*profile.Sample{ wantSamples: []*profile.Sample{
{Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}}, {Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}},
@ -1724,6 +1732,7 @@ func TestTryAdd(t *testing.T) {
3, 0, 500, // hz = 500. Must match the period. 3, 0, 500, // hz = 500. Must match the period.
4, 0, 70, inlinedCallerStack[0], 4, 0, 70, inlinedCallerStack[0],
}, },
count: 2,
wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}}, wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
wantSamples: []*profile.Sample{ wantSamples: []*profile.Sample{
{Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}}, {Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}},
@ -1739,6 +1748,7 @@ func TestTryAdd(t *testing.T) {
// from getting merged into above. // from getting merged into above.
5, 0, 80, inlinedCallerStack[1], inlinedCallerStack[0], 5, 0, 80, inlinedCallerStack[1], inlinedCallerStack[0],
}, },
count: 3,
wantLocs: [][]string{ wantLocs: [][]string{
{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}, {"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"},
{"runtime/pprof.inlinedCallerDump"}, {"runtime/pprof.inlinedCallerDump"},
@ -1751,7 +1761,7 @@ func TestTryAdd(t *testing.T) {
for _, tc := range testCases { for _, tc := range testCases {
t.Run(tc.name, func(t *testing.T) { t.Run(tc.name, func(t *testing.T) {
p, err := translateCPUProfile(tc.input) p, err := translateCPUProfile(tc.input, tc.count)
if err != nil { if err != nil {
t.Fatalf("translating profile: %v", err) t.Fatalf("translating profile: %v", err)
} }

View File

@ -266,8 +266,9 @@ func newProfileBuilder(w io.Writer) *profileBuilder {
} }
// addCPUData adds the CPU profiling data to the profile. // addCPUData adds the CPU profiling data to the profile.
// The data must be a whole number of records, //
// as delivered by the runtime. // The data must be a whole number of records, as delivered by the runtime.
// len(tags) must be equal to the number of records in data.
func (b *profileBuilder) addCPUData(data []uint64, tags []unsafe.Pointer) error { func (b *profileBuilder) addCPUData(data []uint64, tags []unsafe.Pointer) error {
if !b.havePeriod { if !b.havePeriod {
// first record is period // first record is period
@ -282,6 +283,9 @@ func (b *profileBuilder) addCPUData(data []uint64, tags []unsafe.Pointer) error
b.period = 1e9 / int64(data[2]) b.period = 1e9 / int64(data[2])
b.havePeriod = true b.havePeriod = true
data = data[3:] data = data[3:]
// Consume tag slot. Note that there isn't a meaningful tag
// value for this record.
tags = tags[1:]
} }
// Parse CPU samples from the profile. // Parse CPU samples from the profile.
@ -306,14 +310,14 @@ func (b *profileBuilder) addCPUData(data []uint64, tags []unsafe.Pointer) error
if data[0] < 3 || tags != nil && len(tags) < 1 { if data[0] < 3 || tags != nil && len(tags) < 1 {
return fmt.Errorf("malformed profile") return fmt.Errorf("malformed profile")
} }
if len(tags) < 1 {
return fmt.Errorf("mismatched profile records and tags")
}
count := data[2] count := data[2]
stk := data[3:data[0]] stk := data[3:data[0]]
data = data[data[0]:] data = data[data[0]:]
var tag unsafe.Pointer tag := tags[0]
if tags != nil { tags = tags[1:]
tag = tags[0]
tags = tags[1:]
}
if count == 0 && len(stk) == 1 { if count == 0 && len(stk) == 1 {
// overflow record // overflow record
@ -327,6 +331,10 @@ func (b *profileBuilder) addCPUData(data []uint64, tags []unsafe.Pointer) error
} }
b.m.lookup(stk, tag).count += int64(count) b.m.lookup(stk, tag).count += int64(count)
} }
if len(tags) != 0 {
return fmt.Errorf("mismatched profile records and tags")
}
return nil return nil
} }

View File

@ -17,16 +17,20 @@ import (
"runtime" "runtime"
"strings" "strings"
"testing" "testing"
"unsafe"
) )
// translateCPUProfile parses binary CPU profiling stack trace data // translateCPUProfile parses binary CPU profiling stack trace data
// generated by runtime.CPUProfile() into a profile struct. // generated by runtime.CPUProfile() into a profile struct.
// This is only used for testing. Real conversions stream the // This is only used for testing. Real conversions stream the
// data into the profileBuilder as it becomes available. // data into the profileBuilder as it becomes available.
func translateCPUProfile(data []uint64) (*profile.Profile, error) { //
// count is the number of records in data.
func translateCPUProfile(data []uint64, count int) (*profile.Profile, error) {
var buf bytes.Buffer var buf bytes.Buffer
b := newProfileBuilder(&buf) b := newProfileBuilder(&buf)
if err := b.addCPUData(data, nil); err != nil { tags := make([]unsafe.Pointer, count)
if err := b.addCPUData(data, tags); err != nil {
return nil, err return nil, err
} }
b.build() b.build()
@ -46,7 +50,7 @@ func TestConvertCPUProfileEmpty(t *testing.T) {
var buf bytes.Buffer var buf bytes.Buffer
b := []uint64{3, 0, 500} // empty profile at 500 Hz (2ms sample period) b := []uint64{3, 0, 500} // empty profile at 500 Hz (2ms sample period)
p, err := translateCPUProfile(b) p, err := translateCPUProfile(b, 1)
if err != nil { if err != nil {
t.Fatalf("translateCPUProfile: %v", err) t.Fatalf("translateCPUProfile: %v", err)
} }
@ -120,7 +124,7 @@ func TestConvertCPUProfile(t *testing.T) {
5, 0, 40, uint64(addr2 + 1), uint64(addr2 + 2), // 40 samples in addr2 5, 0, 40, uint64(addr2 + 1), uint64(addr2 + 2), // 40 samples in addr2
5, 0, 10, uint64(addr1 + 1), uint64(addr1 + 2), // 10 samples in addr1 5, 0, 10, uint64(addr1 + 1), uint64(addr1 + 2), // 10 samples in addr1
} }
p, err := translateCPUProfile(b) p, err := translateCPUProfile(b, 4)
if err != nil { if err != nil {
t.Fatalf("translating profile: %v", err) t.Fatalf("translating profile: %v", err)
} }
@ -429,7 +433,7 @@ func TestEmptyStack(t *testing.T) {
3, 0, 500, // hz = 500 3, 0, 500, // hz = 500
3, 0, 10, // 10 samples with an empty stack trace 3, 0, 10, // 10 samples with an empty stack trace
} }
_, err := translateCPUProfile(b) _, err := translateCPUProfile(b, 2)
if err != nil { if err != nil {
t.Fatalf("translating profile: %v", err) t.Fatalf("translating profile: %v", err)
} }