aboutsummaryrefslogtreecommitdiffstats
path: root/Documentation/ftrace.txt
diff options
context:
space:
mode:
authorLinus Torvalds <torvalds@linux-foundation.org>2008-12-28 15:21:10 -0500
committerLinus Torvalds <torvalds@linux-foundation.org>2008-12-28 15:21:10 -0500
commitb0f4b285d7ed174804658539129a834270f4829a (patch)
treebe7f8dca58075aba2c6a137fcfd4d44c5c333efc /Documentation/ftrace.txt
parentbe9c5ae4eeec2e85527e95647348b8ea4eb25128 (diff)
parent5250d329e38cdf7580faeb9c53c17d3588d7d19c (diff)
Merge branch 'tracing-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
* 'tracing-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip: (241 commits) sched, trace: update trace_sched_wakeup() tracing/ftrace: don't trace on early stage of a secondary cpu boot, v3 Revert "x86: disable X86_PTRACE_BTS" ring-buffer: prevent false positive warning ring-buffer: fix dangling commit race ftrace: enable format arguments checking x86, bts: memory accounting x86, bts: add fork and exit handling ftrace: introduce tracing_reset_online_cpus() helper tracing: fix warnings in kernel/trace/trace_sched_switch.c tracing: fix warning in kernel/trace/trace.c tracing/ring-buffer: remove unused ring_buffer size trace: fix task state printout ftrace: add not to regex on filtering functions trace: better use of stack_trace_enabled for boot up code trace: add a way to enable or disable the stack tracer x86: entry_64 - introduce FTRACE_ frame macro v2 tracing/ftrace: add the printk-msg-only option tracing/ftrace: use preempt_enable_no_resched_notrace in ring_buffer_time_stamp() x86, bts: correctly report invalid bts records ... Fixed up trivial conflict in scripts/recordmcount.pl due to SH bits being already partly merged by the SH merge.
Diffstat (limited to 'Documentation/ftrace.txt')
-rw-r--r--Documentation/ftrace.txt149
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
319iter_ctrl 321trace_options
320--------- 322-------------
321 323
322The iter_ctrl file is used to control what gets printed in the trace 324The trace_options file is used to control what gets printed in the trace
323output. To see what is available, simply cat the file: 325output. 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
329To disable one of the options, echo in the option prepended with "no". 331To 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
333To enable an option, leave off the "no". 335To 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
337Here are the available options: 339Here 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
395x494] <- /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,
1059a search through /proc/mounts may be needed to find where the debugfs 1075a search through /proc/mounts may be needed to find where the debugfs
1060file-system is mounted. 1076file-system is mounted.
1061 1077
1078
1079Single thread tracing
1080---------------------
1081
1082By writing into /debug/tracing/set_ftrace_pid you can trace a
1083single thread. For example:
1084
1085# cat /debug/tracing/set_ftrace_pid
1086no pid
1087# echo 3111 > /debug/tracing/set_ftrace_pid
1088# cat /debug/tracing/set_ftrace_pid
10893111
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
1115If you want to trace a function when executing, you could use
1116something 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
1125int 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
1062dynamic ftrace 1155dynamic 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 1254Note: 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
1163Produces: 1260Produces:
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
1215sys_nanosleep 1312sys_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
1218hrtimer_run_queues 1315hrtimer_run_queues
1219hrtimer_run_pending 1316hrtimer_run_pending
@@ -1299,41 +1396,29 @@ trace entries
1299------------- 1396-------------
1300 1397
1301Having too much or not enough data can be troublesome in diagnosing 1398Having too much or not enough data can be troublesome in diagnosing
1302an issue in the kernel. The file trace_entries is used to modify 1399an issue in the kernel. The file buffer_size_kb is used to modify
1303the size of the internal trace buffers. The number listed 1400the size of the internal trace buffers. The number listed
1304is the number of entries that can be recorded per CPU. To know 1401is the number of entries that can be recorded per CPU. To know
1305the full size, multiply the number of possible CPUS with the 1402the full size, multiply the number of possible CPUS with the
1306number of entries. 1403number of entries.
1307 1404
1308 # cat /debug/tracing/trace_entries 1405 # cat /debug/tracing/buffer_size_kb
130965620 14061408 (units kilobytes)
1310 1407
1311Note, to modify this, you must have tracing completely disabled. To do that, 1408Note, to modify this, you must have tracing completely disabled. To do that,
1312echo "nop" into the current_tracer. If the current_tracer is not set 1409echo "nop" into the current_tracer. If the current_tracer is not set
1313to "nop", an EINVAL error will be returned. 1410to "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
1318100045 141510000 (units kilobytes)
1319
1320
1321Notice that we echoed in 100,000 but the size is 100,045. The entries
1322are held in individual pages. It allocates the number of pages it takes
1323to fulfill the request. If more entries may fit on the last page
1324then they will be added.
1325
1326 # echo 1 > /debug/tracing/trace_entries
1327 # cat /debug/tracing/trace_entries
132885
1329
1330This shows us that 85 entries can fit in a single page.
1331 1416
1332The number of pages which will be allocated is limited to a percentage 1417The number of pages which will be allocated is limited to a percentage
1333of available memory. Allocating too much will produce an error. 1418of 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
133885 142385
1339 1424