• Jiri Olsa's avatar
    perf report: Ask for ordered events for --tasks option · 8614ada0
    Jiri Olsa authored
    If we have the time in, keep the events in time order.
    
    Committer notes:
    
    Trying to be more verbose, what actual effect this will have in this particular
    case?
    
    Before and after this patch shows the artifacts:
    
      --- /tmp/before 2018-02-06 15:40:29.536411625 -0300
      +++ /tmp/after  2018-02-06 15:40:51.963403599 -0300
      @@ -5,34 +5,34 @@
             2540     2540     1818 |   gnome-terminal-
             3489     3489     2540 |    bash
            32433    32433     3489 |     perf
      -     32434    32434    32433 |      perf
      +     32434    32434    32433 |      make
            32441    32441    32434 |       make
            32514    32514    32441 |        make
              511      511    32514 |         sh
      -       512      512      511 |          sh
      +       512      512      511 |          install
    <SNIP>
    
    We don't have 'perf' calling 'perf' calling 'make', etc, the second
    'perf' actually is 'make', i.e.  there was reordering of the relevant
    PERF_RECORD_COMM and PERF_RECORD_FORK records.
    
    Ditto for sh/install later on.
    
    Look for FORK and COMM meta events, for those tids:
    
      # perf report -D | egrep 'PERF_RECORD_(FORK|COMM)' | egrep '3243[34]'
      0 14774650990679 0x1a3cd8 [0x38]: PERF_RECORD_FORK(32433:32433):(3489:3489)
      1 14774652080381 0x1d6568 [0x30]: PERF_RECORD_COMM exec: perf:32433/32433
      1 14774742473340 0x1dbb48 [0x38]: PERF_RECORD_FORK(32434:32434):(32433:32433)
      0 14774752005779 0x1a4af8 [0x30]: PERF_RECORD_COMM exec: make:32434/32434
      0 14774753997960 0x1a5578 [0x38]: PERF_RECORD_FORK(32435:32435):(32434:32434)
      0 14774756070782 0x1a5618 [0x38]: PERF_RECORD_FORK(32438:32438):(32434:32434)
      0 14774757772939 0x1a5680 [0x38]: PERF_RECORD_FORK(32440:32440):(32434:32434)
      0 14774758230600 0x1a56e8 [0x38]: PERF_RECORD_FORK(32441:32441):(32434:32434)
      #
    
    First column is the cpu, second is the timestamp.
    
    So they are on different CPUs, thus ring buffers, and when we don't use
    the ordered_events class, we end up mixing that up, use it to take
    advantage of the PERF_RECORD_FINISHED_ROUND meta events to go on
    ordering the events using the PERF_SAMPLE_TIME present in the
    PERF_RECORD_{FORK,COMM,EXIT,SAMPLE,etc} records in the ring buffer.
    Signed-off-by: default avatarJiri Olsa <jolsa@kernel.org>
    Tested-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
    Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
    Cc: David Ahern <dsahern@gmail.com>
    Cc: Namhyung Kim <namhyung@kernel.org>
    Cc: Peter Zijlstra <peterz@infradead.org>
    Link: http://lkml.kernel.org/r/20180206181813.10943-2-jolsa@kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
    8614ada0
builtin-report.c 37.7 KB