| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <20230117044101.274203396@goodmis.org>
Date: Mon, 16 Jan 2023 23:40:14 -0500
From: Steven Rostedt <rostedt@...dmis.org>
To: linux-kernel@...r.kernel.org, linux-trace-kernel@...r.kernel.org
Cc: Masami Hiramatsu <mhiramat@...nel.org>,
Andrew Morton <akpm@...ux-foundation.org>,
Ross Zwisler <zwisler@...gle.com>
Subject: [PATCH 4/5] tracing/histogram: Document variable stacktrace
From: "Steven Rostedt (Google)" <rostedt@...dmis.org>
Add a little documentation (and a useful example) of how a stacktrace can
be used within a histogram variable.
Signed-off-by: Steven Rostedt (Google) <rostedt@...dmis.org>
---
Documentation/trace/histogram.rst | 49 +++++++++++++++++++++++++++++++
1 file changed, 49 insertions(+)
diff --git a/Documentation/trace/histogram.rst b/Documentation/trace/histogram.rst
index f95459aa984f..5b7f985f35d9 100644
--- a/Documentation/trace/histogram.rst
+++ b/Documentation/trace/histogram.rst
@@ -1786,6 +1786,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 +1942,53 @@ 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
+
2.2.3 Hist trigger 'handlers' and 'actions'
-------------------------------------------
--
2.39.0
Powered by blists - more mailing lists