Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel os linux

tracing/histogram: Wrap remaining shell snippets in code blocks

Most shell command snippets (echo/cat) and their output are already in
literal code blocks. However a few still isn't wrapped, in which the
htmldocs output is ugly.

Wrap the remaining unwrapped snippets, while also fix recent kernel test
robot warnings.

Link: https://lore.kernel.org/linux-trace-kernel/20230129031402.47420-1-bagasdotme@gmail.com

Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Jonathan Corbet <corbet@lwn.net>
Link: https://lore.kernel.org/linux-doc/202301290253.LU5yIxcJ-lkp@intel.com/
Fixes: 88238513bb2671 ("tracing/histogram: Document variable stacktrace")
Reported-by: kernel test robot <lkp@intel.com>
Signed-off-by: Bagas Sanjaya <bagasdotme@gmail.com>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>

authored by

Bagas Sanjaya and committed by
Steven Rostedt (Google)
a2ff84a5 b18c58af

+47 -46
+47 -46
Documentation/trace/histogram.rst
··· 1864 1864 The above shows the latency "lat" in a power of 2 grouping. 1865 1865 1866 1866 Like any other event, once a histogram is enabled for the event, the 1867 - output can be displayed by reading the event's 'hist' file. 1867 + output can be displayed by reading the event's 'hist' file:: 1868 1868 1869 1869 # cat /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/hist 1870 1870 ··· 1911 1911 1912 1912 1913 1913 The latency values can also be grouped linearly by a given size with 1914 - the ".buckets" modifier and specify a size (in this case groups of 10). 1914 + the ".buckets" modifier and specify a size (in this case groups of 10):: 1915 1915 1916 1916 # echo 'hist:keys=pid,prio,lat.buckets=10:sort=lat' >> \ 1917 1917 /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger ··· 1945 1945 1946 1946 To save stacktraces, create a synthetic event with a field of type "unsigned long[]" 1947 1947 or even just "long[]". For example, to see how long a task is blocked in an 1948 - uninterruptible state: 1948 + uninterruptible state:: 1949 1949 1950 1950 # cd /sys/kernel/tracing 1951 1951 # echo 's:block_lat pid_t pid; u64 delta; unsigned long[] stack;' > dynamic_events ··· 1990 1990 => kthread+0xe9/0x110 1991 1991 => ret_from_fork+0x2c/0x50 1992 1992 1993 - A synthetic event that has a stacktrace field may use it as a key in histogram: 1993 + A synthetic event that has a stacktrace field may use it as a key in 1994 + histogram:: 1994 1995 1995 1996 # echo 'hist:delta.buckets=100,stack.stacktrace:sort=delta' > events/synthetic/block_lat/trigger 1996 1997 # cat events/synthetic/block_lat/hist ··· 2184 2183 wakeup_new_test($testpid) if comm=="cyclictest"' >> \ 2185 2184 /sys/kernel/debug/tracing/events/sched/sched_wakeup_new/trigger 2186 2185 2187 - Or, equivalently, using the 'trace' keyword syntax: 2186 + Or, equivalently, using the 'trace' keyword syntax:: 2188 2187 2189 - # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\ 2190 - trace(wakeup_new_test,$testpid) if comm=="cyclictest"' >> \ 2191 - /sys/kernel/debug/tracing/events/sched/sched_wakeup_new/trigger 2188 + # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\ 2189 + trace(wakeup_new_test,$testpid) if comm=="cyclictest"' >> \ 2190 + /sys/kernel/debug/tracing/events/sched/sched_wakeup_new/trigger 2192 2191 2193 2192 Creating and displaying a histogram based on those events is now 2194 2193 just a matter of using the fields and new synthetic event in the ··· 2321 2320 resulting latency, stored in wakeup_lat, exceeds the current 2322 2321 maximum latency, a snapshot is taken. As part of the setup, all 2323 2322 the scheduler events are also enabled, which are the events that 2324 - will show up in the snapshot when it is taken at some point: 2323 + will show up in the snapshot when it is taken at some point:: 2325 2324 2326 - # echo 1 > /sys/kernel/debug/tracing/events/sched/enable 2325 + # echo 1 > /sys/kernel/debug/tracing/events/sched/enable 2327 2326 2328 - # echo 'hist:keys=pid:ts0=common_timestamp.usecs \ 2329 - if comm=="cyclictest"' >> \ 2330 - /sys/kernel/debug/tracing/events/sched/sched_waking/trigger 2327 + # echo 'hist:keys=pid:ts0=common_timestamp.usecs \ 2328 + if comm=="cyclictest"' >> \ 2329 + /sys/kernel/debug/tracing/events/sched/sched_waking/trigger 2331 2330 2332 - # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \ 2333 - onmax($wakeup_lat).save(next_prio,next_comm,prev_pid,prev_prio, \ 2334 - prev_comm):onmax($wakeup_lat).snapshot() \ 2335 - if next_comm=="cyclictest"' >> \ 2336 - /sys/kernel/debug/tracing/events/sched/sched_switch/trigger 2331 + # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \ 2332 + onmax($wakeup_lat).save(next_prio,next_comm,prev_pid,prev_prio, \ 2333 + prev_comm):onmax($wakeup_lat).snapshot() \ 2334 + if next_comm=="cyclictest"' >> \ 2335 + /sys/kernel/debug/tracing/events/sched/sched_switch/trigger 2337 2336 2338 2337 When the histogram is displayed, for each bucket the max value 2339 2338 and the saved values corresponding to the max are displayed 2340 2339 following the rest of the fields. 2341 2340 2342 2341 If a snapshot was taken, there is also a message indicating that, 2343 - along with the value and event that triggered the global maximum: 2342 + along with the value and event that triggered the global maximum:: 2344 2343 2345 - # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist 2346 - { next_pid: 2101 } hitcount: 200 2347 - max: 52 next_prio: 120 next_comm: cyclictest \ 2348 - prev_pid: 0 prev_prio: 120 prev_comm: swapper/6 2344 + # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist 2345 + { next_pid: 2101 } hitcount: 200 2346 + max: 52 next_prio: 120 next_comm: cyclictest \ 2347 + prev_pid: 0 prev_prio: 120 prev_comm: swapper/6 2349 2348 2350 - { next_pid: 2103 } hitcount: 1326 2351 - max: 572 next_prio: 19 next_comm: cyclictest \ 2352 - prev_pid: 0 prev_prio: 120 prev_comm: swapper/1 2349 + { next_pid: 2103 } hitcount: 1326 2350 + max: 572 next_prio: 19 next_comm: cyclictest \ 2351 + prev_pid: 0 prev_prio: 120 prev_comm: swapper/1 2353 2352 2354 - { next_pid: 2102 } hitcount: 1982 \ 2355 - max: 74 next_prio: 19 next_comm: cyclictest \ 2356 - prev_pid: 0 prev_prio: 120 prev_comm: swapper/5 2353 + { next_pid: 2102 } hitcount: 1982 \ 2354 + max: 74 next_prio: 19 next_comm: cyclictest \ 2355 + prev_pid: 0 prev_prio: 120 prev_comm: swapper/5 2357 2356 2358 - Snapshot taken (see tracing/snapshot). Details: 2359 - triggering value { onmax($wakeup_lat) }: 572 \ 2360 - triggered by event with key: { next_pid: 2103 } 2357 + Snapshot taken (see tracing/snapshot). Details: 2358 + triggering value { onmax($wakeup_lat) }: 572 \ 2359 + triggered by event with key: { next_pid: 2103 } 2361 2360 2362 - Totals: 2363 - Hits: 3508 2364 - Entries: 3 2365 - Dropped: 0 2361 + Totals: 2362 + Hits: 3508 2363 + Entries: 3 2364 + Dropped: 0 2366 2365 2367 2366 In the above case, the event that triggered the global maximum has 2368 2367 the key with next_pid == 2103. If you look at the bucket that has ··· 2440 2439 $cwnd variable. If the value has changed, a snapshot is taken. 2441 2440 As part of the setup, all the scheduler and tcp events are also 2442 2441 enabled, which are the events that will show up in the snapshot 2443 - when it is taken at some point: 2442 + when it is taken at some point:: 2444 2443 2445 - # echo 1 > /sys/kernel/debug/tracing/events/sched/enable 2446 - # echo 1 > /sys/kernel/debug/tracing/events/tcp/enable 2444 + # echo 1 > /sys/kernel/debug/tracing/events/sched/enable 2445 + # echo 1 > /sys/kernel/debug/tracing/events/tcp/enable 2447 2446 2448 - # echo 'hist:keys=dport:cwnd=snd_cwnd: \ 2449 - onchange($cwnd).save(snd_wnd,srtt,rcv_wnd): \ 2450 - onchange($cwnd).snapshot()' >> \ 2451 - /sys/kernel/debug/tracing/events/tcp/tcp_probe/trigger 2447 + # echo 'hist:keys=dport:cwnd=snd_cwnd: \ 2448 + onchange($cwnd).save(snd_wnd,srtt,rcv_wnd): \ 2449 + onchange($cwnd).snapshot()' >> \ 2450 + /sys/kernel/debug/tracing/events/tcp/tcp_probe/trigger 2452 2451 2453 2452 When the histogram is displayed, for each bucket the tracked value 2454 2453 and the saved values corresponding to that value are displayed ··· 2471 2470 { dport: 443 } hitcount: 211 2472 2471 changed: 10 snd_wnd: 26960 srtt: 17379 rcv_wnd: 28800 2473 2472 2474 - Snapshot taken (see tracing/snapshot). Details:: 2473 + Snapshot taken (see tracing/snapshot). Details: 2475 2474 2476 - triggering value { onchange($cwnd) }: 10 2477 - triggered by event with key: { dport: 80 } 2475 + triggering value { onchange($cwnd) }: 10 2476 + triggered by event with key: { dport: 80 } 2478 2477 2479 2478 Totals: 2480 2479 Hits: 414