This shows you the differences between two versions of the page.
Both sides previous revision Previous revision Next revision | Previous revision | ||
realtime:documentation:howto:tools:cyclictest:tracing [2018/08/22 10:07] ebugden [Function Tracing] Fix typo |
realtime:documentation:howto:tools:cyclictest:tracing [2022/01/19 20:01] bartwensley [Producing a Trace] Removed --ftrace option which has not been supported since rt-tests version 1.4. |
||
---|---|---|---|
Line 1: | Line 1: | ||
====== Cyclictest - Latency debugging with tracing ====== | ====== Cyclictest - Latency debugging with tracing ====== | ||
- | Tracing is useful when trying to determine the cause of a latency because it can reveal relevant details about execution. There are several options in Cyclictest that can be used to produce traces via Ftrace. | + | Tracing is useful when trying to determine the cause of a latency because it can reveal relevant details about execution. There are several options in Cyclictest that can be used to capture traces in combination with Ftrace. |
- | ===== Break Trace Option ===== | + | Information about how to set up Ftrace as well as how to view traces taken with Ftrace can be found [[realtime:documentation:howto:tools:ftrace|here]]. |
- | A trace can be collected through Cyclictest by using the break trace (--breaktrace) option together with one of the tracing options. The break trace option will stop tracing and end Cyclictest if it detects a latency that is longer than a specified limit. This option is intended to be used with the Cyclictest options that enable Ftrace instrumentation (e.g. --irqsoff). | + | ---- |
+ | |||
+ | ===== Break Trace Option ===== | ||
- | <WRAP center round info 60%> | + | A trace can be collected through Cyclictest by using the break trace (--breaktrace) option together with the --tracemark option. These options will stop tracing and end Cyclictest if it detects a latency that is longer than a specified limit. The ftrace must be started before Cyclictest is executed. |
- | Ftrace might not behave the same way after using the break trace option. When the break trace option is used, Cyclictest changes some Ftrace options to get the desired trace format, such as specifying print-parent and latency-format. The Ftrace options that were set before are not restored after Cyclictest runs. | + | |
- | </WRAP> | + | |
===== Selecting Instrumentation ===== | ===== Selecting Instrumentation ===== | ||
- | Cyclictest offers a number options which use different Ftrace tracers and instrumentation. These options are described in the Cyclictest help text (--help) and on the man page. The most important things to keep in mind when choosing instrumentation are the trace detail and the resulting overhead. A trace with more detail will require a higher overhead. In general, it is effective to corner the source of the latency over several iterations of tracing and analysis while gradually increasing the trace detail. Start with a small amount of instrumentation, which produces a simple trace. One good option would be to start by eliminating the most obvious possible sources of latency by tracing when interrupts or preemption are disabled. | + | Ftrace provides a selection of tracers and instrumentation. These options are described in the Ftrace documentation [[realtime:documentation:howto:tools:ftrace|here]]. The most important things to keep in mind when choosing instrumentation are the trace detail and the resulting overhead. A trace with more detail will require a higher overhead. In general, it is effective to corner the source of the latency over several iterations of tracing and analysis while gradually increasing the trace detail. Start with a small amount of instrumentation, which produces a simple trace. One good option would be to start by eliminating the most obvious possible sources of latency by tracing when interrupts or preemption are disabled. |
==== Function Tracing ==== | ==== Function Tracing ==== | ||
Line 19: | Line 19: | ||
It can sometimes be tempting to immediately jump to enabling function tracing. A full function trace is highly detailed because it includes all of the function calls that were made in the kernel. Function tracing can be very useful in the debugging process, but starting with such a highly detailed trace is not recommended. Analyzing a full function trace can be time consuming and confusing, especially if the latency's cause is complex. Additionally, function tracing has a significant overhead so it has a higher chance of affecting the behavior of the system. Because of this high overhead, in some cases it is possible that the targeted latency will not occur when function tracing is enabled. | It can sometimes be tempting to immediately jump to enabling function tracing. A full function trace is highly detailed because it includes all of the function calls that were made in the kernel. Function tracing can be very useful in the debugging process, but starting with such a highly detailed trace is not recommended. Analyzing a full function trace can be time consuming and confusing, especially if the latency's cause is complex. Additionally, function tracing has a significant overhead so it has a higher chance of affecting the behavior of the system. Because of this high overhead, in some cases it is possible that the targeted latency will not occur when function tracing is enabled. | ||
- | Function tracing can be particularly useful for identifying latencies that are caused by the firmware or the hardware. However, these kinds of latencies are not that common so it is not recommended to start by exploring this possibility. | + | Function tracing can be particularly useful for identifying latencies that are caused by the firmware or the hardware such as [[realtime:documentation:howto:debugging:smi-latency:cyclictest-tracing|SMI related latencies]]. However, these kinds of latencies are not that common so it is not recommended to start by exploring this possibility. |
===== Latency Tracing ===== | ===== Latency Tracing ===== | ||
- | There are a couple steps that can help correctly produce a trace that includes the relevant latency. The following tips are relevant if the goal is to obtain a trace that includes the system's maximum latency. In general, it is a good idea to start by resolving the longest latencies in a system and to work down towards solving the shorter latencies. | + | There are a couple of steps that can help correctly produce a trace that includes the relevant latency. The following tips are relevant if the goal is to obtain a trace that includes the system's maximum latency. In general, it is a good idea to start by resolving the longest latencies in a system and to work down towards solving the shorter latencies. |
Before tracing, make sure that the correct options for measuring the latency have been chosen and that Cyclictest detects the latency without having any tracing enabled. If the latency is not detected without any instrumentation, adding tracing will not help because the cause of the investigated latency will usually not be present in the resulting trace. Some suggestions for choosing the right Cyclictest options for a particular situation can be found on the Cyclictest [[realtime:documentation:howto:tools:cyclictest:test-design#option-selection|Test Design]] page. | Before tracing, make sure that the correct options for measuring the latency have been chosen and that Cyclictest detects the latency without having any tracing enabled. If the latency is not detected without any instrumentation, adding tracing will not help because the cause of the investigated latency will usually not be present in the resulting trace. Some suggestions for choosing the right Cyclictest options for a particular situation can be found on the Cyclictest [[realtime:documentation:howto:tools:cyclictest:test-design#option-selection|Test Design]] page. | ||
Line 39: | Line 39: | ||
</code> | </code> | ||
- | and after a couple hours a maximum latency of 130 us is detected. To measure the value of the maximum latency with the overhead from function tracing, the following Cyclictest command could be run: | + | and after a couple hours a maximum latency of 130 us is detected. To measure the value of the maximum latency with the overhead from function tracing, ftrace can be enabled and then the following Cyclictest command could be run: |
<code bash> | <code bash> | ||
- | cyclictest --mlockall --smp --priority=80 --interval=200 --distance=0 --breaktrace=2000 --ftrace | + | cyclictest --mlockall --smp --priority=80 --interval=200 --distance=0 --breaktrace=2000 --tracemark |
</code> | </code> | ||
- | After a few hours a latency of 190 us is detected. The maximum latency observed during this overhead measuring test will be used to determine the appropriate break trace limit for tracing the original latency. This process is explained in the next page section. | + | After a few hours a latency of 190 us is detected. The maximum latency observed during this overhead measuring test will be used to determine the appropriate break trace limit for tracing the original latency. This process is explained in the next section. |
Since the intent of this step is just to observe the overhead, the break trace limit should be much longer than the length of the expected latencies and the tracing should never actually break. If the tracing does break, Cyclictest should be run again with a higher break trace limit. The magnitude of the increase of the maximum latency due to tracing depends on what generates the latency, so it is important to be critical and to make sure that the high latency has actually occurred and the suspected spike is not just an elevated baseline due to the tracing. If the latency spikes at a similar time or in a similar situation as before the tracing was enabled, it is a good sign that it is the same latency as before. | Since the intent of this step is just to observe the overhead, the break trace limit should be much longer than the length of the expected latencies and the tracing should never actually break. If the tracing does break, Cyclictest should be run again with a higher break trace limit. The magnitude of the increase of the maximum latency due to tracing depends on what generates the latency, so it is important to be critical and to make sure that the high latency has actually occurred and the suspected spike is not just an elevated baseline due to the tracing. If the latency spikes at a similar time or in a similar situation as before the tracing was enabled, it is a good sign that it is the same latency as before. | ||
Line 51: | Line 51: | ||
==== Producing a Trace ==== | ==== Producing a Trace ==== | ||
- | Finally, a trace that includes the latency can be produced by running Cyclictest with a break trace limit that is slightly below the maximum latency value that was observed with tracing enabled. Continuing the example from the previous section, if the maximum latency with the overhead from function tracing is 190 us then the following command could be used to produce the trace: | + | Finally, a trace that includes the latency can be produced by starting ftrace and then running Cyclictest with a break trace limit that is slightly below the maximum latency value that was observed with tracing enabled. Continuing the example from the previous section, if the maximum latency with the overhead from function tracing is 190 us then the following command could be used to produce the trace: |
<code bash> | <code bash> | ||
- | cyclictest --mlockall --smp --priority=80 --interval=200 --distance=0 --breaktrace=180 --ftrace | + | cyclictest --mlockall --smp --priority=80 --interval=200 --distance=0 --breaktrace=180 --tracemark |
</code> | </code> | ||
using a break trace limit of 180 us. This new limit will cause Cyclictest to stop when the maximum latency occurs and will produce the relevant trace. This trace can then be viewed via tracefs in the same way as other Ftrace traces. | using a break trace limit of 180 us. This new limit will cause Cyclictest to stop when the maximum latency occurs and will produce the relevant trace. This trace can then be viewed via tracefs in the same way as other Ftrace traces. |