Patchwork [4/4] simpletrace.py: Simpletrace v2 tracelog reader script

login
register
mail settings
Submitter Harsh Prateek Bora
Date Jan. 2, 2012, 6:50 a.m.
Message ID <1325487023-10613-5-git-send-email-harsh@linux.vnet.ibm.com>
Download mbox | patch
Permalink /patch/133798/
State New
Headers show

Comments

Harsh Prateek Bora - Jan. 2, 2012, 6:50 a.m.
Signed-off-by: Harsh Prateek Bora <harsh@linux.vnet.ibm.com>
---
 scripts/simpletrace.py |  110 +++++++++++++++++++++++++++++++++++++++++++-----
 1 files changed, 99 insertions(+), 11 deletions(-)
Harsh Prateek Bora - Jan. 2, 2012, 7:03 a.m.
Hi,
Please ignore this duplicate patch in the series which was sent by 
mistake, consider the one with subject '[RFC PATCH 4/4] simpletrace.py: 
updated log reader script to handle new log format'. Sorry for 
inconvenience.

- Harsh

On 01/02/2012 12:20 PM, Harsh Prateek Bora wrote:
> Signed-off-by: Harsh Prateek Bora<harsh@linux.vnet.ibm.com>
> ---
>   scripts/simpletrace.py |  110 +++++++++++++++++++++++++++++++++++++++++++-----
>   1 files changed, 99 insertions(+), 11 deletions(-)
>
> diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
> index f55e5e6..69829dd 100755
> --- a/scripts/simpletrace.py
> +++ b/scripts/simpletrace.py
> @@ -12,16 +12,37 @@
>   import struct
>   import re
>   import inspect
> +import sys
> +from tracetool import *
>
>   header_event_id = 0xffffffffffffffff
>   header_magic    = 0xf2b177cb0aa429b4
>   header_version  = 0
> +log_header_ver  = 2
>   dropped_event_id = 0xfffffffffffffffe
>
>   trace_fmt = '=QQQQQQQQ'
> +header_fmt = '=QQII'
> +header_len = struct.calcsize(header_fmt)
>   trace_len = struct.calcsize(trace_fmt)
>   event_re  = re.compile(r'(disable\s+)?([a-zA-Z0-9_]+)\(([^)]*)\).*')
>
> +def get_event_argtypes(fobj):
> +    """Parse a trace-events file into {event_num: (name, type arg, ...)}."""
> +
> +    events = {dropped_event_id: ('name', 'args')}
> +    event_num = 0
> +    for line in fobj:
> +        m = event_re.match(line.strip())
> +        if m is None:
> +            continue
> +
> +        disable, name, args = m.groups()
> +        events[event_num] = tuple(args.split(','))
> +        event_num += 1
> +    return events
> +
> +
>   def parse_events(fobj):
>       """Parse a trace-events file into {event_num: (name, arg1, ...)}."""
>
> @@ -48,15 +69,16 @@ def read_record(fobj):
>           return None
>       return struct.unpack(trace_fmt, s)
>
> +def read_header(fobj):
> +    '''Read a trace record header'''
> +    s = fobj.read(header_len)
> +    if len(s) != header_len:
> +        return None
> +    return struct.unpack(header_fmt, s)
> +
> +
>   def read_trace_file(fobj):
>       """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:
> -        raise ValueError('not a trace file or incompatible version')
> -
>       while True:
>           rec = read_record(fobj)
>           if rec is None:
> @@ -64,6 +86,59 @@ def read_trace_file(fobj):
>
>           yield rec
>
> +def process_event(event_id, fobj):
> +    params = etypes[event_id]
> +    for elem in params:
> +        if is_string(elem):
> +            l = fobj.read(4)
> +            (len,) = struct.unpack('=L', l)
> +            s = fobj.read(len)
> +            sfmt = `len`+'s'
> +            (str,) = struct.unpack_from(sfmt, s)
> +            type, sep, var = elem.rpartition('*')
> +            print '%(arg)s=%(val)s' % { 'arg': var.lstrip(), 'val': str },
> +        elif '*' in elem:
> +            (value,) = struct.unpack('=Q', fobj.read(8))
> +            type, sep, var = elem.rpartition('*')
> +            print '%(arg)s=0x%(val)u' % { 'arg': var.lstrip(), 'val': value },
> +        else:
> +            (value,) = struct.unpack('=Q', fobj.read(8))
> +            type, sep, var = elem.rpartition(' ')
> +            print '%(arg)s=%(val)u' % { 'arg': var.lstrip(), 'val': value },
> +    print
> +    return
> +
> +etypes = get_event_argtypes(open(sys.argv[1], 'r'))
> +def processv2(fobj):
> +    '''Process simpletrace v2 log trace records'''
> +    events = parse_events(open(sys.argv[1], 'r'))
> +    #print events
> +    max_events = len(events) - 1
> +    last_timestamp = None
> +    while True:
> +        # read record header
> +        rechdr = read_header(fobj)
> +        if rechdr is None:
> +            print "No more records"
> +            break
> +
> +        if rechdr[0]>= max_events:
> +            print "Invalid Event ID found, Trace Log may be corrupted !!!"
> +            sys.exit(1)
> +
> +        if last_timestamp is None:
> +            last_timestamp = rechdr[1]
> +        delta_ns = rechdr[1] - last_timestamp
> +        last_timestamp = rechdr[1]
> +
> +        print events[rechdr[0]][0],  '%0.3f' % (delta_ns / 1000.0),
> +        # read data
> +        # process_event(rec[0], fobj)
> +        # rechdr[2] is record length (including header)
> +        #print etypes[rechdr[0]]
> +        #data = fobj.read(rechdr[2] - header_len)
> +        process_event(rechdr[0], fobj)
> +
>   class Analyzer(object):
>       """A trace file analyzer which processes trace records.
>
> @@ -90,8 +165,6 @@ 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)
> @@ -129,8 +202,10 @@ def run(analyzer):
>           sys.exit(1)
>
>       events = parse_events(open(sys.argv[1], 'r'))
> -    process(events, sys.argv[2], analyzer)
> +    process(events, log, analyzer)
> +
>
> +log = open(sys.argv[2], 'rb')
>   if __name__ == '__main__':
>       class Formatter(Analyzer):
>           def __init__(self):
> @@ -148,4 +223,17 @@ if __name__ == '__main__':
>                   fields.append('%s=0x%x' % (event[i], rec[i + 1]))
>               print ' '.join(fields)
>
> -    run(Formatter())
> +    #run(Formatter())
> +    header = read_header(log)
> +    if header is None or \
> +        header[0] != header_event_id or \
> +        header[1] != header_magic:
> +         raise ValueError('not a valid trace file')
> +    if header[2] == 0:   # version 1
> +        # ver 1 tracelog header contains few more unused bytes
> +        temp = log.read(40) # read those bytes and continue
> +        run(Formatter())
> +    elif header[2] == 2: # version 2
> +        processv2(log)
> +    else:
> +        raise ValueError('trace file version not supported')

