-
Notifications
You must be signed in to change notification settings - Fork 17.8k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
cmd/pprof: header size >= 2**16 #6915
Labels
Milestone
Comments
The pprof fork seems to be in misc/pprof https://code.google.com/p/go/source/browse/misc/pprof PrintSymbolizedProfile is what outputs the extra '---' raw was introduced in 1.4 by the looks, including that line https://code.google.com/p/gperftools/source/detail?r=19dfa9e3733155e57406fbd082273eb53cb2750e&name=19dfa9e3 |
Looking at this, there are a few issues here with the interaction of FixCallerAddress and the fact raw is a symbolized profile. Just removing the line with --- from the heap works but we don't get symbols resolved go tool pprof --text --alloc_space ~/go/src/github.com/dotcloud/docker/heap | head Adjusting heap profiles for 1-in-524288 sampling rate Total: 760.5 MB 408.0 53.6% 53.6% 408.0 53.6% 0x0000000000428771 255.0 33.5% 87.2% 255.0 33.5% 0x000000000042b565 88.0 11.6% 98.8% 88.0 11.6% 0x00000000004286a2 5.5 0.7% 99.5% 5.5 0.7% 0x00000000004143f1 3.0 0.4% 99.9% 3.0 0.4% 0x000000000042bc69 0.5 0.1% 99.9% 0.5 0.1% 0x00000000004143c7 0.5 0.1% 100.0% 0.5 0.1% 0x0000000000428668 0.0 0.0% 100.0% 0.5 0.1% 0x00000000004073c0 0.0 0.0% 100.0% 8.0 1.1% 0x000000000040ee11 Hacking pprof to do the subtraction perl pprof --text --alloc_space ~/go/src/github.com/dotcloud/docker/heap | head Adjusting heap profiles for 1-in-524288 sampling rate Total: 760.5 MB 166.0 21.8% 21.8% 180.5 23.7% github.com/dotcloud/docker/graphdriver/aufs.getParentIds 146.5 19.3% 41.1% 149.5 19.7% github.com/dotcloud/docker/utils.(*TruncIndex).lookup 94.0 12.4% 53.5% 94.0 12.4% io/ioutil.readAll 57.0 7.5% 60.9% 57.0 7.5% strings.Join 26.5 3.5% 64.4% 27.5 3.6% io.Copy 26.0 3.4% 67.9% 35.5 4.7% encoding/json.(*decodeState).literalStore 25.5 3.4% 71.2% 25.5 3.4% encoding/json.unquote 22.0 2.9% 74.1% 22.0 2.9% syscall.ByteSliceFromString 21.0 2.8% 76.9% 21.0 2.8% index/suffixarray.initGroups |
Comment 3 by baron@xaprb.com: I noticed that in some kinds of profiling, there are extra --- lines, and in other kinds there are not extra lines and the tools work ok without modifying the raw output. |
Dave - note that pprof support two modes with a profile. The common mode as you mention, where you need the binary for symbols, and the raw mode which outputs a symbolized profile/heap, this avoids having to have the exact binary around (useful for bug reporting, etc). go tool pprof --raw http://localhost:6060/debug/pprof/heap Read http://localhost:6060/debug/pprof/symbol Fetching /pprof/heap profile from localhost:6060 to /tmp/6QVfEKcwS_ Wrote profile to /tmp/6QVfEKcwS_ Adjusting heap profiles for 1-in-524288 sampling rate --- symbol binary=./pprofd --- --- profile heap profile: 1: 288 [2: 296] @ heap/1048576 1: 288 [2: 296] @ This bug is about the output with --raw not working with the parsing for raw, but there are multiple bugs not just the output rendering. Note if you do as you suggest pprof errors. mkdir /tmp/pprofd; cd /tmp/pprofd curl http://play.golang.org/p/oUJCQPRzWL.go > pprofd.go go build ./pprofd In another terminal, caputure a heap: go tool pprof --raw http://localhost:6060/debug/pprof/heap > /tmp/heap Your method won't work on symbolized heaps: go tool pprof --text ./pprofd /tmp/heap FATAL ERROR: Symbolized profile '/tmp/heap' cannot be used with a binary arg. Try again without passing './pprofd'. Options are - fix pprof --raw as per the help examples: pprof --raw localhost:1234 > ./local.raw pprof --text ./local.raw Fetches a remote profile for later analysis and then analyzes it in text mode. Options to fix are - remove --raw from the go fork of pprof or fix it - which shouldn't be too hard, but you want to make sure that FixCallerAddress with raw symbolized profiles does the right thing. I'm happy to take a stab at either. |
Comment 7 by baron@xaprb.com: I think it would be great to move away from Perl, although I don't think the Perl in this tool is too bad actually. But I wonder if the original "upstream" maintainers would have any input on it. Maybe they'd rather see some redesign or something instead of a straight Perl->Go rewrite. |
I'm going to mark this issue as Thinking. I'm pretty sure there is general agreement that rewriting the current pprof in Go would be a good idea, but it is a non trivial amount of work and is not on anyone's radar at the moment. Labels changed: added release-none, repo-main. Status changed to Thinking. |
Go rewrite of that script seems to be open sourced. https://golang.org/cl/153750043 |
I've only looked at this briefly - but wanted to respond before I go on vacation, I'm not sure we're quite there go version go version devel +7e89fedb40e6 Tue Oct 21 13:26:40 2014 +0200 linux/amd64 I need to look in some more detail though - I'm seeing some issues with go tool pprof (old) vs running the binary pprof directly using godoc and running ab in the background against it go tool pprof --raw http://localhost:6060/debug/pprof/profile > /tmp/profile.raw Possible precedence issue with control flow operator at /usr/src/go/pkg/tool/linux_amd64/pprof line 3014. Read http://localhost:6060/debug/pprof/symbol Gathering CPU profile from http://localhost:6060/debug/pprof/profile?seconds=30 for 30 seconds to /tmp/uqzfHV5A7S root@85a3e81044dc://usr/src/go# go tool pprof /tmp/profile.raw Possible precedence issue with control flow operator at /usr/src/go/pkg/tool/linux_amd64/pprof line 3014. Welcome to pprof! For help, type 'help'. (pprof) top Total: 1990 samples 599 30.1% 30.1% 599 30.1% syscall.Syscall 120 6.0% 36.1% 120 6.0% scanblock 71 3.6% 39.7% 71 3.6% runtime.MSpan_Sweep 54 2.7% 42.4% 54 2.7% runtime.readvarint 51 2.6% 45.0% 51 2.6% runtime.mallocgc 45 2.3% 47.2% 45 2.3% runtime.memmove 38 1.9% 49.1% 38 1.9% adjustpointers 38 1.9% 51.1% 38 1.9% runtime.findfunc 36 1.8% 52.9% 36 1.8% runtime.step 31 1.6% 54.4% 31 1.6% syscall.Syscall6 (pprof) ./bin/pprof /tmp/profile.raw parsing profile: unrecognized profile format ./bin/pprof --raw http://localhost:6060/debug/pprof/profile > /tmp/profile.new.raw Fetching profile from http://localhost:6060/debug/pprof/profile Please wait... (30s) Saved profile in /root/pprof/pprof.localhost:6060.samples.cpu.002.pb.gz ./bin/pprof /tmp/profile.new.raw parsing profile: unrecognized profile format ./bin/pprof --text /root/pprof/pprof.localhost:6060.samples.cpu.002.pb.gz 27.28s of 27.28s total ( 100%) flat flat% sum% cum cum% 27.28s 100% 100% 27.28s 100% ./bin/pprof --top ./bin/godoc /root/pprof/pprof.localhost:6060.samples.cpu.002.pb.gz | head 20.51s of 27.28s total (75.18%) Dropped 326 nodes (cum <= 0.14s) Showing top 80 nodes out of 158 (cum >= 0.23s) flat flat% sum% cum cum% 7.48s 27.42% 27.42% 7.75s 28.41% syscall.Syscall 1.88s 6.89% 34.31% 1.88s 6.89% scanblock 1.09s 4.00% 38.31% 1.09s 4.00% runtime.MSpan_Sweep 0.76s 2.79% 41.09% 0.76s 2.79% runtime.readvarint 0.62s 2.27% 43.37% 0.90s 3.30% runtime.mallocgc 0.58s 2.13% 45.49% 0.58s 2.13% runtime.memmove Looking at the legacy parser src/cmd/pprof/internal/profile/legacy_profile.go it doesn't seem to handle symbolized raw dumps. The new src/cmd/pprof/internal/report/report.go basically just does? case Raw: fmt.Fprint(w, rpt.prof.String()) return nil From my understanding of it the previous raw command was designed to allow a profile with the symbols to be captured and shared without needing to share the binary. I can try make the go pprof support the legacy raw format as input, but as the meaning of --raw has changed in this version I'm not sure if it's a meaningful flag as we can save the pb. I'd expect the ability to resolve the symbols at sampling time vi http://localhost:6060/debug/pprof/symbol - looking at HasFileLines and src/cmd/pprof/internal/profile/profile.go it looks like the format supports it - I'd expect the raw format to be the fully populated protobuf with symbols for standalone analysis not the string representation of the Profile struct. |
OK so the way to achieve remote symbolized dump with the new pprof is pprof --symbolize=remote --proto -output=/tmp/p.pb.gz http://localhost:6060/debug/pprof/profile ./bin/pprof --text /tmp/p.pb.gz | head 16.97s of 22.06s total (76.93%) Dropped 317 nodes (cum <= 0.11s) flat flat% sum% cum cum% 6.24s 28.29% 28.29% 6.41s 29.06% syscall.Syscall 1.21s 5.49% 33.77% 1.21s 5.49% scanblock 0.91s 4.13% 37.90% 0.91s 4.13% runtime.MSpan_Sweep 0.65s 2.95% 40.84% 0.65s 2.95% adjustpointers 0.53s 2.40% 43.25% 0.53s 2.40% runtime.readvarint 0.48s 2.18% 45.42% 0.49s 2.22% runtime.step 0.46s 2.09% 47.51% 0.46s 2.09% runtime.memmove ./bin/pprof --symbolize=remote --raw http://localhost:6060/debug/pprof/profile will create a raw profile with symbols but as previous comment this is not supported as an input to pprof. I'd probably argue if you just have a URL to pprof we should default to remote. |
mikioh
changed the title
go tool pprof: header size >= 2**16
cmd/pprof: header size >= 2**16
Aug 13, 2015
Obsolete. The profiles are not text anymore, and the program isn't a Perl script anymore. |
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
by baron@xaprb.com:
The text was updated successfully, but these errors were encountered: