]> Cypherpunks repositories - gostls13.git/commitdiff
runtime/pprof: fix the inlined frame merge logic
authorHana Kim <hyangah@gmail.com>
Tue, 12 Nov 2019 22:42:08 +0000 (17:42 -0500)
committerHyang-Ah Hana Kim <hyangah@gmail.com>
Thu, 14 Nov 2019 16:20:45 +0000 (16:20 +0000)
tryAdd shouldn't succeed (and accept the new frame) if the last
existing frame on the deck is not an inlined frame.

For example, when we see the followig stack
[300656 300664 300655 300664]

with each PC corresponds to

[{PC:300656 Func:nil Function:runtime.nanotime File:/workdir/go/src/runtime/time_nofake.go Line:19 Entry:300416 {0x28dac8 0x386c80}}]
[{PC:300664 Func:0x28dac8 Function:runtime.checkTimers File:/workdir/go/src/runtime/proc.go Line:2623 Entry:300416 {0x28dac8 0x386c80}}]
[{PC:300655 Func:nil Function:runtime.nanotime File:/workdir/go/src/runtime/time_nofake.go Line:19 Entry:300416 {0x28dac8 0x386c80}}]
[{PC:300664 Func:0x28dac8 Function:runtime.checkTimers File:/workdir/go/src/runtime/proc.go Line:2623 Entry:300416 {0x28dac8 0x386c80}}]

PC:300656 and PC:300664 belong to a single location entry,
but the bug in the current tryAdd logic placed the entire stack into one
location entry.

Also adds tests - this crash is a tricky case to test because I think it
should happen with normal go code. The new TestTryAdd simulates it by
using fake call sequences. The test crashed without the fix.

Update #35538

Change-Id: I6d3483f757abf4c429ab91616e4def90832fc04a
Reviewed-on: https://go-review.googlesource.com/c/go/+/206958
Reviewed-by: Keith Randall <khr@golang.org>
src/runtime/pprof/pprof_test.go
src/runtime/pprof/proto.go

index 5cbe9ab7a8be11ecb8aafbf3d4378fefe5c17ef4..9eba0078a525ab19d30f997a02ac503f270f458c 100644 (file)
@@ -16,7 +16,6 @@ import (
        "math/big"
        "os"
        "os/exec"
-       "reflect"
        "regexp"
        "runtime"
        "runtime/pprof/internal/profile"
@@ -108,17 +107,21 @@ func TestCPUProfileMultithreaded(t *testing.T) {
 // containsInlinedCall reports whether the function body for the function f is
 // known to contain an inlined function call within the first maxBytes bytes.
 func containsInlinedCall(f interface{}, maxBytes int) bool {
-       rf := reflect.ValueOf(f)
-       if rf.Kind() != reflect.Func {
-               panic(fmt.Sprintf("%T is not a function", f))
-       }
-       fFunc := runtime.FuncForPC(rf.Pointer())
+       _, found := findInlinedCall(f, maxBytes)
+       return found
+}
+
+// findInlinedCall returns the PC of an inlined function call within
+// the funtion body for the function f if any.
+func findInlinedCall(f interface{}, maxBytes int) (pc uint64, found bool) {
+       fFunc := runtime.FuncForPC(uintptr(funcPC(f)))
        if fFunc == nil || fFunc.Entry() == 0 {
                panic("failed to locate function entry")
        }
 
        for offset := 0; offset < maxBytes; offset++ {
-               inner := runtime.FuncForPC(fFunc.Entry() + uintptr(offset))
+               innerPC := fFunc.Entry() + uintptr(offset)
+               inner := runtime.FuncForPC(innerPC)
                if inner == nil {
                        // No function known for this PC value.
                        // It might simply be misaligned, so keep searching.
@@ -131,16 +134,16 @@ func containsInlinedCall(f interface{}, maxBytes int) bool {
                if inner.Name() != fFunc.Name() {
                        // This PC has f as its entry-point, but is not f. Therefore, it must be a
                        // function inlined into f.
-                       return true
+                       return uint64(innerPC), true
                }
        }
 
-       return false
+       return 0, false
 }
 
 func TestCPUProfileInlining(t *testing.T) {
        if !containsInlinedCall(inlinedCaller, 4<<10) {
-               t.Skipf("Can't determine whether inlinedCallee was inlined into inlinedCaller.")
+               t.Skip("Can't determine whether inlinedCallee was inlined into inlinedCaller.")
        }
 
        p := testCPUProfile(t, stackContains, []string{"runtime/pprof.inlinedCallee", "runtime/pprof.inlinedCaller"}, avoidFunctions(), func(dur time.Duration) {
@@ -1135,3 +1138,85 @@ func TestTracebackAll(t *testing.T) {
                runtime.Stack(buf, true)
        }
 }
+
+// TestTryAdd tests the cases that's hard to test with real program execution.
+// For example, the current go compilers may not inline functions involved in recursion
+// but that may not be true in the future compilers. This tests such cases by
+// using fake call sequences and forcing the profile build utilizing
+// translateCPUProfile defined in proto_test.go
+func TestTryAdd(t *testing.T) {
+       inlinedCallerPtr := uint64(funcPC(inlinedCaller)) + 1
+       inlinedCalleePtr, found := findInlinedCall(inlinedCaller, 4<<10)
+       if !found {
+               t.Skip("Can't determine whether inlinedCallee was inlined into inlinedCaller.")
+       }
+       inlinedCalleePtr += 1 // +1 to be safely inside of the function body.
+
+       period := int64(2000 * 1000) // 1/500*1e9 nanosec.
+
+       testCases := []struct {
+               name        string
+               input       []uint64          // following the input format assumed by profileBuilder.addCPUData.
+               wantLocs    [][]string        // ordered location entries with function names.
+               wantSamples []*profile.Sample // ordered samples, we care only about Value and the profile location IDs.
+       }{{
+               name: "bug35538",
+               input: []uint64{
+                       3, 0, 500, // hz = 500. Must match the period.
+                       7, 0, 10, inlinedCalleePtr, inlinedCallerPtr, inlinedCalleePtr, inlinedCallerPtr,
+                       5, 0, 20, inlinedCalleePtr, inlinedCallerPtr,
+               },
+               wantLocs: [][]string{{"runtime/pprof.inlinedCallee", "runtime/pprof.inlinedCaller"}},
+               wantSamples: []*profile.Sample{
+                       {Value: []int64{10, 10 * period}, Location: []*profile.Location{{ID: 1}, {ID: 1}}},
+                       {Value: []int64{20, 20 * period}, Location: []*profile.Location{{ID: 1}}},
+               },
+       }, {
+               name: "recursive_inlined_funcs",
+               input: []uint64{
+                       3, 0, 500, // hz = 500. Must match the period.
+                       5, 0, 30, inlinedCalleePtr, inlinedCalleePtr,
+                       4, 0, 40, inlinedCalleePtr,
+               },
+               wantLocs: [][]string{{"runtime/pprof.inlinedCallee"}},
+               wantSamples: []*profile.Sample{
+                       {Value: []int64{30, 30 * period}, Location: []*profile.Location{{ID: 1}, {ID: 1}}},
+                       {Value: []int64{40, 40 * period}, Location: []*profile.Location{{ID: 1}}},
+               },
+       }}
+
+       for _, tc := range testCases {
+               t.Run(tc.name, func(t *testing.T) {
+                       p, err := translateCPUProfile(tc.input)
+                       if err != nil {
+                               t.Fatalf("translating profile: %v", err)
+                       }
+                       t.Logf("Profile: %v\n", p)
+
+                       // One location entry with all inlined functions.
+                       var gotLoc [][]string
+                       for _, loc := range p.Location {
+                               var names []string
+                               for _, line := range loc.Line {
+                                       names = append(names, line.Function.Name)
+                               }
+                               gotLoc = append(gotLoc, names)
+                       }
+                       if got, want := fmtJSON(gotLoc), fmtJSON(tc.wantLocs); got != want {
+                               t.Errorf("Got Location = %+v\n\twant %+v", got, want)
+                       }
+                       // All samples should point to one location.
+                       var gotSamples []*profile.Sample
+                       for _, sample := range p.Sample {
+                               var locs []*profile.Location
+                               for _, loc := range sample.Location {
+                                       locs = append(locs, &profile.Location{ID: loc.ID})
+                               }
+                               gotSamples = append(gotSamples, &profile.Sample{Value: sample.Value, Location: locs})
+                       }
+                       if got, want := fmtJSON(gotSamples), fmtJSON(tc.wantSamples); got != want {
+                               t.Errorf("Got Samples = %+v\n\twant %+v", got, want)
+                       }
+               })
+       }
+}
index 3e6012df575441a9b6a4d5be6e106279197737e1..a42cd80c153b2d62ec23feec4ce081e86b46d685 100644 (file)
@@ -471,13 +471,12 @@ func (d *pcDeck) reset() {
 func (d *pcDeck) tryAdd(pc uintptr, frames []runtime.Frame, symbolizeResult symbolizeFlag) (success bool) {
        if existing := len(d.pcs); existing > 0 {
                // 'frames' are all expanded from one 'pc' and represent all inlined functions
-               // so we check only the first one.
+               // so we check only the last one.
                newFrame := frames[0]
                last := d.frames[existing-1]
-               if last.Func != nil && newFrame.Func != nil { // Can't be an inlined frame.
+               if last.Func != nil { // the last frame can't be inlined. Flush.
                        return false
                }
-
                if last.Entry == 0 || newFrame.Entry == 0 { // Possibly not a Go function. Don't try to merge.
                        return false
                }