pprof: ignores symbols in symbolized profile with no mappings about pprof HOT 19 CLOSED

@aalexand perhaps it's worthwhile to revert #114 since this isn't specific to the changes made there.

from pprof.

The profile coming from the 1.8 handler on OSX is unsymbolized and has no mappings.
I'd prefer all Go profiles to be symbolized online. Is online symbolization available on OSX? If not, we would need a mapping in the profile to enable offline symbolization.

Can somebody from the Go distro take a look?

from pprof.

After cherry-picking https://go-review.googlesource.com/34192
it seems to work for me.
I don't understand how it worked on Linux given that go1.8 release branch doesn't include the change.

Filed golang/go#19786

from pprof.

I assume @aalexand tried this on a linux system that was using a patched version.
Closing as there is no work to do for this in pprof.

from pprof.

@rauls5382 I don't understand your comment. I originally reported this issue in #111 and I was definitely using stock toolchains in both Linux and Darwin.

from pprof.

Yes, the issue is on all platforms. The comment from @aalexand at the beginning of this issue suggests that this only happens on OSX, but that appears not to be the case.

from pprof.

I mean, that's nice, but it's factually incorrect. The problem does not occur on Linux on Go 1.8.

I think this should be reopened and investigated more deeply.

from pprof.

I see. I saw your comment on #111 thinking that this reproduced on both, but you were referring to the original issue, not the symbolization failure.

From @aalexand investigation seems the difference is that the OSX profile has no mappings, so pprof cannot symbolize it. Moving forward we want online symbolization in Go anyway, but it may be worth opening an issue against go about they not having mappings on OSX -- those will be useful to symbolize non-Go symbols offline.

from pprof.

Great, thanks for that.

Could you mention that issue when you've filed it?

from pprof.

I see. OSX is still missing the mappings section with Go tip.

(pprof) raw
PeriodType: cpu nanoseconds
Period: 100000
Time: 2017-03-30 12:10:20.33628219 -0400 EDT
Duration: 5.19
Samples:
samples/count cpu/nanoseconds
        436   43600000: 1 2 3 
          1     100000: 4 
          1     100000: 5 6 7 8 
Locations
     1: 0x12dc6e0 main.run /Users/hakim/scratch/server.go:10 s=0
     2: 0x12dc729 main.main /Users/hakim/scratch/server.go:18 s=0
     3: 0x102d6d4 runtime.main /Users/hakim/go/src/runtime/proc.go:185 s=0
     4: 0x12d42f8 runtime/pprof.profileWriter /Users/hakim/go/src/runtime/pprof/pprof.go:706 s=0
     5: 0x105c5c6 runtime.usleep /Users/hakim/go/src/runtime/sys_darwin_amd64.s:323 s=0
     6: 0x1037775 runtime.sysmon /Users/hakim/go/src/runtime/proc.go:3741 s=0
     7: 0x103090d runtime.mstart1 /Users/hakim/go/src/runtime/proc.go:1162 s=0
     8: 0x10307e3 runtime.mstart /Users/hakim/go/src/runtime/proc.go:1132 s=0
Mappings

from pprof.

@hyangah can you file a Go bug for this? Or I can do it - LMK, want to make sure we don't race.

from pprof.

Yes, I can.
Can you provide a pointer to how pprof retrieved Mappings with go1.7? (pre-proto era, I guess)

Clearly, https://github.com/golang/go/blob/master/src/runtime/pprof/proto.go#L370 is not for osx.

from pprof.

I think go 1.7 generated the profile in a legacy format - https://github.com/golang/go/blob/go1.7.4/src/runtime/pprof/pprof.go#L683, and that has special handling for when there aren't any mappings -

In #89 there was a workaround added by @rauls5382 to create a fake mapping for non-legacy (i.e. proto) profiles as well but only when there is a binary explicitly specified on the command line. We could probably add the fake mapping if the profile source is remote but this seems a fragile hack.

from pprof.

Indeed, 1.8 removed the legacy format: golang/go@76f12cd

from pprof.

So uh, time to reopen this?

from pprof.

@tamird and @rauls5382, I've confirmed that the current pprof (what you get from go get -u github.com/google/pprof) does not work properly with profiles that are symbolized but have no mappings, while the pprof we shipped in Go 1.8 does work fine.

