tracing.txt 8.5 KB
Newer Older
S
Stefan Hajnoczi 已提交
1 2 3 4 5 6 7 8 9 10 11 12 13 14
= Tracing =

== Introduction ==

This document describes the tracing infrastructure in QEMU and how to use it
for debugging, profiling, and observing execution.

== Quickstart ==

1. Build with the 'simple' trace backend:

    ./configure --trace-backend=simple
    make

15
2. Create a file with the events you want to trace:
S
Stefan Hajnoczi 已提交
16

17 18
   echo bdrv_aio_readv   > /tmp/events
   echo bdrv_aio_writev >> /tmp/events
S
Stefan Hajnoczi 已提交
19

20 21 22 23 24
3. Run the virtual machine to produce a trace file:

    qemu -trace events=/tmp/events ... # your normal QEMU invocation

4. Pretty-print the binary trace file:
S
Stefan Hajnoczi 已提交
25 26 27 28 29

    ./simpletrace.py trace-events trace-*

== Trace events ==

30
There is a set of static trace events declared in the "trace-events" source
S
Stefan Hajnoczi 已提交
31 32 33 34 35 36
file.  Each trace event declaration names the event, its arguments, and the
format string which can be used for pretty-printing:

    qemu_malloc(size_t size, void *ptr) "size %zu ptr %p"
    qemu_free(void *ptr) "ptr %p"

37
The "trace-events" file is processed by the "tracetool" script during build to
S
Stefan Hajnoczi 已提交
38 39 40 41
generate code for the trace events.  Trace events are invoked directly from
source code like this:

    #include "trace.h"  /* needed for trace event prototype */
42
    
S
Stefan Hajnoczi 已提交
43 44 45 46 47 48 49 50 51 52 53 54 55
    void *qemu_malloc(size_t size)
    {
        void *ptr;
        if (!size && !allow_zero_malloc()) {
            abort();
        }
        ptr = oom_check(malloc(size ? size : 1));
        trace_qemu_malloc(size, ptr);  /* <-- trace event */
        return ptr;
    }

=== Declaring trace events ===

56
The "tracetool" script produces the trace.h header file which is included by
S
Stefan Hajnoczi 已提交
57
every source file that uses trace events.  Since many source files include
58 59
trace.h, it uses a minimum of types and other header files included to keep the
namespace clean and compile times and dependencies down.
S
Stefan Hajnoczi 已提交
60 61 62 63 64 65 66 67 68 69 70 71 72

Trace events should use types as follows:

 * Use stdint.h types for fixed-size types.  Most offsets and guest memory
   addresses are best represented with uint32_t or uint64_t.  Use fixed-size
   types over primitive types whose size may change depending on the host
   (32-bit versus 64-bit) so trace events don't truncate values or break
   the build.

 * Use void * for pointers to structs or for arrays.  The trace.h header
   cannot include all user-defined struct declarations and it is therefore
   necessary to use void * for pointers to structs.

73 74 75 76 77
   Pointers (including char *) cannot be dereferenced easily (or at all) in
   some trace backends.  If pointers are used, ensure they are meaningful by
   themselves and do not assume the data they point to will be traced.  Do
   not pass in string arguments.

S
Stefan Hajnoczi 已提交
78 79 80
 * For everything else, use primitive scalar types (char, int, long) with the
   appropriate signedness.

81 82
Format strings should reflect the types defined in the trace event.  Take
special care to use PRId64 and PRIu64 for int64_t and uint64_t types,
83 84 85 86
respectively.  This ensures portability between 32- and 64-bit platforms.  Note
that format strings must begin and end with double quotes.  When using
portability macros, ensure they are preceded and followed by double quotes:
"value %"PRIx64"".
87

S
Stefan Hajnoczi 已提交
88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106
=== Hints for adding new trace events ===

1. Trace state changes in the code.  Interesting points in the code usually
   involve a state change like starting, stopping, allocating, freeing.  State
   changes are good trace events because they can be used to understand the
   execution of the system.

2. Trace guest operations.  Guest I/O accesses like reading device registers
   are good trace events because they can be used to understand guest
   interactions.

3. Use correlator fields so the context of an individual line of trace output
   can be understood.  For example, trace the pointer returned by malloc and
   used as an argument to free.  This way mallocs and frees can be matched up.
   Trace events with no context are not very useful.

4. Name trace events after their function.  If there are multiple trace events
   in one function, append a unique distinguisher at the end of the name.

