* perf trace: substruct BTF based pretty printing
@ 2024-09-11 20:25 Arnaldo Carvalho de Melo
2024-09-12 1:29 ` Howard Chu
0 siblings, 1 reply; 5+ messages in thread
From: Arnaldo Carvalho de Melo @ 2024-09-11 20:25 UTC (permalink / raw)
To: Howard Chu
Cc: Adrian Hunter, Alan Maguire, Jiri Olsa, Kan Liang, Namhyung Kim,
Linux Kernel Mailing List, linux-perf-users
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@number:~# 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
root@number:~# 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@number:~#
root@number:~#
root@number:~# grep -w value /sys/kernel/tracing/events/syscalls/sys_enter_rseq/format
root@number:~# 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@number:~# 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@number:~# 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@number:~#
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: perf trace: substruct BTF based pretty printing
2024-09-11 20:25 perf trace: substruct BTF based pretty printing Arnaldo Carvalho de Melo
@ 2024-09-12 1:29 ` Howard Chu
2024-09-23 17:42 ` Howard Chu
0 siblings, 1 reply; 5+ messages in thread
From: Howard Chu @ 2024-09-12 1:29 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Adrian Hunter, Alan Maguire, Jiri Olsa, Kan Liang, Namhyung Kim,
Linux Kernel Mailing List, linux-perf-users
Hello Arnaldo,
On Wed, Sep 11, 2024 at 1:25 PM Arnaldo Carvalho de Melo
<acme@kernel.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@number:~# 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 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@number:~# 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@number:~#
> root@number:~#
> root@number:~# grep -w value /sys/kernel/tracing/events/syscalls/sys_enter_rseq/format
> root@number:~# 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@number:~# 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@number:~# 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@number:~#
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: perf trace: substruct BTF based pretty printing
2024-09-12 1:29 ` Howard Chu
@ 2024-09-23 17:42 ` Howard Chu
2024-09-23 17:47 ` Alan Maguire
0 siblings, 1 reply; 5+ messages in thread
From: Howard Chu @ 2024-09-23 17:42 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Adrian Hunter, Alan Maguire, Jiri Olsa, Kan Liang, Namhyung Kim,
Linux Kernel Mailing List, linux-perf-users
Hello,
On Wed, Sep 11, 2024 at 6:29 PM Howard Chu <howardchu95@gmail.com> wrote:
>
> Hello Arnaldo,
>
> On Wed, Sep 11, 2024 at 1:25 PM Arnaldo Carvalho de Melo
> <acme@kernel.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@number:~# 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.
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@number:~# 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@number:~#
> > root@number:~#
> > root@number:~# grep -w value /sys/kernel/tracing/events/syscalls/sys_enter_rseq/format
> > root@number:~# 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@number:~# 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@number:~# 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@number:~#
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: perf trace: substruct BTF based pretty printing
2024-09-23 17:42 ` Howard Chu
@ 2024-09-23 17:47 ` Alan Maguire
2024-09-23 18:17 ` Howard Chu
0 siblings, 1 reply; 5+ messages in thread
From: Alan Maguire @ 2024-09-23 17:47 UTC (permalink / raw)
To: Howard Chu, Arnaldo Carvalho de Melo
Cc: Adrian Hunter, Jiri Olsa, Kan Liang, Namhyung Kim,
Linux Kernel Mailing List, linux-perf-users
On 23/09/2024 18:42, Howard Chu wrote:
> Hello,
>
> On Wed, Sep 11, 2024 at 6:29 PM Howard Chu <howardchu95@gmail.com> wrote:
>>
>> Hello Arnaldo,
>>
>> On Wed, Sep 11, 2024 at 1:25 PM Arnaldo Carvalho de Melo
>> <acme@kernel.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@number:~# 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@number:~# 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@number:~#
>>> root@number:~#
>>> root@number:~# grep -w value /sys/kernel/tracing/events/syscalls/sys_enter_rseq/format
>>> root@number:~# 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@number:~# 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@number:~# 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@number:~#
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: perf trace: substruct BTF based pretty printing
2024-09-23 17:47 ` Alan Maguire
@ 2024-09-23 18:17 ` Howard Chu
0 siblings, 0 replies; 5+ messages in thread
From: Howard Chu @ 2024-09-23 18:17 UTC (permalink / raw)
To: Alan Maguire
Cc: Arnaldo Carvalho de Melo, Adrian Hunter, Jiri Olsa, Kan Liang,
Namhyung Kim, Linux Kernel Mailing List, linux-perf-users
Hello Alan,
On Mon, Sep 23, 2024 at 10:48 AM Alan Maguire <alan.maguire@oracle.com> wrote:
>
> On 23/09/2024 18:42, Howard Chu wrote:
> > Hello,
> >
> > On Wed, Sep 11, 2024 at 6:29 PM Howard Chu <howardchu95@gmail.com> wrote:
> >>
> >> Hello Arnaldo,
> >>
> >> On Wed, Sep 11, 2024 at 1:25 PM Arnaldo Carvalho de Melo
> >> <acme@kernel.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@number:~# 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!
I think if the struct is filled with 0, showing "{ 0 }" is a really good idea.
Thanks,
Howard
>
> 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@number:~# 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@number:~#
> >>> root@number:~#
> >>> root@number:~# grep -w value /sys/kernel/tracing/events/syscalls/sys_enter_rseq/format
> >>> root@number:~# 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@number:~# 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@number:~# 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@number:~#
>
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2024-09-23 18:17 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-09-11 20:25 perf trace: substruct BTF based pretty printing Arnaldo Carvalho de Melo
2024-09-12 1:29 ` Howard Chu
2024-09-23 17:42 ` Howard Chu
2024-09-23 17:47 ` Alan Maguire
2024-09-23 18:17 ` Howard Chu
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).