mirror of
https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git
synced 2025-01-04 04:02:26 +00:00
tracing/histogram: Document variable stacktrace
Add a little documentation (and a useful example) of how a stacktrace can be used within a histogram variable and synthetic event. Link: https://lkml.kernel.org/r/20230117152236.320181354@goodmis.org Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Andrew Morton <akpm@linux-foundation.org> Cc: Tom Zanussi <zanussi@kernel.org> Cc: Ross Zwisler <zwisler@google.com> Cc: Ching-lin Yu <chinglinyu@google.com> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
This commit is contained in:
Steven Rostedt (Google)
parent
cc5fc8bfc9
commit
88238513bb
@ -81,6 +81,7 @@ Documentation written by Tom Zanussi
|
||||
.usecs display a common_timestamp in microseconds
|
||||
.percent display a number of percentage value
|
||||
.graph display a bar-graph of a value
|
||||
.stacktrace display as a stacktrace (must by a long[] type)
|
||||
============= =================================================
|
||||
|
||||
Note that in general the semantics of a given field aren't
|
||||
@ -1786,6 +1787,8 @@ or assigned to a variable and referenced in a subsequent expression::
|
||||
# echo 'hist:keys=next_pid:us_per_sec=1000000 ...' >> event/trigger
|
||||
# echo 'hist:keys=next_pid:timestamp_secs=common_timestamp/$us_per_sec ...' >> event/trigger
|
||||
|
||||
Variables can even hold stacktraces, which are useful with synthetic events.
|
||||
|
||||
2.2.2 Synthetic Events
|
||||
----------------------
|
||||
|
||||
@ -1940,6 +1943,132 @@ the ".buckets" modifier and specify a size (in this case groups of 10).
|
||||
Entries: 16
|
||||
Dropped: 0
|
||||
|
||||
To save stacktraces, create a synthetic event with a field of type "unsigned long[]"
|
||||
or even just "long[]". For example, to see how long a task is blocked in an
|
||||
uninterruptible state:
|
||||
|
||||
# cd /sys/kernel/tracing
|
||||
# echo 's:block_lat pid_t pid; u64 delta; unsigned long[] stack;' > dynamic_events
|
||||
# echo 'hist:keys=next_pid:ts=common_timestamp.usecs,st=stacktrace if prev_state == 2' >> events/sched/sched_switch/trigger
|
||||
# echo 'hist:keys=prev_pid:delta=common_timestamp.usecs-$ts,s=$st:onmax($delta).trace(block_lat,prev_pid,$delta,$s)' >> events/sched/sched_switch/trigger
|
||||
# echo 1 > events/synthetic/block_lat/enable
|
||||
# cat trace
|
||||
|
||||
# tracer: nop
|
||||
#
|
||||
# entries-in-buffer/entries-written: 2/2 #P:8
|
||||
#
|
||||
# _-----=> irqs-off/BH-disabled
|
||||
# / _----=> need-resched
|
||||
# | / _---=> hardirq/softirq
|
||||
# || / _--=> preempt-depth
|
||||
# ||| / _-=> migrate-disable
|
||||
# |||| / delay
|
||||
# TASK-PID CPU# ||||| TIMESTAMP FUNCTION
|
||||
# | | | ||||| | |
|
||||
<idle>-0 [005] d..4. 521.164922: block_lat: pid=0 delta=8322 stack=STACK:
|
||||
=> __schedule+0x448/0x7b0
|
||||
=> schedule+0x5a/0xb0
|
||||
=> io_schedule+0x42/0x70
|
||||
=> bit_wait_io+0xd/0x60
|
||||
=> __wait_on_bit+0x4b/0x140
|
||||
=> out_of_line_wait_on_bit+0x91/0xb0
|
||||
=> jbd2_journal_commit_transaction+0x1679/0x1a70
|
||||
=> kjournald2+0xa9/0x280
|
||||
=> kthread+0xe9/0x110
|
||||
=> ret_from_fork+0x2c/0x50
|
||||
|
||||
<...>-2 [004] d..4. 525.184257: block_lat: pid=2 delta=76 stack=STACK:
|
||||
=> __schedule+0x448/0x7b0
|
||||
=> schedule+0x5a/0xb0
|
||||
=> schedule_timeout+0x11a/0x150
|
||||
=> wait_for_completion_killable+0x144/0x1f0
|
||||
=> __kthread_create_on_node+0xe7/0x1e0
|
||||
=> kthread_create_on_node+0x51/0x70
|
||||
=> create_worker+0xcc/0x1a0
|
||||
=> worker_thread+0x2ad/0x380
|
||||
=> kthread+0xe9/0x110
|
||||
=> ret_from_fork+0x2c/0x50
|
||||
|
||||
A synthetic event that has a stacktrace field may use it as a key in histogram:
|
||||
|
||||
# echo 'hist:delta.buckets=100,stack.stacktrace:sort=delta' > events/synthetic/block_lat/trigger
|
||||
# cat events/synthetic/block_lat/hist
|
||||
|
||||
# event histogram
|
||||
#
|
||||
# trigger info: hist:keys=delta.buckets=100,stacktrace:vals=hitcount:sort=delta.buckets=100:size=2048 [active]
|
||||
#
|
||||
|
||||
{ delta: ~ 0-99, stacktrace:
|
||||
event_hist_trigger+0x464/0x480
|
||||
event_triggers_call+0x52/0xe0
|
||||
trace_event_buffer_commit+0x193/0x250
|
||||
trace_event_raw_event_sched_switch+0xfc/0x150
|
||||
__traceiter_sched_switch+0x41/0x60
|
||||
__schedule+0x448/0x7b0
|
||||
schedule_idle+0x26/0x40
|
||||
cpu_startup_entry+0x19/0x20
|
||||
start_secondary+0xed/0xf0
|
||||
secondary_startup_64_no_verify+0xe0/0xeb
|
||||
} hitcount: 6
|
||||
{ delta: ~ 0-99, stacktrace:
|
||||
event_hist_trigger+0x464/0x480
|
||||
event_triggers_call+0x52/0xe0
|
||||
trace_event_buffer_commit+0x193/0x250
|
||||
trace_event_raw_event_sched_switch+0xfc/0x150
|
||||
__traceiter_sched_switch+0x41/0x60
|
||||
__schedule+0x448/0x7b0
|
||||
schedule_idle+0x26/0x40
|
||||
cpu_startup_entry+0x19/0x20
|
||||
__pfx_kernel_init+0x0/0x10
|
||||
arch_call_rest_init+0xa/0x24
|
||||
start_kernel+0x964/0x98d
|
||||
secondary_startup_64_no_verify+0xe0/0xeb
|
||||
} hitcount: 3
|
||||
{ delta: ~ 0-99, stacktrace:
|
||||
event_hist_trigger+0x464/0x480
|
||||
event_triggers_call+0x52/0xe0
|
||||
trace_event_buffer_commit+0x193/0x250
|
||||
trace_event_raw_event_sched_switch+0xfc/0x150
|
||||
__traceiter_sched_switch+0x41/0x60
|
||||
__schedule+0x448/0x7b0
|
||||
schedule+0x5a/0xb0
|
||||
worker_thread+0xaf/0x380
|
||||
kthread+0xe9/0x110
|
||||
ret_from_fork+0x2c/0x50
|
||||
} hitcount: 1
|
||||
{ delta: ~ 100-199, stacktrace:
|
||||
event_hist_trigger+0x464/0x480
|
||||
event_triggers_call+0x52/0xe0
|
||||
trace_event_buffer_commit+0x193/0x250
|
||||
trace_event_raw_event_sched_switch+0xfc/0x150
|
||||
__traceiter_sched_switch+0x41/0x60
|
||||
__schedule+0x448/0x7b0
|
||||
schedule_idle+0x26/0x40
|
||||
cpu_startup_entry+0x19/0x20
|
||||
start_secondary+0xed/0xf0
|
||||
secondary_startup_64_no_verify+0xe0/0xeb
|
||||
} hitcount: 15
|
||||
[..]
|
||||
{ delta: ~ 8500-8599, stacktrace:
|
||||
event_hist_trigger+0x464/0x480
|
||||
event_triggers_call+0x52/0xe0
|
||||
trace_event_buffer_commit+0x193/0x250
|
||||
trace_event_raw_event_sched_switch+0xfc/0x150
|
||||
__traceiter_sched_switch+0x41/0x60
|
||||
__schedule+0x448/0x7b0
|
||||
schedule_idle+0x26/0x40
|
||||
cpu_startup_entry+0x19/0x20
|
||||
start_secondary+0xed/0xf0
|
||||
secondary_startup_64_no_verify+0xe0/0xeb
|
||||
} hitcount: 1
|
||||
|
||||
Totals:
|
||||
Hits: 89
|
||||
Entries: 11
|
||||
Dropped: 0
|
||||
|
||||
2.2.3 Hist trigger 'handlers' and 'actions'
|
||||
-------------------------------------------
|
||||
|
||||
|
||||
Loading…
Reference in New Issue
Block a user