The rest of the code assumes that idtoname is a (int -> str)
dictionary, so convert the data accordingly.
This is necessary to make the script work with Python 3 (where
reads from a binary file return 'bytes' objects, not 'str').
Fixes the following error:
$ python3 ./scripts/simpletrace.py trace-events-all trace-27445
b'object_class_dynamic_cast_assert' event is logged but is not \
declared in the trace events file, try using trace-events-all instead.
Signed-off-by: Eduardo Habkost <ehabkost@redhat.com>
Message-id: 20180619194549.15584-1-ehabkost@redhat.com
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Improves error messages from:
ValueError: Error on line 72: need more than 1 value to unpack
To
ValueError: Error at /home/berrange/src/virt/qemu/trace-events:72:
need more than 1 value to unpack
Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Message-id: 20180306154650.24075-1-berrange@redhat.com
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
The timestamp argument to a trace event method is documented as follows:
The method can also take a timestamp argument before the trace event
arguments:
def runstate_set(self, timestamp, new_state):
...
Timestamps have the uint64_t type and are in nanoseconds.
In reality methods with a timestamp argument actually receive a tuple
like (123456789,) as the timestamp argument. This is due to a bug in
simpletrace.py.
This patch unpacks the tuple so that methods receive the correct
timestamp argument type.
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Message-id: 20180222163901.14095-1-stefanha@redhat.com
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
The simpletrace.py script can pretty-print flight recorder ring buffers.
These are not full simpletrace binary trace files but just the end of a
trace file. There is no header and the event ID mapping information is
often unavailable since the ring buffer may have filled up and discarded
event ID mapping records.
The simpletrace.stp script that generates ring buffer traces uses the
same trace-events-all input file as simpletrace.py. Therefore both
scripts have the same global ordering of trace events. A dynamic event
ID mapping isn't necessary: just use the trace-events-all file as the
reference for how event IDs are numbered.
It is now possible to analyze simpletrace.stp ring buffers again using:
$ ./simpletrace.py trace-events-all path/to/ring-buffer
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Reviewed-by: Daniel P. Berrange <berrange@redhat.com>
Message-id: 20170815084430.7128-3-stefanha@redhat.com
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
With the move of some docs/ to docs/devel/ on ac06724a71,
no references were updated.
Signed-off-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Signed-off-by: Michael Tokarev <mjt@tls.msk.ru>
Today, if we use a trace-event file which does not declare an event
existing in the log file we'll get the following error:
$ scripts/simpletrace.py trace-events trace-68508
Traceback (most recent call last):
File "scripts/simpletrace.py", line 242, in <module>
run(Formatter())
File "scripts/simpletrace.py", line 217, in run
process(events, sys.argv[2], analyzer, read_header=read_header)
File "scripts/simpletrace.py", line 192, in process
for rec in read_trace_records(edict, log):
File "scripts/simpletrace.py", line 107, in read_trace_records
rec = read_record(edict, idtoname, fobj)
File "scripts/simpletrace.py", line 71, in read_record
return get_record(edict, idtoname, rechdr, fobj)
File "scripts/simpletrace.py", line 45, in get_record
event = edict[name]
KeyError: 'qemu_mutex_locked'
This patch improves this error by adding a hint instead of just that
KeyError log:
$ scripts/simpletrace.py trace-events trace-68508
'qemu_mutex_locked' event is logged but is not declared in the trace
events file, try using trace-events-all instead.
Signed-off-by: Jose Ricardo Ziviani <joserz@linux.vnet.ibm.com>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Message-id: 1496075404-8845-1-git-send-email-joserz@linux.vnet.ibm.com
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Users can inherit from the simpletrace.Analyzer class and receive
callbacks when events of interest occur in a trace file. The method
signature is a little magic because the timestamp and pid arguments are
optional. Document this.
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Message-id: 20170411095654.18383-1-stefanha@redhat.com
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
When loading a simpletrace binary file we just report
"Not a valid trace file!" which is not very helpful. Report
exactly which field we found to be invalid.
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Signed-off-by: Daniel P. Berrange <berrange@redhat.com>
Message-id: 20170125161417.31949-9-berrange@redhat.com
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
The _read_events method is used by callers outside of
its module, so should be a public method, not private.
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Reviewed-by: Lluís Vilanova <vilanova@ac.upc.edu>
Signed-off-by: Daniel P. Berrange <berrange@redhat.com>
Message-id: 1475588159-30598-18-git-send-email-berrange@redhat.com
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Currently simpletrace assumes that events are given IDs
starting from 0, based on the order in which they appear
in the trace-events file, with no gaps. When the
trace-events file is split up, this assumption becomes
problematic.
To deal with this, extend the simpletrace format so that
it outputs a table of event name <-> ID mappings. That
will allow QEMU to assign arbitrary IDs to events without
breaking simpletrace parsing.
The v3 simple trace format was
FILE HEADER
EVENT TRACE RECORD 0
EVENT TRACE RECORD 1
...
EVENT TRACE RECORD N
The v4 simple trace format is now
FILE HEADER
EVENT MAPPING RECORD 0
EVENT MAPPING RECORD 1
...
EVENT MAPPING RECORD M
EVENT TRACE RECORD RECORD 0
EVENT TRACE RECORD RECORD 1
...
EVENT TRACE RECORD N
Although this shows all the mapping records being emitted
upfront, this is not required by the format. While the main
simpletrace backend will emit all mappings at startup,
the systemtap simpletrace.stp script will emit the mappings
at first use. eg
FILE HEADER
...
EVENT MAPPING RECORD 0
EVENT TRACE RECORD RECORD 0
EVENT TRACE RECORD RECORD 1
EVENT MAPPING RECORD 1
EVENT TRACE RECORD RECORD 2
...
EVENT TRACE RECORD N
This is more space efficient given that most trace records
only include a subset of events.
In modifying the systemtap simpletrace code, a 'begin' probe
was added to emit the trace event header, so you no longer
need to add '--no-header' when running simpletrace.py for
systemtap generated trace files.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com>
Message-id: 1475588159-30598-12-git-send-email-berrange@redhat.com
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
It can be useful to read simpletrace files that have no header. For
example, a ring buffer may not have a header record but can still be
processed if the user is sure the file format version is compatible.
$ scripts/simpletrace.py --no-header trace-events trace-file
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Extract the pid field from the trace record and print it.
Change the trace record tuple from:
(event_num, timestamp, arg1, ..., arg6)
to:
(event_num, timestamp, pid, arg1, ..., arg6)
Trace event methods now support 3 prototypes:
1. <event-name>(arg1, arg2, arg3)
2. <event-name>(timestamp, arg1, arg2, arg3)
3. <event-name>(timestamp, pid, arg1, arg2, arg3)
Existing script continue to work without changes, they only know about
prototypes 1 and 2.
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Backends now only contain the essential backend-specific code, and most of the work is moved to frontend code.
Signed-off-by: Lluís Vilanova <vilanova@ac.upc.edu>
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
The following tracetool cleanup changes the event numbering policy.
Signed-off-by: Lluís Vilanova <vilanova@ac.upc.edu>
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Support new tracelog format for multiple arguments and strings.
Signed-off-by: Harsh Prateek Bora <harsh@linux.vnet.ibm.com>
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
The simpletrace.process() function invokes analyzer methods with the
wrong number of arguments if a timestamp should be included. This patch
fixes the issue so that trace analysis scripts can make use of
timestamps.
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
Trace events outside the global mutex cannot be used with the simple
trace backend since it is not thread-safe. There is no check to prevent
them being enabled so people sometimes learn this the hard way.
This patch restructures the simple trace backend with a ring buffer
suitable for multiple concurrent writers. A writeout thread empties the
trace buffer when threshold fill levels are reached. Should the
writeout thread be unable to keep up with trace generation, records will
simply be dropped.
Each time events are dropped a special record is written to the trace
file indicating how many events were dropped. The event ID is
0xfffffffffffffffe and its signature is dropped(uint32_t count).
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
The simpletrace.py script pretty-prints a binary trace file. Most of
the code can be reused by trace file analysis scripts, so turn it into a
module.
Here is an example script that uses the new simpletrace module:
#!/usr/bin/env python
# Print virtqueue elements that were never returned to the guest.
import simpletrace
class VirtqueueRequestTracker(simpletrace.Analyzer):
def __init__(self):
self.elems = set()
def virtqueue_pop(self, vq, elem, in_num, out_num):
self.elems.add(elem)
def virtqueue_fill(self, vq, elem, length, idx):
self.elems.remove(elem)
def end(self):
for elem in self.elems:
print hex(elem)
simpletrace.run(VirtqueueRequestTracker())
The simpletrace API is based around the Analyzer class. Users implement
an analyzer subclass and add methods for trace events they want to
process. A catchall() method is invoked for trace events which do not
have dedicated methods. Finally, there are also begin() and end()
methods like in sed that can be used to perform setup or print
statistics at the end.
A binary trace file is processed either with:
simpletrace.run(analyzer) # uses command-line args
or with:
simpletrace.process('path/to/trace-events',
'path/to/trace-file',
analyzer)
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
Signed-off-by: Aurelien Jarno <aurelien@aurel32.net>
The regular expression to parse trace event definitions assumed the
format string would be a simple double-quoted string. However, we now
use PRI?64 for portability which splits string literals. The regular
expression can disregard the format string entirely since simpletrace.py
never needs to use it.
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
Signed-off-by: Blue Swirl <blauwirbel@gmail.com>
This patch adds a simple tracer which produces binary trace files. To
try out the simple backend:
$ ./configure --trace-backend=simple
$ make
After running QEMU you can pretty-print the trace:
$ ./simpletrace.py trace-events trace.log
The output of simpletrace.py looks like this:
qemu_realloc 0.699 ptr=0x24363f0 size=0x3 newptr=0x24363f0
qemu_free 0.768 ptr=0x24363f0
^ ^---- timestamp delta (us)
|____ trace event name
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
trace: Make trace record fields 64-bit
Explicitly use 64-bit fields in trace records so that timestamps and
magic numbers work for 32-bit host builds.
Includes fixes from Prerna Saxena <prerna@linux.vnet.ibm.com>.
Signed-off-by: Prerna Saxena <prerna@linux.vnet.ibm.com>
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
Philippe Mathieu-Daudé
Eduardo Habkost
Daniel P. Berrangé
Stefan Hajnoczi
Philippe Mathieu-Daudé
Jose Ricardo Ziviani
Lluís Vilanova
Stefan Weil
Harsh Prateek Bora
Stefan Hajnoczi
Blue Swirl