perf tools: Fix ordering with unstable tsc

Rebased to acme's perf/core branch. Changed realloc to handle failure. Remainder is based on what Frederic posted in February.

From: Frederic Weisbecker <[email protected]>

On a system with a TSC considered as unstable, one can encounter this kind of warning:

     $ perf sched rec pong 2
     $ perf sched lat
     Warning: Timestamp below last timeslice flush

This happens when trace events trigger with a potentially high period, such as sched_stat_sleep, sched_stat_runtime, sched_stat_wait, etc... The perf event core then implement that weight by sending as many events as the given period. For example as many as the time the task has been sleeping in sched_stat_sleep event.

If this happens while irqs are disabled with an unstable tsc and this takes more time than a jiffy, then the timestamps of the events get stuck to the value of that next jiffy because sched_clock_local() bounds the timestamp to that maximum. The local timer tick is supposed to update that boundary but it can't given that irqs are disabled.

We can then meet this kind of scenario in perf record:

===== CPU 0 ===== ==== CPU 1 ====

PASS n
... ...
1 1
1 2
1 3 <-- max recorded

finished round event
PASS n + 1

1 4
1 5
1 6

finished round event
PASS n + 2

1 7
... ...

CPU 0 is stuck sending events with irqs disabled and with the stale timestamp. When we do the events reordering for perf script for example, we flush all the events before timestamp 3 when we reach PASS n + 2, considering we can't anymore have timestamps below 3 now. But we still do have timestamps below 3 on PASS n + 2.

To solve that issue, instead of considering that timestamps are globally monotonic, we assume they are locally monotonic. Instead of recording the max timestamp on each pass, we check the max one per CPU on each pass and keep the smallest over these as the new barrier up to which we flush the events on the PASS n + 2. This still relies on a bit of global monotonicity because if some CPU doesn't have events in PASS n, we expect it not to have event in PASS n + 2 past the barrier recorded in PASS n. So this is still not a totally robust ordering but it's still better than what we had before.

The only way to have a deterministic and solid ordering will be to use per cpu perf.data files.

---
 tools/perf/util/evsel.c   |    5 +-
 tools/perf/util/session.c |  161 +++++++++++++++++++++++++++++++++------------
 tools/perf/util/session.h |    3 +-
 3 files changed, 126 insertions(+), 43 deletions(-)

index ffdd94e..b6ca970 100644
@@ -471,9 +471,12 @@ void perf_evsel__config(struct perf_evsel *evsel, struct perf_record_opts *opts,
 	if (opts->raw_samples) {
 		attr->sample_type	|= PERF_SAMPLE_TIME;
 		attr->sample_type	|= PERF_SAMPLE_RAW;
-		attr->sample_type	|= PERF_SAMPLE_CPU;
 	}
 
+	/* Need to know the CPU for tools that need to order events */
+	if (attr->sample_type & PERF_SAMPLE_TIME)
+		attr->sample_type	|= PERF_SAMPLE_CPU;
+
 	if (opts->no_delay) {
 		attr->watermark = 0;
 		attr->wakeup_events = 1;

index aab414f..13cc305 100644
@@ -16,7 +16,7 @@ struct thread;
 struct ordered_samples {
 	u64			last_flush;
 	u64			next_flush;
-	u64			max_timestamp;
+	u64			*last_cpu_timestamp;
 	struct list_head	samples;
 	struct list_head	sample_cache;
 	struct list_head	to_free;

@@ -45,6 +45,7 @@ struct perf_session {
 	int			cwdlen;
 	char			*cwd;
 	struct ordered_samples	ordered_samples;
+	unsigned int		nr_cpus;
 	char			filename[1];
 };
 

1.7.10.1

Hi Arnaldo,

Something with your recent changes (last month) is causing perf to segfault with this patch. Ignore for now; I'll repost when I can figure it out.

David

Em Sat, Oct 06, 2012 at 09:17:08AM -0600, David Ahern escreveu:

Ok, I was waiting anyway for Frédéric and others to do some review on it,

Thanks!

- Arnaldo