search

google / pprof

pprof is a tool for visualization and analysis of profiling data
Apache License 2.0
7.73k stars 599 forks source link

pprof fails to work with Go modules #611

Open odeke-em opened 3 years ago

odeke-em commented 3 years ago

Please answer these questions before submitting your issue. Thanks!

What version of pprof are you using?

If you are using pprof via go tool pprof, what's your go env output?

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN="/home/emmanuel/go/src/go.googlesource.com/go/bin"
GOCACHE="/home/emmanuel/.cache/go-build"
GOENV="/home/emmanuel/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/emmanuel/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/emmanuel/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/emmanuel/go/src/go.googlesource.com/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/emmanuel/go/src/go.googlesource.com/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="devel +e0fae78e1d Sat Mar 20 17:08:03 2021 +0000"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/emmanuel/go/src/go.googlesource.com/go/src/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build1299038824=/tmp/go-build -gno-record-gcc-switches"

If you run pprof from GitHub, what's the Git revision?

I am building using the latest Go version which uses the vendored version v0.0.0-20210226084205-cbba55b83ad5

What operating system and processor architecture are you using?

Linux, but this issue is agnostic of operating system

What did you do?

I have code built using Go modules, and when I try to invoke list it fails

What did you expect to see?

Able to view the various profile hits successfully!

What did you see instead?

$ go tool pprof 7.cpu 
File: gaiad
Build ID: 25a7357603c82d28fd8454d0a6710289487f313a
Type: cpu
Time: Mar 20, 2021 at 8:53pm (PDT)
Duration: 40.27s, Total samples = 24.84s (61.69%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) list memdb
Total: 24.84s
ROUTINE ======================== github.com/syndtr/goleveldb/leveldb.(*memdbReleaser).Release in github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/db_iter.go
         0       10ms (flat, cum)  0.04% of Total
 Error: could not find file github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/db_iter.go on path /home/emmanuel/go/src/github.com/orijtech/oragent/cmd/orprof/orprof/8e7fb00173
ROUTINE ======================== github.com/syndtr/goleveldb/leveldb/memdb.(*DB).Find in github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go
         0      110ms (flat, cum)  0.44% of Total
 Error: could not find file github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go on path /home/emmanuel/go/src/github.com/orijtech/oragent/cmd/orprof/orprof/8e7fb00173
ROUTINE ======================== github.com/syndtr/goleveldb/leveldb/memdb.(*DB).Put in github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go
         0      480ms (flat, cum)  1.93% of Total
 Error: could not find file github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go on path /home/emmanuel/go/src/github.com/orijtech/oragent/cmd/orprof/orprof/8e7fb00173
ROUTINE ======================== github.com/syndtr/goleveldb/leveldb/memdb.(*DB).findGE in github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go
     160ms      540ms (flat, cum)  2.17% of Total
 Error: could not find file github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go on path /home/emmanuel/go/src/github.com/orijtech/oragent/cmd/orprof/orprof/8e7fb00173
ROUTINE ======================== github.com/syndtr/goleveldb/leveldb/memdb.(*DB).randHeight in github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go
      10ms       20ms (flat, cum) 0.081% of Total
 Error: could not find file github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go on path /home/emmanuel/go/src/github.com/orijtech/oragent/cmd/orprof/orprof/8e7fb00173
ROUTINE ======================== github.com/syndtr/goleveldb/leveldb/memdb.(*dbIter).Next in github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go
      10ms       50ms (flat, cum)   0.2% of Total
 Error: could not find file github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go on path /home/emmanuel/go/src/github.com/orijtech/oragent/cmd/orprof/orprof/8e7fb00173
ROUTINE ======================== github.com/syndtr/goleveldb/leveldb/memdb.(*dbIter).Release in github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go
         0       10ms (flat, cum)  0.04% of Total
 Error: could not find file github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go on path /home/emmanuel/go/src/github.com/orijtech/oragent/cmd/orprof/orprof/8e7fb00173
ROUTINE ======================== github.com/syndtr/goleveldb/leveldb/memdb.(*dbIter).fill in github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go
      20ms       20ms (flat, cum) 0.081% of Total
 Error: could not find file github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/memdb/memdb.go on path /home/emmanuel/go/src/github.com/orijtech/oragent/cmd/orprof/orprof/8e7fb00173

Proposed remedy

I propose that we instead change this code https://github.com/google/pprof/blob/cbba55b83ad56c9286566b96b0c82cead332b729/internal/report/source.go#L921

and then also include $GOPATH/pkg/mod as a directory to search from, and I can mail a PR for this, and I am doing so in my local source of Go, but I believe this affects everyone and will need to be distributed

diff --git a/src/cmd/vendor/github.com/google/pprof/internal/report/source.go b/src/cmd/vendor/github.com/google/pprof/internal/report/source.go
index 4f841eff5d..8931278bf8 100644
--- a/src/cmd/vendor/github.com/google/pprof/internal/report/source.go
+++ b/src/cmd/vendor/github.com/google/pprof/internal/report/source.go
@@ -25,6 +25,7 @@ import (
        "os"
        "path/filepath"
        "regexp"
        "sort"
        "strconv"
        "strings"
@@ -918,7 +919,11 @@ func openSourceFile(path, searchPath, trim string) (*os.File, error) {
                return f, err
        }
        // Scan each component of the path.
-       for _, dir := range filepath.SplitList(searchPath) {
+       components := filepath.SplitList(searchPath)
+       if gopath := os.Getenv("GOPATH"); gopath != "" {
+               components = append(components, filepath.Join(gopath, "pkg", "mod"))
+       }
+       for _, dir := range components {
                // Search up for every parent of each possible path.
                for {
                        filename := filepath.Join(dir, path)
@@ -932,6 +937,7 @@ func openSourceFile(path, searchPath, trim string) (*os.File, error) {
                        dir = parent
                }
        }
mzimmerman commented 2 years ago

I just hit this bug -- is there any workaround other than implementing this patch to the pprof tool?

EnchanterIO commented 2 years ago

I run into the same problem when downloading the debug info from a remote server: go tool pprof -noinlines http://$IP/debug/pprof/allocs.

As a short term workaround that seems to have move the needle for me was creating a symlink for the pkg dir.

ln -s /home/$myUser/go/pkg pkg

Now the output displays as expected:

ROUTINE ======================== github.com/syndtr/goleveldb/leveldb/cache.(*Cache).Get in pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/cache/cache.go
      37MB     2.76GB (flat, cum) 0.018% of Total
         .          .    372:   }
         .          .    373:
         .          .    374:   hash := murmur32(ns, key, 0xf00)
         .          .    375:   for {
         .          .    376:       h, b := r.getBucket(hash)
         .   122.51MB    377:       done, _, n := b.get(r, h, hash, ns, key, setFunc == nil)