14c3b5a48SBlue Swirl#!/usr/bin/env python 24c3b5a48SBlue Swirl# 34c3b5a48SBlue Swirl# Pretty-printer for simple trace backend binary trace files 44c3b5a48SBlue Swirl# 54c3b5a48SBlue Swirl# Copyright IBM, Corp. 2010 64c3b5a48SBlue Swirl# 74c3b5a48SBlue Swirl# This work is licensed under the terms of the GNU GPL, version 2. See 84c3b5a48SBlue Swirl# the COPYING file in the top-level directory. 94c3b5a48SBlue Swirl# 104c3b5a48SBlue Swirl# For help see docs/tracing.txt 114c3b5a48SBlue Swirl 124c3b5a48SBlue Swirlimport struct 134c3b5a48SBlue Swirlimport re 1459da6684SStefan Hajnocziimport inspect 1590a147a2SHarsh Prateek Borafrom tracetool import _read_events, Event 1690a147a2SHarsh Prateek Borafrom tracetool.backend.simple import is_string 174c3b5a48SBlue Swirl 184c3b5a48SBlue Swirlheader_event_id = 0xffffffffffffffff 194c3b5a48SBlue Swirlheader_magic = 0xf2b177cb0aa429b4 200b5538c3SStefan Hajnoczidropped_event_id = 0xfffffffffffffffe 214c3b5a48SBlue Swirl 2290a147a2SHarsh Prateek Boralog_header_fmt = '=QQQ' 2390a147a2SHarsh Prateek Borarec_header_fmt = '=QQII' 244c3b5a48SBlue Swirl 2590a147a2SHarsh Prateek Boradef read_header(fobj, hfmt): 2690a147a2SHarsh Prateek Bora '''Read a trace record header''' 2790a147a2SHarsh Prateek Bora hlen = struct.calcsize(hfmt) 2890a147a2SHarsh Prateek Bora hdr = fobj.read(hlen) 2990a147a2SHarsh Prateek Bora if len(hdr) != hlen: 304c3b5a48SBlue Swirl return None 3190a147a2SHarsh Prateek Bora return struct.unpack(hfmt, hdr) 324c3b5a48SBlue Swirl 3390a147a2SHarsh Prateek Boradef get_record(edict, rechdr, fobj): 3480ff35cdSStefan Hajnoczi """Deserialize a trace record from a file into a tuple (event_num, timestamp, pid, arg1, ..., arg6).""" 3590a147a2SHarsh Prateek Bora if rechdr is None: 3690a147a2SHarsh Prateek Bora return None 3780ff35cdSStefan Hajnoczi rec = (rechdr[0], rechdr[1], rechdr[3]) 3890a147a2SHarsh Prateek Bora if rechdr[0] != dropped_event_id: 3990a147a2SHarsh Prateek Bora event_id = rechdr[0] 4090a147a2SHarsh Prateek Bora event = edict[event_id] 4190a147a2SHarsh Prateek Bora for type, name in event.args: 4290a147a2SHarsh Prateek Bora if is_string(type): 4390a147a2SHarsh Prateek Bora l = fobj.read(4) 4490a147a2SHarsh Prateek Bora (len,) = struct.unpack('=L', l) 4590a147a2SHarsh Prateek Bora s = fobj.read(len) 4690a147a2SHarsh Prateek Bora rec = rec + (s,) 4790a147a2SHarsh Prateek Bora else: 4890a147a2SHarsh Prateek Bora (value,) = struct.unpack('=Q', fobj.read(8)) 4990a147a2SHarsh Prateek Bora rec = rec + (value,) 5090a147a2SHarsh Prateek Bora else: 5190a147a2SHarsh Prateek Bora (value,) = struct.unpack('=Q', fobj.read(8)) 5290a147a2SHarsh Prateek Bora rec = rec + (value,) 5390a147a2SHarsh Prateek Bora return rec 5490a147a2SHarsh Prateek Bora 5590a147a2SHarsh Prateek Bora 5690a147a2SHarsh Prateek Boradef read_record(edict, fobj): 5780ff35cdSStefan Hajnoczi """Deserialize a trace record from a file into a tuple (event_num, timestamp, pid, arg1, ..., arg6).""" 5890a147a2SHarsh Prateek Bora rechdr = read_header(fobj, rec_header_fmt) 5990a147a2SHarsh Prateek Bora return get_record(edict, rechdr, fobj) # return tuple of record elements 6090a147a2SHarsh Prateek Bora 61*15327c3dSStefan Hajnoczidef read_trace_header(fobj): 62*15327c3dSStefan Hajnoczi """Read and verify trace file header""" 6390a147a2SHarsh Prateek Bora header = read_header(fobj, log_header_fmt) 644c3b5a48SBlue Swirl if header is None or \ 654c3b5a48SBlue Swirl header[0] != header_event_id or \ 6690a147a2SHarsh Prateek Bora header[1] != header_magic: 6790a147a2SHarsh Prateek Bora raise ValueError('Not a valid trace file!') 6890a147a2SHarsh Prateek Bora 6990a147a2SHarsh Prateek Bora log_version = header[2] 70ef0bd3bbSLluís Vilanova if log_version not in [0, 2, 3]: 71ef0bd3bbSLluís Vilanova raise ValueError('Unknown version of tracelog format!') 72ef0bd3bbSLluís Vilanova if log_version != 3: 73ef0bd3bbSLluís Vilanova raise ValueError('Log format %d not supported with this QEMU release!' 74ef0bd3bbSLluís Vilanova % log_version) 754c3b5a48SBlue Swirl 76*15327c3dSStefan Hajnoczidef read_trace_records(edict, fobj): 77*15327c3dSStefan Hajnoczi """Deserialize trace records from a file, yielding record tuples (event_num, timestamp, pid, arg1, ..., arg6).""" 784c3b5a48SBlue Swirl while True: 7990a147a2SHarsh Prateek Bora rec = read_record(edict, fobj) 804c3b5a48SBlue Swirl if rec is None: 814c3b5a48SBlue Swirl break 824c3b5a48SBlue Swirl 834c3b5a48SBlue Swirl yield rec 844c3b5a48SBlue Swirl 8559da6684SStefan Hajnocziclass Analyzer(object): 8659da6684SStefan Hajnoczi """A trace file analyzer which processes trace records. 8759da6684SStefan Hajnoczi 8859da6684SStefan Hajnoczi An analyzer can be passed to run() or process(). The begin() method is 8959da6684SStefan Hajnoczi invoked, then each trace record is processed, and finally the end() method 9059da6684SStefan Hajnoczi is invoked. 9159da6684SStefan Hajnoczi 9259da6684SStefan Hajnoczi If a method matching a trace event name exists, it is invoked to process 9359da6684SStefan Hajnoczi that trace record. Otherwise the catchall() method is invoked.""" 9459da6684SStefan Hajnoczi 9559da6684SStefan Hajnoczi def begin(self): 9659da6684SStefan Hajnoczi """Called at the start of the trace.""" 9759da6684SStefan Hajnoczi pass 9859da6684SStefan Hajnoczi 9959da6684SStefan Hajnoczi def catchall(self, event, rec): 10059da6684SStefan Hajnoczi """Called if no specific method for processing a trace event has been found.""" 10159da6684SStefan Hajnoczi pass 10259da6684SStefan Hajnoczi 10359da6684SStefan Hajnoczi def end(self): 10459da6684SStefan Hajnoczi """Called at the end of the trace.""" 10559da6684SStefan Hajnoczi pass 10659da6684SStefan Hajnoczi 107*15327c3dSStefan Hajnoczidef process(events, log, analyzer, read_header=True): 10859da6684SStefan Hajnoczi """Invoke an analyzer on each event in a log.""" 10959da6684SStefan Hajnoczi if isinstance(events, str): 11090a147a2SHarsh Prateek Bora events = _read_events(open(events, 'r')) 11159da6684SStefan Hajnoczi if isinstance(log, str): 11259da6684SStefan Hajnoczi log = open(log, 'rb') 11359da6684SStefan Hajnoczi 114*15327c3dSStefan Hajnoczi if read_header: 115*15327c3dSStefan Hajnoczi read_trace_header(log) 116*15327c3dSStefan Hajnoczi 11790a147a2SHarsh Prateek Bora dropped_event = Event.build("Dropped_Event(uint64_t num_events_dropped)") 11890a147a2SHarsh Prateek Bora edict = {dropped_event_id: dropped_event} 11990a147a2SHarsh Prateek Bora 1201dad2ce9SLluís Vilanova for num, event in enumerate(events): 12190a147a2SHarsh Prateek Bora edict[num] = event 12290a147a2SHarsh Prateek Bora 12359da6684SStefan Hajnoczi def build_fn(analyzer, event): 12490a147a2SHarsh Prateek Bora if isinstance(event, str): 12590a147a2SHarsh Prateek Bora return analyzer.catchall 12690a147a2SHarsh Prateek Bora 12790a147a2SHarsh Prateek Bora fn = getattr(analyzer, event.name, None) 12859da6684SStefan Hajnoczi if fn is None: 12959da6684SStefan Hajnoczi return analyzer.catchall 13059da6684SStefan Hajnoczi 13190a147a2SHarsh Prateek Bora event_argcount = len(event.args) 13259da6684SStefan Hajnoczi fn_argcount = len(inspect.getargspec(fn)[0]) - 1 13359da6684SStefan Hajnoczi if fn_argcount == event_argcount + 1: 13459da6684SStefan Hajnoczi # Include timestamp as first argument 13580ff35cdSStefan Hajnoczi return lambda _, rec: fn(*((rec[1:2],) + rec[3:3 + event_argcount])) 13680ff35cdSStefan Hajnoczi elif fn_argcount == event_argcount + 2: 13780ff35cdSStefan Hajnoczi # Include timestamp and pid 13880ff35cdSStefan Hajnoczi return lambda _, rec: fn(*rec[1:3 + event_argcount]) 13959da6684SStefan Hajnoczi else: 14080ff35cdSStefan Hajnoczi # Just arguments, no timestamp or pid 14180ff35cdSStefan Hajnoczi return lambda _, rec: fn(*rec[3:3 + event_argcount]) 14259da6684SStefan Hajnoczi 14359da6684SStefan Hajnoczi analyzer.begin() 14459da6684SStefan Hajnoczi fn_cache = {} 145*15327c3dSStefan Hajnoczi for rec in read_trace_records(edict, log): 14659da6684SStefan Hajnoczi event_num = rec[0] 14790a147a2SHarsh Prateek Bora event = edict[event_num] 14859da6684SStefan Hajnoczi if event_num not in fn_cache: 14959da6684SStefan Hajnoczi fn_cache[event_num] = build_fn(analyzer, event) 15059da6684SStefan Hajnoczi fn_cache[event_num](event, rec) 15159da6684SStefan Hajnoczi analyzer.end() 15259da6684SStefan Hajnoczi 15359da6684SStefan Hajnoczidef run(analyzer): 15459da6684SStefan Hajnoczi """Execute an analyzer on a trace file given on the command-line. 15559da6684SStefan Hajnoczi 15659da6684SStefan Hajnoczi This function is useful as a driver for simple analysis scripts. More 15759da6684SStefan Hajnoczi advanced scripts will want to call process() instead.""" 15859da6684SStefan Hajnoczi import sys 15959da6684SStefan Hajnoczi 160*15327c3dSStefan Hajnoczi read_header = True 161*15327c3dSStefan Hajnoczi if len(sys.argv) == 4 and sys.argv[1] == '--no-header': 162*15327c3dSStefan Hajnoczi read_header = False 163*15327c3dSStefan Hajnoczi del sys.argv[1] 164*15327c3dSStefan Hajnoczi elif len(sys.argv) != 3: 165*15327c3dSStefan Hajnoczi sys.stderr.write('usage: %s [--no-header] <trace-events> ' \ 166*15327c3dSStefan Hajnoczi '<trace-file>\n' % sys.argv[0]) 16759da6684SStefan Hajnoczi sys.exit(1) 16859da6684SStefan Hajnoczi 16990a147a2SHarsh Prateek Bora events = _read_events(open(sys.argv[1], 'r')) 170*15327c3dSStefan Hajnoczi process(events, sys.argv[2], analyzer, read_header=read_header) 17159da6684SStefan Hajnoczi 17259da6684SStefan Hajnocziif __name__ == '__main__': 17359da6684SStefan Hajnoczi class Formatter(Analyzer): 17459da6684SStefan Hajnoczi def __init__(self): 1754c3b5a48SBlue Swirl self.last_timestamp = None 1764c3b5a48SBlue Swirl 17759da6684SStefan Hajnoczi def catchall(self, event, rec): 17859da6684SStefan Hajnoczi timestamp = rec[1] 1794c3b5a48SBlue Swirl if self.last_timestamp is None: 18059da6684SStefan Hajnoczi self.last_timestamp = timestamp 18159da6684SStefan Hajnoczi delta_ns = timestamp - self.last_timestamp 18259da6684SStefan Hajnoczi self.last_timestamp = timestamp 1834c3b5a48SBlue Swirl 18480ff35cdSStefan Hajnoczi fields = [event.name, '%0.3f' % (delta_ns / 1000.0), 18580ff35cdSStefan Hajnoczi 'pid=%d' % rec[2]] 18680ff35cdSStefan Hajnoczi i = 3 18790a147a2SHarsh Prateek Bora for type, name in event.args: 18890a147a2SHarsh Prateek Bora if is_string(type): 18980ff35cdSStefan Hajnoczi fields.append('%s=%s' % (name, rec[i])) 19090a147a2SHarsh Prateek Bora else: 19180ff35cdSStefan Hajnoczi fields.append('%s=0x%x' % (name, rec[i])) 19290a147a2SHarsh Prateek Bora i += 1 19359da6684SStefan Hajnoczi print ' '.join(fields) 1944c3b5a48SBlue Swirl 19559da6684SStefan Hajnoczi run(Formatter()) 196