9

I've previously used the pprof tool without issue and it worked great - now I see output like the following no matter what I profile:

Output from pprof

the application being profiled in this example probably makes 40+ function calls and even more complex apps are producing similar callgraphs for both cpu and memprofiling.

The apps Im trying to profile are all web applications, I am profiling them for one minute at a time and using wrk to generate 200,000,000+ requests = all returning data and a 2xx response

pprof suddenly stopped working a few days ago running osx yosemite - in an attempt to resolve the issue I recently upgraded to el capitan but result is the same.

Note: this is not just call graphs - calling list or top command produce similarly barren results but the apps themselves work fine:

    (pprof) top
269.97kB of 269.97kB total (  100%)
      flat  flat%   sum%        cum   cum%
  269.97kB   100%   100%   269.97kB   100%  
(pprof)

I am using the following package: "github.com/davecheney/profile" with go v1.5.1

For clarity, here's what I'm doing to generate the profiles::

I import the above package into main.go and place the following at the top of my main func:

defer profile.Start(profile.MemProfile).Stop()

I then build the binary and run it:

go build -o orig /Users/danielwall/www/netlistener/application/adrequest.go /Users/danielwall/www/netlistener/application/cookie.go /Users/danielwall/www/netlistener/application/header.go /Users/danielwall/www/netlistener/application/lex.go /Users/danielwall/www/netlistener/application/main.go /Users/danielwall/www/netlistener/application/publisher_ids.go /Users/danielwall/www/netlistener/application/request.go /Users/danielwall/www/netlistener/application/response.go /Users/danielwall/www/netlistener/application/server.go /Users/danielwall/www/netlistener/application/sniff.go /Users/danielwall/www/netlistener/application/status.go /Users/danielwall/www/netlistener/application/transfer.go

./orig

I then see output like this:

2015/11/16 11:39:49 profile: memory profiling enabled, /var/folders/26/2sj70_sn72l_93j7tf6r07gr0000gn/T/profile614358295/mem.pprof

Now I work the app from another terminal :

    wrk -d60 -c10 -H "X-Device: desktop" -H "X-Country-Code: GB" "http://localhost:8189/app?id=111&schema=xml2&ad_type=auto&url=http://test.com/&category=bob"
Running 1m test @ http://localhost:8189/app?id=111&schema=xml2&ad_type=auto&url=http://test.com/&category=bob
  2 threads and 10 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   414.09us    0.92ms  55.36ms   95.66%
    Req/Sec    17.57k     3.19k   22.59k    76.00%
  2097764 requests in 1.00m, 684.20MB read
Requests/sec:  34958.03
Transfer/sec:     11.40MB

After 60 seconds, I go back to check my profile:

^C2015/11/16 12:05:20 profile: caught interrupt, stopping profiles

go tool pprof /var/folders/26/2sj70_sn72l_93j7tf6r07gr0000gn/T/profile614358295/mem.pprof

Any ideas what might be happening here or where I could start with trouble shooting/solving this?

Any help suggestions welcome.

SwiftD
  • 5,769
  • 6
  • 43
  • 67
  • 1
    Show *how* you make the profiles. Especially your config for the `profile.Start`. – Ainar-G Nov 16 '15 at 13:23
  • Updated to include everything I did on last run - thanks for looking – SwiftD Nov 16 '15 at 13:35
  • Any reason why you feed `go build` files one by one instead of just `go build`? Also, `go tool pprof` call seems to be missing the binary itself, should be `go tool pprof ./orig /path/to/profile.pprof`. – Ainar-G Nov 16 '15 at 13:41
  • go build picks up all the test files, thats why I list them individually (I have a script that spits out the list of files that arent tests (is there a better way?) - I think you may have the solution there with missing binary in options passed to pprof though -let me check – SwiftD Nov 16 '15 at 13:43
  • @Ainar-G yep missing the binary passed to pprof (user muppetry) - thanks for your help - if you submit as answer happy to accept :) – SwiftD Nov 16 '15 at 13:45
  • Answered. Also, I don't quite get what you mean by "go build picks up all the test files". It won't build any `foo_test.go` files unless you are using `go test` or `go build -tags test`. – Ainar-G Nov 16 '15 at 13:47
  • You're right if building in same directory - I was trying to build subdir as go build subdir/* - that was why it was picking up test files (I have some temporary relative paths, so cant currently build from the subdir - not planning to keep going forward) – SwiftD Nov 16 '15 at 13:53

1 Answers1

10

Your go tool pprof call is missing the binary itself. Call it as

go tool pprof ./orig /path/to/profile.pprof
Ainar-G
  • 34,563
  • 13
  • 93
  • 119