[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <56D04CC7.4010605@gmail.com>
Date: Fri, 26 Feb 2016 22:01:59 +0900
From: Taeung Song <treeze.taeung@...il.com>
To: Arnaldo Carvalho de Melo <arnaldo.melo@...il.com>
Cc: Steven Rostedt <rostedt@...dmis.org>,
Ingo Molnar <mingo@...hat.com>, Jiri Olsa <jolsa@...nel.org>,
Namhyung Kim <namhyung@...nel.org>,
linux-kernel@...r.kernel.org, Thomas Gleixner <tglx@...utronix.de>,
Lai Jiangshan <jiangshanlai@...il.com>
Subject: Re: [PATCH v2 1/3] tracing/syscalls: Rename variable 'nr' to
'syscall_nr'
On 02/26/2016 09:24 PM, Taeung Song wrote:
> 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@...et ~]# 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@...et ~]#
>>
>>> + 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.
>
[Result of perf-trace test about exception handling for 'nr' or
'__syscall_nr']
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 20916dd..a252f3a 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -1724,8 +1724,12 @@ static int trace__read_syscall_info(struct trace
*trace, int id)
sc->args = sc->tp_format->format.fields;
sc->nr_args = sc->tp_format->format.nr_fields;
- /* drop nr field - not relevant here; does not exist on older
kernels */
- if (sc->args && strcmp(sc->args->name, "nr") == 0) {
+ /*
+ * We need to check and discard the first variable '__syscall_nr'
+ * or 'nr' that mean the syscall number. It is needless here.
+ * So drop '__syscall_nr' or 'nr' field but does not exist on
older kernels.
+ */
+ if (sc->args && (!strcmp(sc->args->name, "__syscall_nr") ||
!strcmp(sc->args->name, "nr"))) {
sc->args = sc->args->next;
--sc->nr_args;
}
Case 1) => "original environment"
kernel : has 'nr' (4.2.0-30-generic)
builtin-trace.c : not modified
# perf trace ./a.out
...(omitted)...
0.369 ( 0.099 ms): a.out/3790 write(fd: 3, buf: 0x4006ce, count: 4
) = 4
...(omitted)...
Case 2)
kernel : has 'nr' (4.2.0-30-generic)
builtin-trace.c : modified
# perf trace ./a.out
0.269 ( 0.012 ms): a.out/4488 write(fd: 3, buf: 0x4006ce, count: 4
) = 4
Case 3) => "has some problems"
kernel : has '__syscall_nr' (4.5.0-rc4+)
builtin-trace.c : not modified
# perf trace ./a.out
0.288 ( 0.009 ms): a.out/4452 write(__syscall_nr: 3, fd: 4196046,
buf: 0x4, count: 2140 ) = 4
Case 4) => "final environment"
kernel : has '__syscall_nr' (4.5.0-rc4+)
builtin-trace.c : modified (for '__syscall_nr')
# perf trace ./a.out
0.334 ( 0.012 ms): a.out/5517 write(fd: 3, buf: 0x4006ce, count: 4
) = 4
I'll send modified patchset soon.
Thanks,
Taeung
Powered by blists - more mailing lists