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>
Signed-off-by: Aurelien Jarno <aurelien@aurel32.net>

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
+class Analyzer(object):
+    """A trace file analyzer which processes trace records.
 
-    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]
+    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.
 
-        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 a method matching a trace event name exists, it is invoked to process
+    that trace record.  Otherwise the catchall() method is invoked."""
 
-if len(sys.argv) != 3:
-    err('usage: %s <trace-events> <trace-file>' % sys.argv[0])
+    def begin(self):
+        """Called at the start of the trace."""
+        pass
 
-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)
+    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())