simpletrace: Make simpletrace.py a Python module

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>
---
 scripts/simpletrace.py |  123 +++++++++++++++++++++++++++++++++++-------------
 1 files changed, 90 insertions(+), 33 deletions(-)

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 <stefanha@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
> 
> 
>