So @tamird, you should use 'go tool pprof' instead of 'pprof', and @rauls5382, you may want to fix / reassign this.

First window:

$ cat /tmp/x.go
package main

import (
	"crypto/rand"
	"log"
	"net/http"
	_ "net/http/pprof"
)

func main() {
	go func() {
		for {
			rand.Prime(rand.Reader, 1024)
		}
	}()
	log.Fatal(http.ListenAndServe("localhost:8000", nil))
}
$ go run /tmp/x.go

Second window.

Go tool pprof works:

$ go tool pprof -symbolize=remote http://localhost:8000/debug/pprof/profile?seconds=5
Fetching profile from http://localhost:8000/debug/pprof/profile?seconds=5
Please wait... (5s)
Saved profile in /Users/rsc/pprof/pprof.localhost:8000.samples.cpu.002.pb.gz
Entering interactive mode (type "help" for commands)
(pprof) top10
3.94s of 3.97s total (99.24%)
Dropped 3 nodes (cum <= 0.02s)
Showing top 10 nodes out of 41 (cum >= 0.04s)
      flat  flat%   sum%        cum   cum%
     1.92s 48.36% 48.36%      1.92s 48.36%  math/big.addMulVVW
     0.63s 15.87% 64.23%      0.63s 15.87%  runtime.usleep
     0.45s 11.34% 75.57%      2.73s 68.77%  math/big.nat.montgomery
     0.45s 11.34% 86.90%      0.45s 11.34%  syscall.Syscall
     0.32s  8.06% 94.96%      0.32s  8.06%  runtime.memmove
     0.05s  1.26% 96.22%      0.05s  1.26%  runtime.kevent
     0.04s  1.01% 97.23%      2.79s 70.28%  math/big.nat.expNNMontgomery
     0.03s  0.76% 97.98%      0.03s  0.76%  math/rand.(*rngSource).Seed
     0.03s  0.76% 98.74%      0.03s  0.76%  runtime.memclrNoHeapPointers
     0.02s   0.5% 99.24%      0.04s  1.01%  math/big.nat.divLarge
(pprof)

but current github.com/google/pprof does not:

$ pprof -symbolize=remote http://localhost:8000/debug/pprof/profile?seconds=5
Fetching profile over HTTP from http://localhost:8000/debug/pprof/profile?seconds=5
Saved profile in /Users/rsc/pprof/pprof.samples.cpu.001.pb.gz
Type: cpu
Time: Apr 3, 2017 at 11:51am (EDT)
Duration: 5s, Total samples = 4.10s (81.94%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top10
Showing nodes accounting for 4.10s, 100% of 4.10s total
      flat  flat%   sum%        cum   cum%
     4.10s   100%   100%      4.10s   100%  <unknown>
(pprof) 

Dropping -symbolize=remote does not change the behavior.

from pprof.

https://github.com/golang/go/blob/release-branch.go1.8/src/cmd/pprof/pprof.go vs
https://github.com/google/pprof/blob/master/pprof.go

So, go1.8 pprof uses symbolz.Symbolize if --symbolize is remote, "", or force.

@rauls5382, is it not possible to fall back to symbolz?

from pprof.

@rauls5382, do you plan to look at this issue? Feel free to unassign if not.

from pprof.

Apologies for the long latency.

In profile.proto the samples that came from a single binary are grouped together through the mapping. It would be good if the Go runtime would generate a mapping for the samples and associate them to the binary (the result of os.Executable()). That would relieve the user from having to pass the name of the binary to pprof for offline symbolization.

More generally, the mappings would be useful for a handler returning profiles with samples from two different binaries, for example for cross-language support.

pprof relies on the mappings to drive symbolization. It creates a single mapping for the legacy Go profiles. I was hoping to avoid doing that when handling profile.proto profiles, but we already do it in some cases if there are no mappings. I'll send shortly a commit to do this all the time, which will resolve the problem.

@rsc, would you consider adding mappings to the profiles generated in Go? Even if some of the fields aren't meaningful on some platforms, the mapping still has value. This may be moot with online symbolization in Go, but it may still prove valuable for cross-language support.

from pprof.