summaryrefslogtreecommitdiff
path: root/Documentation/trace/histogram.rst
diff options
context:
space:
mode:
authorRoss Zwisler <zwisler@chromium.org>2023-01-26 00:32:51 +0300
committerJonathan Corbet <corbet@lwn.net>2023-02-01 00:02:30 +0300
commit2abfcd293b79baf62895894fa3ea2386ffbe6338 (patch)
treeb74867f24b7c6d6b6909856063d6c184a29195e0 /Documentation/trace/histogram.rst
parentb05ada5615f844c3fdcf5e2a0fa35a4bc1a394f2 (diff)
downloadlinux-2abfcd293b79baf62895894fa3ea2386ffbe6338.tar.xz
docs: ftrace: always use canonical ftrace path
The canonical location for the tracefs filesystem is at /sys/kernel/tracing. But, from Documentation/trace/ftrace.rst: Before 4.1, all ftrace tracing control files were within the debugfs file system, which is typically located at /sys/kernel/debug/tracing. For backward compatibility, when mounting the debugfs file system, the tracefs file system will be automatically mounted at: /sys/kernel/debug/tracing Many parts of Documentation still reference this older debugfs path, so let's update them to avoid confusion. Signed-off-by: Ross Zwisler <zwisler@google.com> Reviewed-by: Steven Rostedt (Google) <rostedt@goodmis.org> Link: https://lore.kernel.org/r/20230125213251.2013791-1-zwisler@google.com Signed-off-by: Jonathan Corbet <corbet@lwn.net>
Diffstat (limited to 'Documentation/trace/histogram.rst')
-rw-r--r--Documentation/trace/histogram.rst190
1 files changed, 95 insertions, 95 deletions
diff --git a/Documentation/trace/histogram.rst b/Documentation/trace/histogram.rst
index f95459aa984f..7b7e4893b8f6 100644
--- a/Documentation/trace/histogram.rst
+++ b/Documentation/trace/histogram.rst
@@ -102,12 +102,12 @@ Documentation written by Tom Zanussi
trigger, read its current contents, and then turn it off::
# echo 'hist:keys=skbaddr.hex:vals=len' > \
- /sys/kernel/debug/tracing/events/net/netif_rx/trigger
+ /sys/kernel/tracing/events/net/netif_rx/trigger
- # cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
+ # cat /sys/kernel/tracing/events/net/netif_rx/hist
# echo '!hist:keys=skbaddr.hex:vals=len' > \
- /sys/kernel/debug/tracing/events/net/netif_rx/trigger
+ /sys/kernel/tracing/events/net/netif_rx/trigger
The trigger file itself can be read to show the details of the
currently attached hist trigger. This information is also displayed
@@ -169,13 +169,13 @@ Documentation written by Tom Zanussi
aggregation on and off when conditions of interest are hit::
# echo 'hist:keys=skbaddr.hex:vals=len:pause' > \
- /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ /sys/kernel/tracing/events/net/netif_receive_skb/trigger
# echo 'enable_hist:net:netif_receive_skb if filename==/usr/bin/wget' > \
- /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
+ /sys/kernel/tracing/events/sched/sched_process_exec/trigger
# echo 'disable_hist:net:netif_receive_skb if comm==wget' > \
- /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
+ /sys/kernel/tracing/events/sched/sched_process_exit/trigger
The above sets up an initially paused hist trigger which is unpaused
and starts aggregating events when a given program is executed, and
@@ -218,7 +218,7 @@ Extended error information
event. The fields that can be used for the hist trigger are listed
in the kmalloc event's format file::
- # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/format
+ # cat /sys/kernel/tracing/events/kmem/kmalloc/format
name: kmalloc
ID: 374
format:
@@ -238,7 +238,7 @@ Extended error information
the kernel that made one or more calls to kmalloc::
# echo 'hist:key=call_site:val=bytes_req.buckets=32' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+ /sys/kernel/tracing/events/kmem/kmalloc/trigger
This tells the tracing system to create a 'hist' trigger using the
call_site field of the kmalloc event as the key for the table, which
@@ -252,7 +252,7 @@ Extended error information
file in the kmalloc event's subdirectory (for readability, a number
of entries have been omitted)::
- # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+ # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
# trigger info: hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
{ call_site: 18446744072106379007 } hitcount: 1 bytes_req: 176
@@ -292,7 +292,7 @@ Extended error information
the trigger info, which can also be displayed by reading the
'trigger' file::
- # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+ # cat /sys/kernel/tracing/events/kmem/kmalloc/trigger
hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
At the end of the output are a few lines that display the overall
@@ -323,7 +323,7 @@ Extended error information
command history and re-execute it with a '!' prepended::
# echo '!hist:key=call_site:val=bytes_req' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+ /sys/kernel/tracing/events/kmem/kmalloc/trigger
Finally, notice that the call_site as displayed in the output above
isn't really very useful. It's an address, but normally addresses
@@ -331,9 +331,9 @@ Extended error information
value, simply append '.hex' to the field name in the trigger::
# echo 'hist:key=call_site.hex:val=bytes_req' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+ /sys/kernel/tracing/events/kmem/kmalloc/trigger
- # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+ # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
# trigger info: hist:keys=call_site.hex:vals=bytes_req:sort=hitcount:size=2048 [active]
{ call_site: ffffffffa026b291 } hitcount: 1 bytes_req: 433
@@ -376,9 +376,9 @@ Extended error information
trigger::
# echo 'hist:key=call_site.sym:val=bytes_req' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+ /sys/kernel/tracing/events/kmem/kmalloc/trigger
- # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+ # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
# trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=hitcount:size=2048 [active]
{ call_site: [ffffffff810adcb9] syslog_print_all } hitcount: 1 bytes_req: 1024
@@ -426,9 +426,9 @@ Extended error information
the 'sort' parameter, along with the 'descending' modifier::
# echo 'hist:key=call_site.sym:val=bytes_req:sort=bytes_req.descending' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+ /sys/kernel/tracing/events/kmem/kmalloc/trigger
- # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+ # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
# trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=bytes_req.descending:size=2048 [active]
{ call_site: [ffffffffa046041c] i915_gem_execbuffer2 [i915] } hitcount: 2186 bytes_req: 3397464
@@ -467,9 +467,9 @@ Extended error information
name, just use 'sym-offset' instead::
# echo 'hist:key=call_site.sym-offset:val=bytes_req:sort=bytes_req.descending' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+ /sys/kernel/tracing/events/kmem/kmalloc/trigger
- # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+ # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
# trigger info: hist:keys=call_site.sym-offset:vals=bytes_req:sort=bytes_req.descending:size=2048 [active]
{ call_site: [ffffffffa046041c] i915_gem_execbuffer2+0x6c/0x2c0 [i915] } hitcount: 4569 bytes_req: 3163720
@@ -506,9 +506,9 @@ Extended error information
allocated in a descending order::
# echo 'hist:keys=call_site.sym:values=bytes_req,bytes_alloc:sort=bytes_alloc.descending' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+ /sys/kernel/tracing/events/kmem/kmalloc/trigger
- # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+ # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
# trigger info: hist:keys=call_site.sym:vals=bytes_req,bytes_alloc:sort=bytes_alloc.descending:size=2048 [active]
{ call_site: [ffffffffa046041c] i915_gem_execbuffer2 [i915] } hitcount: 7403 bytes_req: 4084360 bytes_alloc: 5958016
@@ -549,7 +549,7 @@ Extended error information
value 'stacktrace' for the key parameter::
# echo 'hist:keys=stacktrace:values=bytes_req,bytes_alloc:sort=bytes_alloc' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+ /sys/kernel/tracing/events/kmem/kmalloc/trigger
The above trigger will use the kernel stack trace in effect when an
event is triggered as the key for the hash table. This allows the
@@ -559,7 +559,7 @@ Extended error information
every callpath in the system that led up to a kmalloc (in this case
every callpath to a kmalloc for a kernel compile)::
- # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+ # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
# trigger info: hist:keys=stacktrace:vals=bytes_req,bytes_alloc:sort=bytes_alloc:size=2048 [active]
{ stacktrace:
@@ -658,9 +658,9 @@ Extended error information
keeps a per-process sum of total bytes read::
# echo 'hist:key=common_pid.execname:val=count:sort=count.descending' > \
- /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger
+ /sys/kernel/tracing/events/syscalls/sys_enter_read/trigger
- # cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/hist
+ # cat /sys/kernel/tracing/events/syscalls/sys_enter_read/hist
# trigger info: hist:keys=common_pid.execname:vals=count:sort=count.descending:size=2048 [active]
{ common_pid: gnome-terminal [ 3196] } hitcount: 280 count: 1093512
@@ -699,9 +699,9 @@ Extended error information
counts for the system during the run::
# echo 'hist:key=id.syscall:val=hitcount' > \
- /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger
+ /sys/kernel/tracing/events/raw_syscalls/sys_enter/trigger
- # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
+ # cat /sys/kernel/tracing/events/raw_syscalls/sys_enter/hist
# trigger info: hist:keys=id.syscall:vals=hitcount:sort=hitcount:size=2048 [active]
{ id: sys_fsync [ 74] } hitcount: 1
@@ -753,9 +753,9 @@ Extended error information
hitcount sum as the secondary key::
# echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount' > \
- /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger
+ /sys/kernel/tracing/events/raw_syscalls/sys_enter/trigger
- # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
+ # cat /sys/kernel/tracing/events/raw_syscalls/sys_enter/hist
# trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:size=2048 [active]
{ id: sys_read [ 0], common_pid: rtkit-daemon [ 1877] } hitcount: 1
@@ -803,9 +803,9 @@ Extended error information
can use that to filter out all the other syscalls::
# echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount if id == 16' > \
- /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger
+ /sys/kernel/tracing/events/raw_syscalls/sys_enter/trigger
- # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
+ # cat /sys/kernel/tracing/events/raw_syscalls/sys_enter/hist
# trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:size=2048 if id == 16 [active]
{ id: sys_ioctl [ 16], common_pid: gmain [ 2769] } hitcount: 1
@@ -846,9 +846,9 @@ Extended error information
each process::
# echo 'hist:key=common_pid.execname,size:val=hitcount:sort=common_pid,size' > \
- /sys/kernel/debug/tracing/events/syscalls/sys_enter_recvfrom/trigger
+ /sys/kernel/tracing/events/syscalls/sys_enter_recvfrom/trigger
- # cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_recvfrom/hist
+ # cat /sys/kernel/tracing/events/syscalls/sys_enter_recvfrom/hist
# trigger info: hist:keys=common_pid.execname,size:vals=hitcount:sort=common_pid.execname,size:size=2048 [active]
{ common_pid: smbd [ 784], size: 4 } hitcount: 1
@@ -899,9 +899,9 @@ Extended error information
much smaller number, say 256::
# echo 'hist:key=child_comm:val=hitcount:size=256' > \
- /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
+ /sys/kernel/tracing/events/sched/sched_process_fork/trigger
- # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
+ # cat /sys/kernel/tracing/events/sched/sched_process_fork/hist
# trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
{ child_comm: dconf worker } hitcount: 1
@@ -935,9 +935,9 @@ Extended error information
displays as [paused]::
# echo 'hist:key=child_comm:val=hitcount:size=256:pause' >> \
- /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
+ /sys/kernel/tracing/events/sched/sched_process_fork/trigger
- # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
+ # cat /sys/kernel/tracing/events/sched/sched_process_fork/hist
# trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [paused]
{ child_comm: dconf worker } hitcount: 1
@@ -972,9 +972,9 @@ Extended error information
again, and the data has changed::
# echo 'hist:key=child_comm:val=hitcount:size=256:cont' >> \
- /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
+ /sys/kernel/tracing/events/sched/sched_process_fork/trigger
- # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
+ # cat /sys/kernel/tracing/events/sched/sched_process_fork/hist
# trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
{ child_comm: dconf worker } hitcount: 1
@@ -1026,7 +1026,7 @@ Extended error information
netif_receive_skb event::
# echo 'hist:key=stacktrace:vals=len:pause' > \
- /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ /sys/kernel/tracing/events/net/netif_receive_skb/trigger
Next, we set up an 'enable_hist' trigger on the sched_process_exec
event, with an 'if filename==/usr/bin/wget' filter. The effect of
@@ -1037,7 +1037,7 @@ Extended error information
hash table keyed on stacktrace::
# echo 'enable_hist:net:netif_receive_skb if filename==/usr/bin/wget' > \
- /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
+ /sys/kernel/tracing/events/sched/sched_process_exec/trigger
The aggregation continues until the netif_receive_skb is paused
again, which is what the following disable_hist event does by
@@ -1045,7 +1045,7 @@ Extended error information
filter 'comm==wget'::
# echo 'disable_hist:net:netif_receive_skb if comm==wget' > \
- /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
+ /sys/kernel/tracing/events/sched/sched_process_exit/trigger
Whenever a process exits and the comm field of the disable_hist
trigger filter matches 'comm==wget', the netif_receive_skb hist
@@ -1058,7 +1058,7 @@ Extended error information
$ wget https://www.kernel.org/pub/linux/kernel/v3.x/patch-3.19.xz
- # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
+ # cat /sys/kernel/tracing/events/net/netif_receive_skb/hist
# trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
{ stacktrace:
@@ -1142,12 +1142,12 @@ Extended error information
again, we can just clear the histogram first::
# echo 'hist:key=stacktrace:vals=len:clear' >> \
- /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ /sys/kernel/tracing/events/net/netif_receive_skb/trigger
Just to verify that it is in fact cleared, here's what we now see in
the hist file::
- # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
+ # cat /sys/kernel/tracing/events/net/netif_receive_skb/hist
# trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
Totals:
@@ -1162,21 +1162,21 @@ Extended error information
sched_process_exit events as such::
# echo 'enable_event:net:netif_receive_skb if filename==/usr/bin/wget' > \
- /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
+ /sys/kernel/tracing/events/sched/sched_process_exec/trigger
# echo 'disable_event:net:netif_receive_skb if comm==wget' > \
- /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
+ /sys/kernel/tracing/events/sched/sched_process_exit/trigger
If you read the trigger files for the sched_process_exec and
sched_process_exit triggers, you should see two triggers for each:
one enabling/disabling the hist aggregation and the other
enabling/disabling the logging of events::
- # cat /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
+ # cat /sys/kernel/tracing/events/sched/sched_process_exec/trigger
enable_event:net:netif_receive_skb:unlimited if filename==/usr/bin/wget
enable_hist:net:netif_receive_skb:unlimited if filename==/usr/bin/wget
- # cat /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
+ # cat /sys/kernel/tracing/events/sched/sched_process_exit/trigger
enable_event:net:netif_receive_skb:unlimited if comm==wget
disable_hist:net:netif_receive_skb:unlimited if comm==wget
@@ -1192,7 +1192,7 @@ Extended error information
saw in the last run, but this time you should also see the
individual events in the trace file::
- # cat /sys/kernel/debug/tracing/trace
+ # cat /sys/kernel/tracing/trace
# tracer: nop
#
@@ -1226,15 +1226,15 @@ Extended error information
other things::
# echo 'hist:keys=skbaddr.hex:vals=len if len < 0' >> \
- /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ /sys/kernel/tracing/events/net/netif_receive_skb/trigger
# echo 'hist:keys=skbaddr.hex:vals=len if len > 4096' >> \
- /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ /sys/kernel/tracing/events/net/netif_receive_skb/trigger
# echo 'hist:keys=skbaddr.hex:vals=len if len == 256' >> \
- /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ /sys/kernel/tracing/events/net/netif_receive_skb/trigger
# echo 'hist:keys=skbaddr.hex:vals=len' >> \
- /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ /sys/kernel/tracing/events/net/netif_receive_skb/trigger
# echo 'hist:keys=len:vals=common_preempt_count' >> \
- /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ /sys/kernel/tracing/events/net/netif_receive_skb/trigger
The above set of commands create four triggers differing only in
their filters, along with a completely different though fairly
@@ -1246,7 +1246,7 @@ Extended error information
Displaying the contents of the 'hist' file for the event shows the
contents of all five histograms::
- # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
+ # cat /sys/kernel/tracing/events/net/netif_receive_skb/hist
# event histogram
#
@@ -1367,15 +1367,15 @@ Extended error information
field in the shared 'foo' histogram data::
# echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
- /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ /sys/kernel/tracing/events/net/netif_receive_skb/trigger
# echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
- /sys/kernel/debug/tracing/events/net/netif_rx/trigger
+ /sys/kernel/tracing/events/net/netif_rx/trigger
You can see that they're updating common histogram data by reading
each event's hist files at the same time::
- # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist;
- cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
+ # cat /sys/kernel/tracing/events/net/netif_receive_skb/hist;
+ cat /sys/kernel/tracing/events/net/netif_rx/hist
# event histogram
#
@@ -1488,15 +1488,15 @@ Extended error information
couple of triggers named 'bar' using those fields::
# echo 'hist:name=bar:key=stacktrace:val=hitcount' > \
- /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
+ /sys/kernel/tracing/events/sched/sched_process_fork/trigger
# echo 'hist:name=bar:key=stacktrace:val=hitcount' > \
- /sys/kernel/debug/tracing/events/net/netif_rx/trigger
+ /sys/kernel/tracing/events/net/netif_rx/trigger
And displaying the output of either shows some interesting if
somewhat confusing output::
- # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
- # cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
+ # cat /sys/kernel/tracing/events/sched/sched_process_fork/hist
+ # cat /sys/kernel/tracing/events/net/netif_rx/hist
# event histogram
#
@@ -1826,19 +1826,19 @@ variable reference to a variable on another event::
u64 lat; \
pid_t pid; \
int prio' >> \
- /sys/kernel/debug/tracing/synthetic_events
+ /sys/kernel/tracing/synthetic_events
Reading the tracing/synthetic_events file lists all the currently
defined synthetic events, in this case the event defined above::
- # cat /sys/kernel/debug/tracing/synthetic_events
+ # cat /sys/kernel/tracing/synthetic_events
wakeup_latency u64 lat; pid_t pid; int prio
An existing synthetic event definition can be removed by prepending
the command that defined it with a '!'::
# echo '!wakeup_latency u64 lat pid_t pid int prio' >> \
- /sys/kernel/debug/tracing/synthetic_events
+ /sys/kernel/tracing/synthetic_events
At this point, there isn't yet an actual 'wakeup_latency' event
instantiated in the event subsystem - for this to happen, a 'hist
@@ -1850,20 +1850,20 @@ done, the 'wakeup_latency' synthetic event instance is created.
The new event is created under the tracing/events/synthetic/ directory
and looks and behaves just like any other event::
- # ls /sys/kernel/debug/tracing/events/synthetic/wakeup_latency
+ # ls /sys/kernel/tracing/events/synthetic/wakeup_latency
enable filter format hist id trigger
A histogram can now be defined for the new synthetic event::
# echo 'hist:keys=pid,prio,lat.log2:sort=lat' >> \
- /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger
+ /sys/kernel/tracing/events/synthetic/wakeup_latency/trigger
The above shows the latency "lat" in a power of 2 grouping.
Like any other event, once a histogram is enabled for the event, the
output can be displayed by reading the event's 'hist' file.
- # cat /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/hist
+ # cat /sys/kernel/tracing/events/synthetic/wakeup_latency/hist
# event histogram
#
@@ -1911,7 +1911,7 @@ The latency values can also be grouped linearly by a given size with
the ".buckets" modifier and specify a size (in this case groups of 10).
# echo 'hist:keys=pid,prio,lat.buckets=10:sort=lat' >> \
- /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger
+ /sys/kernel/tracing/events/synthetic/wakeup_latency/trigger
# event histogram
#
@@ -2039,9 +2039,9 @@ The following commonly-used handler.action pairs are available:
event::
# echo 'wakeup_new_test pid_t pid' >> \
- /sys/kernel/debug/tracing/synthetic_events
+ /sys/kernel/tracing/synthetic_events
- # cat /sys/kernel/debug/tracing/synthetic_events
+ # cat /sys/kernel/tracing/synthetic_events
wakeup_new_test pid_t pid
The following hist trigger both defines the missing testpid
@@ -2052,26 +2052,26 @@ The following commonly-used handler.action pairs are available:
# echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\
wakeup_new_test($testpid) if comm=="cyclictest"' >> \
- /sys/kernel/debug/tracing/events/sched/sched_wakeup_new/trigger
+ /sys/kernel/tracing/events/sched/sched_wakeup_new/trigger
Or, equivalently, using the 'trace' keyword syntax:
# echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\
trace(wakeup_new_test,$testpid) if comm=="cyclictest"' >> \
- /sys/kernel/debug/tracing/events/sched/sched_wakeup_new/trigger
+ /sys/kernel/tracing/events/sched/sched_wakeup_new/trigger
Creating and displaying a histogram based on those events is now
just a matter of using the fields and new synthetic event in the
tracing/events/synthetic directory, as usual::
# echo 'hist:keys=pid:sort=pid' >> \
- /sys/kernel/debug/tracing/events/synthetic/wakeup_new_test/trigger
+ /sys/kernel/tracing/events/synthetic/wakeup_new_test/trigger
Running 'cyclictest' should cause wakeup_new events to generate
wakeup_new_test synthetic events which should result in histogram
output in the wakeup_new_test event's hist file::
- # cat /sys/kernel/debug/tracing/events/synthetic/wakeup_new_test/hist
+ # cat /sys/kernel/tracing/events/synthetic/wakeup_new_test/hist
A more typical usage would be to use two events to calculate a
latency. The following example uses a set of hist triggers to
@@ -2080,14 +2080,14 @@ The following commonly-used handler.action pairs are available:
First, we define a 'wakeup_latency' synthetic event::
# echo 'wakeup_latency u64 lat; pid_t pid; int prio' >> \
- /sys/kernel/debug/tracing/synthetic_events
+ /sys/kernel/tracing/synthetic_events
Next, we specify that whenever we see a sched_waking event for a
cyclictest thread, save the timestamp in a 'ts0' variable::
# echo 'hist:keys=$saved_pid:saved_pid=pid:ts0=common_timestamp.usecs \
if comm=="cyclictest"' >> \
- /sys/kernel/debug/tracing/events/sched/sched_waking/trigger
+ /sys/kernel/tracing/events/sched/sched_waking/trigger
Then, when the corresponding thread is actually scheduled onto the
CPU by a sched_switch event (saved_pid matches next_pid), calculate
@@ -2097,19 +2097,19 @@ The following commonly-used handler.action pairs are available:
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:\
onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,\
$saved_pid,next_prio) if next_comm=="cyclictest"' >> \
- /sys/kernel/debug/tracing/events/sched/sched_switch/trigger
+ /sys/kernel/tracing/events/sched/sched_switch/trigger
We also need to create a histogram on the wakeup_latency synthetic
event in order to aggregate the generated synthetic event data::
# echo 'hist:keys=pid,prio,lat:sort=pid,lat' >> \
- /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger
+ /sys/kernel/tracing/events/synthetic/wakeup_latency/trigger
Finally, once we've run cyclictest to actually generate some
events, we can see the output by looking at the wakeup_latency
synthetic event's hist file::
- # cat /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/hist
+ # cat /sys/kernel/tracing/events/synthetic/wakeup_latency/hist
- onmax(var).save(field,.. .)
@@ -2135,19 +2135,19 @@ The following commonly-used handler.action pairs are available:
# echo 'hist:keys=pid:ts0=common_timestamp.usecs \
if comm=="cyclictest"' >> \
- /sys/kernel/debug/tracing/events/sched/sched_waking/trigger
+ /sys/kernel/tracing/events/sched/sched_waking/trigger
# echo 'hist:keys=next_pid:\
wakeup_lat=common_timestamp.usecs-$ts0:\
onmax($wakeup_lat).save(next_comm,prev_pid,prev_prio,prev_comm) \
if next_comm=="cyclictest"' >> \
- /sys/kernel/debug/tracing/events/sched/sched_switch/trigger
+ /sys/kernel/tracing/events/sched/sched_switch/trigger
When the histogram is displayed, the max value and the saved
values corresponding to the max are displayed following the rest
of the fields::
- # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist
+ # cat /sys/kernel/tracing/events/sched/sched_switch/hist
{ next_pid: 2255 } hitcount: 239
common_timestamp-ts0: 0
max: 27
@@ -2193,17 +2193,17 @@ The following commonly-used handler.action pairs are available:
the scheduler events are also enabled, which are the events that
will show up in the snapshot when it is taken at some point:
- # echo 1 > /sys/kernel/debug/tracing/events/sched/enable
+ # echo 1 > /sys/kernel/tracing/events/sched/enable
# echo 'hist:keys=pid:ts0=common_timestamp.usecs \
if comm=="cyclictest"' >> \
- /sys/kernel/debug/tracing/events/sched/sched_waking/trigger
+ /sys/kernel/tracing/events/sched/sched_waking/trigger
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
onmax($wakeup_lat).save(next_prio,next_comm,prev_pid,prev_prio, \
prev_comm):onmax($wakeup_lat).snapshot() \
if next_comm=="cyclictest"' >> \
- /sys/kernel/debug/tracing/events/sched/sched_switch/trigger
+ /sys/kernel/tracing/events/sched/sched_switch/trigger
When the histogram is displayed, for each bucket the max value
and the saved values corresponding to the max are displayed
@@ -2212,7 +2212,7 @@ The following commonly-used handler.action pairs are available:
If a snapshot was taken, there is also a message indicating that,
along with the value and event that triggered the global maximum:
- # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist
+ # cat /sys/kernel/tracing/events/sched/sched_switch/hist
{ next_pid: 2101 } hitcount: 200
max: 52 next_prio: 120 next_comm: cyclictest \
prev_pid: 0 prev_prio: 120 prev_comm: swapper/6
@@ -2247,7 +2247,7 @@ The following commonly-used handler.action pairs are available:
sched_switch events, which should match the time displayed in the
global maximum)::
- # cat /sys/kernel/debug/tracing/snapshot
+ # cat /sys/kernel/tracing/snapshot
<...>-2103 [005] d..3 309.873125: sched_switch: prev_comm=cyclictest prev_pid=2103 prev_prio=19 prev_state=D ==> next_comm=swapper/5 next_pid=0 next_prio=120
<idle>-0 [005] d.h3 309.873611: sched_waking: comm=cyclictest pid=2102 prio=19 target_cpu=005
@@ -2312,13 +2312,13 @@ The following commonly-used handler.action pairs are available:
enabled, which are the events that will show up in the snapshot
when it is taken at some point:
- # echo 1 > /sys/kernel/debug/tracing/events/sched/enable
- # echo 1 > /sys/kernel/debug/tracing/events/tcp/enable
+ # echo 1 > /sys/kernel/tracing/events/sched/enable
+ # echo 1 > /sys/kernel/tracing/events/tcp/enable
# echo 'hist:keys=dport:cwnd=snd_cwnd: \
onchange($cwnd).save(snd_wnd,srtt,rcv_wnd): \
onchange($cwnd).snapshot()' >> \
- /sys/kernel/debug/tracing/events/tcp/tcp_probe/trigger
+ /sys/kernel/tracing/events/tcp/tcp_probe/trigger
When the histogram is displayed, for each bucket the tracked value
and the saved values corresponding to that value are displayed
@@ -2327,7 +2327,7 @@ The following commonly-used handler.action pairs are available:
If a snapshot was taken, there is also a message indicating that,
along with the value and event that triggered the snapshot::
- # cat /sys/kernel/debug/tracing/events/tcp/tcp_probe/hist
+ # cat /sys/kernel/tracing/events/tcp/tcp_probe/hist
{ dport: 1521 } hitcount: 8
changed: 10 snd_wnd: 35456 srtt: 154262 rcv_wnd: 42112
@@ -2361,7 +2361,7 @@ The following commonly-used handler.action pairs are available:
And finally, looking at the snapshot data should show at or near
the end the event that triggered the snapshot::
- # cat /sys/kernel/debug/tracing/snapshot
+ # cat /sys/kernel/tracing/snapshot
gnome-shell-1261 [006] dN.3 49.823113: sched_stat_runtime: comm=gnome-shell pid=1261 runtime=49347 [ns] vruntime=1835730389 [ns]
kworker/u16:4-773 [003] d..3 49.823114: sched_switch: prev_comm=kworker/u16:4 prev_pid=773 prev_prio=120 prev_state=R+ ==> next_comm=kworker/3:2 next_pid=135 next_prio=120