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

From: Taeung Song
Date: Fri Feb 26 2016 - 07:24:56 EST


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)

+ 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.

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