pprof fails to work with Go modules

[odeke-em]

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

pprof/internal/report/source.go

Line 921 in cbba55b

for _, dir := range filepath.SplitList(searchPath) {

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]

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

[EnchanterIO]

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)