Happy new year!
This series make some improments for the kernel latency tracers, especilly
for the wakeup tracers. The latency tracers will show us more useful
information. With this series, the wakeup tracers look like this
when display-graph is enabled:
# 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)();
<idle>-0 0dNs. 66us : <stack trace>
=> try_to_wake_up
=> __queue_work
=> queue_work_on
=> call_timer_fn
=> run_timer_softirq
=> __do_softirq
=> irq_exit
=> smp_apic_timer_interrupt
=> apic_timer_interrupt
=> native_safe_halt
=> default_idle
=> default_idle_call
=> do_idle
=> cpu_startup_entry
=> start_kernel
=> secondary_startup_64
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. | 1.125 us |
__next_timer_interrupt();
75 us | 0) <idle>-0 | dNs. | | call_timer_fn() {
76 us | 0) <idle>-0 | dNs. | |
delayed_work_timer_fn() {
[...]
564 us | 0) kworker-13 | d... | |
set_next_entity() {
565 us | 0) kworker-13 | d... | 0.524 us |
__update_load_avg_se();
566 us | 0) kworker-13 | d... | 0.562 us |
__update_load_avg_cfs_rq();
567 us | 0) kworker-13 | d... | 2.765 us | }
568 us | 0) kworker-13 | d... | + 10.077 us | }
569 us | 0) kworker-13 | d... | 0.000 us | __schedule();
kworker/-13 0d... 593us : <stack trace>
=> schedule
=> worker_thread
=> kthread
=> ret_from_fork
593 us | 0) kworker-13 | d... | | /* 13:120:I
==> [000] 339:100:R kworker/0:1H */
Changbin Du (5):
function_graph: Support displaying relative timestamp
sched/tracing: Show more info for funcgraph wakeup tracers
sched/tracing: Put a margin between flags and duration for wakeup
tracers
sched/tracing: Show stacktrace for wakeup tracers
trace/doc: Add latency tracer funcgraph example
Documentation/trace/ftrace.rst | 51 ++++++++++++++++++++++++++++
kernel/trace/trace.h | 9 ++---
kernel/trace/trace_functions_graph.c | 30 ++++++++++++++--
kernel/trace/trace_irqsoff.c | 2 +-
kernel/trace/trace_sched_wakeup.c | 11 ++++--
5 files changed, 94 insertions(+), 9 deletions(-)
--
2.17.1
