Messages in this thread | | | Date | Mon, 15 Jan 2018 13:31:57 +0100 | From | Peter Zijlstra <> | Subject | Re: [PATCH] perf/trace : Fix repetitious traces of perf on tracepoint 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 : |
| |
On Mon, Jan 15, 2018 at 08:33:53PM +0800, Cheng Jian wrote: > perf record -e sched:sched_wakeup_new ./bug_fork > > bug_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) : > > bug_fork 1059 [001] 62.913666: sched:sched_wakeup_new: > comm=bug_fork pid=1060 prio=120 target_cpu=002 > bug_fork 1059 [001] 62.913680: sched:sched_wakeup_new: > comm=bug_fork pid=1060 prio=120 target_cpu=002 > bug_fork 1059 [001] 62.913689: sched:sched_wakeup_new: > comm=bug_fork pid=1060 prio=120 target_cpu=002 > bug_fork 1059 [001] 62.913698: sched:sched_wakeup_new: > comm=bug_fork pid=1060 prio=120 target_cpu=002 > bug_fork 1059 [001] 62.913705: sched:sched_wakeup_new: > comm=bug_fork pid=1060 prio=120 target_cpu=002
Please don't wrap that, that's unreadable
> > but ftrace report this event only once : > > bug_fork-1059 [002] d... 62.913666: sched_wakeup_new: > comm=bug_fork pid=1060 prio=120 target_cpu=002 > > perf script print 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. If we trace both > of them and task(waken) != current(wakee), it will match this event > at the beginning for tracing current task, and then match again for > tracing the waken task. But these events are registered at all cpus > most of the time, so these events will be matched nr_cpu times > in this branch. > > We just forcus on the task thread here, so check the cpu number of > this event and task. > > after this patch, perf script(perf-1039, parent-1040, child-1041): > > bug_fork 1040 [002] 36.535963: sched:sched_wakeup_new: > comm=bug_fork pid=1041 prio=120 target_cpu=003 > bug_fork 1040 [002] 36.536079: sched:sched_wakeup_new: > comm=bug_fork pid=1041 prio=120 target_cpu=003 > > match it twice, an match for tracing current(parent) and an match > for task(child).
So what is the bug? The parent gets one, the child gets one, that's correct, no?
| |