functrace(8) trace kernel function calls matching specified wildcards. Uses Linux ftrace.

SYNOPSIS

functrace [-hH] [-p PID] [-d secs] funcstring

DESCRIPTION

This tool provides a quick way to capture the execution of kernel functions, showing basic details including as the process ID, timestamp, and calling function.

WARNING: This uses dynamic tracing of (what can be many) kernel functions, and could cause kernel panics or freezes. Test, and know what you are doing, before use.

Also beware of feedback loops: tracing tcp* functions over an ssh session, or writing ext4* functions to an ext4 file system. For the former, tcp trace data could be redirected to a file (as in the usage message). For the latter, trace to the screen or a different file system.

SEE ALSO: kprobe(8), which can dynamically trace a single function call or return, and examine CPU registers and return values.

Since this uses ftrace, only the root user can use this tool.

REQUIREMENTS

FTRACE CONFIG, which you may already have enabled and available on recent kernels.

OPTIONS

-d seconds
Set the duration of tracing, in seconds. Trace output will be buffered and printed at the end. This also reduces overheads by buffering in-kernel, instead of printing events as they occur.

The ftrace buffer has a fixed size per-CPU (see /sys/kernel/debug/tracing/buffer_size_kb). If you think events are missing, try increasing that size.

-h
Print usage message.
-H
Print column headers.
-p PID
Only trace kernel functions when this process ID is on-CPU.
funcstring
A function name to trace, which may include file glob style wildcards ("*") at the beginning or ending of a string only. Eg, "vfs*" means match "vfs" followed by anything.

EXAMPLES

Trace calls to do_nanosleep():
# functrace do_nanosleep
Trace calls to all kernel functions ending in "*sleep":
# functrace '*sleep'
Trace all "vfs*" kernel function calls for PID 198:
# functrace -p 198 'vfs*'
Trace all "tcp*" kernel function calls, and output to a file until Ctrl-C:
# functrace 'tcp*' > out
Trace all "tcp*" kernel function calls, output to a file, for 1 second (buffered):
# functrace -d 1 'tcp*' > out

FIELDS

The output format depends on the kernel version, and headings can be printed using -H. The format is the same as the ftrace function trace format, described in the kernel source under Documentation/trace/ftrace.txt.

Typical fields are:

TASK-PID
The process name (which could include dashes), a dash, and the process ID.
CPU#
The CPU ID, in brackets.
||||
Kernel state flags. For example, on Linux 3.16 these are for irqs-off, need-resched, hardirq/softirq, and preempt-depth.
TIMESTAMP
Time of event, in seconds.
FUNCTION
Kernel function name.

OVERHEAD

This can generate a lot of trace data quickly, depending on the frequency of the traced events. Such data will cause performance overheads. This also works without buffering by default, printing function events as they happen (uses trace_pipe), context switching and consuming CPU to do so. If needed, you can try the "-d secs" option, which buffers events instead, reducing overhead. If you think the buffer option is losing events, try increasing the buffer size (buffer_size_kb).

It's a good idea to use funccount(8) first, which is lower overhead, to help you select which functions you may want to trace using functrace(8).

SOURCE

This is from the perf-tools collection:
https://github.com/brendangregg/perf-tools

Also look under the examples directory for a text file containing example usage, output, and commentary for this tool.

OS

Linux

STABILITY

Unstable - in development.

AUTHOR

Brendan Gregg