Patch

diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index f55e5e6..69829dd 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -12,16 +12,37 @@ 
 import struct
 import re
 import inspect
+import sys
+from tracetool import *
 
 header_event_id = 0xffffffffffffffff
 header_magic    = 0xf2b177cb0aa429b4
 header_version  = 0
+log_header_ver  = 2
 dropped_event_id = 0xfffffffffffffffe
 
 trace_fmt = '=QQQQQQQQ'
+header_fmt = '=QQII'
+header_len = struct.calcsize(header_fmt)
 trace_len = struct.calcsize(trace_fmt)
 event_re  = re.compile(r'(disable\s+)?([a-zA-Z0-9_]+)\(([^)]*)\).*')
 
+def get_event_argtypes(fobj):
+    """Parse a trace-events file into {event_num: (name, type arg, ...)}."""
+
+    events = {dropped_event_id: ('name', 'args')}
+    event_num = 0
+    for line in fobj:
+        m = event_re.match(line.strip())
+        if m is None:
+            continue
+
+        disable, name, args = m.groups()
+        events[event_num] = tuple(args.split(','))
+        event_num += 1
+    return events
+
+
 def parse_events(fobj):
     """Parse a trace-events file into {event_num: (name, arg1, ...)}."""
 
@@ -48,15 +69,16 @@  def read_record(fobj):
         return None
     return struct.unpack(trace_fmt, s)
 
