Re: [Qemu-devel] [PATCH] simpletrace: Make simpletrace.py a Python module

[Aurelien Jarno]

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 <address@hidden>
> ---
>  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
address@hidden                 http://www.aurel32.net