107 108 109 110 111
5. If specific trace events are going to be called a huge number of times, this
   might have a noticeable performance impact even when the trace events are
   programmatically disabled. In this case you should declare the trace event
   with the "disable" property, which will effectively disable it at compile
   time (using the "nop" backend).
S
Stefan Hajnoczi 已提交
112

113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142
== Generic interface and monitor commands ==

You can programmatically query and control the dynamic state of trace events
through a backend-agnostic interface:

* trace_print_events

* trace_event_set_state
  Enables or disables trace events at runtime inside QEMU.
  The function returns "true" if the state of the event has been successfully
  changed, or "false" otherwise:

    #include "trace/control.h"
    
    trace_event_set_state("virtio_irq", true); /* enable */
    [...]
    trace_event_set_state("virtio_irq", false); /* disable */

Note that some of the backends do not provide an implementation for this
interface, in which case QEMU will just print a warning.

This functionality is also provided through monitor commands:

* info trace-events
  View available trace events and their state.  State 1 means enabled, state 0
  means disabled.

* trace-event NAME on|off
  Enable/disable a given trace event.

143 144 145 146
The "-trace events=<file>" command line argument can be used to enable the
events listed in <file> from the very beginning of the program. This file must
contain one event name per line.

S
Stefan Hajnoczi 已提交
147 148
== Trace backends ==

149
The "tracetool" script automates tedious trace event code generation and also
S
Stefan Hajnoczi 已提交
150 151
keeps the trace event declarations independent of the trace backend.  The trace
events are not tightly coupled to a specific trace backend, such as LTTng or
152
SystemTap.  Support for trace backends can be added by extending the "tracetool"
S
Stefan Hajnoczi 已提交
153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169
script.

The trace backend is chosen at configure time and only one trace backend can
be built into the binary:

    ./configure --trace-backend=simple

For a list of supported trace backends, try ./configure --help or see below.

The following subsections describe the supported trace backends.

=== Nop ===

The "nop" backend generates empty trace event functions so that the compiler
can optimize out trace events completely.  This is the default and imposes no
performance penalty.

170 171 172
Note that regardless of the selected trace backend, events with the "disable"
property will be generated with the "nop" backend.

173 174 175 176 177 178 179 180
=== Stderr ===

The "stderr" backend sends trace events directly to standard error.  This
effectively turns trace events into debug printfs.

This is the simplest backend and can be used together with existing code that
uses DPRINTF().

S
Stefan Hajnoczi 已提交
181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204
=== Simpletrace ===

The "simple" backend supports common use cases and comes as part of the QEMU
source tree.  It may not be as powerful as platform-specific or third-party
trace backends but it is portable.  This is the recommended trace backend
unless you have specific needs for more advanced backends.

==== Monitor commands ====

* info trace
  Display the contents of trace buffer.  This command dumps the trace buffer
  with simple formatting.  For full pretty-printing, use the simpletrace.py
  script on a binary trace file.

  The trace buffer is written into until full.  The full trace buffer is
  flushed and emptied.  This means the 'info trace' will display few or no
  entries if the buffer has just been flushed.

* trace-file on|off|flush|set <path>
  Enable/disable/flush the trace file or set the trace file name.

==== Analyzing trace files ====

The "simple" backend produces binary trace files that can be formatted with the
205
simpletrace.py script.  The script takes the "trace-events" file and the binary
S
Stefan Hajnoczi 已提交
206 207 208 209
trace:

    ./simpletrace.py trace-events trace-12345

210
You must ensure that the same "trace-events" file was used to build QEMU,
S
Stefan Hajnoczi 已提交
211 212 213 214 215 216 217 218
otherwise trace event declarations may have changed and output will not be
consistent.

=== LTTng Userspace Tracer ===

The "ust" backend uses the LTTng Userspace Tracer library.  There are no
monitor commands built into QEMU, instead UST utilities should be used to list,
enable/disable, and dump traces.
219 220 221 222 223 224 225 226 227 228 229 230 231 232

=== SystemTap ===

The "dtrace" backend uses DTrace sdt probes but has only been tested with
SystemTap.  When SystemTap support is detected a .stp file with wrapper probes
is generated to make use in scripts more convenient.  This step can also be
performed manually after a build in order to change the binary name in the .stp
probes:

    scripts/tracetool --dtrace --stap \
                      --binary path/to/qemu-binary \
                      --target-type system \
                      --target-arch x86_64 \
                      <trace-events >qemu.stp