• Joel Fernandes (Google)'s avatar
    perf sched: Show start of latency as well · dc000c45
    Joel Fernandes (Google) authored
    The 'perf sched latency' tool is really useful at showing worst-case
    latencies that task encountered since wakeup. However it shows only the
    end of the latency. Often times the start of a latency is interesting as
    it can show what else was going on at the time to cause the latency. I
    certainly myself spending a lot of time backtracking to the start of the
    latency in "perf sched script" which wastes a lot of time.
    
    This patch therefore adds a new column "Max delay start". Considering
    this, also rename "Maximum delay at" to "Max delay end" as its easier to
    understand.
    
    Example of the new output:
    
      ----------------------------------------------------------------------------------------------------------------------------------
       Task                  | Runtime ms  | Switches | Avg delay ms  | Max delay ms   | Max delay start         | Max delay end       |
      ----------------------------------------------------------------------------------------------------------------------------------
       MediaScannerSer:11936 |  651.296 ms |    67978 | avg: 0.113 ms | max: 77.250 ms | max start: 477.691360 s | max end: 477.768610 s
       audio@2.0-servi:(3)   |    0.000 ms |     3440 | avg: 0.034 ms | max: 72.267 ms | max start: 477.697051 s | max end: 477.769318 s
       AudioOut_1D:8112      |    0.000 ms |     2588 | avg: 0.083 ms | max: 64.020 ms | max start: 477.710740 s | max end: 477.774760 s
       Time-limited te:14973 | 7966.090 ms |    24807 | avg: 0.073 ms | max: 15.563 ms | max start: 477.162746 s | max end: 477.178309 s
       surfaceflinger:8049   |    9.680 ms |      603 | avg: 0.063 ms | max: 13.275 ms | max start: 476.931791 s | max end: 476.945067 s
       HeapTaskDaemon:(3)    | 1588.830 ms |     7040 | avg: 0.065 ms | max:  6.880 ms | max start: 473.666043 s | max end: 473.672922 s
       mount-passthrou:(3)   | 1370.809 ms |    68904 | avg: 0.011 ms | max:  6.524 ms | max start: 478.090630 s | max end: 478.097154 s
       ReferenceQueueD:(3)   |   11.794 ms |     1725 | avg: 0.014 ms | max:  6.521 ms | max start: 476.119782 s | max end: 476.126303 s
       writer:14077          |   18.410 ms |     1427 | avg: 0.036 ms | max:  6.131 ms | max start: 474.169675 s | max end: 474.175805 s
    Signed-off-by: default avatarJoel Fernandes (Google) <joel@joelfernandes.org>
    Acked-by: default avatarNamhyung Kim <namhyung@kernel.org>
    Link: https://lore.kernel.org/r/20200925235634.4089867-1-joel@joelfernandes.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
    dc000c45
builtin-sched.c 89 KB