Re: [PATCH v2 1/3] tracing/syscalls: Rename variable 'nr' to 'syscall_nr'

[Arnaldo Carvalho de Melo <acme@kernel.org>]

Em Fri, Feb 26, 2016 at 09:24:46PM +0900, Taeung Song escreveu:
> Hi, Arnaldo
> 
> On 02/26/2016 03:42 AM, Arnaldo Carvalho de Melo wrote:
> >Em Fri, Feb 26, 2016 at 03:31:19AM +0900, Taeung Song escreveu:
> >>Hi, Arnaldo
> >>
> >>On 02/26/2016 02:57 AM, Arnaldo Carvalho de Melo wrote:
> >>>Em Fri, Feb 26, 2016 at 02:38:57AM +0900, Taeung Song escreveu:
> >>>>There is a problem about duplicated variable name i.e.
> >>>>     # cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_io_getevents/format
> >>>>     name: sys_enter_io_getevents
> >>>>     ID: 739
> >>>>     format:
> >>>>             field:unsigned short common_type; offset:0;  size:2; signed:0;
> >>>>             field:unsigned char common_flags; offset:2;  size:1; signed:0;
> >>>>             field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
> >>>>             field:int common_pid;offset:4;size:4;signed:1;
> >>>>             field:int nr;                     offset:8;  size:4; signed:1;
> >>>>             field:aio_context_t ctx_id;       offset:16; size:8; signed:0;
> >>>>             field:long min_nr;                offset:24; size:8; signed:0;
> >>>>             field:long nr;                    offset:32; size:8; signed:0;
> >>>>             field:struct io_event * events;   offset:40; size:8; signed:0;
> >>>>             field:struct timespec * timeout;  offset:48; size:8; signed:0;
> >>>>
> >>>>             print fmt: "ctx_id: 0x%08lx, min_nr: 0x%08lx, nr: 0x%08lx,
> >>>>                         events: 0x%08lx, timeout: 0x%08lx", ((unsigned long)(REC->ctx_id)),
> >>>>                         ((unsigned long)(REC->min_nr)), ((unsigned long)(REC->nr)),
> >>>>                         ((unsigned long)(REC->events)), ((unsigned long)(REC->timeout))
> >>>>
> >>>>As above 'int nr;' and 'long nr;' variables have
> >>>>duplicated name so problems are occurred in perf-script i.e.
> >>>>
> >>>>     # perf record -e syscalls:*
> >>>>     # perf script -g python
> >>>>     # perf script -s perf-script.py
> >>>>       File "perf-script.py", line 8694
> >>>>         def syscalls__sys_enter_io_getevents(event_name, context, common_cpu,
> >>>>     SyntaxError: duplicate argument 'nr' in function definition
> >>>>     Error running python script perf-script.py
> >>>
> >>>Please test this with 'perf trace', which this patch breaks, this patch
> >>>should make it understand this 3rd variation of the non common list of
> >>>fields in syscall tracepoints:
> >>
> >>OK, I will test it.
> >>But IMHO, I think the bottom change has a problem.
> >>Because sys_enter_io_getevent() has a argument 'long nr'.
> >
> >It doesn't matter
> >
> >>So this if statement must not have strcmp(sc->args->name, "nr") == 0.
> >
> >This is checking for the first variable, if that has that name, it
> >should be discarded, as in the past it wasn't there, so for the tool to
> >work on kernels with "nr" as the first (for the syscall number) variable
> >and for kernels without it, we must check and discard.
> >
> >Now we must check and discard the first "nr" (for kernels with this
> >meaning the syscall number) and also if it is called "syscall_nr").
> >The other fields are taken as the syscall arguments, in the order that
> >they come, that is what what we will match with what is in the
> >raw_syscalls:sys_enter args array:
> >
> >[root@jouet ~]# cat
> >/sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/format
> >name: sys_enter
> >ID: 17
> >format:
> >	field:unsigned short common_type;	offset:0;	size:2; signed:0;
> >	field:unsigned char common_flags;	offset:2;	size:1; signed:0;
> >	field:unsigned char common_preempt_count;	offset:3; size:1;	signed:0;
> >	field:int common_pid;	offset:4;	size:4;	signed:1;
> >
> >	field:long id;	offset:8;	size:8;	signed:1;
> >	field:unsigned long args[6];	offset:16;	size:48; signed:0;
> >
> >print fmt: "NR %ld (%lx, %lx, %lx, %lx, %lx, %lx)", REC->id,
> >REC->args[0], REC->args[1], REC->args[2], REC->args[3], REC->args[4],
> >REC->args[5]
> >[root@jouet ~]#
> >
> >>+ if (sc->args && strcmp(sc->args->name, "syscall_nr") == 0) {
> >>
> >>I think the above instance seem better than the bottom.
> >>
> >>+	if (sc->args && (strcmp(sc->args->name, "syscall_nr") ||
> >>strcmp(sc->args->name, "nr")) == 0) {
> >
> >Right in this 'if' body we do:
> >
> >		sc->args = sc->args->next;
> >		sc->nr_args--;
> >
> >something like that.
> >
> >- Arnaldo
> >
> >>But I'll test again with perf-trace.
> >
> >Right, look at the output of 'perf trace' before and after, so that you
> >can check if, say, we're using that syscall_nr value as the fd for the
> >'write' syscall ('fd' comes right after 'nr'/'syscall_nr').
> >
> 
> Sorry, I'm late.
> 
> I tested perf-trace with the bottom change.
> (does not rename it to '__syscall_nr' on kernel)

"With this change:"

> 
> +        if (sc->args && (strcmp(sc->args->name, "__syscall_nr") ||
> strcmp(sc->args->name, "nr")) == 0) {
>                  sc->args = sc->args->next;
>                  --sc->nr_args;
>          }
> 
> But there are some problems as below.

Right, there is a silly error, we have to test both strcmp(), checking
if one of them is equal to zero, i.e. if there was a match.

- Arnaldo
 
> 0.322 ( 0.012 ms): a.out/27045 write(nr: 3, fd: 4196046, buf: 0x4, count:
> 2140 ) = 4
> 
> So, I modified the above change. (I'll send it as new patch)
> And then I tested again as below
> 
> 0.345 ( 0.016 ms): a.out/27695 write(fd: 3, buf: 0x4006ce, count: 4 ) = 4
> 
> And I tested perf-trace with renamed '__syscall_nr' on modified kernel.
> Everything is ok for aught I know.
> 
> 0.345 ( 0.016 ms): a.out/27695 write(fd: 3, buf: 0x4006ce, count: 4 ) = 4
> 
> I'm writing another patchset. I'll send it soon.
> 
> Thanks,
> Taeung