+def read_header(fobj):
+    '''Read a trace record header'''
+    s = fobj.read(header_len)
+    if len(s) != header_len:
+        return None
+    return struct.unpack(header_fmt, s)
+
+
 def read_trace_file(fobj):
     """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:
-        raise ValueError('not a trace file or incompatible version')
-
     while True:
         rec = read_record(fobj)
         if rec is None:
@@ -64,6 +86,59 @@  def read_trace_file(fobj):
 
         yield rec
 
+def process_event(event_id, fobj):
+    params = etypes[event_id]
+    for elem in params:
+        if is_string(elem):
+            l = fobj.read(4)
+            (len,) = struct.unpack('=L', l)
+            s = fobj.read(len)
+            sfmt = `len`+'s'
+            (str,) = struct.unpack_from(sfmt, s)
+            type, sep, var = elem.rpartition('*')
+            print '%(arg)s=%(val)s' % { 'arg': var.lstrip(), 'val': str },
+        elif '*' in elem:
+            (value,) = struct.unpack('=Q', fobj.read(8))
+            type, sep, var = elem.rpartition('*')
+            print '%(arg)s=0x%(val)u' % { 'arg': var.lstrip(), 'val': value },
+        else:
+            (value,) = struct.unpack('=Q', fobj.read(8))
+            type, sep, var = elem.rpartition(' ')
+            print '%(arg)s=%(val)u' % { 'arg': var.lstrip(), 'val': value },
+    print
+    return
+
+etypes = get_event_argtypes(open(sys.argv[1], 'r'))
+def processv2(fobj):
+    '''Process simpletrace v2 log trace records'''
+    events = parse_events(open(sys.argv[1], 'r'))
+    #print events
+    max_events = len(events) - 1
+    last_timestamp = None
+    while True:
+        # read record header
+        rechdr = read_header(fobj)
+        if rechdr is None:
+            print "No more records"
+            break
+
+        if rechdr[0] >= max_events:
+            print "Invalid Event ID found, Trace Log may be corrupted !!!"
+            sys.exit(1)
+
+        if last_timestamp is None:
+            last_timestamp = rechdr[1]
+        delta_ns = rechdr[1] - last_timestamp
+        last_timestamp = rechdr[1]
+
+        print events[rechdr[0]][0],  '%0.3f' % (delta_ns / 1000.0),
+        # read data
+        # process_event(rec[0], fobj)
+        # rechdr[2] is record length (including header)
+        #print etypes[rechdr[0]]
+        #data = fobj.read(rechdr[2] - header_len)
+        process_event(rechdr[0], fobj)
+
 class Analyzer(object):
     """A trace file analyzer which processes trace records.
 
@@ -90,8 +165,6 @@  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)
@@ -129,8 +202,10 @@  def run(analyzer):
         sys.exit(1)
 
     events = parse_events(open(sys.argv[1], 'r'))
-    process(events, sys.argv[2], analyzer)
+    process(events, log, analyzer)
+
 
+log = open(sys.argv[2], 'rb')
 if __name__ == '__main__':
     class Formatter(Analyzer):
         def __init__(self):
@@ -148,4 +223,17 @@  if __name__ == '__main__':
                 fields.append('%s=0x%x' % (event[i], rec[i + 1]))
             print ' '.join(fields)
 
-    run(Formatter())
+    #run(Formatter())
+    header = read_header(log)
+    if header is None or \
+        header[0] != header_event_id or \
+        header[1] != header_magic:
+         raise ValueError('not a valid trace file')
+    if header[2] == 0:   # version 1
+        # ver 1 tracelog header contains few more unused bytes
+        temp = log.read(40) # read those bytes and continue
+        run(Formatter())
+    elif header[2] == 2: # version 2
+        processv2(log)
+    else:
+        raise ValueError('trace file version not supported')