aboutsummaryrefslogtreecommitdiffstats
path: root/Documentation/trace/ftrace.txt
diff options
context:
space:
mode:
Diffstat (limited to 'Documentation/trace/ftrace.txt')
-rw-r--r--Documentation/trace/ftrace.txt76
1 files changed, 43 insertions, 33 deletions
diff --git a/Documentation/trace/ftrace.txt b/Documentation/trace/ftrace.txt
index a39b3c749de5..957b22fde2df 100644
--- a/Documentation/trace/ftrace.txt
+++ b/Documentation/trace/ftrace.txt
@@ -26,6 +26,12 @@ disabled, and more (ftrace allows for tracer plugins, which
26means that the list of tracers can always grow). 26means that the list of tracers can always grow).
27 27
28 28
29Implementation Details
30----------------------
31
32See ftrace-design.txt for details for arch porters and such.
33
34
29The File System 35The File System
30--------------- 36---------------
31 37
@@ -85,26 +91,19 @@ of ftrace. Here is a list of some of the key files:
85 This file holds the output of the trace in a human 91 This file holds the output of the trace in a human
86 readable format (described below). 92 readable format (described below).
87 93
88 latency_trace:
89
90 This file shows the same trace but the information
91 is organized more to display possible latencies
92 in the system (described below).
93
94 trace_pipe: 94 trace_pipe:
95 95
96 The output is the same as the "trace" file but this 96 The output is the same as the "trace" file but this
97 file is meant to be streamed with live tracing. 97 file is meant to be streamed with live tracing.
98 Reads from this file will block until new data 98 Reads from this file will block until new data is
99 is retrieved. Unlike the "trace" and "latency_trace" 99 retrieved. Unlike the "trace" file, this file is a
100 files, this file is a consumer. This means reading 100 consumer. This means reading from this file causes
101 from this file causes sequential reads to display 101 sequential reads to display more current data. Once
102 more current data. Once data is read from this 102 data is read from this file, it is consumed, and
103 file, it is consumed, and will not be read 103 will not be read again with a sequential read. The
104 again with a sequential read. The "trace" and 104 "trace" file is static, and if the tracer is not
105 "latency_trace" files are static, and if the 105 adding more data,they will display the same
106 tracer is not adding more data, they will display 106 information every time they are read.
107 the same information every time they are read.
108 107
109 trace_options: 108 trace_options:
110 109
@@ -117,10 +116,10 @@ of ftrace. Here is a list of some of the key files:
117 Some of the tracers record the max latency. 116 Some of the tracers record the max latency.
118 For example, the time interrupts are disabled. 117 For example, the time interrupts are disabled.
119 This time is saved in this file. The max trace 118 This time is saved in this file. The max trace
120 will also be stored, and displayed by either 119 will also be stored, and displayed by "trace".
121 "trace" or "latency_trace". A new max trace will 120 A new max trace will only be recorded if the
122 only be recorded if the latency is greater than 121 latency is greater than the value in this
123 the value in this file. (in microseconds) 122 file. (in microseconds)
124 123
125 buffer_size_kb: 124 buffer_size_kb:
126 125
@@ -134,7 +133,7 @@ of ftrace. Here is a list of some of the key files:
134 than requested, the rest of the page will be used, 133 than requested, the rest of the page will be used,
135 making the actual allocation bigger than requested. 134 making the actual allocation bigger than requested.
136 ( Note, the size may not be a multiple of the page size 135 ( Note, the size may not be a multiple of the page size
137 due to buffer managment overhead. ) 136 due to buffer management overhead. )
138 137
139 This can only be updated when the current_tracer 138 This can only be updated when the current_tracer
140 is set to "nop". 139 is set to "nop".
@@ -210,7 +209,7 @@ Here is the list of current tracers that may be configured.
210 the trace with the longest max latency. 209 the trace with the longest max latency.
211 See tracing_max_latency. When a new max is recorded, 210 See tracing_max_latency. When a new max is recorded,
212 it replaces the old trace. It is best to view this 211 it replaces the old trace. It is best to view this
213 trace via the latency_trace file. 212 trace with the latency-format option enabled.
214 213
215 "preemptoff" 214 "preemptoff"
216 215
@@ -307,8 +306,8 @@ the lowest priority thread (pid 0).
307Latency trace format 306Latency trace format
308-------------------- 307--------------------
309 308
310For traces that display latency times, the latency_trace file 309When the latency-format option is enabled, the trace file gives
311gives somewhat more information to see why a latency happened. 310somewhat more information to see why a latency happened.
312Here is a typical trace. 311Here is a typical trace.
313 312
314# tracer: irqsoff 313# tracer: irqsoff
@@ -380,9 +379,10 @@ explains which is which.
380 379
381The above is mostly meaningful for kernel developers. 380The above is mostly meaningful for kernel developers.
382 381
383 time: This differs from the trace file output. The trace file output 382 time: When the latency-format option is enabled, the trace file
384 includes an absolute timestamp. The timestamp used by the 383 output includes a timestamp relative to the start of the
385 latency_trace file is relative to the start of the trace. 384 trace. This differs from the output when latency-format
385 is disabled, which includes an absolute timestamp.
386 386
387 delay: This is just to help catch your eye a bit better. And 387 delay: This is just to help catch your eye a bit better. And
388 needs to be fixed to be only relative to the same CPU. 388 needs to be fixed to be only relative to the same CPU.
@@ -440,7 +440,8 @@ Here are the available options:
440 sym-addr: 440 sym-addr:
441 bash-4000 [01] 1477.606694: simple_strtoul <c0339346> 441 bash-4000 [01] 1477.606694: simple_strtoul <c0339346>
442 442
443 verbose - This deals with the latency_trace file. 443 verbose - This deals with the trace file when the
444 latency-format option is enabled.
444 445
445 bash 4000 1 0 00000000 00010a95 [58127d26] 1720.415ms \ 446 bash 4000 1 0 00000000 00010a95 [58127d26] 1720.415ms \
446 (+0.000ms): simple_strtoul (strict_strtoul) 447 (+0.000ms): simple_strtoul (strict_strtoul)
@@ -472,7 +473,7 @@ Here are the available options:
472 the app is no longer running 473 the app is no longer running
473 474
474 The lookup is performed when you read 475 The lookup is performed when you read
475 trace,trace_pipe,latency_trace. Example: 476 trace,trace_pipe. Example:
476 477
477 a.out-1623 [000] 40874.465068: /root/a.out[+0x480] <-/root/a.out[+0 478 a.out-1623 [000] 40874.465068: /root/a.out[+0x480] <-/root/a.out[+0
478x494] <- /root/a.out[+0x4a8] <- /lib/libc-2.7.so[+0x1e1a6] 479x494] <- /root/a.out[+0x4a8] <- /lib/libc-2.7.so[+0x1e1a6]
@@ -481,6 +482,11 @@ x494] <- /root/a.out[+0x4a8] <- /lib/libc-2.7.so[+0x1e1a6]
481 every scheduling event. Will add overhead if 482 every scheduling event. Will add overhead if
482 there's a lot of tasks running at once. 483 there's a lot of tasks running at once.
483 484
485 latency-format - This option changes the trace. When
486 it is enabled, the trace displays
487 additional information about the
488 latencies, as described in "Latency
489 trace format".
484 490
485sched_switch 491sched_switch
486------------ 492------------
@@ -596,12 +602,13 @@ To reset the maximum, echo 0 into tracing_max_latency. Here is
596an example: 602an example:
597 603
598 # echo irqsoff > current_tracer 604 # echo irqsoff > current_tracer
605 # echo latency-format > trace_options
599 # echo 0 > tracing_max_latency 606 # echo 0 > tracing_max_latency
600 # echo 1 > tracing_enabled 607 # echo 1 > tracing_enabled
601 # ls -ltr 608 # ls -ltr
602 [...] 609 [...]
603 # echo 0 > tracing_enabled 610 # echo 0 > tracing_enabled
604 # cat latency_trace 611 # cat trace
605# tracer: irqsoff 612# tracer: irqsoff
606# 613#
607irqsoff latency trace v1.1.5 on 2.6.26 614irqsoff latency trace v1.1.5 on 2.6.26
@@ -703,12 +710,13 @@ which preemption was disabled. The control of preemptoff tracer
703is much like the irqsoff tracer. 710is much like the irqsoff tracer.
704 711
705 # echo preemptoff > current_tracer 712 # echo preemptoff > current_tracer
713 # echo latency-format > trace_options
706 # echo 0 > tracing_max_latency 714 # echo 0 > tracing_max_latency
707 # echo 1 > tracing_enabled 715 # echo 1 > tracing_enabled
708 # ls -ltr 716 # ls -ltr
709 [...] 717 [...]
710 # echo 0 > tracing_enabled 718 # echo 0 > tracing_enabled
711 # cat latency_trace 719 # cat trace
712# tracer: preemptoff 720# tracer: preemptoff
713# 721#
714preemptoff latency trace v1.1.5 on 2.6.26-rc8 722preemptoff latency trace v1.1.5 on 2.6.26-rc8
@@ -850,12 +858,13 @@ Again, using this trace is much like the irqsoff and preemptoff
850tracers. 858tracers.
851 859
852 # echo preemptirqsoff > current_tracer 860 # echo preemptirqsoff > current_tracer
861 # echo latency-format > trace_options
853 # echo 0 > tracing_max_latency 862 # echo 0 > tracing_max_latency
854 # echo 1 > tracing_enabled 863 # echo 1 > tracing_enabled
855 # ls -ltr 864 # ls -ltr
856 [...] 865 [...]
857 # echo 0 > tracing_enabled 866 # echo 0 > tracing_enabled
858 # cat latency_trace 867 # cat trace
859# tracer: preemptirqsoff 868# tracer: preemptirqsoff
860# 869#
861preemptirqsoff latency trace v1.1.5 on 2.6.26-rc8 870preemptirqsoff latency trace v1.1.5 on 2.6.26-rc8
@@ -1012,11 +1021,12 @@ Instead of performing an 'ls', we will run 'sleep 1' under
1012'chrt' which changes the priority of the task. 1021'chrt' which changes the priority of the task.
1013 1022
1014 # echo wakeup > current_tracer 1023 # echo wakeup > current_tracer
1024 # echo latency-format > trace_options
1015 # echo 0 > tracing_max_latency 1025 # echo 0 > tracing_max_latency
1016 # echo 1 > tracing_enabled 1026 # echo 1 > tracing_enabled
1017 # chrt -f 5 sleep 1 1027 # chrt -f 5 sleep 1
1018 # echo 0 > tracing_enabled 1028 # echo 0 > tracing_enabled
1019 # cat latency_trace 1029 # cat trace
1020# tracer: wakeup 1030# tracer: wakeup
1021# 1031#
1022wakeup latency trace v1.1.5 on 2.6.26-rc8 1032wakeup latency trace v1.1.5 on 2.6.26-rc8