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
 
Hash Suite for Android: free password hash cracker in your pocket
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <8ad3ada6-f719-43ca-bf16-0095be555302@oracle.com>
Date: Mon, 23 Sep 2024 18:47:54 +0100
From: Alan Maguire <alan.maguire@...cle.com>
To: Howard Chu <howardchu95@...il.com>,
        Arnaldo Carvalho de Melo <acme@...nel.org>
Cc: Adrian Hunter <adrian.hunter@...el.com>, Jiri Olsa <jolsa@...nel.org>,
        Kan Liang <kan.liang@...ux.intel.com>,
        Namhyung Kim <namhyung@...nel.org>,
        Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
        linux-perf-users@...r.kernel.org
Subject: Re: perf trace: substruct BTF based pretty printing

On 23/09/2024 18:42, Howard Chu wrote:
> Hello,
> 
> On Wed, Sep 11, 2024 at 6:29 PM Howard Chu <howardchu95@...il.com> wrote:
>>
>> Hello Arnaldo,
>>
>> On Wed, Sep 11, 2024 at 1:25 PM Arnaldo Carvalho de Melo
>> <acme@...nel.org> wrote:
>>>
>>> Hi Howard,
>>>
>>>         Not really a requirement on you to do work, just a some notes to
>>> add to our discussion/experiment on using BTF to pretty print syscall
>>> (and tracepoints/whatever) arguments:
>>>
>>> root@...ber:~# perf trace -e setitimer -p 5444 |& head -5
>>>      0.000 ( 0.017 ms): Xwayland/5444 setitimer(value: (struct __kernel_old_itimerval){})                   = 0
>>>      0.050 ( 0.004 ms): Xwayland/5444 setitimer(value: (struct __kernel_old_itimerval){})                   = 0
>>>      0.142 ( 0.005 ms): Xwayland/5444 setitimer(value: (struct __kernel_old_itimerval){})                   = 0
>>>      0.174 ( 0.004 ms): Xwayland/5444 setitimer(value: (struct __kernel_old_itimerval){})                   = 0
>>>      0.293 ( 0.004 ms): Xwayland/5444 setitimer(value: (struct __kernel_old_itimerval){})                   = 0
> 
> First of all I bypass the from_user check to make perf trace use BTF
> output instead of just printing an address:
> 
>         for (i = 0, field = sc->args; field; ++i, field = field->next) {
>                 // XXX We're only collecting pointer payloads _from_ user space
>                 /*if (!sc->arg_fmt[i].from_user)*/
>                         /*continue;*/
> 
> Got the bad output:
> 
>    500.218 ( 0.015 ms): a.out/112335 setitimer(value: (struct
> __kernel_old_itimerval){})                   = 0
> 
> But after switching on emit_zeroes from btf_dump_type_data_opts:
> 
> dump_data_opts.compact   = true;
> dump_data_opts.skip_names = !arg->trace->show_arg_names;
> dump_data_opts.emit_zeroes = true; // this
> 
> My output is good:
> 
>  96058.828 ( 0.010 ms): a.out/104347 setitimer(value: (struct
> __kernel_old_itimerval){.it_interval = (struct
> __kernel_old_timeval){.tv_sec = (__kernel_long_t)0,.tv_usec =
> (__kernel_long_t)500000,},.it_value = (struct
> __kernel_old_timeval){.tv_sec = (__kernel_long_t)0,.tv_usec =
> (__kernel_long_t)500000,},}) = 0
> 
> So I think this is btf_dump's problem... Because most of the time we
> want to omit the zeroes, but that will have the side effect of not
> being able to print the whole output. I'll figure something out.
>

One thing we could think about is if there's a way for BTF data dump to
better represent the fact that a structure is all 0s; currently we will
show "{}" since we skip emitting zeroed data, but maybe - at the
toplevel only - "{ 0 }" would be more expressive? Thanks!

Alan

> Thanks,
> Howard
>>
>> First glance, yes this is a substruct, but we should be able to
>> collect those substruct data in BPF, since it is substruct, not
>> substruct pointer. It seems to be the same -p problem we discussed
>> here:
>>
>> Before:
>> ```
>> perf $ perf trace -e open -p 3792392
>>          ? (         ):  ... [continued]: open())
>>                        = -1 ENOENT (No such file or directory)
>>          ? (         ):  ... [continued]: open())
>>                        = -1 ENOENT (No such file or directory)
>> ```
>>
>> We can see there's no output.
>>
>> After:
>> ```
>> perf $ perf trace -e open -p 3792392
>>      0.000 ( 0.123 ms): a.out/3792392 open(filename: "DINGZHEN",
>> flags: WRONLY)                             = -1 ENOENT (No such file
>> or directory)
>>   1000.398 ( 0.116 ms): a.out/3792392 open(filename: "DINGZHEN",
>> flags: WRONLY)                             = -1 ENOENT (No such file
>> or directory)
>> ```
>>
>> I will test and fix it later.
>>
>> Thanks,
>> Howard
>>
>>> root@...ber:~# strace -e setitimer -p 5444 |& head -5
>>> strace: Process 5444 attached
>>> setitimer(ITIMER_REAL, {it_interval={tv_sec=0, tv_usec=5000}, it_value={tv_sec=0, tv_usec=5000}}, NULL) = 0
>>> setitimer(ITIMER_REAL, {it_interval={tv_sec=0, tv_usec=0}, it_value={tv_sec=0, tv_usec=0}}, NULL) = 0
>>> setitimer(ITIMER_REAL, {it_interval={tv_sec=0, tv_usec=5000}, it_value={tv_sec=0, tv_usec=5000}}, NULL) = 0
>>> setitimer(ITIMER_REAL, {it_interval={tv_sec=0, tv_usec=0}, it_value={tv_sec=0, tv_usec=0}}, NULL) = 0
>>> root@...ber:~#
>>> root@...ber:~#
>>> root@...ber:~# grep -w value /sys/kernel/tracing/events/syscalls/sys_enter_rseq/format
>>> root@...ber:~# grep -w value /sys/kernel/tracing/events/syscalls/sys_enter_setitimer/format
>>>         field:struct __kernel_old_itimerval * value;    offset:24;      size:8; signed:0;
>>> print fmt: "which: 0x%08lx, value: 0x%08lx, ovalue: 0x%08lx", ((unsigned long)(REC->which)), ((unsigned long)(REC->value)), ((unsigned long)(REC->ovalue))
>>> root@...ber:~# pahole __kernel_old_itimerval
>>> struct __kernel_old_itimerval {
>>>         struct __kernel_old_timeval it_interval;         /*     0    16 */
>>>         struct __kernel_old_timeval it_value;            /*    16    16 */
>>>
>>>         /* size: 32, cachelines: 1, members: 2 */
>>>         /* last cacheline: 32 bytes */
>>> };
>>>
>>> root@...ber:~# pahole -E __kernel_old_itimerval
>>> struct __kernel_old_itimerval {
>>>         struct __kernel_old_timeval {
>>>                 /* typedef __kernel_long_t */ long int           tv_sec;                 /*     0     8 */
>>>                 /* typedef __kernel_long_t */ long int           tv_usec;                /*     8     8 */
>>>         } it_interval; /*     0    16 */
>>>         struct __kernel_old_timeval {
>>>                 /* typedef __kernel_long_t */ long int           tv_sec;                 /*    16     8 */
>>>                 /* typedef __kernel_long_t */ long int           tv_usec;                /*    24     8 */
>>>         } it_value; /*    16    16 */
>>>
>>>         /* size: 32, cachelines: 1, members: 2 */
>>>         /* last cacheline: 32 bytes */
>>> };
>>>
>>> root@...ber:~#


Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