Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 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 --trace-backend=simple |
| 13 | make |
| 14 | |
| 15 | 2. Enable trace events you are interested in: |
| 16 | |
| 17 | $EDITOR trace-events # remove "disable" from events you want |
| 18 | |
| 19 | 3. Run the virtual machine to produce a trace file: |
| 20 | |
| 21 | qemu ... # your normal QEMU invocation |
| 22 | |
| 23 | 4. Pretty-print the binary trace file: |
| 24 | |
| 25 | ./simpletrace.py trace-events trace-* |
| 26 | |
| 27 | == Trace events == |
| 28 | |
| 29 | There is a set of static trace events declared in the trace-events source |
| 30 | file. Each trace event declaration names the event, its arguments, and the |
| 31 | format string which can be used for pretty-printing: |
| 32 | |
| 33 | qemu_malloc(size_t size, void *ptr) "size %zu ptr %p" |
| 34 | qemu_free(void *ptr) "ptr %p" |
| 35 | |
| 36 | The trace-events file is processed by the tracetool script during build to |
| 37 | generate code for the trace events. Trace events are invoked directly from |
| 38 | source code like this: |
| 39 | |
| 40 | #include "trace.h" /* needed for trace event prototype */ |
| 41 | |
| 42 | void *qemu_malloc(size_t size) |
| 43 | { |
| 44 | void *ptr; |
| 45 | if (!size && !allow_zero_malloc()) { |
| 46 | abort(); |
| 47 | } |
| 48 | ptr = oom_check(malloc(size ? size : 1)); |
| 49 | trace_qemu_malloc(size, ptr); /* <-- trace event */ |
| 50 | return ptr; |
| 51 | } |
| 52 | |
| 53 | === Declaring trace events === |
| 54 | |
| 55 | The tracetool script produces the trace.h header file which is included by |
| 56 | every source file that uses trace events. Since many source files include |
| 57 | trace.h, it uses a minimum of types and other header files included to keep |
| 58 | the namespace clean and compile times and dependencies down. |
| 59 | |
| 60 | Trace events should use types as follows: |
| 61 | |
| 62 | * Use stdint.h types for fixed-size types. Most offsets and guest memory |
| 63 | addresses are best represented with uint32_t or uint64_t. Use fixed-size |
| 64 | types over primitive types whose size may change depending on the host |
| 65 | (32-bit versus 64-bit) so trace events don't truncate values or break |
| 66 | the build. |
| 67 | |
| 68 | * Use void * for pointers to structs or for arrays. The trace.h header |
| 69 | cannot include all user-defined struct declarations and it is therefore |
| 70 | necessary to use void * for pointers to structs. |
| 71 | |
| 72 | * For everything else, use primitive scalar types (char, int, long) with the |
| 73 | appropriate signedness. |
| 74 | |
Stefan Hajnoczi | 9a85d39 | 2010-10-05 14:28:50 +0100 | [diff] [blame] | 75 | Format strings should reflect the types defined in the trace event. Take |
| 76 | special care to use PRId64 and PRIu64 for int64_t and uint64_t types, |
Stefan Hajnoczi | cf85cf8 | 2010-10-20 16:41:31 +0000 | [diff] [blame] | 77 | respectively. This ensures portability between 32- and 64-bit platforms. Note |
| 78 | that format strings must begin and end with double quotes. When using |
| 79 | portability macros, ensure they are preceded and followed by double quotes: |
| 80 | "value %"PRIx64"". |
Stefan Hajnoczi | 9a85d39 | 2010-10-05 14:28:50 +0100 | [diff] [blame] | 81 | |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 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 | 5. Declare trace events with the "disable" keyword. Some trace events can |
| 102 | produce a lot of output and users are typically only interested in a subset |
| 103 | of trace events. Marking trace events disabled by default saves the user |
| 104 | from having to manually disable noisy trace events. |
| 105 | |
| 106 | == Trace backends == |
| 107 | |
| 108 | The tracetool script automates tedious trace event code generation and also |
| 109 | keeps the trace event declarations independent of the trace backend. The trace |
| 110 | events are not tightly coupled to a specific trace backend, such as LTTng or |
| 111 | SystemTap. Support for trace backends can be added by extending the tracetool |
| 112 | script. |
| 113 | |
| 114 | The trace backend is chosen at configure time and only one trace backend can |
| 115 | be built into the binary: |
| 116 | |
| 117 | ./configure --trace-backend=simple |
| 118 | |
| 119 | For a list of supported trace backends, try ./configure --help or see below. |
| 120 | |
| 121 | The following subsections describe the supported trace backends. |
| 122 | |
| 123 | === Nop === |
| 124 | |
| 125 | The "nop" backend generates empty trace event functions so that the compiler |
| 126 | can optimize out trace events completely. This is the default and imposes no |
| 127 | performance penalty. |
| 128 | |
Stefan Hajnoczi | b48c20f | 2011-02-23 14:00:21 +0000 | [diff] [blame^] | 129 | === Stderr === |
| 130 | |
| 131 | The "stderr" backend sends trace events directly to standard error. This |
| 132 | effectively turns trace events into debug printfs. |
| 133 | |
| 134 | This is the simplest backend and can be used together with existing code that |
| 135 | uses DPRINTF(). |
| 136 | |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 137 | === Simpletrace === |
| 138 | |
| 139 | The "simple" backend supports common use cases and comes as part of the QEMU |
| 140 | source tree. It may not be as powerful as platform-specific or third-party |
| 141 | trace backends but it is portable. This is the recommended trace backend |
| 142 | unless you have specific needs for more advanced backends. |
| 143 | |
Stefan Hajnoczi | b48c20f | 2011-02-23 14:00:21 +0000 | [diff] [blame^] | 144 | Warning: the "simple" backend is not thread-safe so only enable trace events |
| 145 | that are executed while the global mutex is held. Much of QEMU meets this |
| 146 | requirement but some utility functions like qemu_malloc() or thread-related |
| 147 | code cannot be safely traced using the "simple" backend. |
Fabien Chouteau | 320fba2 | 2011-01-27 10:24:41 +0100 | [diff] [blame] | 148 | |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 149 | ==== Monitor commands ==== |
| 150 | |
| 151 | * info trace |
| 152 | Display the contents of trace buffer. This command dumps the trace buffer |
| 153 | with simple formatting. For full pretty-printing, use the simpletrace.py |
| 154 | script on a binary trace file. |
| 155 | |
| 156 | The trace buffer is written into until full. The full trace buffer is |
| 157 | flushed and emptied. This means the 'info trace' will display few or no |
| 158 | entries if the buffer has just been flushed. |
| 159 | |
| 160 | * info trace-events |
| 161 | View available trace events and their state. State 1 means enabled, state 0 |
| 162 | means disabled. |
| 163 | |
| 164 | * trace-event NAME on|off |
| 165 | Enable/disable a given trace event. |
| 166 | |
| 167 | * trace-file on|off|flush|set <path> |
| 168 | Enable/disable/flush the trace file or set the trace file name. |
| 169 | |
| 170 | ==== Enabling/disabling trace events programmatically ==== |
| 171 | |
| 172 | The st_change_trace_event_state() function can be used to enable or disable trace |
| 173 | events at runtime inside QEMU: |
| 174 | |
| 175 | #include "trace.h" |
| 176 | |
| 177 | st_change_trace_event_state("virtio_irq", true); /* enable */ |
| 178 | [...] |
| 179 | st_change_trace_event_state("virtio_irq", false); /* disable */ |
| 180 | |
| 181 | ==== Analyzing trace files ==== |
| 182 | |
| 183 | The "simple" backend produces binary trace files that can be formatted with the |
| 184 | simpletrace.py script. The script takes the trace-events file and the binary |
| 185 | trace: |
| 186 | |
| 187 | ./simpletrace.py trace-events trace-12345 |
| 188 | |
| 189 | You must ensure that the same trace-events file was used to build QEMU, |
| 190 | otherwise trace event declarations may have changed and output will not be |
| 191 | consistent. |
| 192 | |
| 193 | === LTTng Userspace Tracer === |
| 194 | |
| 195 | The "ust" backend uses the LTTng Userspace Tracer library. There are no |
| 196 | monitor commands built into QEMU, instead UST utilities should be used to list, |
| 197 | enable/disable, and dump traces. |
Stefan Hajnoczi | b48c20f | 2011-02-23 14:00:21 +0000 | [diff] [blame^] | 198 | |
| 199 | === SystemTap === |
| 200 | |
| 201 | The "dtrace" backend uses DTrace sdt probes but has only been tested with |
| 202 | SystemTap. When SystemTap support is detected a .stp file with wrapper probes |
| 203 | is generated to make use in scripts more convenient. This step can also be |
| 204 | performed manually after a build in order to change the binary name in the .stp |
| 205 | probes: |
| 206 | |
| 207 | scripts/tracetool --dtrace --stap \ |
| 208 | --binary path/to/qemu-binary \ |
| 209 | --target-type system \ |
| 210 | --target-arch x86_64 \ |
| 211 | <trace-events >qemu.stp |