diff options
-rw-r--r-- | Documentation/trace/ftrace.txt | 68 |
1 files changed, 36 insertions, 32 deletions
diff --git a/Documentation/trace/ftrace.txt b/Documentation/trace/ftrace.txt index a39b3c749de5..355d0f1f8c50 100644 --- a/Documentation/trace/ftrace.txt +++ b/Documentation/trace/ftrace.txt | |||
@@ -85,26 +85,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 | 85 | This file holds the output of the trace in a human |
86 | readable format (described below). | 86 | readable format (described below). |
87 | 87 | ||
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: | 88 | trace_pipe: |
95 | 89 | ||
96 | The output is the same as the "trace" file but this | 90 | The output is the same as the "trace" file but this |
97 | file is meant to be streamed with live tracing. | 91 | file is meant to be streamed with live tracing. |
98 | Reads from this file will block until new data | 92 | Reads from this file will block until new data is |
99 | is retrieved. Unlike the "trace" and "latency_trace" | 93 | retrieved. Unlike the "trace" file, this file is a |
100 | files, this file is a consumer. This means reading | 94 | consumer. This means reading from this file causes |
101 | from this file causes sequential reads to display | 95 | sequential reads to display more current data. Once |
102 | more current data. Once data is read from this | 96 | data is read from this file, it is consumed, and |
103 | file, it is consumed, and will not be read | 97 | will not be read again with a sequential read. The |
104 | again with a sequential read. The "trace" and | 98 | "trace" file is static, and if the tracer is not |
105 | "latency_trace" files are static, and if the | 99 | adding more data,they will display the same |
106 | tracer is not adding more data, they will display | 100 | information every time they are read. |
107 | the same information every time they are read. | ||
108 | 101 | ||
109 | trace_options: | 102 | trace_options: |
110 | 103 | ||
@@ -117,10 +110,10 @@ of ftrace. Here is a list of some of the key files: | |||
117 | Some of the tracers record the max latency. | 110 | Some of the tracers record the max latency. |
118 | For example, the time interrupts are disabled. | 111 | For example, the time interrupts are disabled. |
119 | This time is saved in this file. The max trace | 112 | This time is saved in this file. The max trace |
120 | will also be stored, and displayed by either | 113 | will also be stored, and displayed by "trace". |
121 | "trace" or "latency_trace". A new max trace will | 114 | A new max trace will only be recorded if the |
122 | only be recorded if the latency is greater than | 115 | latency is greater than the value in this |
123 | the value in this file. (in microseconds) | 116 | file. (in microseconds) |
124 | 117 | ||
125 | buffer_size_kb: | 118 | buffer_size_kb: |
126 | 119 | ||
@@ -210,7 +203,7 @@ Here is the list of current tracers that may be configured. | |||
210 | the trace with the longest max latency. | 203 | the trace with the longest max latency. |
211 | See tracing_max_latency. When a new max is recorded, | 204 | See tracing_max_latency. When a new max is recorded, |
212 | it replaces the old trace. It is best to view this | 205 | it replaces the old trace. It is best to view this |
213 | trace via the latency_trace file. | 206 | trace with the latency-format option enabled. |
214 | 207 | ||
215 | "preemptoff" | 208 | "preemptoff" |
216 | 209 | ||
@@ -307,8 +300,8 @@ the lowest priority thread (pid 0). | |||
307 | Latency trace format | 300 | Latency trace format |
308 | -------------------- | 301 | -------------------- |
309 | 302 | ||
310 | For traces that display latency times, the latency_trace file | 303 | When the latency-format option is enabled, the trace file gives |
311 | gives somewhat more information to see why a latency happened. | 304 | somewhat more information to see why a latency happened. |
312 | Here is a typical trace. | 305 | Here is a typical trace. |
313 | 306 | ||
314 | # tracer: irqsoff | 307 | # tracer: irqsoff |
@@ -380,9 +373,10 @@ explains which is which. | |||
380 | 373 | ||
381 | The above is mostly meaningful for kernel developers. | 374 | The above is mostly meaningful for kernel developers. |
382 | 375 | ||
383 | time: This differs from the trace file output. The trace file output | 376 | time: When the latency-format option is enabled, the trace file |
384 | includes an absolute timestamp. The timestamp used by the | 377 | output includes a timestamp relative to the start of the |
385 | latency_trace file is relative to the start of the trace. | 378 | trace. This differs from the output when latency-format |
379 | is disabled, which includes an absolute timestamp. | ||
386 | 380 | ||
387 | delay: This is just to help catch your eye a bit better. And | 381 | 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. | 382 | needs to be fixed to be only relative to the same CPU. |
@@ -440,7 +434,8 @@ Here are the available options: | |||
440 | sym-addr: | 434 | sym-addr: |
441 | bash-4000 [01] 1477.606694: simple_strtoul <c0339346> | 435 | bash-4000 [01] 1477.606694: simple_strtoul <c0339346> |
442 | 436 | ||
443 | verbose - This deals with the latency_trace file. | 437 | verbose - This deals with the trace file when the |
438 | latency-format option is enabled. | ||
444 | 439 | ||
445 | bash 4000 1 0 00000000 00010a95 [58127d26] 1720.415ms \ | 440 | bash 4000 1 0 00000000 00010a95 [58127d26] 1720.415ms \ |
446 | (+0.000ms): simple_strtoul (strict_strtoul) | 441 | (+0.000ms): simple_strtoul (strict_strtoul) |
@@ -472,7 +467,7 @@ Here are the available options: | |||
472 | the app is no longer running | 467 | the app is no longer running |
473 | 468 | ||
474 | The lookup is performed when you read | 469 | The lookup is performed when you read |
475 | trace,trace_pipe,latency_trace. Example: | 470 | trace,trace_pipe. Example: |
476 | 471 | ||
477 | a.out-1623 [000] 40874.465068: /root/a.out[+0x480] <-/root/a.out[+0 | 472 | a.out-1623 [000] 40874.465068: /root/a.out[+0x480] <-/root/a.out[+0 |
478 | x494] <- /root/a.out[+0x4a8] <- /lib/libc-2.7.so[+0x1e1a6] | 473 | x494] <- /root/a.out[+0x4a8] <- /lib/libc-2.7.so[+0x1e1a6] |
@@ -481,6 +476,11 @@ x494] <- /root/a.out[+0x4a8] <- /lib/libc-2.7.so[+0x1e1a6] | |||
481 | every scheduling event. Will add overhead if | 476 | every scheduling event. Will add overhead if |
482 | there's a lot of tasks running at once. | 477 | there's a lot of tasks running at once. |
483 | 478 | ||
479 | latency-format - This option changes the trace. When | ||
480 | it is enabled, the trace displays | ||
481 | additional information about the | ||
482 | latencies, as described in "Latency | ||
483 | trace format". | ||
484 | 484 | ||
485 | sched_switch | 485 | sched_switch |
486 | ------------ | 486 | ------------ |
@@ -596,12 +596,13 @@ To reset the maximum, echo 0 into tracing_max_latency. Here is | |||
596 | an example: | 596 | an example: |
597 | 597 | ||
598 | # echo irqsoff > current_tracer | 598 | # echo irqsoff > current_tracer |
599 | # echo latency-format > trace_options | ||
599 | # echo 0 > tracing_max_latency | 600 | # echo 0 > tracing_max_latency |
600 | # echo 1 > tracing_enabled | 601 | # echo 1 > tracing_enabled |
601 | # ls -ltr | 602 | # ls -ltr |
602 | [...] | 603 | [...] |
603 | # echo 0 > tracing_enabled | 604 | # echo 0 > tracing_enabled |
604 | # cat latency_trace | 605 | # cat trace |
605 | # tracer: irqsoff | 606 | # tracer: irqsoff |
606 | # | 607 | # |
607 | irqsoff latency trace v1.1.5 on 2.6.26 | 608 | irqsoff latency trace v1.1.5 on 2.6.26 |
@@ -703,12 +704,13 @@ which preemption was disabled. The control of preemptoff tracer | |||
703 | is much like the irqsoff tracer. | 704 | is much like the irqsoff tracer. |
704 | 705 | ||
705 | # echo preemptoff > current_tracer | 706 | # echo preemptoff > current_tracer |
707 | # echo latency-format > trace_options | ||
706 | # echo 0 > tracing_max_latency | 708 | # echo 0 > tracing_max_latency |
707 | # echo 1 > tracing_enabled | 709 | # echo 1 > tracing_enabled |
708 | # ls -ltr | 710 | # ls -ltr |
709 | [...] | 711 | [...] |
710 | # echo 0 > tracing_enabled | 712 | # echo 0 > tracing_enabled |
711 | # cat latency_trace | 713 | # cat trace |
712 | # tracer: preemptoff | 714 | # tracer: preemptoff |
713 | # | 715 | # |
714 | preemptoff latency trace v1.1.5 on 2.6.26-rc8 | 716 | preemptoff latency trace v1.1.5 on 2.6.26-rc8 |
@@ -850,12 +852,13 @@ Again, using this trace is much like the irqsoff and preemptoff | |||
850 | tracers. | 852 | tracers. |
851 | 853 | ||
852 | # echo preemptirqsoff > current_tracer | 854 | # echo preemptirqsoff > current_tracer |
855 | # echo latency-format > trace_options | ||
853 | # echo 0 > tracing_max_latency | 856 | # echo 0 > tracing_max_latency |
854 | # echo 1 > tracing_enabled | 857 | # echo 1 > tracing_enabled |
855 | # ls -ltr | 858 | # ls -ltr |
856 | [...] | 859 | [...] |
857 | # echo 0 > tracing_enabled | 860 | # echo 0 > tracing_enabled |
858 | # cat latency_trace | 861 | # cat trace |
859 | # tracer: preemptirqsoff | 862 | # tracer: preemptirqsoff |
860 | # | 863 | # |
861 | preemptirqsoff latency trace v1.1.5 on 2.6.26-rc8 | 864 | preemptirqsoff latency trace v1.1.5 on 2.6.26-rc8 |
@@ -1012,11 +1015,12 @@ Instead of performing an 'ls', we will run 'sleep 1' under | |||
1012 | 'chrt' which changes the priority of the task. | 1015 | 'chrt' which changes the priority of the task. |
1013 | 1016 | ||
1014 | # echo wakeup > current_tracer | 1017 | # echo wakeup > current_tracer |
1018 | # echo latency-format > trace_options | ||
1015 | # echo 0 > tracing_max_latency | 1019 | # echo 0 > tracing_max_latency |
1016 | # echo 1 > tracing_enabled | 1020 | # echo 1 > tracing_enabled |
1017 | # chrt -f 5 sleep 1 | 1021 | # chrt -f 5 sleep 1 |
1018 | # echo 0 > tracing_enabled | 1022 | # echo 0 > tracing_enabled |
1019 | # cat latency_trace | 1023 | # cat trace |
1020 | # tracer: wakeup | 1024 | # tracer: wakeup |
1021 | # | 1025 | # |
1022 | wakeup latency trace v1.1.5 on 2.6.26-rc8 | 1026 | wakeup latency trace v1.1.5 on 2.6.26-rc8 |