Skip to content

Commit

Permalink
perf tools: Fix trace events storms due to weight demux
Browse files Browse the repository at this point in the history
Trace events have a period (weight) of 1 by default. This can be
overriden on events definition by using the __perf_count() macro.

For example, the sched_stat_runtime() is weighted with the runtime of
the task that fired the event.

By default, perf handles such weighted event by dividing it into
individual events carrying a weight of 1. For example if
sched_stat_runtime is fired and the task has run 5000000 nsecs, perf
divides it into 5000000 events in the buffer.

This behaviour makes weighted events unusable because they quickly
fullfill the buffers and we lose most events.

The commit 5d81e5c ("events: Don't
divide events if it has field period") solves this problem by sending
only one event when PERF_SAMPLE_PERIOD flag is set. The weight is
carried in the sample itself such that we don't need to demultiplex it
anymore.

This patch provides the last missing piece to use this feature by
setting PERF_SAMPLE_PERIOD from perf tools when we deal with trace
events.

Before:
	$ ./perf record -e sched:* -a sleep 1
	[ perf record: Woken up 3 times to write data ]
	[ perf record: Captured and wrote 1.619 MB perf.data (~70749 samples) ]
	Warning:
	Processed 16909 events and lost 1 chunks!

	Check IO/CPU overload!

	$ ./perf script
	perf  1894 [003]   824.898327: sched_migrate_task: comm=perf pid=1898 prio=120 orig_cpu=2 dest_cpu=0
	perf  1894 [003]   824.898335: sched_stat_sleep: comm=perf pid=1898 delay=113179500 [ns]
	perf  1894 [003]   824.898336: sched_stat_sleep: comm=perf pid=1898 delay=113179500 [ns]
	perf  1894 [003]   824.898337: sched_stat_sleep: comm=perf pid=1898 delay=113179500 [ns]
	perf  1894 [003]   824.898338: sched_stat_sleep: comm=perf pid=1898 delay=113179500 [ns]
	perf  1894 [003]   824.898339: sched_stat_sleep: comm=perf pid=1898 delay=113179500 [ns]
	perf  1894 [003]   824.898340: sched_stat_sleep: comm=perf pid=1898 delay=113179500 [ns]
	perf  1894 [003]   824.898341: sched_stat_sleep: comm=perf pid=1898 delay=113179500 [ns]
	[...]

After:
	$ ./perf record -e sched:* -a sleep 1
	[ perf record: Woken up 1 times to write data ]
	[ perf record: Captured and wrote 0.074 MB perf.data (~3228 samples) ]

	$ ./perf script

	perf  1461 [000]   554.286957: sched_migrate_task: comm=perf pid=1465 prio=120 orig_cpu=3 dest_cpu=1
	perf  1461 [000]   554.286964: sched_stat_sleep: comm=perf pid=1465 delay=133047190 [ns]
	perf  1461 [000]   554.286967: sched_wakeup: comm=perf pid=1465 prio=120 success=1 target_cpu=001
	swapper     0 [001]   554.286976: sched_stat_wait: comm=perf pid=1465 delay=0 [ns]
	swapper     0 [001]   554.286983: sched_switch: prev_comm=swapper/1 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=perf
	[...]

Signed-off-by: Frederic Weisbecker <[email protected]>
Cc: David Ahern <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Jiri Olsa <[email protected]>
Cc: Namhyung Kim <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
  • Loading branch information
fweisbec authored and acmel committed Jul 25, 2012
1 parent 8760db7 commit 0983cc0
Show file tree
Hide file tree
Showing 2 changed files with 2 additions and 1 deletion.
2 changes: 1 addition & 1 deletion tools/perf/util/evlist.c
Original file line number Diff line number Diff line change
Expand Up @@ -214,7 +214,7 @@ int perf_evlist__add_tracepoints(struct perf_evlist *evlist,
attrs[i].type = PERF_TYPE_TRACEPOINT;
attrs[i].config = err;
attrs[i].sample_type = (PERF_SAMPLE_RAW | PERF_SAMPLE_TIME |
PERF_SAMPLE_CPU);
PERF_SAMPLE_CPU | PERF_SAMPLE_PERIOD);
attrs[i].sample_period = 1;
}

Expand Down
1 change: 1 addition & 0 deletions tools/perf/util/parse-events.c
Original file line number Diff line number Diff line change
Expand Up @@ -377,6 +377,7 @@ static int add_tracepoint(struct list_head **list, int *idx,
attr.sample_type |= PERF_SAMPLE_RAW;
attr.sample_type |= PERF_SAMPLE_TIME;
attr.sample_type |= PERF_SAMPLE_CPU;
attr.sample_type |= PERF_SAMPLE_PERIOD;
attr.sample_period = 1;

snprintf(name, MAX_NAME_LEN, "%s:%s", sys_name, evt_name);
Expand Down

0 comments on commit 0983cc0

Please sign in to comment.