Eric Lee / smarc-ti-linux-kernel

Download as
Browse Code ยป

Commit e8ff14951e0c852eec6c683436dd4b2d6a5f64a4

Authored by Jiri Olsa
Committed by Greg Kroah-Hartman
1 parent 7f5dada0d5

perf session: Do not fail on processing out of order event 

commit f61ff6c06dc8f32c7036013ad802c899ec590607 upstream.

Linus reported perf report command being interrupted due to processing
of 'out of order' event, with following error:

  Timestamp below last timeslice flush
  0x5733a8 [0x28]: failed to process type: 3

I could reproduce the issue and in my case it was caused by one CPU
(mmap) being behind during record and userspace mmap reader seeing the
data after other CPUs data were already stored.

This is expected under some circumstances because we need to limit the
number of events that we queue for reordering when we receive a
PERF_RECORD_FINISHED_ROUND or when we force flush due to memory
pressure.

Reported-by: Linus Torvalds <torvalds@linux-foundation.org>
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Acked-by: Ingo Molnar <mingo@kernel.org>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Corey Ashford <cjashfor@linux.vnet.ibm.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Cc: Matt Fleming <matt.fleming@intel.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/r/1417016371-30249-1-git-send-email-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Signed-off-by: Zhiqiang Zhang <zhangzhiqiang.zhang@huawei.com>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

Showing 2 changed files with 6 additions and 6 deletions Side-by-side Diff

tools/perf/util/event.h
Diff comments   View file @ e8ff149
... ... @@ -214,6 +214,7 @@
214 214 u32 nr_invalid_chains;
215 215 u32 nr_unknown_id;
216 216 u32 nr_unprocessable_samples;
  217 + u32 nr_unordered_events;
217 218 };
218 219  
219 220 struct attr_event {
tools/perf/util/session.c
Diff comments   View file @ e8ff149
... ... @@ -521,15 +521,11 @@
521 521 return -ETIME;
522 522  
523 523 if (timestamp < oe->last_flush) {
524   - WARN_ONCE(1, "Timestamp below last timeslice flush\n");
525   -
526   - pr_oe_time(timestamp, "out of order event");
  524 + pr_oe_time(timestamp, "out of order event\n");
527 525 pr_oe_time(oe->last_flush, "last flush, last_flush_type %d\n",
528 526 oe->last_flush_type);
529 527  
530   - /* We could get out of order messages after forced flush. */
531   - if (oe->last_flush_type != OE_FLUSH__HALF)
532   - return -EINVAL;
  528 + s->stats.nr_unordered_events++;
533 529 }
534 530  
535 531 new = ordered_events__new(oe, timestamp, event);
... ... @@ -1057,6 +1053,9 @@
1057 1053 "Do you have a KVM guest running and not using 'perf kvm'?\n",
1058 1054 session->stats.nr_unprocessable_samples);
1059 1055 }
  1056 +
  1057 + if (session->stats.nr_unordered_events != 0)
  1058 + ui__warning("%u out of order events recorded.\n", session->stats.nr_unordered_events);
1060 1059 }
1061 1060  
1062 1061 volatile int session_done;