Ftrace is the lightweight and flexible function level debugger. It can be used as data collection, debugging and performance tuning on Linux kernel. It does not need to recompile the kernel code. With just existing kernel code we can trace the kernel level function calls flow. The below are the steps to to setup ftrace and how to use this.
1. first we need to make sure the debugfs is supported in the kernel. This can be find in /proc/filesystems file. In my desktop kernel it has been enabled.
2. Now we need to mount the debugfs. Please verify whether this has been mounted by running mount command.
If you are not finding this entry, you can mount this by the below command.
%mount -t debugfs none /sys/kernel/debug
**** Instead of /sys/kernel/debug, you can use your own directory while mounting. ****
3. Now you are all set to go. After you mounted you will find tracing directory, which has so many files as listed below.
4. To know the supported tracers, cat the file available_tracers.
5. As this post is about ftrace, I will concentrate on function and function_graph tracers.
To enable trace, as a root user echo 1 to tracing_on file as below:
%echo 1 > tracing_on
Now select which tracers need to be enabled. Let us say we need function trace. For this we need to echo function to current_tracer file as below:
%echo function > current_tracer
To view the trace information, we need to cat or vi the trace file. The trace file is a just reading the ring buffer and display to the user. The content can be still viewed even after disabling the trace by echoing 0 to tracing on file.
%echo 0 > tracing_on.
But if you remove the function trace from the current trace file, then all the ring buffer data will get erased. because of this, you can not view the trace information.
The above trace output explains all the the kernel calls with on which CPU it is running. The first column is showing the process name and corresponding PID, to which the kernel calls invoked.
The fourth column talks about the time spent from the boot time.
6. To disable trace logging, just echo 0 to tracing_on file. As explained above this will not erase the ring buffer content instead it will stop logging data to ring buffer. Hence we can still view the trace file(ring buffer) content.
7. If we need to get the call graph in heirarchical manner, we have to echo function_graph to current_tracer file.
%echo function_graph > current_trace
The function_graph trace is showing the time spent in each kernel function. The time will be displayed in the second column corresponds to each leaf function. If a function is calling nested functions, then the accumulated time will be displayed, while exiting from that function. If the time taken in a function is exceeding 10 Microseconds, then it will be denoted as '+'. if it is taking more than 100 microseconds, then it will be denoted as '!'.
In my next post will explain about how to attach a process and how to filter out the functions in the trace output.
Thanks
-Shivu