1 .. This work is licensed under a Creative Commons Attribution 4.0 International License.
3 .. http://creativecommons.org/licenses/by/4.0
11 Ftrace is an internal tracer designed to find what is going on inside the kernel. It can be used
12 for debugging or analyzing latencies and performance related issues that take place outside of
13 user-space. Although ftrace is typically considered the function tracer, it is really a frame
14 work of several assorted tracing utilities.
16 One of the most common uses of ftrace is the event tracing.
19 - For KVM4NFV, Ftrace is preferred as it is in-built kernel tool
20 - More stable compared to other debugging tools
25 +-----------------------------+-----------------------------------------------+
27 | **Release** | **Features** |
29 +=============================+===============================================+
30 | | - Ftrace Debugging tool is not implemented in |
31 | Colorado | Colorado release of KVM4NFV |
33 +-----------------------------+-----------------------------------------------+
34 | | - Ftrace aids in debugging the KVM4NFV |
35 | Danube | 4.4-linux-kernel level issues |
36 | | - Option to disable if not required |
37 +-----------------------------+-----------------------------------------------+
38 | | - Breaktrace option is implemented. |
39 | Euphrates | - Implemented post-execute script option to |
40 | | disable the ftrace when it is enabled. |
41 +-----------------------------+-----------------------------------------------+
44 Implementation of Ftrace
45 -------------------------
46 Ftrace uses the debugfs file system to hold the control files as
47 well as the files to display output.
49 When debugfs is configured into the kernel (which selecting any ftrace
50 option will do) the directory /sys/kernel/debug will be created. To mount
51 this directory, you can add to your /etc/fstab file:
55 debugfs /sys/kernel/debug debugfs defaults 0 0
57 Or you can mount it at run time with:
61 mount -t debugfs nodev /sys/kernel/debug
63 Some configurations for Ftrace are used for other purposes, like finding latency or analyzing the
64 system. For the purpose of debugging, the kernel configuration parameters that should be enabled are:
68 CONFIG_FUNCTION_TRACER=y
69 CONFIG_FUNCTION_GRAPH_TRACER=y
71 CONFIG_DYNAMIC_FTRACE=y
73 The above parameters must be enabled in /boot/config-4.4.0-el7.x86_64 i.e., kernel config file for
74 ftrace to work. If not enabled, change the parameter to ``y`` and run.,
79 grub2-mkconfig -o /boot/grub2/grub.cfg
82 Re-check the parameters after reboot before running ftrace.
86 The below is a list of few major files in Ftrace.
90 This is used to set or display the current tracer that is configured.
92 ``available_tracers:``
94 This holds the different types of tracers that have been compiled into the kernel.
95 The tracers listed here can be configured by echoing their name into current_tracer.
99 This sets or displays whether writing to the tracering buffer is enabled. Echo 0 into this
100 file to disable the tracer or 1 to enable it.
104 This file holds the output of the trace in a human readable format.
108 This is a mask that lets the user only trace on specified CPUs. The format is a hex string
109 representing the CPUs.
113 It holds event tracepoints (also known as static tracepoints) that have been compiled into
114 the kernel. It shows what event tracepoints exist and how they are grouped by system.
120 Here is the list of current tracers that may be configured based on usage.
134 Function call tracer to trace all kernel functions.
138 Similar to the function tracer except that the function tracer probes the functions on their
139 entry whereas the function graph tracer traces on both entry and exit of the functions.
143 This is the "trace nothing" tracer. To remove tracers from tracing simply echo "nop" into
151 To list available tracers:
152 [tracing]# cat available_tracers
153 function_graph function wakeup wakeup_rt preemptoff irqsoff preemptirqsoff nop
156 [tracing]# echo function > current_tracer
157 [tracing]# cat current_tracer
161 [tracing]# cat trace | head -10
164 [tracing]# echo 0 > tracing_on
166 To Start/restart tracing:
167 [tracing]# echo 1 > tracing_on;
172 Ftrace is part of KVM4NFV D-Release. KVM4NFV built 4.4-linux-Kernel will be tested by
173 executing cyclictest and analyzing the results/latency values (max, min, avg) generated.
174 Ftrace (or) function tracer is a stable kernel inbuilt debugging tool which tests real time
175 kernel and outputs a log as part of the code. These output logs are useful in following ways.
178 - Helps in Kernel code optimization and
179 - Can be used to better understand the kernel level code flow
181 Ftrace logs for KVM4NFV can be found `here`_:
184 .. _here: http://artifacts.opnfv.org/kvmfornfv.html
186 Ftrace Usage in KVM4NFV Kernel Debugging:
187 -----------------------------------------
188 Kvm4nfv has two scripts in /ci/envs to provide ftrace tool:
196 $ cd kvmfornfv/ci/envs
198 Enabling Ftrace in KVM4NFV
199 --------------------------
201 The enable_trace.sh script is triggered by changing ftrace_enable value in test_kvmfornfv.sh
202 script to 1 (which is zero by default). Change as below to enable Ftrace.
210 - Ftrace is enabled before
212 Details of enable_trace script
213 ------------------------------
215 - CPU coremask is calculated using getcpumask()
216 - All the required events are enabled by,
217 echoing "1" to $TRACEDIR/events/event_name/enable file
223 $TRACEDIR = /sys/kernel/debug/tracing/
224 sudo bash -c "echo 1 > $TRACEDIR/events/irq/enable"
225 sudo bash -c "echo 1 > $TRACEDIR/events/task/enable"
226 sudo bash -c "echo 1 > $TRACEDIR/events/syscalls/enable"
228 The set_event file contains all the enabled events list
230 - Function tracer is selected. May be changed to other avaliable tracers based on requirement
234 sudo bash -c "echo function > $TRACEDIR/current_tracer
236 - When tracing is turned ON by setting ``tracing_on=1``, the ``trace`` file keeps getting append
237 with the traced data until ``tracing_on=0`` and then ftrace_buffer gets cleared.
247 - Once tracing is disabled, disable_trace.sh script is triggered.
251 - Send break trace command when latency > USEC. This is a debugging option to control the latency
252 tracer in the realtime preemption patch. It is useful to track down unexpected large latencies on a
253 system. This option does only work with following kernel config options.
256 * CONFIG_PREEMPT_RT=y
257 * CONFIG_WAKEUP_TIMING=y
258 * CONFIG_LATENCY_TRACE=y
259 * CONFIG_CRITICAL_PREEMPT_TIMING=y
260 * CONFIG_CRITICAL_IRQSOFF_TIMING=y
262 For kernel >= 2.6.24:
263 * CONFIG_PREEMPT_RT=y
265 * CONFIG_IRQSOFF_TRACER=y
266 * CONFIG_PREEMPT_TRACER=y
267 * CONFIG_SCHED_TRACER=y
268 * CONFIG_WAKEUP_LATENCY_HIST
270 - Kernel configuration options enabled. The USEC parameter to the -b option defines a maximum
271 latency value, which is compared against the actual latencies of the test. Once the measured latency
272 is higher than the given maximum, the kernel tracer and cyclictest is stopped. The trace can be read
273 from /proc/latency_trace. Please be aware that the tracer adds significant overhead to the kernel,
274 so the latencies will be much higher than on a kernel with latency tracing disabled.
276 - Breaktrace option will enable the trace by default, suppress the tracing by using --notrace option.
280 post-execute script to yardstick node context teardown is added to disable the ftrace soon after the
281 completion of cyclictest execution throughyardstick. This option is implemented to collect only
282 required ftrace logs for effective debugging if needed.
284 Details of disable_trace Script
285 -------------------------------
286 In disable trace script the following are done:
288 - The trace file is copied and moved to /tmp folder based on timestamp
289 - The current tracer file is set to ``nop``
290 - The set_event file is cleared i.e., all the enabled events are disabled
291 - Kernel Ftrace is disabled/unmounted
294 Publishing Ftrace logs:
295 -----------------------
296 The generated trace log is pushed to `artifacts`_ by kvmfornfv-upload-artifact.sh
297 script available in releng which will be triggered as a part of kvm4nfv daily job.
298 The `trigger`_ in the script is.,
302 echo "Uploading artifacts for future debugging needs...."
303 gsutil cp -r $WORKSPACE/build_output/log-*.tar.gz $GS_LOG_LOCATION > $WORKSPACE/gsutil.log 2>&1
305 .. _artifacts: https://artifacts.opnfv.org/
307 .. _trigger: https://gerrit.opnfv.org/gerrit/gitweb?p=releng.git;a=blob;f=jjb/kvmfornfv/kvmfornfv-upload-artifact.sh;h=56fb4f9c18a83c689a916dc6c85f9e3ddf2479b2;hb=HEAD#l53