• Changbin Du's avatar
    tracing: Put a margin between flags and duration for wakeup tracers · afbab501
    Changbin Du authored
    Don't mix context flags with function duration info.
    
    Instead of this:
    
     # tracer: wakeup_rt
     #
     # wakeup_rt latency trace v1.1.5 on 5.0.0-rc1-test+
     # --------------------------------------------------------------------
     # latency: 177 us, #545/545, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:8)
     #    -----------------
     #    | task: migration/0-11 (uid:0 nice:0 policy:1 rt_prio:99)
     #    -----------------
     #
     #                                       _-----=> irqs-off
     #                                      / _----=> need-resched
     #                                     | / _---=> hardirq/softirq
     #                                     || / _--=> preempt-depth
     #                                     ||| /
     #   REL TIME      CPU  TASK/PID       ||||  DURATION                  FUNCTION CALLS
     #      |          |     |    |        ||||   |   |                     |   |   |   |
             0 us |   0)    <idle>-0    |  dNh5              |  /*      0:120:R   + [000]    11:  0:R migration/0 */
             2 us |   0)    <idle>-0    |  dNh5  0.000 us    |            (null)();
             4 us |   0)    <idle>-0    |  dNh4              |  _raw_spin_unlock() {
             4 us |   0)    <idle>-0    |  dNh4  0.304 us    |    preempt_count_sub();
             5 us |   0)    <idle>-0    |  dNh3  1.063 us    |  }
             5 us |   0)    <idle>-0    |  dNh3  0.266 us    |  ttwu_stat();
             6 us |   0)    <idle>-0    |  dNh3              |  _raw_spin_unlock_irqrestore() {
             6 us |   0)    <idle>-0    |  dNh3  0.273 us    |    preempt_count_sub();
             6 us |   0)    <idle>-0    |  dNh2  0.818 us    |  }
    
    Show this:
    
     # tracer: wakeup
     #
     # wakeup latency trace v1.1.5 on 4.20.0+
     # --------------------------------------------------------------------
     # latency: 593 us, #674/674, CPU#0 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:4)
     #    -----------------
     #    | task: kworker/0:1H-339 (uid:0 nice:-20 policy:0 rt_prio:0)
     #    -----------------
     #
     #                                      _-----=> irqs-off
     #                                     / _----=> need-resched
     #                                    | / _---=> hardirq/softirq
     #                                    || / _--=> preempt-depth
     #                                    ||| /
     #  REL TIME      CPU  TASK/PID       ||||     DURATION                  FUNCTION CALLS
     #     |          |     |    |        ||||      |   |                     |   |   |   |
            0 us |   0)    <idle>-0    |  dNs. |               |  /*      0:120:R   + [000]   339:100:R kworker/0:1H */
            3 us |   0)    <idle>-0    |  dNs. |   0.000 us    |            (null)();
           67 us |   0)    <idle>-0    |  dNs. |   0.721 us    |  ttwu_stat();
           69 us |   0)    <idle>-0    |  dNs. |   0.607 us    |  _raw_spin_unlock_irqrestore();
           71 us |   0)    <idle>-0    |  .Ns. |   0.598 us    |  _raw_spin_lock_irq();
           72 us |   0)    <idle>-0    |  .Ns. |   0.584 us    |  _raw_spin_lock_irq();
           73 us |   0)    <idle>-0    |  dNs. | + 11.118 us   |  __next_timer_interrupt();
           75 us |   0)    <idle>-0    |  dNs. |               |  call_timer_fn() {
           76 us |   0)    <idle>-0    |  dNs. |               |    delayed_work_timer_fn() {
           76 us |   0)    <idle>-0    |  dNs. |               |      __queue_work() {
           ...
    
    Link: http://lkml.kernel.org/r/20190101154614.8887-4-changbin.du@gmail.comSigned-off-by: default avatarChangbin Du <changbin.du@gmail.com>
    Signed-off-by: default avatarSteven Rostedt (VMware) <rostedt@goodmis.org>
    afbab501
trace_functions_graph.c 32.6 KB