On Tue, Feb 22, 2011 at 01:59:41PM +0000, Stefan Hajnoczi wrote:
> 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 <stefa...@linux.vnet.ibm.com>
> ---
> scripts/simpletrace.py | 123
> +++++++++++++++++++++++++++++++++++-------------
> 1 files changed, 90 insertions(+), 33 deletions(-)
Thanks, applied.
> diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
> index 553a727..9fe3dda 100755
> --- a/scripts/simpletrace.py
> +++ b/scripts/simpletrace.py
> @@ -9,9 +9,9 @@
> #
> # For help see docs/tracing.txt
>
> -import sys
> import struct
> import re
> +import inspect
>
> header_event_id = 0xffffffffffffffff
> header_magic = 0xf2b177cb0aa429b4
> @@ -21,12 +21,8 @@ trace_fmt = '=QQQQQQQQ'
> trace_len = struct.calcsize(trace_fmt)
> event_re = re.compile(r'(disable\s+)?([a-zA-Z0-9_]+)\(([^)]*)\).*')
>
> -def err(msg):
> - sys.stderr.write(msg + '\n')
> - sys.exit(1)
> -
> def parse_events(fobj):
> - """Parse a trace-events file."""
> + """Parse a trace-events file into {event_num: (name, arg1, ...)}."""
>
> def get_argnames(args):
> """Extract argument names from a parameter list."""
> @@ -45,20 +41,20 @@ def parse_events(fobj):
> return events
>
> def read_record(fobj):
> - """Deserialize a trace record from a file."""
> + """Deserialize a trace record from a file into a tuple (event_num,
> timestamp, arg1, ..., arg6)."""
> s = fobj.read(trace_len)
> if len(s) != trace_len:
> return None
> return struct.unpack(trace_fmt, s)
>
> def read_trace_file(fobj):
> - """Deserialize trace records from a file."""
> + """Deserialize trace records from a file, yielding record tuples
> (event_num, timestamp, arg1, ..., arg6)."""
> header = read_record(fobj)
> if header is None or \
> header[0] != header_event_id or \
> header[1] != header_magic or \
> header[2] != header_version:
> - err('not a trace file or incompatible version')
> + raise ValueError('not a trace file or incompatible version')
>
> while True:
> rec = read_record(fobj)
> @@ -67,27 +63,88 @@ def read_trace_file(fobj):
>
> yield rec
>
> -class Formatter(object):
> - def __init__(self, events):
> - self.events = events
> - self.last_timestamp = None
> -
> - def format_record(self, rec):
> - if self.last_timestamp is None:
> - self.last_timestamp = rec[1]
> - delta_ns = rec[1] - self.last_timestamp
> - self.last_timestamp = rec[1]
> -
> - event = self.events[rec[0]]
> - fields = [event[0], '%0.3f' % (delta_ns / 1000.0)]
> - for i in xrange(1, len(event)):
> - fields.append('%s=0x%x' % (event[i], rec[i + 1]))
> - return ' '.join(fields)
> -
> -if len(sys.argv) != 3:
> - err('usage: %s <trace-events> <trace-file>' % sys.argv[0])
> -
> -events = parse_events(open(sys.argv[1], 'r'))
> -formatter = Formatter(events)
> -for rec in read_trace_file(open(sys.argv[2], 'rb')):
> - print formatter.format_record(rec)
> +class Analyzer(object):
> + """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.
> +
> + If a method matching a trace event name exists, it is invoked to process
> + that trace record. Otherwise the catchall() method is invoked."""
> +
> + def begin(self):
> + """Called at the start of the trace."""
> + pass
> +
> + def catchall(self, event, rec):
> + """Called if no specific method for processing a trace event has
> been found."""
> + pass
> +
> + def end(self):
> + """Called at the end of the trace."""
> + pass
> +
> +def process(events, log, analyzer):
> + """Invoke an analyzer on each event in a log."""
> + if isinstance(events, str):
> + events = parse_events(open(events, 'r'))
> + if isinstance(log, str):
> + log = open(log, 'rb')
> +
> + def build_fn(analyzer, event):
> + fn = getattr(analyzer, event[0], None)
> + if fn is None:
> + return analyzer.catchall
> +
> + event_argcount = len(event) - 1
> + fn_argcount = len(inspect.getargspec(fn)[0]) - 1
> + if fn_argcount == event_argcount + 1:
> + # Include timestamp as first argument
> + return lambda _, rec: fn(*rec[1:2 + fn_argcount])
> + else:
> + # Just arguments, no timestamp
> + return lambda _, rec: fn(*rec[2:2 + fn_argcount])
> +
> + analyzer.begin()
> + fn_cache = {}
> + for rec in read_trace_file(log):
> + event_num = rec[0]
> + event = events[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()
> +
> +def run(analyzer):
> + """Execute an analyzer on a trace file given on the command-line.
> +
> + This function is useful as a driver for simple analysis scripts. More
> + advanced scripts will want to call process() instead."""
> + import sys
> +
> + if len(sys.argv) != 3:
> + sys.stderr.write('usage: %s <trace-events> <trace-file>\n' %
> sys.argv[0])
> + sys.exit(1)
> +
> + events = parse_events(open(sys.argv[1], 'r'))
> + process(events, sys.argv[2], 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[0], '%0.3f' % (delta_ns / 1000.0)]
> + for i in xrange(1, len(event)):
> + fields.append('%s=0x%x' % (event[i], rec[i + 1]))
> + print ' '.join(fields)
> +
> + run(Formatter())
> --
> 1.7.2.3
>
>
>
--
Aurelien Jarno GPG: 1024D/F1BCDB73
aurel...@aurel32.net http://www.aurel32.net
