functrace (8)

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

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.

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

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

-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.

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

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.

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).

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.

Linux

Unstable - in development.

Brendan Gregg

funccount(8)