diff options
Diffstat (limited to 'Documentation/ftrace.txt')
-rw-r--r-- | Documentation/ftrace.txt | 149 |
1 files changed, 117 insertions, 32 deletions
diff --git a/Documentation/ftrace.txt b/Documentation/ftrace.txt index 9cc4d685dde5..803b1318b13d 100644 --- a/Documentation/ftrace.txt +++ b/Documentation/ftrace.txt | |||
@@ -82,7 +82,7 @@ of ftrace. Here is a list of some of the key files: | |||
82 | tracer is not adding more data, they will display | 82 | tracer is not adding more data, they will display |
83 | the same information every time they are read. | 83 | the same information every time they are read. |
84 | 84 | ||
85 | iter_ctrl: This file lets the user control the amount of data | 85 | trace_options: This file lets the user control the amount of data |
86 | that is displayed in one of the above output | 86 | that is displayed in one of the above output |
87 | files. | 87 | files. |
88 | 88 | ||
@@ -94,10 +94,10 @@ of ftrace. Here is a list of some of the key files: | |||
94 | only be recorded if the latency is greater than | 94 | only be recorded if the latency is greater than |
95 | the value in this file. (in microseconds) | 95 | the value in this file. (in microseconds) |
96 | 96 | ||
97 | trace_entries: This sets or displays the number of bytes each CPU | 97 | buffer_size_kb: This sets or displays the number of kilobytes each CPU |
98 | buffer can hold. The tracer buffers are the same size | 98 | buffer can hold. The tracer buffers are the same size |
99 | for each CPU. The displayed number is the size of the | 99 | for each CPU. The displayed number is the size of the |
100 | CPU buffer and not total size of all buffers. The | 100 | CPU buffer and not total size of all buffers. The |
101 | trace buffers are allocated in pages (blocks of memory | 101 | trace buffers are allocated in pages (blocks of memory |
102 | that the kernel uses for allocation, usually 4 KB in size). | 102 | that the kernel uses for allocation, usually 4 KB in size). |
103 | If the last page allocated has room for more bytes | 103 | If the last page allocated has room for more bytes |
@@ -127,6 +127,8 @@ of ftrace. Here is a list of some of the key files: | |||
127 | be traced. If a function exists in both set_ftrace_filter | 127 | be traced. If a function exists in both set_ftrace_filter |
128 | and set_ftrace_notrace, the function will _not_ be traced. | 128 | and set_ftrace_notrace, the function will _not_ be traced. |
129 | 129 | ||
130 | set_ftrace_pid: Have the function tracer only trace a single thread. | ||
131 | |||
130 | available_filter_functions: This lists the functions that ftrace | 132 | available_filter_functions: This lists the functions that ftrace |
131 | has processed and can trace. These are the function | 133 | has processed and can trace. These are the function |
132 | names that you can pass to "set_ftrace_filter" or | 134 | names that you can pass to "set_ftrace_filter" or |
@@ -316,23 +318,23 @@ The above is mostly meaningful for kernel developers. | |||
316 | The rest is the same as the 'trace' file. | 318 | The rest is the same as the 'trace' file. |
317 | 319 | ||
318 | 320 | ||
319 | iter_ctrl | 321 | trace_options |
320 | --------- | 322 | ------------- |
321 | 323 | ||
322 | The iter_ctrl file is used to control what gets printed in the trace | 324 | The trace_options file is used to control what gets printed in the trace |
323 | output. To see what is available, simply cat the file: | 325 | output. To see what is available, simply cat the file: |
324 | 326 | ||
325 | cat /debug/tracing/iter_ctrl | 327 | cat /debug/tracing/trace_options |
326 | print-parent nosym-offset nosym-addr noverbose noraw nohex nobin \ | 328 | print-parent nosym-offset nosym-addr noverbose noraw nohex nobin \ |
327 | noblock nostacktrace nosched-tree | 329 | noblock nostacktrace nosched-tree nouserstacktrace nosym-userobj |
328 | 330 | ||
329 | To disable one of the options, echo in the option prepended with "no". | 331 | To disable one of the options, echo in the option prepended with "no". |
330 | 332 | ||
331 | echo noprint-parent > /debug/tracing/iter_ctrl | 333 | echo noprint-parent > /debug/tracing/trace_options |
332 | 334 | ||
333 | To enable an option, leave off the "no". | 335 | To enable an option, leave off the "no". |
334 | 336 | ||
335 | echo sym-offset > /debug/tracing/iter_ctrl | 337 | echo sym-offset > /debug/tracing/trace_options |
336 | 338 | ||
337 | Here are the available options: | 339 | Here are the available options: |
338 | 340 | ||
@@ -378,6 +380,20 @@ Here are the available options: | |||
378 | When a trace is recorded, so is the stack of functions. | 380 | When a trace is recorded, so is the stack of functions. |
379 | This allows for back traces of trace sites. | 381 | This allows for back traces of trace sites. |
380 | 382 | ||
383 | userstacktrace - This option changes the trace. | ||
384 | It records a stacktrace of the current userspace thread. | ||
385 | |||
386 | sym-userobj - when user stacktrace are enabled, look up which object the | ||
387 | address belongs to, and print a relative address | ||
388 | This is especially useful when ASLR is on, otherwise you don't | ||
389 | get a chance to resolve the address to object/file/line after the app is no | ||
390 | longer running | ||
391 | |||
392 | The lookup is performed when you read trace,trace_pipe,latency_trace. Example: | ||
393 | |||
394 | a.out-1623 [000] 40874.465068: /root/a.out[+0x480] <-/root/a.out[+0 | ||
395 | x494] <- /root/a.out[+0x4a8] <- /lib/libc-2.7.so[+0x1e1a6] | ||
396 | |||
381 | sched-tree - TBD (any users??) | 397 | sched-tree - TBD (any users??) |
382 | 398 | ||
383 | 399 | ||
@@ -1059,6 +1075,83 @@ For simple one time traces, the above is sufficent. For anything else, | |||
1059 | a search through /proc/mounts may be needed to find where the debugfs | 1075 | a search through /proc/mounts may be needed to find where the debugfs |
1060 | file-system is mounted. | 1076 | file-system is mounted. |
1061 | 1077 | ||
1078 | |||
1079 | Single thread tracing | ||
1080 | --------------------- | ||
1081 | |||
1082 | By writing into /debug/tracing/set_ftrace_pid you can trace a | ||
1083 | single thread. For example: | ||
1084 | |||
1085 | # cat /debug/tracing/set_ftrace_pid | ||
1086 | no pid | ||
1087 | # echo 3111 > /debug/tracing/set_ftrace_pid | ||
1088 | # cat /debug/tracing/set_ftrace_pid | ||
1089 | 3111 | ||
1090 | # echo function > /debug/tracing/current_tracer | ||
1091 | # cat /debug/tracing/trace | head | ||
1092 | # tracer: function | ||
1093 | # | ||
1094 | # TASK-PID CPU# TIMESTAMP FUNCTION | ||
1095 | # | | | | | | ||
1096 | yum-updatesd-3111 [003] 1637.254676: finish_task_switch <-thread_return | ||
1097 | yum-updatesd-3111 [003] 1637.254681: hrtimer_cancel <-schedule_hrtimeout_range | ||
1098 | yum-updatesd-3111 [003] 1637.254682: hrtimer_try_to_cancel <-hrtimer_cancel | ||
1099 | yum-updatesd-3111 [003] 1637.254683: lock_hrtimer_base <-hrtimer_try_to_cancel | ||
1100 | yum-updatesd-3111 [003] 1637.254685: fget_light <-do_sys_poll | ||
1101 | yum-updatesd-3111 [003] 1637.254686: pipe_poll <-do_sys_poll | ||
1102 | # echo -1 > /debug/tracing/set_ftrace_pid | ||
1103 | # cat /debug/tracing/trace |head | ||
1104 | # tracer: function | ||
1105 | # | ||
1106 | # TASK-PID CPU# TIMESTAMP FUNCTION | ||
1107 | # | | | | | | ||
1108 | ##### CPU 3 buffer started #### | ||
1109 | yum-updatesd-3111 [003] 1701.957688: free_poll_entry <-poll_freewait | ||
1110 | yum-updatesd-3111 [003] 1701.957689: remove_wait_queue <-free_poll_entry | ||
1111 | yum-updatesd-3111 [003] 1701.957691: fput <-free_poll_entry | ||
1112 | yum-updatesd-3111 [003] 1701.957692: audit_syscall_exit <-sysret_audit | ||
1113 | yum-updatesd-3111 [003] 1701.957693: path_put <-audit_syscall_exit | ||
1114 | |||
1115 | If you want to trace a function when executing, you could use | ||
1116 | something like this simple program: | ||
1117 | |||
1118 | #include <stdio.h> | ||
1119 | #include <stdlib.h> | ||
1120 | #include <sys/types.h> | ||
1121 | #include <sys/stat.h> | ||
1122 | #include <fcntl.h> | ||
1123 | #include <unistd.h> | ||
1124 | |||
1125 | int main (int argc, char **argv) | ||
1126 | { | ||
1127 | if (argc < 1) | ||
1128 | exit(-1); | ||
1129 | |||
1130 | if (fork() > 0) { | ||
1131 | int fd, ffd; | ||
1132 | char line[64]; | ||
1133 | int s; | ||
1134 | |||
1135 | ffd = open("/debug/tracing/current_tracer", O_WRONLY); | ||
1136 | if (ffd < 0) | ||
1137 | exit(-1); | ||
1138 | write(ffd, "nop", 3); | ||
1139 | |||
1140 | fd = open("/debug/tracing/set_ftrace_pid", O_WRONLY); | ||
1141 | s = sprintf(line, "%d\n", getpid()); | ||
1142 | write(fd, line, s); | ||
1143 | |||
1144 | write(ffd, "function", 8); | ||
1145 | |||
1146 | close(fd); | ||
1147 | close(ffd); | ||
1148 | |||
1149 | execvp(argv[1], argv+1); | ||
1150 | } | ||
1151 | |||
1152 | return 0; | ||
1153 | } | ||
1154 | |||
1062 | dynamic ftrace | 1155 | dynamic ftrace |
1063 | -------------- | 1156 | -------------- |
1064 | 1157 | ||
@@ -1158,7 +1251,11 @@ These are the only wild cards which are supported. | |||
1158 | 1251 | ||
1159 | <match>*<match> will not work. | 1252 | <match>*<match> will not work. |
1160 | 1253 | ||
1161 | # echo hrtimer_* > /debug/tracing/set_ftrace_filter | 1254 | Note: It is better to use quotes to enclose the wild cards, otherwise |
1255 | the shell may expand the parameters into names of files in the local | ||
1256 | directory. | ||
1257 | |||
1258 | # echo 'hrtimer_*' > /debug/tracing/set_ftrace_filter | ||
1162 | 1259 | ||
1163 | Produces: | 1260 | Produces: |
1164 | 1261 | ||
@@ -1213,7 +1310,7 @@ Again, now we want to append. | |||
1213 | # echo sys_nanosleep > /debug/tracing/set_ftrace_filter | 1310 | # echo sys_nanosleep > /debug/tracing/set_ftrace_filter |
1214 | # cat /debug/tracing/set_ftrace_filter | 1311 | # cat /debug/tracing/set_ftrace_filter |
1215 | sys_nanosleep | 1312 | sys_nanosleep |
1216 | # echo hrtimer_* >> /debug/tracing/set_ftrace_filter | 1313 | # echo 'hrtimer_*' >> /debug/tracing/set_ftrace_filter |
1217 | # cat /debug/tracing/set_ftrace_filter | 1314 | # cat /debug/tracing/set_ftrace_filter |
1218 | hrtimer_run_queues | 1315 | hrtimer_run_queues |
1219 | hrtimer_run_pending | 1316 | hrtimer_run_pending |
@@ -1299,41 +1396,29 @@ trace entries | |||
1299 | ------------- | 1396 | ------------- |
1300 | 1397 | ||
1301 | Having too much or not enough data can be troublesome in diagnosing | 1398 | Having too much or not enough data can be troublesome in diagnosing |
1302 | an issue in the kernel. The file trace_entries is used to modify | 1399 | an issue in the kernel. The file buffer_size_kb is used to modify |
1303 | the size of the internal trace buffers. The number listed | 1400 | the size of the internal trace buffers. The number listed |
1304 | is the number of entries that can be recorded per CPU. To know | 1401 | is the number of entries that can be recorded per CPU. To know |
1305 | the full size, multiply the number of possible CPUS with the | 1402 | the full size, multiply the number of possible CPUS with the |
1306 | number of entries. | 1403 | number of entries. |
1307 | 1404 | ||
1308 | # cat /debug/tracing/trace_entries | 1405 | # cat /debug/tracing/buffer_size_kb |
1309 | 65620 | 1406 | 1408 (units kilobytes) |
1310 | 1407 | ||
1311 | Note, to modify this, you must have tracing completely disabled. To do that, | 1408 | Note, to modify this, you must have tracing completely disabled. To do that, |
1312 | echo "nop" into the current_tracer. If the current_tracer is not set | 1409 | echo "nop" into the current_tracer. If the current_tracer is not set |
1313 | to "nop", an EINVAL error will be returned. | 1410 | to "nop", an EINVAL error will be returned. |
1314 | 1411 | ||
1315 | # echo nop > /debug/tracing/current_tracer | 1412 | # echo nop > /debug/tracing/current_tracer |
1316 | # echo 100000 > /debug/tracing/trace_entries | 1413 | # echo 10000 > /debug/tracing/buffer_size_kb |
1317 | # cat /debug/tracing/trace_entries | 1414 | # cat /debug/tracing/buffer_size_kb |
1318 | 100045 | 1415 | 10000 (units kilobytes) |
1319 | |||
1320 | |||
1321 | Notice that we echoed in 100,000 but the size is 100,045. The entries | ||
1322 | are held in individual pages. It allocates the number of pages it takes | ||
1323 | to fulfill the request. If more entries may fit on the last page | ||
1324 | then they will be added. | ||
1325 | |||
1326 | # echo 1 > /debug/tracing/trace_entries | ||
1327 | # cat /debug/tracing/trace_entries | ||
1328 | 85 | ||
1329 | |||
1330 | This shows us that 85 entries can fit in a single page. | ||
1331 | 1416 | ||
1332 | The number of pages which will be allocated is limited to a percentage | 1417 | The number of pages which will be allocated is limited to a percentage |
1333 | of available memory. Allocating too much will produce an error. | 1418 | of available memory. Allocating too much will produce an error. |
1334 | 1419 | ||
1335 | # echo 1000000000000 > /debug/tracing/trace_entries | 1420 | # echo 1000000000000 > /debug/tracing/buffer_size_kb |
1336 | -bash: echo: write error: Cannot allocate memory | 1421 | -bash: echo: write error: Cannot allocate memory |
1337 | # cat /debug/tracing/trace_entries | 1422 | # cat /debug/tracing/buffer_size_kb |
1338 | 85 | 1423 | 85 |
1339 | 1424 | ||