funcslower-bpfcc8
Trace slow kernel or user function calls.
Usage
funcslower [-hf]
[-p
PID]
[{-U | -K}]
[-m
MIN_MS]
[-u
MIN_US]
[-a
ARGUMENTS]
[-T]
[-t]
[-v]
function
[function ...]
Overview
This script traces a kernel or user function's entry and return points, and prints a message when the function's latency exceeded the specified threshold. Multiple functions are supported, and you can mix kernel functions with user functions in different libraries.
WARNING: See the OVERHEAD section.
By default, a minimum millisecond threshold of 1 is used. Recursive functions are not supported: only the inner-most recursive invocation will be traced.
Since this uses BPF, only the root user can use this tool.
Requirements
CONFIG_BPF and bcc.
Options
-p PID Trace this PID only.
-
-m MIN_NS -
Minimum duration to trace, in milliseconds. Default is 1 ms.
-
-u MIN_US -
Minimum duration to trace, in microseconds.
-
-a ARGUMENTS -
Print the function's arguments, up to 6.
-
-T -
Print a HH:MM:SS timestamp with each entry.
-
-t -
Print a seconds timestamp with each entry, at microsecond resolution.
-
-f -
Print output in folded stack format.
-
-U -
Show stacks from user space only (no kernel space stacks).
-
-K -
Show stacks from kernel space only (no user space stacks).
-
-v -
Print the resulting BPF program, for debugging purposes.
- function
-
The function to trace -- multiple functions are supported. If a plain function name is provided, the function is assumed to be a kernel function. For user functions, provide the library name and the function name, e.g. bash:readline or c:malloc.
Examples
- Trace vfs_write calls slower than 1ms:
-
# funcslower vfs_write
- Trace open() calls in libc slower than 10us:
-
# funcslower -u 10 c:open
- Trace both malloc() and free() slower than 10us, in pid 135 only:
-
# funcslower -p 135 -u 10 c:malloc c:free
- Trace the write syscall and print its first 4 arguments:
-
# funcslower -a 4 SyS_write
- Trace opens from libc and print the user and kernel stack frames:
-
# funcslower -UK c:open
Fields
- TIME
-
Time of the event as a human-readable HH:MM:SS format, or a timestamp in seconds at microsecond-accuracy from the first event seen.
- COMM
-
Process name.
- PID
-
Process ID.
- LAT
-
Latency of the operation in either microseconds (us) or milliseconds (ms).
- RVAL
-
The return value from the function. Often useful for diagnosing a relationship between slow and failed function calls.
- FUNC
-
The function name, followed by its arguments if requested.
Overhead
Depending on the function(s) being traced, overhead can become severe. For example, tracing a common function like malloc() can slow down a C/C++ program by a factor of 2 or more. On the other hand, tracing a low-frequency event like the SyS_setreuid() function will probably not be as prohibitive, and in fact negligible for functions that are called up to 100-1000 times per second.
You should first use the funclatency and argdist tools for investigation, because they summarize data in-kernel and have a much lower overhead than this tool. To get a general idea of the number of times a particular function is called (and estimate the overhead), use the funccount tool, e.g.:
# funccount c:open
Source
This is from bcc.
-
https://github.com/iovisor/bcc
Also look in the bcc distribution for a companion _examples.txt file containing example usage, output, and commentary for this tool.
OS
Linux
Stability
Unstable - in development.