By moving the dynamic argument construction to keyword-arguments,
we can remove all of the specialized handling, and streamline it.
If a tracing method wants to access these, they can define the
kwargs, or ignore it be placing `**kwargs` at the end of the
function's arguments list.
Added deprecation warning to Analyzer class to make users aware
of the Analyzer2 class. No removal date is planned.
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-13-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Moved event processing to the Analyzer class to separate specific analyzer
logic (like caching and function signatures) from the _process function.
This allows for new types of Analyzer-based subclasses without changing
the core code.
Note, that the fn_cache is important for performance in cases where the
analyzer is branching away from the catch-all a lot. The cache has no
measurable performance penalty.
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Reviewed-by: Philippe Mathieu-Daudé <philmd@linaro.org>
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-12-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
To avoid duplicate code depending on input types and to better handle
open/close of log with a context-manager, we move the logic of process into
_process.
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-11-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Moved event_mapping and event_id_to_name down one level in the function
call-stack to keep variable instantiation and usage closer (`process`
and `run` has no use of the variables; `read_trace_records` does).
Instead of passing event_mapping and event_id_to_name to the bottom of
the call-stack, we move their use to `read_trace_records`. This
separates responsibility and ownership of the information.
`read_record` now just reads the arguments from the file-object by
knowning the total number of bytes. Parsing it to specific arguments is
moved up to `read_trace_records`.
Special handling of dropped events removed, as they can be handled
by the general code.
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-10-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Instead of explicitly calling `begin` and `end`, we can change the class
to use the context-manager paradigm. This is mostly a styling choice,
used in modern Python code. But it also allows for more advanced analyzers
to handle exceptions gracefully in the `__exit__` method (not
demonstrated here).
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-9-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Define `SimpleException` to differentiate our exceptions from generic
exceptions (IOError, etc.). Adapted simpletrace to support this and
output to stderr.
Reviewed-by: Philippe Mathieu-Daudé <philmd@linaro.org>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-8-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
A failed call to `read_header` wouldn't be handled the same for the two
different code paths (one path would try to use `None` as a list).
Changed to raise exception to be handled centrally. This also allows for
easier unpacking, as errors has been filtered out.
Reviewed-by: Philippe Mathieu-Daudé <philmd@linaro.org>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-7-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
The call to `getargspec` was deprecated and in Python 3.11 it has been
removed in favor of `getfullargspec`. `getfullargspec` is compatible
with QEMU's requirement of at least Python version 3.6.
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Reviewed-by: Philippe Mathieu-Daudé <philmd@linaro.org>
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-6-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Readability is subjective, but I've expanded the naming of the variables
and arguments, to help with understanding for new eyes on the code.
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Reviewed-by: Philippe Mathieu-Daudé <philmd@linaro.org>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Message-id: 20230926103436.25700-5-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
The arguments extracted from `sys.argv` named and unpacked to make it
clear what the arguments are and what they're used for.
The two input files were opened, but never explicitly closed. File usage
changed to use `with` statement to take care of this. At the same time,
ownership of the file-object is moved up to `run` function. Added option
to process to support file-like objects.
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-4-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
It wasn't clear where the constants and structs came from, so I added
comments to help.
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-3-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
It was unclear what was the supported public interface. I.e. when
refactoring the code, what functions/classes are important to retain.
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
Message-id: 20230926103436.25700-2-mads@ynddal.dk
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
Commit e50caf4a5c ("tracing: convert documentation to rST")
converted docs/devel/tracing.txt to docs/devel/tracing.rst.
We still have several references to the old file, so let's fix them
with the following command:
sed -i s/tracing.txt/tracing.rst/ $(git grep -l docs/devel/tracing.txt)
Signed-off-by: Stefano Garzarella <sgarzare@redhat.com>
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
Message-Id: <20210517151702.109066-2-sgarzare@redhat.com>
Signed-off-by: Thomas Huth <thuth@redhat.com>
Commit 4e66c9ef64 "tracetool: add input filename and line number to
Event" forgot to add a line number and a filename argument at one
build method call site.
Traceback (most recent call last):
File "./scripts/simpletrace.py", line 261, in <module>
run(Formatter())
File "./scripts/simpletrace.py", line 236, in run
process(events, sys.argv[2], analyzer, read_header=read_header)
File "./scripts/simpletrace.py", line 177, in process
dropped_event =
Event.build("Dropped_Event(uint64_t num_events_dropped)")
TypeError: build() missing 2 required positional arguments:
'lineno' and 'filename'
Add the missing arguments.
Signed-off-by: Volker Rümelin <vr_qemu@t-online.de>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Message-id: 20210131173415.3392-1-vr_qemu@t-online.de
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
This is only needed for Python 2, which we do not support anymore.
Cc: Philippe Mathieu-Daudé <philmd@redhat.com>
Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
Acked-by: Alex Bennée <alex.bennee@linaro.org>
Acked-by: Markus Armbruster <armbru@redhat.com>
Message-Id: <20200204160604.19883-1-pbonzini@redhat.com>
Signed-off-by: Philippe Mathieu-Daudé <philmd@redhat.com>
Use the program search path to find the Python 3 interpreter.
Patch created mechanically by running:
$ sed -i "s,^#\!/usr/bin/\(env\ \)\?python$,#\!/usr/bin/env python3," \
$(git grep -l 'if __name__.*__main__')
Reported-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Suggested-by: Daniel P. Berrangé <berrange@redhat.com>
Suggested-by: Stefan Hajnoczi <stefanha@redhat.com>
Reviewed-by: Juan Quintela <quintela@redhat.com>
Acked-by: Stefan Hajnoczi <stefanha@redhat.com>
Acked-by: Paolo Bonzini <pbonzini@redhat.com>
Message-Id: <20200130163232.10446-6-philmd@redhat.com>
Signed-off-by: Philippe Mathieu-Daudé <philmd@redhat.com>
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>
Mads Ynddal
Stefano Garzarella
Volker Rümelin
Paolo Bonzini
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