* Bug with 'perf script --symfs'?
@ 2024-07-08 7:50 Ze Xia
2024-07-12 20:13 ` Namhyung Kim
0 siblings, 1 reply; 2+ messages in thread
From: Ze Xia @ 2024-07-08 7:50 UTC (permalink / raw)
To: Peter Zijlstra, Ingo Molnar, Arnaldo Carvalho de Melo,
Namhyung Kim
Cc: linux-perf-users
Hi,
I think I found that `perf script --symfs` option and automatic namespace attaching seems to conflict.
Environment: kernel version `6.5.0-41-generic`, distribution `ubuntu22.04`, arch `x86_64`
Behavior: In `perf script`, if a process is inside another namespace than the default (e.g. inside a docker container), perf script will try to attach to that namespace to read debug info. However, if `--symfs` option is provided, then it will search for debug files with `symfs` prefix *inside the namespace*. Usually the symfs directory isn't present in the namespace, thus I see this behavior as inappropriate.
To reproduce: I run commands below on a ubuntu machine with docker installed. Any glibc based distro without musl installed should also reproduce the issue, as musl isn't present at host but present in the docker container.
In one terminal (create the process to be profiled):
$ docker run -it --rm --name test-symfs --net=host alpine
# now we're inside the container
$ apk add musl-dbg
$ dd if=/dev/zero of=/dev/null
# it stucks here, don't kill it yet
In another terminal (profiling):
$ perf record -a -g sleep 1
$ perf script > success.perf
$ grep musl success.perf | head -n 10
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
Thanks to automatic namespace attaching, this works. Problem comes with `--symfs` option:
$ docker cp test-symfs:/ ./symfs
$ perf script --symfs ./symfs > fail.perf
$ grep musl fail.perf | head -n 10
75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
We can't find the symbol any more.
Rerun the `perf script` with `strace`:
$ strace -o fail.strace perf script --symfs ./symfs > fail.perf
$ grep musl fail.strace | grep stat
newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", 0x7ffce53b7030, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", 0x7ffce53b2140, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "./symfs//usr/lib/debug/lib/ld-musl-x86_64.so.1.debug", 0x7ffce53b41a0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "./symfs//usr/lib/debug/lib/ld-musl-x86_64.so.1", 0x7ffce53b41a0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", 0x7ffce53b41a0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "./symfs//lib/.debug/ld-musl-x86_64.so.1", 0x7ffce53b41a0, 0) = -1 ENOENT (No such file or directory)
Note how `./symfs/` is included in all those calls.
Rerun the success case with strace:
$ strace -o success.strace perf script > success.perf
$ grep musl success.strace | grep stat
newfstatat(AT_FDCWD, "/lib/ld-musl-x86_64.so.1", {st_mode=S_IFREG|0755, st_size=649832, ...}, 0) = 0
newfstatat(AT_FDCWD, "ld-musl-x86_64.so.1.debug", 0x7ffe0949a350, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/lib/ld-musl-x86_64.so.1.debug", 0x7ffe0949a350, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/lib/.debug/ld-musl-x86_64.so.1.debug", 0x7ffe0949a350, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/usr/lib/debug/lib/ld-musl-x86_64.so.1.debug", {st_mode=S_IFREG|0755, st_size=2892848, ...}, 0) = 0
newfstatat(AT_FDCWD, "/usr/lib/debug/lib/ld-musl-x86_64.so.1.debug", {st_mode=S_IFREG|0755, st_size=2892848, ...}, 0) = 0
Note that the calls without `./symfs/` worked, because perf is inside the container's namespace.
To prove that our symfs indeed contains the debug info, we can stop the `dd` command inside docker and rerun `perf script` without `--symfs` option, it also succeeds:
$ strace -o success2.strace perf script --symfs ./symfs > success2.perf
$ grep musl success2.perf | head -n 10
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
$ grep musl success2.strace | grep stat
newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", 0x7ffe14d3d6a0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", {st_mode=S_IFREG|0755, st_size=649832, ...}, 0) = 0
newfstatat(AT_FDCWD, "ld-musl-x86_64.so.1.debug", 0x7ffe14d387a0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1.debug", 0x7ffe14d387a0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "./symfs//lib/.debug/ld-musl-x86_64.so.1.debug", 0x7ffe14d387a0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/usr/lib/debug./symfs//lib/ld-musl-x86_64.so.1.debug", 0x7ffe14d387a0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "./symfs//usr/lib/debug/lib/ld-musl-x86_64.so.1.debug", {st_mode=S_IFREG|0755, st_size=2892848, ...}, 0) = 0
newfstatat(AT_FDCWD, "./symfs//usr/lib/debug/lib/ld-musl-x86_64.so.1", 0x7ffe14d3a810, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", {st_mode=S_IFREG|0755, st_size=649832, ...}, 0) = 0
As the `dd` process is dead now, `perf script` will not attach to its namespace. It reads debug info from our symfs, and it worked.
Expected Behavior: `symfs` is prefixed only if no namespace attaching happened. Or, to be conversative, try twice, with or without `--symfs`.
Kind regards
Ze Xia
^ permalink raw reply [flat|nested] 2+ messages in thread
* Re: Bug with 'perf script --symfs'?
2024-07-08 7:50 Bug with 'perf script --symfs'? Ze Xia
@ 2024-07-12 20:13 ` Namhyung Kim
0 siblings, 0 replies; 2+ messages in thread
From: Namhyung Kim @ 2024-07-12 20:13 UTC (permalink / raw)
To: Ze Xia
Cc: Peter Zijlstra, Ingo Molnar, Arnaldo Carvalho de Melo,
linux-perf-users
Hello,
On Mon, Jul 08, 2024 at 03:50:17PM +0800, Ze Xia wrote:
> Hi,
>
> I think I found that `perf script --symfs` option and automatic namespace attaching seems to conflict.
>
> Environment: kernel version `6.5.0-41-generic`, distribution `ubuntu22.04`, arch `x86_64`
>
> Behavior: In `perf script`, if a process is inside another namespace than the default (e.g. inside a docker container), perf script will try to attach to that namespace to read debug info. However, if `--symfs` option is provided, then it will search for debug files with `symfs` prefix *inside the namespace*. Usually the symfs directory isn't present in the namespace, thus I see this behavior as inappropriate.
>
> To reproduce: I run commands below on a ubuntu machine with docker installed. Any glibc based distro without musl installed should also reproduce the issue, as musl isn't present at host but present in the docker container.
>
> In one terminal (create the process to be profiled):
>
> $ docker run -it --rm --name test-symfs --net=host alpine
> # now we're inside the container
> $ apk add musl-dbg
> $ dd if=/dev/zero of=/dev/null
> # it stucks here, don't kill it yet
>
> In another terminal (profiling):
>
> $ perf record -a -g sleep 1
> $ perf script > success.perf
> $ grep musl success.perf | head -n 10
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
>
> Thanks to automatic namespace attaching, this works. Problem comes with `--symfs` option:
>
> $ docker cp test-symfs:/ ./symfs
> $ perf script --symfs ./symfs > fail.perf
> $ grep musl fail.perf | head -n 10
> 75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 [unknown] (/lib/ld-musl-x86_64.so.1)
>
> We can't find the symbol any more.
>
> Rerun the `perf script` with `strace`:
>
> $ strace -o fail.strace perf script --symfs ./symfs > fail.perf
> $ grep musl fail.strace | grep stat
> newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", 0x7ffce53b7030, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", 0x7ffce53b2140, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "./symfs//usr/lib/debug/lib/ld-musl-x86_64.so.1.debug", 0x7ffce53b41a0, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "./symfs//usr/lib/debug/lib/ld-musl-x86_64.so.1", 0x7ffce53b41a0, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", 0x7ffce53b41a0, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "./symfs//lib/.debug/ld-musl-x86_64.so.1", 0x7ffce53b41a0, 0) = -1 ENOENT (No such file or directory)
>
> Note how `./symfs/` is included in all those calls.
>
> Rerun the success case with strace:
>
> $ strace -o success.strace perf script > success.perf
> $ grep musl success.strace | grep stat
> newfstatat(AT_FDCWD, "/lib/ld-musl-x86_64.so.1", {st_mode=S_IFREG|0755, st_size=649832, ...}, 0) = 0
> newfstatat(AT_FDCWD, "ld-musl-x86_64.so.1.debug", 0x7ffe0949a350, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "/lib/ld-musl-x86_64.so.1.debug", 0x7ffe0949a350, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "/lib/.debug/ld-musl-x86_64.so.1.debug", 0x7ffe0949a350, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "/usr/lib/debug/lib/ld-musl-x86_64.so.1.debug", {st_mode=S_IFREG|0755, st_size=2892848, ...}, 0) = 0
> newfstatat(AT_FDCWD, "/usr/lib/debug/lib/ld-musl-x86_64.so.1.debug", {st_mode=S_IFREG|0755, st_size=2892848, ...}, 0) = 0
>
> Note that the calls without `./symfs/` worked, because perf is inside the container's namespace.
>
> To prove that our symfs indeed contains the debug info, we can stop the `dd` command inside docker and rerun `perf script` without `--symfs` option, it also succeeds:
>
> $ strace -o success2.strace perf script --symfs ./symfs > success2.perf
> $ grep musl success2.perf | head -n 10
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> 75fbf5143992 __cp_end+0x0 (/lib/ld-musl-x86_64.so.1)
> $ grep musl success2.strace | grep stat
> newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", 0x7ffe14d3d6a0, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", {st_mode=S_IFREG|0755, st_size=649832, ...}, 0) = 0
> newfstatat(AT_FDCWD, "ld-musl-x86_64.so.1.debug", 0x7ffe14d387a0, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1.debug", 0x7ffe14d387a0, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "./symfs//lib/.debug/ld-musl-x86_64.so.1.debug", 0x7ffe14d387a0, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "/usr/lib/debug./symfs//lib/ld-musl-x86_64.so.1.debug", 0x7ffe14d387a0, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "./symfs//usr/lib/debug/lib/ld-musl-x86_64.so.1.debug", {st_mode=S_IFREG|0755, st_size=2892848, ...}, 0) = 0
> newfstatat(AT_FDCWD, "./symfs//usr/lib/debug/lib/ld-musl-x86_64.so.1", 0x7ffe14d3a810, 0) = -1 ENOENT (No such file or directory)
> newfstatat(AT_FDCWD, "./symfs//lib/ld-musl-x86_64.so.1", {st_mode=S_IFREG|0755, st_size=649832, ...}, 0) = 0
>
> As the `dd` process is dead now, `perf script` will not attach to its namespace. It reads debug info from our symfs, and it worked.
>
> Expected Behavior: `symfs` is prefixed only if no namespace attaching happened. Or, to be conversative, try twice, with or without `--symfs`.
I'm not sure if it's the reasonable expectation. With --symfs, you can
expect it will prefix the path to all DSO paths. The namespace makes
things complicated but I think the symfs behaivor is simple. There's no
guarantee if the symfs is always out of the namespace, right?
Thanks,
Namhyung
^ permalink raw reply [flat|nested] 2+ messages in thread
end of thread, other threads:[~2024-07-12 20:14 UTC | newest]
Thread overview: 2+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-07-08 7:50 Bug with 'perf script --symfs'? Ze Xia
2024-07-12 20:13 ` Namhyung Kim
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).