golang / go

The Go programming language
https://go.dev
BSD 3-Clause "New" or "Revised" License
122.69k stars 17.49k forks source link

cmd/pprof: make runtime.reflectcall followable by pprof #11786

Open thwd opened 9 years ago

thwd commented 9 years ago

Context: http://stackoverflow.com/q/31419307/532430

Proposal: allow pprof to follow reflective function invocations via runtime.reflectcall so that code "after the jump" can be profiled.

I think the idea is simple enough but if anything was unclear just ask and I'll try to clarify.

ianlancetaylor commented 9 years ago

To be honest, I'm not sure this has to be a proposal. I think the current behaviour is a bug. I don't know what is involved in fixing it, but I can't imagine that anybody would object to a good fix.

adg commented 9 years ago

Agree, this needn't be a proposal.

rsc commented 8 years ago

This is a bug in pprof alone. The full information is in the profile, but the elision of runtime frames is getting confused by the reflect call and eliding everything below it. You can see the extra information using -runtime.

$ cat x_test.go
package x

import (
    "reflect"
    "testing"
)

func TestReflect(t *testing.T) {
    v := reflect.ValueOf(f)
    for i := 0; i < 10000; i++ {
        v.Call(nil)
    }
}

var x [][]byte

func f() {
    x = append(x, make([]byte, 10000))
}
$ go test -memprofile=x.prof x_test.go
ok      command-line-arguments  0.093s
$ go tool pprof -top x.test x.prof
100.50MB of 100.50MB total (  100%)
      flat  flat%   sum%        cum   cum%
  100.50MB   100%   100%   100.50MB   100%  reflect.Value.call
         0     0%   100%   100.50MB   100%  command-line-arguments.TestReflect
         0     0%   100%   100.50MB   100%  reflect.Value.Call
         0     0%   100%   100.50MB   100%  runtime.goexit
         0     0%   100%   100.50MB   100%  testing.tRunner
$ go tool pprof -top -runtime x.test x.prof
100.50MB of 100.50MB total (  100%)
Dropped 1 node (cum <= 0.50MB)
      flat  flat%   sum%        cum   cum%
  100.50MB   100%   100%   100.50MB   100%  runtime.makeslice
         0     0%   100%   100.50MB   100%  command-line-arguments.TestReflect
         0     0%   100%   100.50MB   100%  command-line-arguments.f
         0     0%   100%   100.50MB   100%  reflect.Value.Call
         0     0%   100%   100.50MB   100%  reflect.Value.call
         0     0%   100%   100.50MB   100%  runtime.call32
         0     0%   100%   100.50MB   100%  runtime.goexit
         0     0%   100%   100.50MB   100%  testing.tRunner
$
rsc commented 8 years ago

We ran out of time for this in Go 1.6.