Skip to content
  • Frederic Weisbecker's avatar
    tracing/function-graph-tracer: enhancements for the trace output · 83a8df61
    Frederic Weisbecker authored
    
    
    Impact: enhance the output of the graph-tracer
    
    This patch applies some ideas of Ingo Molnar and Steven Rostedt.
    
    * Output leaf functions in one line with parenthesis, semicolon and duration
      output.
    
    * Add a second column (after cpu) for an overhead sign.
      if duration > 100 us, "!"
      if duration > 10 us, "+"
      else " "
    
    * Print output in us with remaining nanosec: u.n
    
    * Print duration on the right end, following the indentation of the functions.
      Use also visual clues: "-" on entry call (no duration to output) and "+" on
      return (duration output).
    
    The name of the tracer has been fixed as well: function-branch becomes
    function_branch.
    
    Here is an example of the new output:
    
    CPU[000]           dequeue_entity() {                    -
    CPU[000]             update_curr() {                    -
    CPU[000]               update_min_vruntime();                    + 0.512 us
    CPU[000]             }                                + 1.504 us
    CPU[000]             clear_buddies();                    + 0.481 us
    CPU[000]             update_min_vruntime();                    + 0.504 us
    CPU[000]           }                                + 4.557 us
    CPU[000]           hrtick_update() {                    -
    CPU[000]             hrtick_start_fair();                    + 0.489 us
    CPU[000]           }                                + 1.443 us
    CPU[000] +       }                                + 14.655 us
    CPU[000] +     }                                + 15.678 us
    CPU[000] +   }                                + 16.686 us
    CPU[000]     msecs_to_jiffies();                    + 0.481 us
    CPU[000]     put_prev_task_fair();                    + 0.504 us
    CPU[000]     pick_next_task_fair();                    + 0.482 us
    CPU[000]     pick_next_task_rt();                    + 0.504 us
    CPU[000]     pick_next_task_fair();                    + 0.481 us
    CPU[000]     pick_next_task_idle();                    + 0.489 us
    CPU[000]     _spin_trylock();                    + 0.655 us
    CPU[000]     _spin_unlock();                    + 0.609 us
    
    CPU[000]  ------------8<---------- thread bash-2794 ------------8<----------
    
    CPU[000]               finish_task_switch() {                    -
    CPU[000]                 _spin_unlock_irq();                    + 0.722 us
    CPU[000]               }                                + 2.369 us
    CPU[000] !           }                                + 501972.605 us
    CPU[000] !         }                                + 501973.763 us
    CPU[000]           copy_from_read_buf() {                    -
    CPU[000]             _spin_lock_irqsave();                    + 0.670 us
    CPU[000]             _spin_unlock_irqrestore();                    + 0.699 us
    CPU[000]             copy_to_user() {                    -
    CPU[000]               might_fault() {                    -
    CPU[000]                 __might_sleep();                    + 0.503 us
    CPU[000]               }                                + 1.632 us
    CPU[000]               __copy_to_user_ll();                    + 0.542 us
    CPU[000]             }                                + 3.858 us
    CPU[000]             tty_audit_add_data() {                    -
    CPU[000]               _spin_lock_irq();                    + 0.609 us
    CPU[000]               _spin_unlock_irq();                    + 0.624 us
    CPU[000]             }                                + 3.196 us
    CPU[000]             _spin_lock_irqsave();                    + 0.624 us
    CPU[000]             _spin_unlock_irqrestore();                    + 0.625 us
    CPU[000] +         }                                + 13.611 us
    CPU[000]           copy_from_read_buf() {                    -
    CPU[000]             _spin_lock_irqsave();                    + 0.624 us
    CPU[000]             _spin_unlock_irqrestore();                    + 0.616 us
    CPU[000]           }                                + 2.820 us
    CPU[000]
    
    Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
    Signed-off-by: default avatarIngo Molnar <mingo@elte.hu>
    83a8df61