mirror of
https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git
synced 2024-08-23 01:10:04 +00:00
tracing: Put a margin between flags and duration for wakeup tracers
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💯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.com Signed-off-by: Changbin Du <changbin.du@gmail.com> Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
This commit is contained in:
parent
97f0a3bcdf
commit
afbab501c6
1 changed files with 3 additions and 2 deletions
|
@ -380,6 +380,7 @@ static void print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
|
|||
{
|
||||
trace_seq_putc(s, ' ');
|
||||
trace_print_lat_fmt(s, entry);
|
||||
trace_seq_puts(s, " | ");
|
||||
}
|
||||
|
||||
/* If the pid changed since the last trace, output this event */
|
||||
|
@ -1153,7 +1154,7 @@ static void __print_graph_headers_flags(struct trace_array *tr,
|
|||
if (flags & TRACE_GRAPH_PRINT_PROC)
|
||||
seq_puts(s, " TASK/PID ");
|
||||
if (lat)
|
||||
seq_puts(s, "||||");
|
||||
seq_puts(s, "|||| ");
|
||||
if (flags & TRACE_GRAPH_PRINT_DURATION)
|
||||
seq_puts(s, " DURATION ");
|
||||
seq_puts(s, " FUNCTION CALLS\n");
|
||||
|
@ -1169,7 +1170,7 @@ static void __print_graph_headers_flags(struct trace_array *tr,
|
|||
if (flags & TRACE_GRAPH_PRINT_PROC)
|
||||
seq_puts(s, " | | ");
|
||||
if (lat)
|
||||
seq_puts(s, "||||");
|
||||
seq_puts(s, "|||| ");
|
||||
if (flags & TRACE_GRAPH_PRINT_DURATION)
|
||||
seq_puts(s, " | | ");
|
||||
seq_puts(s, " | | | |\n");
|
||||
|
|
Loading…
Reference in a new issue