root / docs / tracing.txt @ f53ec699
History | View | Annotate | Download (10 kB)
1 | 81a97d9d | Stefan Hajnoczi | = Tracing = |
---|---|---|---|
2 | 81a97d9d | Stefan Hajnoczi | |
3 | 81a97d9d | Stefan Hajnoczi | == Introduction == |
4 | 81a97d9d | Stefan Hajnoczi | |
5 | 81a97d9d | Stefan Hajnoczi | This document describes the tracing infrastructure in QEMU and how to use it |
6 | 81a97d9d | Stefan Hajnoczi | for debugging, profiling, and observing execution. |
7 | 81a97d9d | Stefan Hajnoczi | |
8 | 81a97d9d | Stefan Hajnoczi | == Quickstart == |
9 | 81a97d9d | Stefan Hajnoczi | |
10 | 81a97d9d | Stefan Hajnoczi | 1. Build with the 'simple' trace backend: |
11 | 81a97d9d | Stefan Hajnoczi | |
12 | 324883aa | Jun Koi | ./configure --enable-trace-backend=simple |
13 | 81a97d9d | Stefan Hajnoczi | make |
14 | 81a97d9d | Stefan Hajnoczi | |
15 | 03727e6a | Lluís | 2. Create a file with the events you want to trace: |
16 | 81a97d9d | Stefan Hajnoczi | |
17 | 03727e6a | Lluís | echo bdrv_aio_readv > /tmp/events |
18 | 03727e6a | Lluís | echo bdrv_aio_writev >> /tmp/events |
19 | 81a97d9d | Stefan Hajnoczi | |
20 | 03727e6a | Lluís | 3. Run the virtual machine to produce a trace file: |
21 | 03727e6a | Lluís | |
22 | 03727e6a | Lluís | qemu -trace events=/tmp/events ... # your normal QEMU invocation |
23 | 03727e6a | Lluís | |
24 | 03727e6a | Lluís | 4. Pretty-print the binary trace file: |
25 | 81a97d9d | Stefan Hajnoczi | |
26 | 8f44015e | Markus Armbruster | ./scripts/simpletrace.py trace-events trace-* |
27 | 81a97d9d | Stefan Hajnoczi | |
28 | 81a97d9d | Stefan Hajnoczi | == Trace events == |
29 | 81a97d9d | Stefan Hajnoczi | |
30 | 7b92e5bc | Lluís | There is a set of static trace events declared in the "trace-events" source |
31 | 81a97d9d | Stefan Hajnoczi | file. Each trace event declaration names the event, its arguments, and the |
32 | 81a97d9d | Stefan Hajnoczi | format string which can be used for pretty-printing: |
33 | 81a97d9d | Stefan Hajnoczi | |
34 | 4b710a3c | Lluís Vilanova | qemu_vmalloc(size_t size, void *ptr) "size %zu ptr %p" |
35 | 4b710a3c | Lluís Vilanova | qemu_vfree(void *ptr) "ptr %p" |
36 | 81a97d9d | Stefan Hajnoczi | |
37 | 7b92e5bc | Lluís | The "trace-events" file is processed by the "tracetool" script during build to |
38 | 81a97d9d | Stefan Hajnoczi | generate code for the trace events. Trace events are invoked directly from |
39 | 81a97d9d | Stefan Hajnoczi | source code like this: |
40 | 81a97d9d | Stefan Hajnoczi | |
41 | 81a97d9d | Stefan Hajnoczi | #include "trace.h" /* needed for trace event prototype */ |
42 | 49926043 | Lluís | |
43 | 4b710a3c | Lluís Vilanova | void *qemu_vmalloc(size_t size) |
44 | 81a97d9d | Stefan Hajnoczi | { |
45 | 81a97d9d | Stefan Hajnoczi | void *ptr; |
46 | 4b710a3c | Lluís Vilanova | size_t align = QEMU_VMALLOC_ALIGN; |
47 | 4b710a3c | Lluís Vilanova | |
48 | 4b710a3c | Lluís Vilanova | if (size < align) { |
49 | 4b710a3c | Lluís Vilanova | align = getpagesize(); |
50 | 81a97d9d | Stefan Hajnoczi | } |
51 | 4b710a3c | Lluís Vilanova | ptr = qemu_memalign(align, size); |
52 | 4b710a3c | Lluís Vilanova | trace_qemu_vmalloc(size, ptr); |
53 | 81a97d9d | Stefan Hajnoczi | return ptr; |
54 | 81a97d9d | Stefan Hajnoczi | } |
55 | 81a97d9d | Stefan Hajnoczi | |
56 | 81a97d9d | Stefan Hajnoczi | === Declaring trace events === |
57 | 81a97d9d | Stefan Hajnoczi | |
58 | 7b92e5bc | Lluís | The "tracetool" script produces the trace.h header file which is included by |
59 | 81a97d9d | Stefan Hajnoczi | every source file that uses trace events. Since many source files include |
60 | 7b92e5bc | Lluís | trace.h, it uses a minimum of types and other header files included to keep the |
61 | 7b92e5bc | Lluís | namespace clean and compile times and dependencies down. |
62 | 81a97d9d | Stefan Hajnoczi | |
63 | 81a97d9d | Stefan Hajnoczi | Trace events should use types as follows: |
64 | 81a97d9d | Stefan Hajnoczi | |
65 | 81a97d9d | Stefan Hajnoczi | * Use stdint.h types for fixed-size types. Most offsets and guest memory |
66 | 81a97d9d | Stefan Hajnoczi | addresses are best represented with uint32_t or uint64_t. Use fixed-size |
67 | 81a97d9d | Stefan Hajnoczi | types over primitive types whose size may change depending on the host |
68 | 81a97d9d | Stefan Hajnoczi | (32-bit versus 64-bit) so trace events don't truncate values or break |
69 | 81a97d9d | Stefan Hajnoczi | the build. |
70 | 81a97d9d | Stefan Hajnoczi | |
71 | 81a97d9d | Stefan Hajnoczi | * Use void * for pointers to structs or for arrays. The trace.h header |
72 | 81a97d9d | Stefan Hajnoczi | cannot include all user-defined struct declarations and it is therefore |
73 | 81a97d9d | Stefan Hajnoczi | necessary to use void * for pointers to structs. |
74 | 81a97d9d | Stefan Hajnoczi | |
75 | 81a97d9d | Stefan Hajnoczi | * For everything else, use primitive scalar types (char, int, long) with the |
76 | 81a97d9d | Stefan Hajnoczi | appropriate signedness. |
77 | 81a97d9d | Stefan Hajnoczi | |
78 | 9a85d394 | Stefan Hajnoczi | Format strings should reflect the types defined in the trace event. Take |
79 | 9a85d394 | Stefan Hajnoczi | special care to use PRId64 and PRIu64 for int64_t and uint64_t types, |
80 | 913540a3 | Stefan Hajnoczi | respectively. This ensures portability between 32- and 64-bit platforms. |
81 | 9a85d394 | Stefan Hajnoczi | |
82 | 81a97d9d | Stefan Hajnoczi | === Hints for adding new trace events === |
83 | 81a97d9d | Stefan Hajnoczi | |
84 | 81a97d9d | Stefan Hajnoczi | 1. Trace state changes in the code. Interesting points in the code usually |
85 | 81a97d9d | Stefan Hajnoczi | involve a state change like starting, stopping, allocating, freeing. State |
86 | 81a97d9d | Stefan Hajnoczi | changes are good trace events because they can be used to understand the |
87 | 81a97d9d | Stefan Hajnoczi | execution of the system. |
88 | 81a97d9d | Stefan Hajnoczi | |
89 | 81a97d9d | Stefan Hajnoczi | 2. Trace guest operations. Guest I/O accesses like reading device registers |
90 | 81a97d9d | Stefan Hajnoczi | are good trace events because they can be used to understand guest |
91 | 81a97d9d | Stefan Hajnoczi | interactions. |
92 | 81a97d9d | Stefan Hajnoczi | |
93 | 81a97d9d | Stefan Hajnoczi | 3. Use correlator fields so the context of an individual line of trace output |
94 | 81a97d9d | Stefan Hajnoczi | can be understood. For example, trace the pointer returned by malloc and |
95 | 81a97d9d | Stefan Hajnoczi | used as an argument to free. This way mallocs and frees can be matched up. |
96 | 81a97d9d | Stefan Hajnoczi | Trace events with no context are not very useful. |
97 | 81a97d9d | Stefan Hajnoczi | |
98 | 81a97d9d | Stefan Hajnoczi | 4. Name trace events after their function. If there are multiple trace events |
99 | 81a97d9d | Stefan Hajnoczi | in one function, append a unique distinguisher at the end of the name. |
100 | 81a97d9d | Stefan Hajnoczi | |
101 | 31965ae2 | Lluís | == Generic interface and monitor commands == |
102 | 31965ae2 | Lluís | |
103 | b1bae816 | Lluís Vilanova | You can programmatically query and control the state of trace events through a |
104 | b1bae816 | Lluís Vilanova | backend-agnostic interface provided by the header "trace/control.h". |
105 | 31965ae2 | Lluís | |
106 | b1bae816 | Lluís Vilanova | Note that some of the backends do not provide an implementation for some parts |
107 | b1bae816 | Lluís Vilanova | of this interface, in which case QEMU will just print a warning (please refer to |
108 | b1bae816 | Lluís Vilanova | header "trace/control.h" to see which routines are backend-dependent). |
109 | 31965ae2 | Lluís | |
110 | b1bae816 | Lluís Vilanova | The state of events can also be queried and modified through monitor commands: |
111 | 31965ae2 | Lluís | |
112 | 31965ae2 | Lluís | * info trace-events |
113 | 31965ae2 | Lluís | View available trace events and their state. State 1 means enabled, state 0 |
114 | 31965ae2 | Lluís | means disabled. |
115 | 31965ae2 | Lluís | |
116 | 31965ae2 | Lluís | * trace-event NAME on|off |
117 | b1bae816 | Lluís Vilanova | Enable/disable a given trace event or a group of events (using wildcards). |
118 | 31965ae2 | Lluís | |
119 | 23d15e86 | Lluís | The "-trace events=<file>" command line argument can be used to enable the |
120 | 23d15e86 | Lluís | events listed in <file> from the very beginning of the program. This file must |
121 | 23d15e86 | Lluís | contain one event name per line. |
122 | 23d15e86 | Lluís | |
123 | 8f5a0fb1 | Stefan Hajnoczi | If a line in the "-trace events=<file>" file begins with a '-', the trace event |
124 | 8f5a0fb1 | Stefan Hajnoczi | will be disabled instead of enabled. This is useful when a wildcard was used |
125 | 8f5a0fb1 | Stefan Hajnoczi | to enable an entire family of events but one noisy event needs to be disabled. |
126 | 8f5a0fb1 | Stefan Hajnoczi | |
127 | b1bae816 | Lluís Vilanova | Wildcard matching is supported in both the monitor command "trace-event" and the |
128 | b1bae816 | Lluís Vilanova | events list file. That means you can enable/disable the events having a common |
129 | b1bae816 | Lluís Vilanova | prefix in a batch. For example, virtio-blk trace events could be enabled using |
130 | b1bae816 | Lluís Vilanova | the following monitor command: |
131 | b1bae816 | Lluís Vilanova | |
132 | b1bae816 | Lluís Vilanova | trace-event virtio_blk_* on |
133 | b1bae816 | Lluís Vilanova | |
134 | 81a97d9d | Stefan Hajnoczi | == Trace backends == |
135 | 81a97d9d | Stefan Hajnoczi | |
136 | 7b92e5bc | Lluís | The "tracetool" script automates tedious trace event code generation and also |
137 | 81a97d9d | Stefan Hajnoczi | keeps the trace event declarations independent of the trace backend. The trace |
138 | 81a97d9d | Stefan Hajnoczi | events are not tightly coupled to a specific trace backend, such as LTTng or |
139 | 7b92e5bc | Lluís | SystemTap. Support for trace backends can be added by extending the "tracetool" |
140 | 81a97d9d | Stefan Hajnoczi | script. |
141 | 81a97d9d | Stefan Hajnoczi | |
142 | 81a97d9d | Stefan Hajnoczi | The trace backend is chosen at configure time and only one trace backend can |
143 | 81a97d9d | Stefan Hajnoczi | be built into the binary: |
144 | 81a97d9d | Stefan Hajnoczi | |
145 | 81a97d9d | Stefan Hajnoczi | ./configure --trace-backend=simple |
146 | 81a97d9d | Stefan Hajnoczi | |
147 | 81a97d9d | Stefan Hajnoczi | For a list of supported trace backends, try ./configure --help or see below. |
148 | 81a97d9d | Stefan Hajnoczi | |
149 | 81a97d9d | Stefan Hajnoczi | The following subsections describe the supported trace backends. |
150 | 81a97d9d | Stefan Hajnoczi | |
151 | 81a97d9d | Stefan Hajnoczi | === Nop === |
152 | 81a97d9d | Stefan Hajnoczi | |
153 | 81a97d9d | Stefan Hajnoczi | The "nop" backend generates empty trace event functions so that the compiler |
154 | 81a97d9d | Stefan Hajnoczi | can optimize out trace events completely. This is the default and imposes no |
155 | 81a97d9d | Stefan Hajnoczi | performance penalty. |
156 | 81a97d9d | Stefan Hajnoczi | |
157 | dd215f64 | Lluís | Note that regardless of the selected trace backend, events with the "disable" |
158 | dd215f64 | Lluís | property will be generated with the "nop" backend. |
159 | dd215f64 | Lluís | |
160 | b48c20f7 | Stefan Hajnoczi | === Stderr === |
161 | b48c20f7 | Stefan Hajnoczi | |
162 | b48c20f7 | Stefan Hajnoczi | The "stderr" backend sends trace events directly to standard error. This |
163 | b48c20f7 | Stefan Hajnoczi | effectively turns trace events into debug printfs. |
164 | b48c20f7 | Stefan Hajnoczi | |
165 | b48c20f7 | Stefan Hajnoczi | This is the simplest backend and can be used together with existing code that |
166 | b48c20f7 | Stefan Hajnoczi | uses DPRINTF(). |
167 | b48c20f7 | Stefan Hajnoczi | |
168 | 81a97d9d | Stefan Hajnoczi | === Simpletrace === |
169 | 81a97d9d | Stefan Hajnoczi | |
170 | 81a97d9d | Stefan Hajnoczi | The "simple" backend supports common use cases and comes as part of the QEMU |
171 | 81a97d9d | Stefan Hajnoczi | source tree. It may not be as powerful as platform-specific or third-party |
172 | 81a97d9d | Stefan Hajnoczi | trace backends but it is portable. This is the recommended trace backend |
173 | 81a97d9d | Stefan Hajnoczi | unless you have specific needs for more advanced backends. |
174 | 81a97d9d | Stefan Hajnoczi | |
175 | 8f642117 | Stefan Hajnoczi | The "simple" backend currently does not capture string arguments, it simply |
176 | 8f642117 | Stefan Hajnoczi | records the char* pointer value instead of the string that is pointed to. |
177 | 8f642117 | Stefan Hajnoczi | |
178 | e64dd5ef | Eiichi Tsukata | === Ftrace === |
179 | e64dd5ef | Eiichi Tsukata | |
180 | e64dd5ef | Eiichi Tsukata | The "ftrace" backend writes trace data to ftrace marker. This effectively |
181 | e64dd5ef | Eiichi Tsukata | sends trace events to ftrace ring buffer, and you can compare qemu trace |
182 | e64dd5ef | Eiichi Tsukata | data and kernel(especially kvm.ko when using KVM) trace data. |
183 | e64dd5ef | Eiichi Tsukata | |
184 | e64dd5ef | Eiichi Tsukata | if you use KVM, enable kvm events in ftrace: |
185 | e64dd5ef | Eiichi Tsukata | |
186 | e64dd5ef | Eiichi Tsukata | # echo 1 > /sys/kernel/debug/tracing/events/kvm/enable |
187 | e64dd5ef | Eiichi Tsukata | |
188 | e64dd5ef | Eiichi Tsukata | After running qemu by root user, you can get the trace: |
189 | e64dd5ef | Eiichi Tsukata | |
190 | e64dd5ef | Eiichi Tsukata | # cat /sys/kernel/debug/tracing/trace |
191 | e64dd5ef | Eiichi Tsukata | |
192 | e64dd5ef | Eiichi Tsukata | Restriction: "ftrace" backend is restricted to Linux only. |
193 | e64dd5ef | Eiichi Tsukata | |
194 | 81a97d9d | Stefan Hajnoczi | ==== Monitor commands ==== |
195 | 81a97d9d | Stefan Hajnoczi | |
196 | 81a97d9d | Stefan Hajnoczi | * trace-file on|off|flush|set <path> |
197 | 81a97d9d | Stefan Hajnoczi | Enable/disable/flush the trace file or set the trace file name. |
198 | 81a97d9d | Stefan Hajnoczi | |
199 | 81a97d9d | Stefan Hajnoczi | ==== Analyzing trace files ==== |
200 | 81a97d9d | Stefan Hajnoczi | |
201 | 81a97d9d | Stefan Hajnoczi | The "simple" backend produces binary trace files that can be formatted with the |
202 | 7b92e5bc | Lluís | simpletrace.py script. The script takes the "trace-events" file and the binary |
203 | 81a97d9d | Stefan Hajnoczi | trace: |
204 | 81a97d9d | Stefan Hajnoczi | |
205 | 8f44015e | Markus Armbruster | ./scripts/simpletrace.py trace-events trace-12345 |
206 | 81a97d9d | Stefan Hajnoczi | |
207 | 7b92e5bc | Lluís | You must ensure that the same "trace-events" file was used to build QEMU, |
208 | 81a97d9d | Stefan Hajnoczi | otherwise trace event declarations may have changed and output will not be |
209 | 81a97d9d | Stefan Hajnoczi | consistent. |
210 | 81a97d9d | Stefan Hajnoczi | |
211 | 81a97d9d | Stefan Hajnoczi | === LTTng Userspace Tracer === |
212 | 81a97d9d | Stefan Hajnoczi | |
213 | 81a97d9d | Stefan Hajnoczi | The "ust" backend uses the LTTng Userspace Tracer library. There are no |
214 | 81a97d9d | Stefan Hajnoczi | monitor commands built into QEMU, instead UST utilities should be used to list, |
215 | 81a97d9d | Stefan Hajnoczi | enable/disable, and dump traces. |
216 | b48c20f7 | Stefan Hajnoczi | |
217 | b48c20f7 | Stefan Hajnoczi | === SystemTap === |
218 | b48c20f7 | Stefan Hajnoczi | |
219 | b48c20f7 | Stefan Hajnoczi | The "dtrace" backend uses DTrace sdt probes but has only been tested with |
220 | b48c20f7 | Stefan Hajnoczi | SystemTap. When SystemTap support is detected a .stp file with wrapper probes |
221 | b48c20f7 | Stefan Hajnoczi | is generated to make use in scripts more convenient. This step can also be |
222 | b48c20f7 | Stefan Hajnoczi | performed manually after a build in order to change the binary name in the .stp |
223 | b48c20f7 | Stefan Hajnoczi | probes: |
224 | b48c20f7 | Stefan Hajnoczi | |
225 | b48c20f7 | Stefan Hajnoczi | scripts/tracetool --dtrace --stap \ |
226 | b48c20f7 | Stefan Hajnoczi | --binary path/to/qemu-binary \ |
227 | b48c20f7 | Stefan Hajnoczi | --target-type system \ |
228 | b9a7b74f | Paolo Bonzini | --target-name x86_64 \ |
229 | b48c20f7 | Stefan Hajnoczi | <trace-events >qemu.stp |
230 | b7d66a76 | Lluís Vilanova | |
231 | b7d66a76 | Lluís Vilanova | == Trace event properties == |
232 | b7d66a76 | Lluís Vilanova | |
233 | b7d66a76 | Lluís Vilanova | Each event in the "trace-events" file can be prefixed with a space-separated |
234 | b7d66a76 | Lluís Vilanova | list of zero or more of the following event properties. |
235 | b7d66a76 | Lluís Vilanova | |
236 | b7d66a76 | Lluís Vilanova | === "disable" === |
237 | b7d66a76 | Lluís Vilanova | |
238 | b7d66a76 | Lluís Vilanova | If a specific trace event is going to be invoked a huge number of times, this |
239 | b7d66a76 | Lluís Vilanova | might have a noticeable performance impact even when the event is |
240 | b7d66a76 | Lluís Vilanova | programmatically disabled. |
241 | b7d66a76 | Lluís Vilanova | |
242 | b7d66a76 | Lluís Vilanova | In this case you should declare such event with the "disable" property. This |
243 | b7d66a76 | Lluís Vilanova | will effectively disable the event at compile time (by using the "nop" backend), |
244 | b7d66a76 | Lluís Vilanova | thus having no performance impact at all on regular builds (i.e., unless you |
245 | b7d66a76 | Lluís Vilanova | edit the "trace-events" file). |
246 | b7d66a76 | Lluís Vilanova | |
247 | b7d66a76 | Lluís Vilanova | In addition, there might be cases where relatively complex computations must be |
248 | b7d66a76 | Lluís Vilanova | performed to generate values that are only used as arguments for a trace |
249 | b7d66a76 | Lluís Vilanova | function. In these cases you can use the macro 'TRACE_${EVENT_NAME}_ENABLED' to |
250 | b7d66a76 | Lluís Vilanova | guard such computations and avoid its compilation when the event is disabled: |
251 | b7d66a76 | Lluís Vilanova | |
252 | b7d66a76 | Lluís Vilanova | #include "trace.h" /* needed for trace event prototype */ |
253 | b7d66a76 | Lluís Vilanova | |
254 | b7d66a76 | Lluís Vilanova | void *qemu_vmalloc(size_t size) |
255 | b7d66a76 | Lluís Vilanova | { |
256 | b7d66a76 | Lluís Vilanova | void *ptr; |
257 | b7d66a76 | Lluís Vilanova | size_t align = QEMU_VMALLOC_ALIGN; |
258 | b7d66a76 | Lluís Vilanova | |
259 | b7d66a76 | Lluís Vilanova | if (size < align) { |
260 | b7d66a76 | Lluís Vilanova | align = getpagesize(); |
261 | b7d66a76 | Lluís Vilanova | } |
262 | b7d66a76 | Lluís Vilanova | ptr = qemu_memalign(align, size); |
263 | b7d66a76 | Lluís Vilanova | if (TRACE_QEMU_VMALLOC_ENABLED) { /* preprocessor macro */ |
264 | b7d66a76 | Lluís Vilanova | void *complex; |
265 | b7d66a76 | Lluís Vilanova | /* some complex computations to produce the 'complex' value */ |
266 | b7d66a76 | Lluís Vilanova | trace_qemu_vmalloc(size, ptr, complex); |
267 | b7d66a76 | Lluís Vilanova | } |
268 | b7d66a76 | Lluís Vilanova | return ptr; |
269 | b7d66a76 | Lluís Vilanova | } |
270 | b1bae816 | Lluís Vilanova | |
271 | b1bae816 | Lluís Vilanova | You can check both if the event has been disabled and is dynamically enabled at |
272 | b1bae816 | Lluís Vilanova | the same time using the 'trace_event_get_state' routine (see header |
273 | b1bae816 | Lluís Vilanova | "trace/control.h" for more information). |