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>
