| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <ZdYxHYBftzWcQAZt@x1>
Date: Wed, 21 Feb 2024 14:21:33 -0300
From: Arnaldo Carvalho de Melo <acme@...nel.org>
To: Ian Rogers <irogers@...gle.com>
Cc: Namhyung Kim <namhyung@...nel.org>,
Adrian Hunter <adrian.hunter@...el.com>,
Jiri Olsa <jolsa@...nel.org>,
Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
linux-perf-users@...r.kernel.org
Subject: Re: [PATCH 1/1] perf trace: Collect sys_nanosleep first argument
On Wed, Feb 21, 2024 at 09:15:01AM -0800, Ian Rogers wrote:
> On Wed, Feb 21, 2024 at 9:04 AM Arnaldo Carvalho de Melo
> <acme@...nel.org> wrote:
> >
> > That is a 'struct timespec' passed from userspace to the kernel as we
> > can see with a system wide syscall tracing:
> >
> > root@...ber:~# perf trace -e nanosleep
> > 0.000 (10.102 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 38.924 (10.077 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 100.177 (10.107 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 139.171 (10.063 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 200.603 (10.105 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 239.399 (10.064 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 300.994 (10.096 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 339.584 (10.067 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 401.335 (10.057 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 439.758 (10.166 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 501.814 (10.110 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 539.983 (10.227 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 602.284 (10.199 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 640.208 (10.105 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 702.662 (10.163 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 740.440 (10.107 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > 802.993 (10.159 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0
> > ^Croot@...ber:~# strace -p 9150 -e nanosleep
> >
> > If we then use the ptrace method to look at that podman process:
> >
> > root@...ber:~# strace -p 9150 -e nanosleep
> > strace: Process 9150 attached
> > nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0
> > nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0
> > nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0
> > nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0
> > nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0
> > nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0
> > nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0
> > ^Cstrace: Process 9150 detached
> > root@...ber:~#
> >
> > With some changes we can get something closer to the strace output,
> > still in system wide mode:
> >
> > root@...ber:~# perf config trace.show_arg_names=false
> > root@...ber:~# perf config trace.show_duration=false
> > root@...ber:~# perf config trace.show_timestamp=false
> > root@...ber:~# perf config trace.show_zeros=true
> > root@...ber:~# perf config trace.args_alignment=0
> > root@...ber:~# perf trace -e nanosleep --max-events=10
> > podman/2195174 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0
> > podman/9150 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0
> > podman/2195174 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0
> > podman/9150 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0
> > podman/2195174 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0
> > podman/9150 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0
> > podman/2195174 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0
> > podman/9150 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0
> > podman/2195174 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0
> > podman/9150 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0
> > root@...ber:~#
> > root@...ber:~# perf config
> > trace.show_arg_names=false
> > trace.show_duration=false
> > trace.show_timestamp=false
> > trace.show_zeros=true
> > trace.args_alignment=0
> > root@...ber:~# cat ~/.perfconfig
> > # this file is auto-generated.
> > [trace]
> > show_arg_names = false
> > show_duration = false
> > show_timestamp = false
> > show_zeros = true
> > args_alignment = 0
> > root@...ber:~#
> >
> > This will not get reused by any other syscall as nanosleep is the only
> > one to have as its first argument a 'struct timespec" pointer argument
> > passed from userspace to the kernel:
> >
> > root@...ber:~# grep timespec /sys/kernel/tracing/events/syscalls/sys_enter_*/format | grep offset:16
> > /sys/kernel/tracing/events/syscalls/sys_enter_nanosleep/format: field:struct __kernel_timespec * rqtp; offset:16; size:8; signed:0;
> > root@...ber:~#
> >
> > BTF based pretty printing will simplify all this, but then lets just get
> > the low hanging fruits first.
> >
> > Cc: Adrian Hunter <adrian.hunter@...el.com>
> > Cc: Ian Rogers <irogers@...gle.com>
> > Cc: Jiri Olsa <jolsa@...nel.org>
> > Cc: Namhyung Kim <namhyung@...nel.org>
> > Signed-off-by: Arnaldo Carvalho de Melo <acme@...hat.com>
>
> v2? https://lore.kernel.org/lkml/Zbq72dJRpOlfRWnf@kernel.org/
Nope, I thought I hadn't submitted and when doing a
git rebase perf-tools-next/perf-tools-next
It was rebased, so I thought I really hadn't submitted it and sent it.
- Arnaldo
Powered by blists - more mailing lists