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

From: Jiri Olsa
Date: Tue Jan 16 2018 - 10:06:40 EST


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@xxxxxxxxxx>

the duplicated events are gone.. solution looks ok to me

Reviewed-and-Tested-by: Jiri Olsa <jolsa@xxxxxxxxxx>

jirka

> ---
> kernel/events/core.c | 2 ++
> 1 file changed, 2 insertions(+)
>
> diff --git a/kernel/events/core.c b/kernel/events/core.c
> index 4df5b69..a199c03 100644
> --- a/kernel/events/core.c
> +++ b/kernel/events/core.c
> @@ -7924,6 +7924,8 @@ void perf_tp_event(u16 event_type, u64 count, void *record, int entry_size,
> continue;
> if (event->attr.config != entry->type)
> continue;
> + if (event->cpu != task_cpu(task) && event->cpu != -1)
> + continue;
> if (perf_tp_event_match(event, &data, regs))
> perf_swevent_event(event, count, &data, regs);
> }
> --
> 1.8.3.1
>