linux-kernel - Re: [PATCH v3] perf/trace : Fix repetitious traces of perf on tracepoint

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: <20180117133342.GH30880@kernel.org>
Date:   Wed, 17 Jan 2018 10:33:42 -0300
From:   Arnaldo Carvalho de Melo <acme@...nel.org>
To:     Jiri Olsa <jolsa@...hat.com>
Cc:     Cheng Jian <cj.chengjian@...wei.com>, peterz@...radead.org,
        mingo@...hat.com, alexander.shishkin@...ux.intel.com,
        namhyung@...nel.org, xiexiuqi@...wei.com, huawei.libin@...wei.com,
        wangnan0@...wei.com, linux-kernel@...r.kernel.org
Subject: Re: [PATCH v3] perf/trace : Fix repetitious traces of perf on
 tracepoint

Em Tue, Jan 16, 2018 at 04:06:22PM +0100, Jiri Olsa escreveu:
> On Tue, Jan 16, 2018 at 08:40:38PM +0800, Cheng Jian wrote:
> > When i use perf to trace the sched_wakeup_new tracepoint, there is
> > a bug that output the same event repetitiously.
> > It can be reproduced by :
> > 
> > 	#./test_fork
> > 		parent pid : 1059
> > 		child pid : 1060
> > 	#perf record -e sched:sched_wakeup_new -p 1060
> > 
> > test_fork is an demo that can generating wakeup_new event, parent
> > process does nothing but fork a child process, and then they both
> > quit.
> > 
> > There are 4 processors in this machine. before this patch,
> > perf script(perf-1058, parent-1059, child-1060) :
> > 
> >         test_fork  1059 [001]    62.913689: sched:sched_wakeup_new: comm=test_fork pid=1060 prio=120 target_cpu=002
> >         test_fork  1059 [001]    62.913698: sched:sched_wakeup_new: comm=test_fork pid=1060 prio=120 target_cpu=002
> >         test_fork  1059 [001]    62.913705: sched:sched_wakeup_new: comm=test_fork pid=1060 prio=120 target_cpu=002
> > 
> > but ftrace report this event only once :
> > 
> > 	test_fork-1059  [002] d...   62.913680: sched_wakeup_new: comm=test_fork pid=1060 prio=120 target_cpu=002
> > 
> > perf script print the same wakeup_new event multiple times.
> > 
> > These events which trigger this issue all specify a target process.
> > commit e6dab5ffab59 ("perf/trace: Add ability to set a target task
> > for events") has designed a method to trace these events. For
> > example, the sched_wakeup and sched_wakeup_new tracepoint will be
> > caught when the current task wakeup a target task.
> > 
> > These events are registered as per cpu most of the time and attached
> > to the task too, we will get all of them from the perf_event_context
> > of this task, they will be matched success but are all the same event.
> > So check the cpu number of this event to avoid matching them multiple
> > times.
> > 
> > after this patch, perf script(parent-1040, child-1041):
> > 
> > 	test_fork  1040 [002]    36.536079: sched:sched_wakeup_new: comm=test_fork pid=1041 prio=120 target_cpu=003
> > 
> > It will match it only once for tracing task(child-1041).
> > 
> > Signed-off-by: Cheng Jian <cj.chengjian@...wei.com>
> 
> the duplicated events are gone.. solution looks ok to me
> 
> Reviewed-and-Tested-by: Jiri Olsa <jolsa@...nel.org>

I noticed that in the past as well, will try to test this too.

- Arnaldo