* [PATCH 1/9] simpletrace: Improve parsing of sys.argv; fix files never closed.
2023-02-21 9:00 [PATCH 0/9] simpletrace: refactor and general improvements Mads Ynddal
@ 2023-02-21 9:00 ` Mads Ynddal
2023-02-21 9:00 ` [PATCH 2/9] simpletrace: Annotate magic constants from QEMU code Mads Ynddal
` (7 subsequent siblings)
8 siblings, 0 replies; 12+ messages in thread
From: Mads Ynddal @ 2023-02-21 9:00 UTC (permalink / raw)
To: qemu-devel; +Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
From: Mads Ynddal <m.ynddal@samsung.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. Secondary `open`
inside `process` removed so there's only one place to handle `open`.
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
---
scripts/simpletrace.py | 28 +++++++++++-----------------
1 file changed, 11 insertions(+), 17 deletions(-)
diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 1f6d1ae1f3..9211caaec1 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -9,6 +9,7 @@
#
# For help see docs/devel/tracing.rst
+import sys
import struct
import inspect
from tracetool import read_events, Event
@@ -44,7 +45,6 @@ def get_record(edict, idtoname, rechdr, fobj):
try:
event = edict[name]
except KeyError as e:
- import sys
sys.stderr.write('%s event is logged but is not declared ' \
'in the trace events file, try using ' \
'trace-events-all instead.\n' % str(e))
@@ -166,11 +166,6 @@ def end(self):
def process(events, log, analyzer, read_header=True):
"""Invoke an analyzer on each event in a log."""
- if isinstance(events, str):
- events = read_events(open(events, 'r'), events)
- if isinstance(log, str):
- log = open(log, 'rb')
-
if read_header:
read_trace_header(log)
@@ -223,19 +218,18 @@ def run(analyzer):
This function is useful as a driver for simple analysis scripts. More
advanced scripts will want to call process() instead."""
- import sys
-
- read_header = True
- if len(sys.argv) == 4 and sys.argv[1] == '--no-header':
- read_header = False
- del sys.argv[1]
- elif len(sys.argv) != 3:
- sys.stderr.write('usage: %s [--no-header] <trace-events> ' \
- '<trace-file>\n' % sys.argv[0])
+
+ try:
+ # NOTE: See built-in `argparse` module for a more robust cli interface
+ *no_header, trace_event_path, trace_file_path = sys.argv[1:]
+ assert no_header == [] or no_header == ['--no-header'], 'Invalid no-header argument'
+ except (AssertionError, ValueError):
+ sys.stderr.write(f'usage: {sys.argv[0]} [--no-header] <trace-events> <trace-file>\n')
sys.exit(1)
- events = read_events(open(sys.argv[1], 'r'), sys.argv[1])
- process(events, sys.argv[2], analyzer, read_header=read_header)
+ with open(trace_event_path, 'r') as events_fobj, open(trace_file_path, 'rb') as log_fobj:
+ events = read_events(events_fobj, trace_event_path)
+ process(events, log_fobj, analyzer, read_header=not no_header)
if __name__ == '__main__':
class Formatter(Analyzer):
--
2.38.1
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH 2/9] simpletrace: Annotate magic constants from QEMU code
2023-02-21 9:00 [PATCH 0/9] simpletrace: refactor and general improvements Mads Ynddal
2023-02-21 9:00 ` [PATCH 1/9] simpletrace: Improve parsing of sys.argv; fix files never closed Mads Ynddal
@ 2023-02-21 9:00 ` Mads Ynddal
2023-02-21 9:00 ` [PATCH 3/9] simpletrace: changed naming of edict and idtoname to improve readability Mads Ynddal
` (6 subsequent siblings)
8 siblings, 0 replies; 12+ messages in thread
From: Mads Ynddal @ 2023-02-21 9:00 UTC (permalink / raw)
To: qemu-devel; +Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
From: Mads Ynddal <m.ynddal@samsung.com>
It wasn't clear where the constants and structs came from, so I added
comments to help.
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
---
scripts/simpletrace.py | 14 +++++++-------
1 file changed, 7 insertions(+), 7 deletions(-)
diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 9211caaec1..7ba805443d 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -15,15 +15,15 @@
from tracetool import read_events, Event
from tracetool.backend.simple import is_string
-header_event_id = 0xffffffffffffffff
-header_magic = 0xf2b177cb0aa429b4
-dropped_event_id = 0xfffffffffffffffe
+header_event_id = 0xffffffffffffffff # trace/simple.c::HEADER_EVENT_ID
+header_magic = 0xf2b177cb0aa429b4 # trace/simple.c::HEADER_MAGIC
+dropped_event_id = 0xfffffffffffffffe # trace/simple.c::DROPPED_EVENT_ID
-record_type_mapping = 0
-record_type_event = 1
+record_type_mapping = 0 # trace/simple.c::TRACE_RECORD_TYPE_MAPPING
+record_type_event = 1 # trace/simple.c::TRACE_RECORD_TYPE_EVENT
-log_header_fmt = '=QQQ'
-rec_header_fmt = '=QQII'
+log_header_fmt = '=QQQ' # trace/simple.c::TraceLogHeader
+rec_header_fmt = '=QQII' # trace/simple.c::TraceRecord
def read_header(fobj, hfmt):
'''Read a trace record header'''
--
2.38.1
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH 3/9] simpletrace: changed naming of edict and idtoname to improve readability
2023-02-21 9:00 [PATCH 0/9] simpletrace: refactor and general improvements Mads Ynddal
2023-02-21 9:00 ` [PATCH 1/9] simpletrace: Improve parsing of sys.argv; fix files never closed Mads Ynddal
2023-02-21 9:00 ` [PATCH 2/9] simpletrace: Annotate magic constants from QEMU code Mads Ynddal
@ 2023-02-21 9:00 ` Mads Ynddal
2023-02-21 9:10 ` Philippe Mathieu-Daudé
2023-02-21 9:00 ` [PATCH 4/9] simpletrace: update code for Python 3.11 Mads Ynddal
` (5 subsequent siblings)
8 siblings, 1 reply; 12+ messages in thread
From: Mads Ynddal @ 2023-02-21 9:00 UTC (permalink / raw)
To: qemu-devel; +Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
From: Mads Ynddal <m.ynddal@samsung.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>
---
scripts/simpletrace.py | 34 +++++++++++++++++-----------------
1 file changed, 17 insertions(+), 17 deletions(-)
diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 7ba805443d..9981699630 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -33,17 +33,17 @@ def read_header(fobj, hfmt):
return None
return struct.unpack(hfmt, hdr)
-def get_record(edict, idtoname, rechdr, fobj):
+def get_record(event_mapping, event_id_to_name, rechdr, fobj):
"""Deserialize a trace record from a file into a tuple
(name, timestamp, pid, arg1, ..., arg6)."""
if rechdr is None:
return None
if rechdr[0] != dropped_event_id:
event_id = rechdr[0]
- name = idtoname[event_id]
+ name = event_id_to_name[event_id]
rec = (name, rechdr[1], rechdr[3])
try:
- event = edict[name]
+ event = event_mapping[name]
except KeyError as e:
sys.stderr.write('%s event is logged but is not declared ' \
'in the trace events file, try using ' \
@@ -72,10 +72,10 @@ def get_mapping(fobj):
return (event_id, name)
-def read_record(edict, idtoname, fobj):
+def read_record(event_mapping, event_id_to_name, fobj):
"""Deserialize a trace record from a file into a tuple (event_num, timestamp, pid, arg1, ..., arg6)."""
rechdr = read_header(fobj, rec_header_fmt)
- return get_record(edict, idtoname, rechdr, fobj)
+ return get_record(event_mapping, event_id_to_name, rechdr, fobj)
def read_trace_header(fobj):
"""Read and verify trace file header"""
@@ -96,14 +96,14 @@ def read_trace_header(fobj):
raise ValueError('Log format %d not supported with this QEMU release!'
% log_version)
-def read_trace_records(edict, idtoname, fobj):
+def read_trace_records(event_mapping, event_id_to_name, fobj):
"""Deserialize trace records from a file, yielding record tuples (event_num, timestamp, pid, arg1, ..., arg6).
- Note that `idtoname` is modified if the file contains mapping records.
+ Note that `event_id_to_name` is modified if the file contains mapping records.
Args:
- edict (str -> Event): events dict, indexed by name
- idtoname (int -> str): event names dict, indexed by event ID
+ event_mapping (str -> Event): events dict, indexed by name
+ event_id_to_name (int -> str): event names dict, indexed by event ID
fobj (file): input file
"""
@@ -115,9 +115,9 @@ def read_trace_records(edict, idtoname, fobj):
(rectype, ) = struct.unpack('=Q', t)
if rectype == record_type_mapping:
event_id, name = get_mapping(fobj)
- idtoname[event_id] = name
+ event_id_to_name[event_id] = name
else:
- rec = read_record(edict, idtoname, fobj)
+ rec = read_record(event_mapping, event_id_to_name, fobj)
yield rec
@@ -172,16 +172,16 @@ def process(events, log, analyzer, read_header=True):
frameinfo = inspect.getframeinfo(inspect.currentframe())
dropped_event = Event.build("Dropped_Event(uint64_t num_events_dropped)",
frameinfo.lineno + 1, frameinfo.filename)
- edict = {"dropped": dropped_event}
- idtoname = {dropped_event_id: "dropped"}
+ event_mapping = {"dropped": dropped_event}
+ event_id_to_name = {dropped_event_id: "dropped"}
for event in events:
- edict[event.name] = event
+ event_mapping[event.name] = event
# If there is no header assume event ID mapping matches events list
if not read_header:
for event_id, event in enumerate(events):
- idtoname[event_id] = event.name
+ event_id_to_name[event_id] = event.name
def build_fn(analyzer, event):
if isinstance(event, str):
@@ -205,9 +205,9 @@ def build_fn(analyzer, event):
analyzer.begin()
fn_cache = {}
- for rec in read_trace_records(edict, idtoname, log):
+ for rec in read_trace_records(event_mapping, event_id_to_name, log):
event_num = rec[0]
- event = edict[event_num]
+ event = event_mapping[event_num]
if event_num not in fn_cache:
fn_cache[event_num] = build_fn(analyzer, event)
fn_cache[event_num](event, rec)
--
2.38.1
^ permalink raw reply related [flat|nested] 12+ messages in thread* Re: [PATCH 3/9] simpletrace: changed naming of edict and idtoname to improve readability
2023-02-21 9:00 ` [PATCH 3/9] simpletrace: changed naming of edict and idtoname to improve readability Mads Ynddal
@ 2023-02-21 9:10 ` Philippe Mathieu-Daudé
0 siblings, 0 replies; 12+ messages in thread
From: Philippe Mathieu-Daudé @ 2023-02-21 9:10 UTC (permalink / raw)
To: Mads Ynddal, qemu-devel
Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
On 21/2/23 10:00, Mads Ynddal wrote:
> From: Mads Ynddal <m.ynddal@samsung.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>
> ---
> scripts/simpletrace.py | 34 +++++++++++++++++-----------------
> 1 file changed, 17 insertions(+), 17 deletions(-)
Reviewed-by: Philippe Mathieu-Daudé <philmd@linaro.org>
^ permalink raw reply [flat|nested] 12+ messages in thread
* [PATCH 4/9] simpletrace: update code for Python 3.11
2023-02-21 9:00 [PATCH 0/9] simpletrace: refactor and general improvements Mads Ynddal
` (2 preceding siblings ...)
2023-02-21 9:00 ` [PATCH 3/9] simpletrace: changed naming of edict and idtoname to improve readability Mads Ynddal
@ 2023-02-21 9:00 ` Mads Ynddal
2023-02-21 9:01 ` [PATCH 5/9] simpletrace: Changed Analyzer class to become context-manager Mads Ynddal
` (4 subsequent siblings)
8 siblings, 0 replies; 12+ messages in thread
From: Mads Ynddal @ 2023-02-21 9:00 UTC (permalink / raw)
To: qemu-devel; +Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
From: Mads Ynddal <m.ynddal@samsung.com>
The call to `getargspec` was deprecated and in Python 3.11 it has been
removed in favor of `getfullargspec`.
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
---
scripts/simpletrace.py | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 9981699630..7444a6e090 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -192,7 +192,7 @@ def build_fn(analyzer, event):
return analyzer.catchall
event_argcount = len(event.args)
- fn_argcount = len(inspect.getargspec(fn)[0]) - 1
+ fn_argcount = len(inspect.getfullargspec(fn)[0]) - 1
if fn_argcount == event_argcount + 1:
# Include timestamp as first argument
return lambda _, rec: fn(*(rec[1:2] + rec[3:3 + event_argcount]))
--
2.38.1
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH 5/9] simpletrace: Changed Analyzer class to become context-manager
2023-02-21 9:00 [PATCH 0/9] simpletrace: refactor and general improvements Mads Ynddal
` (3 preceding siblings ...)
2023-02-21 9:00 ` [PATCH 4/9] simpletrace: update code for Python 3.11 Mads Ynddal
@ 2023-02-21 9:01 ` Mads Ynddal
2023-02-21 9:01 ` [PATCH 6/9] simpletrace: Simplify construction of tracing methods Mads Ynddal
` (3 subsequent siblings)
8 siblings, 0 replies; 12+ messages in thread
From: Mads Ynddal @ 2023-02-21 9:01 UTC (permalink / raw)
To: qemu-devel; +Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
From: Mads Ynddal <m.ynddal@samsung.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).
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
---
scripts/simpletrace.py | 36 ++++++++++++++++++------------------
1 file changed, 18 insertions(+), 18 deletions(-)
diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 7444a6e090..01bd47a130 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -121,12 +121,12 @@ def read_trace_records(event_mapping, event_id_to_name, fobj):
yield rec
-class Analyzer(object):
+class Analyzer:
"""A trace file analyzer which processes trace records.
- An analyzer can be passed to run() or process(). The begin() method is
- invoked, then each trace record is processed, and finally the end() method
- is invoked.
+ An analyzer can be passed to run() or process(). The __enter__() method is
+ invoked when opening the analyzer using the `with` statement, then each trace
+ record is processed, and finally the __exit__() method is invoked.
If a method matching a trace event name exists, it is invoked to process
that trace record. Otherwise the catchall() method is invoked.
@@ -152,19 +152,19 @@ def runstate_set(self, timestamp, pid, new_state):
...
"""
- def begin(self):
+ def __enter__(self):
"""Called at the start of the trace."""
- pass
+ return self
def catchall(self, event, rec):
"""Called if no specific method for processing a trace event has been found."""
pass
- def end(self):
+ def __exit__(self, _type, value, traceback):
"""Called at the end of the trace."""
pass
-def process(events, log, analyzer, read_header=True):
+def process(events, log, analyzer_class, read_header=True):
"""Invoke an analyzer on each event in a log."""
if read_header:
read_trace_header(log)
@@ -203,15 +203,15 @@ def build_fn(analyzer, event):
# Just arguments, no timestamp or pid
return lambda _, rec: fn(*rec[3:3 + event_argcount])
- analyzer.begin()
- fn_cache = {}
- for rec in read_trace_records(event_mapping, event_id_to_name, log):
- event_num = rec[0]
- event = event_mapping[event_num]
- if event_num not in fn_cache:
- fn_cache[event_num] = build_fn(analyzer, event)
- fn_cache[event_num](event, rec)
- analyzer.end()
+ with analyzer_class() as analyzer:
+ fn_cache = {}
+ for rec in read_trace_records(event_mapping, event_id_to_name, log):
+ event_num = rec[0]
+ event = event_mapping[event_num]
+ if event_num not in fn_cache:
+ fn_cache[event_num] = build_fn(analyzer, event)
+ fn_cache[event_num](event, rec)
+
def run(analyzer):
"""Execute an analyzer on a trace file given on the command-line.
@@ -254,4 +254,4 @@ def catchall(self, event, rec):
i += 1
print(' '.join(fields))
- run(Formatter())
+ run(Formatter)
--
2.38.1
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH 6/9] simpletrace: Simplify construction of tracing methods
2023-02-21 9:00 [PATCH 0/9] simpletrace: refactor and general improvements Mads Ynddal
` (4 preceding siblings ...)
2023-02-21 9:01 ` [PATCH 5/9] simpletrace: Changed Analyzer class to become context-manager Mads Ynddal
@ 2023-02-21 9:01 ` Mads Ynddal
2023-02-21 9:01 ` [PATCH 7/9] simpletrace: Improved error handling on struct unpack Mads Ynddal
` (2 subsequent siblings)
8 siblings, 0 replies; 12+ messages in thread
From: Mads Ynddal @ 2023-02-21 9:01 UTC (permalink / raw)
To: qemu-devel; +Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
From: Mads Ynddal <m.ynddal@samsung.com>
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.
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
---
scripts/simpletrace.py | 84 ++++++++++++++++--------------------------
1 file changed, 32 insertions(+), 52 deletions(-)
diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 01bd47a130..df52b09dbc 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -131,16 +131,25 @@ class Analyzer:
If a method matching a trace event name exists, it is invoked to process
that trace record. Otherwise the catchall() method is invoked.
+ The methods are called with a set of keyword-arguments. These can be ignored
+ using `**kwargs` or defined like any keyword-argument.
+
+ The following keyword-arguments are available:
+ event: Event object of current trace
+ event_id: The id of the event in the current trace file
+ timestamp_ns: The timestamp in nanoseconds of the trace
+ pid: The process id recorded for the given trace
+
Example:
The following method handles the runstate_set(int new_state) trace event::
- def runstate_set(self, new_state):
+ def runstate_set(self, new_state, **kwargs):
...
- The method can also take a timestamp argument before the trace event
- arguments::
+ The method can also explicitly take a timestamp keyword-argument with the
+ trace event arguments::
- def runstate_set(self, timestamp, new_state):
+ def runstate_set(self, new_state, *, timestamp, **kwargs):
...
Timestamps have the uint64_t type and are in nanoseconds.
@@ -148,7 +157,7 @@ def runstate_set(self, timestamp, new_state):
The pid can be included in addition to the timestamp and is useful when
dealing with traces from multiple processes::
- def runstate_set(self, timestamp, pid, new_state):
+ def runstate_set(self, new_state, *, timestamp, pid, **kwargs):
...
"""
@@ -156,7 +165,7 @@ def __enter__(self):
"""Called at the start of the trace."""
return self
- def catchall(self, event, rec):
+ def catchall(self, *rec_args, event, timestamp_ns, pid, event_id):
"""Called if no specific method for processing a trace event has been found."""
pass
@@ -183,34 +192,11 @@ def process(events, log, analyzer_class, read_header=True):
for event_id, event in enumerate(events):
event_id_to_name[event_id] = event.name
- def build_fn(analyzer, event):
- if isinstance(event, str):
- return analyzer.catchall
-
- fn = getattr(analyzer, event.name, None)
- if fn is None:
- return analyzer.catchall
-
- event_argcount = len(event.args)
- fn_argcount = len(inspect.getfullargspec(fn)[0]) - 1
- if fn_argcount == event_argcount + 1:
- # Include timestamp as first argument
- return lambda _, rec: fn(*(rec[1:2] + rec[3:3 + event_argcount]))
- elif fn_argcount == event_argcount + 2:
- # Include timestamp and pid
- return lambda _, rec: fn(*rec[1:3 + event_argcount])
- else:
- # Just arguments, no timestamp or pid
- return lambda _, rec: fn(*rec[3:3 + event_argcount])
-
with analyzer_class() as analyzer:
- fn_cache = {}
- for rec in read_trace_records(event_mapping, event_id_to_name, log):
- event_num = rec[0]
- event = event_mapping[event_num]
- if event_num not in fn_cache:
- fn_cache[event_num] = build_fn(analyzer, event)
- fn_cache[event_num](event, rec)
+ for event_id, timestamp_ns, record_pid, *rec_args in read_trace_records(event_mapping, event_id_to_name, log):
+ event = event_mapping[event_id]
+ fn = getattr(analyzer, event.name, analyzer.catchall)
+ fn(*rec_args, event=event, event_id=event_id, timestamp_ns=timestamp_ns, pid=record_pid)
def run(analyzer):
@@ -234,24 +220,18 @@ def run(analyzer):
if __name__ == '__main__':
class Formatter(Analyzer):
def __init__(self):
- self.last_timestamp = None
-
- def catchall(self, event, rec):
- timestamp = rec[1]
- if self.last_timestamp is None:
- self.last_timestamp = timestamp
- delta_ns = timestamp - self.last_timestamp
- self.last_timestamp = timestamp
-
- fields = [event.name, '%0.3f' % (delta_ns / 1000.0),
- 'pid=%d' % rec[2]]
- i = 3
- for type, name in event.args:
- if is_string(type):
- fields.append('%s=%s' % (name, rec[i]))
- else:
- fields.append('%s=0x%x' % (name, rec[i]))
- i += 1
- print(' '.join(fields))
+ self.last_timestamp_ns = None
+
+ def catchall(self, *rec_args, event, timestamp_ns, pid, event_id):
+ if self.last_timestamp_ns is None:
+ self.last_timestamp_ns = timestamp_ns
+ delta_ns = timestamp_ns - self.last_timestamp_ns
+ self.last_timestamp_ns = timestamp_ns
+
+ fields = [
+ f'{name}={r}' if is_string(type) else f'{name}=0x{r:x}'
+ for r, (type, name) in zip(rec_args, event.args)
+ ]
+ print(f'{event.name} {delta_ns / 1000:0.3f} {pid=} ' + ' '.join(fields))
run(Formatter)
--
2.38.1
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH 7/9] simpletrace: Improved error handling on struct unpack
2023-02-21 9:00 [PATCH 0/9] simpletrace: refactor and general improvements Mads Ynddal
` (5 preceding siblings ...)
2023-02-21 9:01 ` [PATCH 6/9] simpletrace: Simplify construction of tracing methods Mads Ynddal
@ 2023-02-21 9:01 ` Mads Ynddal
2023-02-21 9:01 ` [PATCH 8/9] simpletrace: define exception and add handling Mads Ynddal
2023-02-21 9:01 ` [PATCH 9/9] simpletrace: Refactor to separate responsibilities Mads Ynddal
8 siblings, 0 replies; 12+ messages in thread
From: Mads Ynddal @ 2023-02-21 9:01 UTC (permalink / raw)
To: qemu-devel; +Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
From: Mads Ynddal <m.ynddal@samsung.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.
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
---
scripts/simpletrace.py | 41 ++++++++++++++++-------------------------
1 file changed, 16 insertions(+), 25 deletions(-)
diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index df52b09dbc..61af68618f 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -30,26 +30,24 @@ def read_header(fobj, hfmt):
hlen = struct.calcsize(hfmt)
hdr = fobj.read(hlen)
if len(hdr) != hlen:
- return None
+ raise ValueError('Error reading header. Wrong filetype provided?')
return struct.unpack(hfmt, hdr)
def get_record(event_mapping, event_id_to_name, rechdr, fobj):
"""Deserialize a trace record from a file into a tuple
(name, timestamp, pid, arg1, ..., arg6)."""
- if rechdr is None:
- return None
- if rechdr[0] != dropped_event_id:
- event_id = rechdr[0]
+ event_id, timestamp_ns, length, pid = rechdr
+ if event_id != dropped_event_id:
name = event_id_to_name[event_id]
- rec = (name, rechdr[1], rechdr[3])
try:
event = event_mapping[name]
except KeyError as e:
- sys.stderr.write('%s event is logged but is not declared ' \
+ sys.stderr.write(f'{e} event is logged but is not declared ' \
'in the trace events file, try using ' \
- 'trace-events-all instead.\n' % str(e))
+ 'trace-events-all instead.\n')
sys.exit(1)
+ rec = (name, timestamp_ns, pid)
for type, name in event.args:
if is_string(type):
l = fobj.read(4)
@@ -60,9 +58,8 @@ def get_record(event_mapping, event_id_to_name, rechdr, fobj):
(value,) = struct.unpack('=Q', fobj.read(8))
rec = rec + (value,)
else:
- rec = ("dropped", rechdr[1], rechdr[3])
- (value,) = struct.unpack('=Q', fobj.read(8))
- rec = rec + (value,)
+ (dropped_count,) = struct.unpack('=Q', fobj.read(8))
+ rec = ("dropped", timestamp_ns, pid, dropped_count)
return rec
def get_mapping(fobj):
@@ -79,22 +76,16 @@ def read_record(event_mapping, event_id_to_name, fobj):
def read_trace_header(fobj):
"""Read and verify trace file header"""
- header = read_header(fobj, log_header_fmt)
- if header is None:
- raise ValueError('Not a valid trace file!')
- if header[0] != header_event_id:
- raise ValueError('Not a valid trace file, header id %d != %d' %
- (header[0], header_event_id))
- if header[1] != header_magic:
- raise ValueError('Not a valid trace file, header magic %d != %d' %
- (header[1], header_magic))
-
- log_version = header[2]
+ _header_event_id, _header_magic, log_version = read_header(fobj, log_header_fmt)
+ if _header_event_id != header_event_id:
+ raise ValueError(f'Not a valid trace file, header id {_header_event_id} != {header_event_id}')
+ if _header_magic != header_magic:
+ raise ValueError(f'Not a valid trace file, header magic {_header_magic} != {header_magic}')
+
if log_version not in [0, 2, 3, 4]:
- raise ValueError('Unknown version of tracelog format!')
+ raise ValueError(f'Unknown version {log_version} of tracelog format!')
if log_version != 4:
- raise ValueError('Log format %d not supported with this QEMU release!'
- % log_version)
+ raise ValueError(f'Log format {log_version} not supported with this QEMU release!')
def read_trace_records(event_mapping, event_id_to_name, fobj):
"""Deserialize trace records from a file, yielding record tuples (event_num, timestamp, pid, arg1, ..., arg6).
--
2.38.1
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH 8/9] simpletrace: define exception and add handling
2023-02-21 9:00 [PATCH 0/9] simpletrace: refactor and general improvements Mads Ynddal
` (6 preceding siblings ...)
2023-02-21 9:01 ` [PATCH 7/9] simpletrace: Improved error handling on struct unpack Mads Ynddal
@ 2023-02-21 9:01 ` Mads Ynddal
2023-02-21 9:12 ` Philippe Mathieu-Daudé
2023-02-21 9:01 ` [PATCH 9/9] simpletrace: Refactor to separate responsibilities Mads Ynddal
8 siblings, 1 reply; 12+ messages in thread
From: Mads Ynddal @ 2023-02-21 9:01 UTC (permalink / raw)
To: qemu-devel; +Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
From: Mads Ynddal <m.ynddal@samsung.com>
Define `SimpleException` to differentiate our exceptions from generic
exceptions (IOError, etc.). Adapted simpletrace to support this and
output to stderr.
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
---
scripts/simpletrace.py | 23 +++++++++++++++--------
1 file changed, 15 insertions(+), 8 deletions(-)
diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 61af68618f..35d2a757c4 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -25,12 +25,15 @@
log_header_fmt = '=QQQ' # trace/simple.c::TraceLogHeader
rec_header_fmt = '=QQII' # trace/simple.c::TraceRecord
+class SimpleException(Exception):
+ pass
+
def read_header(fobj, hfmt):
'''Read a trace record header'''
hlen = struct.calcsize(hfmt)
hdr = fobj.read(hlen)
if len(hdr) != hlen:
- raise ValueError('Error reading header. Wrong filetype provided?')
+ raise SimpleException('Error reading header. Wrong filetype provided?')
return struct.unpack(hfmt, hdr)
def get_record(event_mapping, event_id_to_name, rechdr, fobj):
@@ -42,10 +45,10 @@ def get_record(event_mapping, event_id_to_name, rechdr, fobj):
try:
event = event_mapping[name]
except KeyError as e:
- sys.stderr.write(f'{e} event is logged but is not declared ' \
- 'in the trace events file, try using ' \
- 'trace-events-all instead.\n')
- sys.exit(1)
+ raise SimpleException(
+ f'{e} event is logged but is not declared in the trace events'
+ 'file, try using trace-events-all instead.'
+ )
rec = (name, timestamp_ns, pid)
for type, name in event.args:
@@ -201,8 +204,7 @@ def run(analyzer):
*no_header, trace_event_path, trace_file_path = sys.argv[1:]
assert no_header == [] or no_header == ['--no-header'], 'Invalid no-header argument'
except (AssertionError, ValueError):
- sys.stderr.write(f'usage: {sys.argv[0]} [--no-header] <trace-events> <trace-file>\n')
- sys.exit(1)
+ raise SimpleException(f'usage: {sys.argv[0]} [--no-header] <trace-events> <trace-file>\n')
with open(trace_event_path, 'r') as events_fobj, open(trace_file_path, 'rb') as log_fobj:
events = read_events(events_fobj, trace_event_path)
@@ -225,4 +227,9 @@ def catchall(self, *rec_args, event, timestamp_ns, pid, event_id):
]
print(f'{event.name} {delta_ns / 1000:0.3f} {pid=} ' + ' '.join(fields))
- run(Formatter)
+ try:
+ run(Formatter)
+ except SimpleException as e:
+ sys.stderr.write(e + "\n")
+ sys.exit(1)
+
--
2.38.1
^ permalink raw reply related [flat|nested] 12+ messages in thread* Re: [PATCH 8/9] simpletrace: define exception and add handling
2023-02-21 9:01 ` [PATCH 8/9] simpletrace: define exception and add handling Mads Ynddal
@ 2023-02-21 9:12 ` Philippe Mathieu-Daudé
0 siblings, 0 replies; 12+ messages in thread
From: Philippe Mathieu-Daudé @ 2023-02-21 9:12 UTC (permalink / raw)
To: Mads Ynddal, qemu-devel
Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
On 21/2/23 10:01, Mads Ynddal wrote:
> From: Mads Ynddal <m.ynddal@samsung.com>
>
> Define `SimpleException` to differentiate our exceptions from generic
> exceptions (IOError, etc.). Adapted simpletrace to support this and
> output to stderr.
>
> Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
> ---
> scripts/simpletrace.py | 23 +++++++++++++++--------
> 1 file changed, 15 insertions(+), 8 deletions(-)
Reviewed-by: Philippe Mathieu-Daudé <philmd@linaro.org>
^ permalink raw reply [flat|nested] 12+ messages in thread
* [PATCH 9/9] simpletrace: Refactor to separate responsibilities
2023-02-21 9:00 [PATCH 0/9] simpletrace: refactor and general improvements Mads Ynddal
` (7 preceding siblings ...)
2023-02-21 9:01 ` [PATCH 8/9] simpletrace: define exception and add handling Mads Ynddal
@ 2023-02-21 9:01 ` Mads Ynddal
8 siblings, 0 replies; 12+ messages in thread
From: Mads Ynddal @ 2023-02-21 9:01 UTC (permalink / raw)
To: qemu-devel; +Cc: John Snow, Stefan Hajnoczi, Cleber Rosa, Mads Ynddal
From: Mads Ynddal <m.ynddal@samsung.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.
Signed-off-by: Mads Ynddal <m.ynddal@samsung.com>
---
scripts/simpletrace.py | 121 +++++++++++++++++++----------------------
1 file changed, 55 insertions(+), 66 deletions(-)
diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 35d2a757c4..465fcac609 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -24,6 +24,7 @@
log_header_fmt = '=QQQ' # trace/simple.c::TraceLogHeader
rec_header_fmt = '=QQII' # trace/simple.c::TraceRecord
+rec_header_fmt_len = struct.calcsize(rec_header_fmt)
class SimpleException(Exception):
pass
@@ -36,35 +37,6 @@ def read_header(fobj, hfmt):
raise SimpleException('Error reading header. Wrong filetype provided?')
return struct.unpack(hfmt, hdr)
-def get_record(event_mapping, event_id_to_name, rechdr, fobj):
- """Deserialize a trace record from a file into a tuple
- (name, timestamp, pid, arg1, ..., arg6)."""
- event_id, timestamp_ns, length, pid = rechdr
- if event_id != dropped_event_id:
- name = event_id_to_name[event_id]
- try:
- event = event_mapping[name]
- except KeyError as e:
- raise SimpleException(
- f'{e} event is logged but is not declared in the trace events'
- 'file, try using trace-events-all instead.'
- )
-
- rec = (name, timestamp_ns, pid)
- for type, name in event.args:
- if is_string(type):
- l = fobj.read(4)
- (len,) = struct.unpack('=L', l)
- s = fobj.read(len)
- rec = rec + (s,)
- else:
- (value,) = struct.unpack('=Q', fobj.read(8))
- rec = rec + (value,)
- else:
- (dropped_count,) = struct.unpack('=Q', fobj.read(8))
- rec = ("dropped", timestamp_ns, pid, dropped_count)
- return rec
-
def get_mapping(fobj):
(event_id, ) = struct.unpack('=Q', fobj.read(8))
(len, ) = struct.unpack('=L', fobj.read(4))
@@ -72,10 +44,11 @@ def get_mapping(fobj):
return (event_id, name)
-def read_record(event_mapping, event_id_to_name, fobj):
- """Deserialize a trace record from a file into a tuple (event_num, timestamp, pid, arg1, ..., arg6)."""
- rechdr = read_header(fobj, rec_header_fmt)
- return get_record(event_mapping, event_id_to_name, rechdr, fobj)
+def read_record(fobj):
+ """Deserialize a trace record from a file into a tuple (event_num, timestamp, pid, args)."""
+ event_id, timestamp_ns, record_length, record_pid = read_header(fobj, rec_header_fmt)
+ args_payload = fobj.read(record_length - rec_header_fmt_len)
+ return (event_id, timestamp_ns, record_pid, args_payload)
def read_trace_header(fobj):
"""Read and verify trace file header"""
@@ -90,30 +63,60 @@ def read_trace_header(fobj):
if log_version != 4:
raise ValueError(f'Log format {log_version} not supported with this QEMU release!')
-def read_trace_records(event_mapping, event_id_to_name, fobj):
- """Deserialize trace records from a file, yielding record tuples (event_num, timestamp, pid, arg1, ..., arg6).
-
- Note that `event_id_to_name` is modified if the file contains mapping records.
+def read_trace_records(events, fobj, read_header):
+ """Deserialize trace records from a file, yielding record tuples (event, event_num, timestamp, pid, arg1, ..., arg6).
Args:
event_mapping (str -> Event): events dict, indexed by name
- event_id_to_name (int -> str): event names dict, indexed by event ID
fobj (file): input file
+ read_header (bool): whether to headers were read from fobj
"""
- while True:
- t = fobj.read(8)
- if len(t) == 0:
- break
+ frameinfo = inspect.getframeinfo(inspect.currentframe())
+ dropped_event = Event.build("Dropped_Event(uint64_t num_events_dropped)",
+ frameinfo.lineno + 1, frameinfo.filename)
+
+ event_mapping = {e.name: e for e in events}
+ event_mapping["dropped"] = dropped_event
+ event_id_to_name = {dropped_event_id: "dropped"}
+
+ # If there is no header assume event ID mapping matches events list
+ if not read_header:
+ for event_id, event in enumerate(events):
+ event_id_to_name[event_id] = event.name
+ while t := fobj.read(8):
(rectype, ) = struct.unpack('=Q', t)
if rectype == record_type_mapping:
- event_id, name = get_mapping(fobj)
- event_id_to_name[event_id] = name
+ event_id, event_name = get_mapping(fobj)
+ event_id_to_name[event_id] = event_name
else:
- rec = read_record(event_mapping, event_id_to_name, fobj)
-
- yield rec
+ event_id, timestamp_ns, pid, args_payload = read_record(fobj)
+ event_name = event_id_to_name[event_id]
+
+ try:
+ event = event_mapping[event_name]
+ except KeyError as e:
+ raise SimpleException(
+ f'{e} event is logged but is not declared in the trace events'
+ 'file, try using trace-events-all instead.'
+ )
+
+ offset = 0
+ args = []
+ for type, _ in event.args:
+ if is_string(type):
+ (len,) = struct.unpack_from('=L', args_payload, offset=offset)
+ offset += 4
+ s = args_payload[offset:offset+len]
+ offset += len
+ args.append(s)
+ else:
+ (value,) = struct.unpack_from('=Q', args_payload, offset=offset)
+ offset += 8
+ args.append(value)
+
+ yield (event_mapping[event_name], event_name, timestamp_ns, pid) + tuple(args)
class Analyzer:
"""A trace file analyzer which processes trace records.
@@ -167,28 +170,15 @@ def __exit__(self, _type, value, traceback):
"""Called at the end of the trace."""
pass
-def process(events, log, analyzer_class, read_header=True):
+def process(events_fobj, trace_event_path, log_fobj, analyzer_class, read_header=True):
"""Invoke an analyzer on each event in a log."""
if read_header:
- read_trace_header(log)
-
- frameinfo = inspect.getframeinfo(inspect.currentframe())
- dropped_event = Event.build("Dropped_Event(uint64_t num_events_dropped)",
- frameinfo.lineno + 1, frameinfo.filename)
- event_mapping = {"dropped": dropped_event}
- event_id_to_name = {dropped_event_id: "dropped"}
+ read_trace_header(log_fobj)
- for event in events:
- event_mapping[event.name] = event
-
- # If there is no header assume event ID mapping matches events list
- if not read_header:
- for event_id, event in enumerate(events):
- event_id_to_name[event_id] = event.name
+ events = read_events(events_fobj, trace_event_path)
with analyzer_class() as analyzer:
- for event_id, timestamp_ns, record_pid, *rec_args in read_trace_records(event_mapping, event_id_to_name, log):
- event = event_mapping[event_id]
+ for event, event_id, timestamp_ns, record_pid, *rec_args in read_trace_records(events, log_fobj, read_header):
fn = getattr(analyzer, event.name, analyzer.catchall)
fn(*rec_args, event=event, event_id=event_id, timestamp_ns=timestamp_ns, pid=record_pid)
@@ -207,8 +197,7 @@ def run(analyzer):
raise SimpleException(f'usage: {sys.argv[0]} [--no-header] <trace-events> <trace-file>\n')
with open(trace_event_path, 'r') as events_fobj, open(trace_file_path, 'rb') as log_fobj:
- events = read_events(events_fobj, trace_event_path)
- process(events, log_fobj, analyzer, read_header=not no_header)
+ process(events_fobj, trace_event_path, log_fobj, analyzer, read_header=not no_header)
if __name__ == '__main__':
class Formatter(Analyzer):
--
2.38.1
^ permalink raw reply related [flat|nested] 12+ messages in thread