Skip to content
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

Hang with a particular profile file #78

Closed
paraboul opened this issue Jan 9, 2017 · 3 comments
Closed

Hang with a particular profile file #78

paraboul opened this issue Jan 9, 2017 · 3 comments

Comments

@paraboul
Copy link

paraboul commented Jan 9, 2017

Depending on the behavior of my profiled binary, libprofiler outputs a profiling file (see attached) that makes pprof hangs. I wasn't able to easily strace where it's stuck.

Tested on linux. Profiled executable built with clang 3.7+

profile.txt (.txt for the sake of github upload)

@paraboul paraboul changed the title Hang with a particuliar profile file Hang with a particular profile file Jan 9, 2017
@paraboul
Copy link
Author

paraboul commented Jan 9, 2017

Ok, got a backtrace :

(gdb) goroutine 1 bt
#0  syscall.Syscall6 () at /usr/lib/go/src/syscall/asm_linux_amd64.s:45
#1  0x00000000004acf27 in syscall.Pread (fd=3, p= []uint8 = {...}, offset=0, n=0, err=...) at /usr/lib/go/src/syscall/zsyscall_linux_amd64.go:1372
#2  0x0000000000470c69 in os.(*File).pread (f=0xc42002e9a0, b= []uint8 = {...}, off=0, n=842386256064, err=...) at /usr/lib/go/src/os/file_unix.go:238
#3  0x000000000046e87c in os.(*File).ReadAt (f=0xc42002e9a0, b= []uint8 = {...}, off=0, n=842350659584, err=...) at /usr/lib/go/src/os/file.go:120
#4  0x00000000005c6f88 in debug/elf.NewFile (r=..., ~r1=0xc42002e9a0, ~r2=...) at /usr/lib/go/src/debug/elf/file.go:228
#5  0x00000000005c6ceb in debug/elf.Open (name="/dev/dri/renderD128", ~r1=0xc42220f101, ~r2=...) at /usr/lib/go/src/debug/elf/file.go:190
#6  0x000000000054137b in github.com/google/pprof/internal/binutils.(*Binutils).openELF (b=0xc420071680, name="/dev/dri/renderD128", start=139960538550272, limit=139964847157248, offset=0, ~r4=..., ~r5=...)
    at /home/paraboul/dev/nidium/Nidium/third-party/pprof/src/github.com/google/pprof/internal/binutils/binutils.go:157
#7  0x0000000000540c8a in github.com/google/pprof/internal/binutils.(*Binutils).Open (b=0xc420071680, name="/dev/dri/renderD128", start=139960538550272, limit=139964847157248, offset=0, ~r4=..., ~r5=...)
    at /home/paraboul/dev/nidium/Nidium/third-party/pprof/src/github.com/google/pprof/internal/binutils/binutils.go:134
#8  0x00000000005c0432 in github.com/google/pprof/internal/symbolizer.newMapping (prof=0xc421fb5540, obj=..., ui=..., force=false, ~r4=0x1, ~r5=...)
    at /home/paraboul/dev/nidium/Nidium/third-party/pprof/src/github.com/google/pprof/internal/symbolizer/symbolizer.go:313
#9  0x00000000005bee23 in github.com/google/pprof/internal/symbolizer.doLocalSymbolize (mode="", prof=0xc421fb5540, obj=..., ui=..., ~r4=...)
    at /home/paraboul/dev/nidium/Nidium/third-party/pprof/src/github.com/google/pprof/internal/symbolizer/symbolizer.go:122
#10 0x00000000005be579 in github.com/google/pprof/internal/symbolizer.(*Symbolizer).Symbolize (s=0xc42014c200, mode="", sources=0xc422207da0, p=0xc421fb5540, ~r3=...)
    at /home/paraboul/dev/nidium/Nidium/third-party/pprof/src/github.com/google/pprof/internal/symbolizer/symbolizer.go:77
#11 0x00000000004dd7f4 in github.com/google/pprof/internal/driver.fetchProfiles (s=0xc42200abd0, o=0xc420071620, ~r2=0x0, ~r3=...)

So it seems that for some reason, it tries to symbolize a device file (/dev/dri/renderD128), and get stuck here.

Edit:
So yes, the profiled executable is using OpenGL (through Mesa), which I guess use a DRM device (/dev/dri/renderD128) that pprof tries to symbolize.

Is there a way I can tell pprof not to symbolize this? Also, I guess that a kind of timeout would avoid that.

Without symbolization :

../tools/pprof -symbolize=None ./nidium /tmp/profile.nidium                                                                                                                         paraboul@nigiro
File: nidium
Type: cpu
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 2.83s, 100% of 2.83s total
Dropped 3 nodes (cum <= 0.01s)
Showing top 10 nodes out of 15
      flat  flat%   sum%        cum   cum%
     2.46s 86.93% 86.93%      2.66s 93.99%  [nidium]
     0.16s  5.65% 92.58%      2.32s 81.98%  [renderD128]
     0.13s  4.59% 97.17%      0.60s 21.20%  [libc-2.24.so]
     0.03s  1.06% 98.23%      0.06s  2.12%  [libglib-2.0.so.0.5000.2]
     0.02s  0.71% 98.94%      0.02s  0.71%  [ld-2.24.so]
     0.01s  0.35% 99.29%      0.02s  0.71%  [libdrm_intel.so.1.0.0]
     0.01s  0.35% 99.65%      0.05s  1.77%  [libgtk-3.so.0.2200.6]
     0.01s  0.35%   100%      0.11s  3.89%  [libpthread-2.24.so]

aalexand added a commit to aalexand/pprof that referenced this issue Jan 10, 2017
Trying to symbolize files like /dev/dri/renderD128 makes pprof hang as
it tries to read from this device file. So do not attempt the symbolization.

Skip [heap] file, too - the profile from issue google#78 has a couple samples
in the heap (perhaps some generated code) and trying to locate a file
with that name can't succeed.
aalexand added a commit to aalexand/pprof that referenced this issue Jan 10, 2017
Trying to symbolize files like /dev/dri/renderD128 makes pprof hang as
it tries to read from this device file. So do not attempt the symbolization.

Skip [heap] file, too - the profile from issue google#78 has a couple samples
in the heap (perhaps some generated code) and trying to locate a file
with that name can't succeed.

Fixes google#78.
@nlw0
Copy link

nlw0 commented Mar 14, 2024

I seem to have a similar issue, pprof hangs and it's an OpenGL application. But I don't see this device in my output. Any workarounds?

user@NV41PZ:~$ pprof -symbolize=None  myapp myapp-prof.out
File: myapp
Type: cpu
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 134.72s, 99.61% of 135.25s total
Dropped 10 nodes (cum <= 0.68s)
      flat  flat%   sum%        cum   cum%
   132.83s 98.21% 98.21%    135.25s   100%  [myapp]
     1.10s  0.81% 99.02%    135.25s   100%  [libc.so.6]
     0.46s  0.34% 99.36%      0.84s  0.62%  [libstdc++.so.6.0.30]
     0.33s  0.24% 99.61%      0.68s   0.5%  [iris_dri.so]

@aalexand
Copy link
Collaborator

@nlw0 please file a separate issue with steps and necessary data to reproduce.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants