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