Vladimir Sementsov-Ogievskiy | ff8e482 | 2022-01-26 17:11:28 +0100 | [diff] [blame] | 1 | .. _tracing: |
| 2 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 3 | ======= |
| 4 | Tracing |
| 5 | ======= |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 6 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 7 | Introduction |
| 8 | ============ |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 9 | |
| 10 | This document describes the tracing infrastructure in QEMU and how to use it |
| 11 | for debugging, profiling, and observing execution. |
| 12 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 13 | Quickstart |
| 14 | ========== |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 15 | |
Stefan Hajnoczi | 7e46d5f | 2020-12-16 16:09:23 +0000 | [diff] [blame] | 16 | Enable tracing of ``memory_region_ops_read`` and ``memory_region_ops_write`` |
| 17 | events:: |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 18 | |
Stefan Hajnoczi | 7e46d5f | 2020-12-16 16:09:23 +0000 | [diff] [blame] | 19 | $ qemu --trace "memory_region_ops_*" ... |
| 20 | ... |
| 21 | 719585@1608130130.441188:memory_region_ops_read cpu 0 mr 0x562fdfbb3820 addr 0x3cc value 0x67 size 1 |
| 22 | 719585@1608130130.441190:memory_region_ops_write cpu 0 mr 0x562fdfbd2f00 addr 0x3d4 value 0x70e size 2 |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 23 | |
Stefan Hajnoczi | 7e46d5f | 2020-12-16 16:09:23 +0000 | [diff] [blame] | 24 | This output comes from the "log" trace backend that is enabled by default when |
| 25 | ``./configure --enable-trace-backends=BACKENDS`` was not explicitly specified. |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 26 | |
Stefan Hajnoczi | 3faf22e | 2021-01-12 16:58:58 +0000 | [diff] [blame] | 27 | Multiple patterns can be specified by repeating the ``--trace`` option:: |
| 28 | |
| 29 | $ qemu --trace "kvm_*" --trace "virtio_*" ... |
| 30 | |
| 31 | When patterns are used frequently it is more convenient to store them in a |
| 32 | file to avoid long command-line options:: |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 33 | |
Stefan Hajnoczi | 7e46d5f | 2020-12-16 16:09:23 +0000 | [diff] [blame] | 34 | $ echo "memory_region_ops_*" >/tmp/events |
Stefan Hajnoczi | 3faf22e | 2021-01-12 16:58:58 +0000 | [diff] [blame] | 35 | $ echo "kvm_*" >>/tmp/events |
Stefan Hajnoczi | 7e46d5f | 2020-12-16 16:09:23 +0000 | [diff] [blame] | 36 | $ qemu --trace events=/tmp/events ... |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 37 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 38 | Trace events |
| 39 | ============ |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 40 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 41 | Sub-directory setup |
| 42 | ------------------- |
Daniel P. Berrange | d4fa843 | 2017-01-25 16:14:16 +0000 | [diff] [blame] | 43 | |
Stefan Hajnoczi | 0dfb3ca | 2021-01-12 16:58:59 +0000 | [diff] [blame] | 44 | Each directory in the source tree can declare a set of trace events in a local |
| 45 | "trace-events" file. All directories which contain "trace-events" files must be |
| 46 | listed in the "trace_events_subdirs" variable in the top level meson.build |
| 47 | file. During build, the "trace-events" file in each listed subdirectory will be |
| 48 | processed by the "tracetool" script to generate code for the trace events. |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 49 | |
Daniel P. Berrange | d4fa843 | 2017-01-25 16:14:16 +0000 | [diff] [blame] | 50 | The individual "trace-events" files are merged into a "trace-events-all" file, |
Marc-André Lureau | 7a42e68 | 2022-04-20 17:25:55 +0400 | [diff] [blame] | 51 | which is also installed into "/usr/share/qemu". |
Daniel P. Berrange | d4fa843 | 2017-01-25 16:14:16 +0000 | [diff] [blame] | 52 | This merged file is to be used by the "simpletrace.py" script to later analyse |
| 53 | traces in the simpletrace data format. |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 54 | |
Stefan Hajnoczi | 0dfb3ca | 2021-01-12 16:58:59 +0000 | [diff] [blame] | 55 | The following files are automatically generated in <builddir>/trace/ during the |
| 56 | build: |
Daniel P. Berrange | d4fa843 | 2017-01-25 16:14:16 +0000 | [diff] [blame] | 57 | |
Stefan Hajnoczi | 0dfb3ca | 2021-01-12 16:58:59 +0000 | [diff] [blame] | 58 | - trace-<subdir>.c - the trace event state declarations |
| 59 | - trace-<subdir>.h - the trace event enums and probe functions |
| 60 | - trace-dtrace-<subdir>.h - DTrace event probe specification |
| 61 | - trace-dtrace-<subdir>.dtrace - DTrace event probe helper declaration |
| 62 | - trace-dtrace-<subdir>.o - binary DTrace provider (generated by dtrace) |
| 63 | - trace-ust-<subdir>.h - UST event probe helper declarations |
Daniel P. Berrange | d4fa843 | 2017-01-25 16:14:16 +0000 | [diff] [blame] | 64 | |
Stefan Hajnoczi | 0dfb3ca | 2021-01-12 16:58:59 +0000 | [diff] [blame] | 65 | Here <subdir> is the sub-directory path with '/' replaced by '_'. For example, |
| 66 | "accel/kvm" becomes "accel_kvm" and the final filename for "trace-<subdir>.c" |
| 67 | becomes "trace-accel_kvm.c". |
| 68 | |
| 69 | Source files in the source tree do not directly include generated files in |
| 70 | "<builddir>/trace/". Instead they #include the local "trace.h" file, without |
| 71 | any sub-directory path prefix. eg io/channel-buffer.c would do:: |
Daniel P. Berrange | d4fa843 | 2017-01-25 16:14:16 +0000 | [diff] [blame] | 72 | |
| 73 | #include "trace.h" |
| 74 | |
Stefan Hajnoczi | 0dfb3ca | 2021-01-12 16:58:59 +0000 | [diff] [blame] | 75 | The "io/trace.h" file must be created manually with an #include of the |
| 76 | corresponding "trace/trace-<subdir>.h" file that will be generated in the |
| 77 | builddir:: |
| 78 | |
| 79 | $ echo '#include "trace/trace-io.h"' >io/trace.h |
| 80 | |
| 81 | While it is possible to include a trace.h file from outside a source file's own |
| 82 | sub-directory, this is discouraged in general. It is strongly preferred that |
| 83 | all events be declared directly in the sub-directory that uses them. The only |
| 84 | exception is where there are some shared trace events defined in the top level |
| 85 | directory trace-events file. The top level directory generates trace files |
| 86 | with a filename prefix of "trace/trace-root" instead of just "trace". This is |
| 87 | to avoid ambiguity between a trace.h in the current directory, vs the top level |
| 88 | directory. |
Daniel P. Berrange | d4fa843 | 2017-01-25 16:14:16 +0000 | [diff] [blame] | 89 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 90 | Using trace events |
| 91 | ------------------ |
Daniel P. Berrange | 1412cf5 | 2016-06-16 09:39:47 +0100 | [diff] [blame] | 92 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 93 | Trace events are invoked directly from source code like this:: |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 94 | |
| 95 | #include "trace.h" /* needed for trace event prototype */ |
Lluís | 4992604 | 2011-08-31 20:31:10 +0200 | [diff] [blame] | 96 | |
Lluís Vilanova | 4b710a3 | 2011-09-20 21:03:48 +0200 | [diff] [blame] | 97 | void *qemu_vmalloc(size_t size) |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 98 | { |
| 99 | void *ptr; |
Lluís Vilanova | 4b710a3 | 2011-09-20 21:03:48 +0200 | [diff] [blame] | 100 | size_t align = QEMU_VMALLOC_ALIGN; |
| 101 | |
| 102 | if (size < align) { |
| 103 | align = getpagesize(); |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 104 | } |
Lluís Vilanova | 4b710a3 | 2011-09-20 21:03:48 +0200 | [diff] [blame] | 105 | ptr = qemu_memalign(align, size); |
| 106 | trace_qemu_vmalloc(size, ptr); |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 107 | return ptr; |
| 108 | } |
| 109 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 110 | Declaring trace events |
| 111 | ---------------------- |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 112 | |
Lluís | 7b92e5b | 2011-04-06 20:33:56 +0200 | [diff] [blame] | 113 | The "tracetool" script produces the trace.h header file which is included by |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 114 | every source file that uses trace events. Since many source files include |
Lluís | 7b92e5b | 2011-04-06 20:33:56 +0200 | [diff] [blame] | 115 | trace.h, it uses a minimum of types and other header files included to keep the |
| 116 | namespace clean and compile times and dependencies down. |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 117 | |
| 118 | Trace events should use types as follows: |
| 119 | |
| 120 | * Use stdint.h types for fixed-size types. Most offsets and guest memory |
| 121 | addresses are best represented with uint32_t or uint64_t. Use fixed-size |
| 122 | types over primitive types whose size may change depending on the host |
| 123 | (32-bit versus 64-bit) so trace events don't truncate values or break |
| 124 | the build. |
| 125 | |
| 126 | * Use void * for pointers to structs or for arrays. The trace.h header |
| 127 | cannot include all user-defined struct declarations and it is therefore |
| 128 | necessary to use void * for pointers to structs. |
| 129 | |
| 130 | * For everything else, use primitive scalar types (char, int, long) with the |
| 131 | appropriate signedness. |
| 132 | |
Stefan Hajnoczi | ec09f87 | 2018-06-21 16:02:54 +0100 | [diff] [blame] | 133 | * Avoid floating point types (float and double) because SystemTap does not |
| 134 | support them. In most cases it is possible to round to an integer type |
| 135 | instead. This may require scaling the value first by multiplying it by 1000 |
| 136 | or the like when digits after the decimal point need to be preserved. |
| 137 | |
Stefan Hajnoczi | 9a85d39 | 2010-10-05 14:28:50 +0100 | [diff] [blame] | 138 | Format strings should reflect the types defined in the trace event. Take |
| 139 | special care to use PRId64 and PRIu64 for int64_t and uint64_t types, |
Stefan Hajnoczi | 913540a | 2011-09-13 13:34:35 +0100 | [diff] [blame] | 140 | respectively. This ensures portability between 32- and 64-bit platforms. |
Philippe Mathieu-Daudé | 9f7ad79 | 2019-09-16 11:51:21 +0200 | [diff] [blame] | 141 | Format strings must not end with a newline character. It is the responsibility |
| 142 | of backends to adapt line ending for proper logging. |
Stefan Hajnoczi | 9a85d39 | 2010-10-05 14:28:50 +0100 | [diff] [blame] | 143 | |
Daniel P. Berrange | d4fa843 | 2017-01-25 16:14:16 +0000 | [diff] [blame] | 144 | Each event declaration will start with the event name, then its arguments, |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 145 | finally a format string for pretty-printing. For example:: |
Daniel P. Berrange | d4fa843 | 2017-01-25 16:14:16 +0000 | [diff] [blame] | 146 | |
| 147 | qemu_vmalloc(size_t size, void *ptr) "size %zu ptr %p" |
| 148 | qemu_vfree(void *ptr) "ptr %p" |
| 149 | |
| 150 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 151 | Hints for adding new trace events |
| 152 | --------------------------------- |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 153 | |
| 154 | 1. Trace state changes in the code. Interesting points in the code usually |
| 155 | involve a state change like starting, stopping, allocating, freeing. State |
| 156 | changes are good trace events because they can be used to understand the |
| 157 | execution of the system. |
| 158 | |
| 159 | 2. Trace guest operations. Guest I/O accesses like reading device registers |
| 160 | are good trace events because they can be used to understand guest |
| 161 | interactions. |
| 162 | |
| 163 | 3. Use correlator fields so the context of an individual line of trace output |
| 164 | can be understood. For example, trace the pointer returned by malloc and |
| 165 | used as an argument to free. This way mallocs and frees can be matched up. |
| 166 | Trace events with no context are not very useful. |
| 167 | |
| 168 | 4. Name trace events after their function. If there are multiple trace events |
| 169 | in one function, append a unique distinguisher at the end of the name. |
| 170 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 171 | Generic interface and monitor commands |
| 172 | ====================================== |
Lluís | 31965ae | 2011-08-31 20:31:24 +0200 | [diff] [blame] | 173 | |
Lluís Vilanova | b1bae81 | 2013-03-05 14:47:38 +0100 | [diff] [blame] | 174 | You can programmatically query and control the state of trace events through a |
| 175 | backend-agnostic interface provided by the header "trace/control.h". |
Lluís | 31965ae | 2011-08-31 20:31:24 +0200 | [diff] [blame] | 176 | |
Lluís Vilanova | b1bae81 | 2013-03-05 14:47:38 +0100 | [diff] [blame] | 177 | Note that some of the backends do not provide an implementation for some parts |
| 178 | of this interface, in which case QEMU will just print a warning (please refer to |
| 179 | header "trace/control.h" to see which routines are backend-dependent). |
Lluís | 31965ae | 2011-08-31 20:31:24 +0200 | [diff] [blame] | 180 | |
Lluís Vilanova | b1bae81 | 2013-03-05 14:47:38 +0100 | [diff] [blame] | 181 | The state of events can also be queried and modified through monitor commands: |
Lluís | 31965ae | 2011-08-31 20:31:24 +0200 | [diff] [blame] | 182 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 183 | * ``info trace-events`` |
Lluís | 31965ae | 2011-08-31 20:31:24 +0200 | [diff] [blame] | 184 | View available trace events and their state. State 1 means enabled, state 0 |
| 185 | means disabled. |
| 186 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 187 | * ``trace-event NAME on|off`` |
Lluís Vilanova | b1bae81 | 2013-03-05 14:47:38 +0100 | [diff] [blame] | 188 | Enable/disable a given trace event or a group of events (using wildcards). |
Lluís | 31965ae | 2011-08-31 20:31:24 +0200 | [diff] [blame] | 189 | |
Yaowei Bai | db817b8 | 2018-07-04 11:17:27 +0800 | [diff] [blame] | 190 | The "--trace events=<file>" command line argument can be used to enable the |
Lluís | 23d15e8 | 2011-08-31 20:31:31 +0200 | [diff] [blame] | 191 | events listed in <file> from the very beginning of the program. This file must |
| 192 | contain one event name per line. |
| 193 | |
Yaowei Bai | db817b8 | 2018-07-04 11:17:27 +0800 | [diff] [blame] | 194 | If a line in the "--trace events=<file>" file begins with a '-', the trace event |
Stefan Hajnoczi | 8f5a0fb | 2012-11-05 08:48:29 +0100 | [diff] [blame] | 195 | will be disabled instead of enabled. This is useful when a wildcard was used |
| 196 | to enable an entire family of events but one noisy event needs to be disabled. |
| 197 | |
Lluís Vilanova | b1bae81 | 2013-03-05 14:47:38 +0100 | [diff] [blame] | 198 | Wildcard matching is supported in both the monitor command "trace-event" and the |
| 199 | events list file. That means you can enable/disable the events having a common |
| 200 | prefix in a batch. For example, virtio-blk trace events could be enabled using |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 201 | the following monitor command:: |
Lluís Vilanova | b1bae81 | 2013-03-05 14:47:38 +0100 | [diff] [blame] | 202 | |
| 203 | trace-event virtio_blk_* on |
| 204 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 205 | Trace backends |
| 206 | ============== |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 207 | |
Lluís | 7b92e5b | 2011-04-06 20:33:56 +0200 | [diff] [blame] | 208 | The "tracetool" script automates tedious trace event code generation and also |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 209 | keeps the trace event declarations independent of the trace backend. The trace |
| 210 | events are not tightly coupled to a specific trace backend, such as LTTng or |
Lluís | 7b92e5b | 2011-04-06 20:33:56 +0200 | [diff] [blame] | 211 | SystemTap. Support for trace backends can be added by extending the "tracetool" |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 212 | script. |
| 213 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 214 | The trace backends are chosen at configure time:: |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 215 | |
Stefan Hajnoczi | 7e46d5f | 2020-12-16 16:09:23 +0000 | [diff] [blame] | 216 | ./configure --enable-trace-backends=simple,dtrace |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 217 | |
| 218 | For a list of supported trace backends, try ./configure --help or see below. |
Dr. David Alan Gilbert | b73e8bd | 2014-10-07 15:12:41 +0100 | [diff] [blame] | 219 | If multiple backends are enabled, the trace is sent to them all. |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 220 | |
Peter Maydell | 3b0fc80 | 2016-11-04 16:27:17 +0000 | [diff] [blame] | 221 | If no backends are explicitly selected, configure will default to the |
| 222 | "log" backend. |
| 223 | |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 224 | The following subsections describe the supported trace backends. |
| 225 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 226 | Nop |
| 227 | --- |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 228 | |
| 229 | The "nop" backend generates empty trace event functions so that the compiler |
Peter Maydell | 3b0fc80 | 2016-11-04 16:27:17 +0000 | [diff] [blame] | 230 | can optimize out trace events completely. This imposes no performance |
| 231 | penalty. |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 232 | |
Lluís | dd215f6 | 2011-08-31 20:31:38 +0200 | [diff] [blame] | 233 | Note that regardless of the selected trace backend, events with the "disable" |
| 234 | property will be generated with the "nop" backend. |
| 235 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 236 | Log |
| 237 | --- |
Stefan Hajnoczi | b48c20f | 2011-02-23 14:00:21 +0000 | [diff] [blame] | 238 | |
Richard W.M. Jones | ab8eb29 | 2016-03-20 21:00:14 +0000 | [diff] [blame] | 239 | The "log" backend sends trace events directly to standard error. This |
Stefan Hajnoczi | b48c20f | 2011-02-23 14:00:21 +0000 | [diff] [blame] | 240 | effectively turns trace events into debug printfs. |
| 241 | |
| 242 | This is the simplest backend and can be used together with existing code that |
| 243 | uses DPRINTF(). |
| 244 | |
Stefan Hajnoczi | 418ed14 | 2021-01-25 11:35:07 +0000 | [diff] [blame] | 245 | The -msg timestamp=on|off command-line option controls whether or not to print |
| 246 | the tid/timestamp prefix for each trace event. |
| 247 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 248 | Simpletrace |
| 249 | ----------- |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 250 | |
Stefan Hajnoczi | 7e46d5f | 2020-12-16 16:09:23 +0000 | [diff] [blame] | 251 | The "simple" backend writes binary trace logs to a file from a thread, making |
| 252 | it lower overhead than the "log" backend. A Python API is available for writing |
| 253 | offline trace file analysis scripts. It may not be as powerful as |
| 254 | platform-specific or third-party trace backends but it is portable and has no |
| 255 | special library dependencies. |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 256 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 257 | Monitor commands |
| 258 | ~~~~~~~~~~~~~~~~ |
Stefan Hajnoczi | c72e3e4 | 2020-12-16 16:09:21 +0000 | [diff] [blame] | 259 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 260 | * ``trace-file on|off|flush|set <path>`` |
Stefan Hajnoczi | c72e3e4 | 2020-12-16 16:09:21 +0000 | [diff] [blame] | 261 | Enable/disable/flush the trace file or set the trace file name. |
| 262 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 263 | Analyzing trace files |
| 264 | ~~~~~~~~~~~~~~~~~~~~~ |
Stefan Hajnoczi | c72e3e4 | 2020-12-16 16:09:21 +0000 | [diff] [blame] | 265 | |
| 266 | The "simple" backend produces binary trace files that can be formatted with the |
| 267 | simpletrace.py script. The script takes the "trace-events-all" file and the |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 268 | binary trace:: |
Stefan Hajnoczi | c72e3e4 | 2020-12-16 16:09:21 +0000 | [diff] [blame] | 269 | |
| 270 | ./scripts/simpletrace.py trace-events-all trace-12345 |
| 271 | |
| 272 | You must ensure that the same "trace-events-all" file was used to build QEMU, |
| 273 | otherwise trace event declarations may have changed and output will not be |
| 274 | consistent. |
| 275 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 276 | Ftrace |
| 277 | ------ |
Eiichi Tsukata | e64dd5e | 2013-04-11 20:25:16 +0900 | [diff] [blame] | 278 | |
| 279 | The "ftrace" backend writes trace data to ftrace marker. This effectively |
| 280 | sends trace events to ftrace ring buffer, and you can compare qemu trace |
| 281 | data and kernel(especially kvm.ko when using KVM) trace data. |
| 282 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 283 | if you use KVM, enable kvm events in ftrace:: |
Eiichi Tsukata | e64dd5e | 2013-04-11 20:25:16 +0900 | [diff] [blame] | 284 | |
| 285 | # echo 1 > /sys/kernel/debug/tracing/events/kvm/enable |
| 286 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 287 | After running qemu by root user, you can get the trace:: |
Eiichi Tsukata | e64dd5e | 2013-04-11 20:25:16 +0900 | [diff] [blame] | 288 | |
| 289 | # cat /sys/kernel/debug/tracing/trace |
| 290 | |
| 291 | Restriction: "ftrace" backend is restricted to Linux only. |
| 292 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 293 | Syslog |
| 294 | ------ |
Paul Durrant | 0a85241 | 2016-08-04 14:44:14 +0100 | [diff] [blame] | 295 | |
| 296 | The "syslog" backend sends trace events using the POSIX syslog API. The log |
| 297 | is opened specifying the LOG_DAEMON facility and LOG_PID option (so events |
| 298 | are tagged with the pid of the particular QEMU process that generated |
| 299 | them). All events are logged at LOG_INFO level. |
| 300 | |
| 301 | NOTE: syslog may squash duplicate consecutive trace events and apply rate |
| 302 | limiting. |
| 303 | |
| 304 | Restriction: "syslog" backend is restricted to POSIX compliant OS. |
| 305 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 306 | LTTng Userspace Tracer |
| 307 | ---------------------- |
Stefan Hajnoczi | 81a97d9 | 2010-06-22 15:07:09 +0100 | [diff] [blame] | 308 | |
| 309 | The "ust" backend uses the LTTng Userspace Tracer library. There are no |
| 310 | monitor commands built into QEMU, instead UST utilities should be used to list, |
| 311 | enable/disable, and dump traces. |
Stefan Hajnoczi | b48c20f | 2011-02-23 14:00:21 +0000 | [diff] [blame] | 312 | |
Mohamad Gebai | ef3ef4a | 2014-01-29 22:47:57 -0500 | [diff] [blame] | 313 | Package lttng-tools is required for userspace tracing. You must ensure that the |
| 314 | current user belongs to the "tracing" group, or manually launch the |
| 315 | lttng-sessiond daemon for the current user prior to running any instance of |
| 316 | QEMU. |
| 317 | |
| 318 | While running an instrumented QEMU, LTTng should be able to list all available |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 319 | events:: |
Mohamad Gebai | ef3ef4a | 2014-01-29 22:47:57 -0500 | [diff] [blame] | 320 | |
| 321 | lttng list -u |
| 322 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 323 | Create tracing session:: |
Mohamad Gebai | ef3ef4a | 2014-01-29 22:47:57 -0500 | [diff] [blame] | 324 | |
| 325 | lttng create mysession |
| 326 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 327 | Enable events:: |
Mohamad Gebai | ef3ef4a | 2014-01-29 22:47:57 -0500 | [diff] [blame] | 328 | |
| 329 | lttng enable-event qemu:g_malloc -u |
| 330 | |
| 331 | Where the events can either be a comma-separated list of events, or "-a" to |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 332 | enable all tracepoint events. Start and stop tracing as needed:: |
Mohamad Gebai | ef3ef4a | 2014-01-29 22:47:57 -0500 | [diff] [blame] | 333 | |
| 334 | lttng start |
| 335 | lttng stop |
| 336 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 337 | View the trace:: |
Mohamad Gebai | ef3ef4a | 2014-01-29 22:47:57 -0500 | [diff] [blame] | 338 | |
| 339 | lttng view |
| 340 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 341 | Destroy tracing session:: |
Mohamad Gebai | ef3ef4a | 2014-01-29 22:47:57 -0500 | [diff] [blame] | 342 | |
| 343 | lttng destroy |
| 344 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 345 | Babeltrace can be used at any later time to view the trace:: |
Mohamad Gebai | ef3ef4a | 2014-01-29 22:47:57 -0500 | [diff] [blame] | 346 | |
| 347 | babeltrace $HOME/lttng-traces/mysession-<date>-<time> |
| 348 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 349 | SystemTap |
| 350 | --------- |
Stefan Hajnoczi | b48c20f | 2011-02-23 14:00:21 +0000 | [diff] [blame] | 351 | |
| 352 | The "dtrace" backend uses DTrace sdt probes but has only been tested with |
| 353 | SystemTap. When SystemTap support is detected a .stp file with wrapper probes |
| 354 | is generated to make use in scripts more convenient. This step can also be |
| 355 | performed manually after a build in order to change the binary name in the .stp |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 356 | probes:: |
Stefan Hajnoczi | b48c20f | 2011-02-23 14:00:21 +0000 | [diff] [blame] | 357 | |
Lin Ma | 2e4ccbb | 2015-09-11 14:58:50 +0800 | [diff] [blame] | 358 | scripts/tracetool.py --backends=dtrace --format=stap \ |
| 359 | --binary path/to/qemu-binary \ |
| 360 | --target-type system \ |
| 361 | --target-name x86_64 \ |
Stefan Hajnoczi | bd20038 | 2019-10-09 14:51:54 +0100 | [diff] [blame] | 362 | --group=all \ |
Stefan Hajnoczi | c05012a | 2020-08-27 15:29:12 +0100 | [diff] [blame] | 363 | trace-events-all \ |
| 364 | qemu.stp |
Lluís Vilanova | b7d66a7 | 2011-12-06 17:38:15 +0100 | [diff] [blame] | 365 | |
Daniel P. Berrangé | 62dd104 | 2019-01-23 12:00:16 +0000 | [diff] [blame] | 366 | To facilitate simple usage of systemtap where there merely needs to be printf |
| 367 | logging of certain probes, a helper script "qemu-trace-stap" is provided. |
| 368 | Consult its manual page for guidance on its usage. |
| 369 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 370 | Trace event properties |
| 371 | ====================== |
Lluís Vilanova | b7d66a7 | 2011-12-06 17:38:15 +0100 | [diff] [blame] | 372 | |
Daniel P. Berrange | 1412cf5 | 2016-06-16 09:39:47 +0100 | [diff] [blame] | 373 | Each event in the "trace-events-all" file can be prefixed with a space-separated |
Lluís Vilanova | b7d66a7 | 2011-12-06 17:38:15 +0100 | [diff] [blame] | 374 | list of zero or more of the following event properties. |
| 375 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 376 | "disable" |
| 377 | --------- |
Lluís Vilanova | b7d66a7 | 2011-12-06 17:38:15 +0100 | [diff] [blame] | 378 | |
| 379 | If a specific trace event is going to be invoked a huge number of times, this |
| 380 | might have a noticeable performance impact even when the event is |
| 381 | programmatically disabled. |
| 382 | |
| 383 | In this case you should declare such event with the "disable" property. This |
| 384 | will effectively disable the event at compile time (by using the "nop" backend), |
| 385 | thus having no performance impact at all on regular builds (i.e., unless you |
Daniel P. Berrange | 1412cf5 | 2016-06-16 09:39:47 +0100 | [diff] [blame] | 386 | edit the "trace-events-all" file). |
Lluís Vilanova | b7d66a7 | 2011-12-06 17:38:15 +0100 | [diff] [blame] | 387 | |
| 388 | In addition, there might be cases where relatively complex computations must be |
| 389 | performed to generate values that are only used as arguments for a trace |
Peter Maydell | 1aa6430 | 2020-01-20 15:11:40 +0000 | [diff] [blame] | 390 | function. In these cases you can use 'trace_event_get_state_backends()' to |
| 391 | guard such computations, so they are skipped if the event has been either |
| 392 | compile-time disabled or run-time disabled. If the event is compile-time |
| 393 | disabled, this check will have no performance impact. |
Lluís Vilanova | b7d66a7 | 2011-12-06 17:38:15 +0100 | [diff] [blame] | 394 | |
Stefan Hajnoczi | e50caf4 | 2020-12-16 16:09:22 +0000 | [diff] [blame] | 395 | :: |
| 396 | |
Lluís Vilanova | b7d66a7 | 2011-12-06 17:38:15 +0100 | [diff] [blame] | 397 | #include "trace.h" /* needed for trace event prototype */ |
| 398 | |
| 399 | void *qemu_vmalloc(size_t size) |
| 400 | { |
| 401 | void *ptr; |
| 402 | size_t align = QEMU_VMALLOC_ALIGN; |
| 403 | |
| 404 | if (size < align) { |
| 405 | align = getpagesize(); |
| 406 | } |
| 407 | ptr = qemu_memalign(align, size); |
Peter Maydell | 1aa6430 | 2020-01-20 15:11:40 +0000 | [diff] [blame] | 408 | if (trace_event_get_state_backends(TRACE_QEMU_VMALLOC)) { |
Lluís Vilanova | b7d66a7 | 2011-12-06 17:38:15 +0100 | [diff] [blame] | 409 | void *complex; |
| 410 | /* some complex computations to produce the 'complex' value */ |
| 411 | trace_qemu_vmalloc(size, ptr, complex); |
| 412 | } |
| 413 | return ptr; |
| 414 | } |
Lluís Vilanova | b1bae81 | 2013-03-05 14:47:38 +0100 | [diff] [blame] | 415 | |