Merge remote-tracking branch 'remotes/alistair23/tags/pull-riscv-to-apply-20211022...
[qemu.git] / scripts / simpletrace.py
1 #!/usr/bin/env python3
2 #
3 # Pretty-printer for simple trace backend binary trace files
4 #
5 # Copyright IBM, Corp. 2010
6 #
7 # This work is licensed under the terms of the GNU GPL, version 2. See
8 # the COPYING file in the top-level directory.
9 #
10 # For help see docs/devel/tracing.rst
11
12 import struct
13 import inspect
14 from tracetool import read_events, Event
15 from tracetool.backend.simple import is_string
16
17 header_event_id = 0xffffffffffffffff
18 header_magic = 0xf2b177cb0aa429b4
19 dropped_event_id = 0xfffffffffffffffe
20
21 record_type_mapping = 0
22 record_type_event = 1
23
24 log_header_fmt = '=QQQ'
25 rec_header_fmt = '=QQII'
26
27 def read_header(fobj, hfmt):
28 '''Read a trace record header'''
29 hlen = struct.calcsize(hfmt)
30 hdr = fobj.read(hlen)
31 if len(hdr) != hlen:
32 return None
33 return struct.unpack(hfmt, hdr)
34
35 def get_record(edict, idtoname, rechdr, fobj):
36 """Deserialize a trace record from a file into a tuple
37 (name, timestamp, pid, arg1, ..., arg6)."""
38 if rechdr is None:
39 return None
40 if rechdr[0] != dropped_event_id:
41 event_id = rechdr[0]
42 name = idtoname[event_id]
43 rec = (name, rechdr[1], rechdr[3])
44 try:
45 event = edict[name]
46 except KeyError as e:
47 import sys
48 sys.stderr.write('%s event is logged but is not declared ' \
49 'in the trace events file, try using ' \
50 'trace-events-all instead.\n' % str(e))
51 sys.exit(1)
52
53 for type, name in event.args:
54 if is_string(type):
55 l = fobj.read(4)
56 (len,) = struct.unpack('=L', l)
57 s = fobj.read(len)
58 rec = rec + (s,)
59 else:
60 (value,) = struct.unpack('=Q', fobj.read(8))
61 rec = rec + (value,)
62 else:
63 rec = ("dropped", rechdr[1], rechdr[3])
64 (value,) = struct.unpack('=Q', fobj.read(8))
65 rec = rec + (value,)
66 return rec
67
68 def get_mapping(fobj):
69 (event_id, ) = struct.unpack('=Q', fobj.read(8))
70 (len, ) = struct.unpack('=L', fobj.read(4))
71 name = fobj.read(len).decode()
72
73 return (event_id, name)
74
75 def read_record(edict, idtoname, fobj):
76 """Deserialize a trace record from a file into a tuple (event_num, timestamp, pid, arg1, ..., arg6)."""
77 rechdr = read_header(fobj, rec_header_fmt)
78 return get_record(edict, idtoname, rechdr, fobj)
79
80 def read_trace_header(fobj):
81 """Read and verify trace file header"""
82 header = read_header(fobj, log_header_fmt)
83 if header is None:
84 raise ValueError('Not a valid trace file!')
85 if header[0] != header_event_id:
86 raise ValueError('Not a valid trace file, header id %d != %d' %
87 (header[0], header_event_id))
88 if header[1] != header_magic:
89 raise ValueError('Not a valid trace file, header magic %d != %d' %
90 (header[1], header_magic))
91
92 log_version = header[2]
93 if log_version not in [0, 2, 3, 4]:
94 raise ValueError('Unknown version of tracelog format!')
95 if log_version != 4:
96 raise ValueError('Log format %d not supported with this QEMU release!'
97 % log_version)
98
99 def read_trace_records(edict, idtoname, fobj):
100 """Deserialize trace records from a file, yielding record tuples (event_num, timestamp, pid, arg1, ..., arg6).
101
102 Note that `idtoname` is modified if the file contains mapping records.
103
104 Args:
105 edict (str -> Event): events dict, indexed by name
106 idtoname (int -> str): event names dict, indexed by event ID
107 fobj (file): input file
108
109 """
110 while True:
111 t = fobj.read(8)
112 if len(t) == 0:
113 break
114
115 (rectype, ) = struct.unpack('=Q', t)
116 if rectype == record_type_mapping:
117 event_id, name = get_mapping(fobj)
118 idtoname[event_id] = name
119 else:
120 rec = read_record(edict, idtoname, fobj)
121
122 yield rec
123
124 class Analyzer(object):
125 """A trace file analyzer which processes trace records.
126
127 An analyzer can be passed to run() or process(). The begin() method is
128 invoked, then each trace record is processed, and finally the end() method
129 is invoked.
130
131 If a method matching a trace event name exists, it is invoked to process
132 that trace record. Otherwise the catchall() method is invoked.
133
134 Example:
135 The following method handles the runstate_set(int new_state) trace event::
136
137 def runstate_set(self, new_state):
138 ...
139
140 The method can also take a timestamp argument before the trace event
141 arguments::
142
143 def runstate_set(self, timestamp, new_state):
144 ...
145
146 Timestamps have the uint64_t type and are in nanoseconds.
147
148 The pid can be included in addition to the timestamp and is useful when
149 dealing with traces from multiple processes::
150
151 def runstate_set(self, timestamp, pid, new_state):
152 ...
153 """
154
155 def begin(self):
156 """Called at the start of the trace."""
157 pass
158
159 def catchall(self, event, rec):
160 """Called if no specific method for processing a trace event has been found."""
161 pass
162
163 def end(self):
164 """Called at the end of the trace."""
165 pass
166
167 def process(events, log, analyzer, read_header=True):
168 """Invoke an analyzer on each event in a log."""
169 if isinstance(events, str):
170 events = read_events(open(events, 'r'), events)
171 if isinstance(log, str):
172 log = open(log, 'rb')
173
174 if read_header:
175 read_trace_header(log)
176
177 frameinfo = inspect.getframeinfo(inspect.currentframe())
178 dropped_event = Event.build("Dropped_Event(uint64_t num_events_dropped)",
179 frameinfo.lineno + 1, frameinfo.filename)
180 edict = {"dropped": dropped_event}
181 idtoname = {dropped_event_id: "dropped"}
182
183 for event in events:
184 edict[event.name] = event
185
186 # If there is no header assume event ID mapping matches events list
187 if not read_header:
188 for event_id, event in enumerate(events):
189 idtoname[event_id] = event.name
190
191 def build_fn(analyzer, event):
192 if isinstance(event, str):
193 return analyzer.catchall
194
195 fn = getattr(analyzer, event.name, None)
196 if fn is None:
197 return analyzer.catchall
198
199 event_argcount = len(event.args)
200 fn_argcount = len(inspect.getargspec(fn)[0]) - 1
201 if fn_argcount == event_argcount + 1:
202 # Include timestamp as first argument
203 return lambda _, rec: fn(*(rec[1:2] + rec[3:3 + event_argcount]))
204 elif fn_argcount == event_argcount + 2:
205 # Include timestamp and pid
206 return lambda _, rec: fn(*rec[1:3 + event_argcount])
207 else:
208 # Just arguments, no timestamp or pid
209 return lambda _, rec: fn(*rec[3:3 + event_argcount])
210
211 analyzer.begin()
212 fn_cache = {}
213 for rec in read_trace_records(edict, idtoname, log):
214 event_num = rec[0]
215 event = edict[event_num]
216 if event_num not in fn_cache:
217 fn_cache[event_num] = build_fn(analyzer, event)
218 fn_cache[event_num](event, rec)
219 analyzer.end()
220
221 def run(analyzer):
222 """Execute an analyzer on a trace file given on the command-line.
223
224 This function is useful as a driver for simple analysis scripts. More
225 advanced scripts will want to call process() instead."""
226 import sys
227
228 read_header = True
229 if len(sys.argv) == 4 and sys.argv[1] == '--no-header':
230 read_header = False
231 del sys.argv[1]
232 elif len(sys.argv) != 3:
233 sys.stderr.write('usage: %s [--no-header] <trace-events> ' \
234 '<trace-file>\n' % sys.argv[0])
235 sys.exit(1)
236
237 events = read_events(open(sys.argv[1], 'r'), sys.argv[1])
238 process(events, sys.argv[2], analyzer, read_header=read_header)
239
240 if __name__ == '__main__':
241 class Formatter(Analyzer):
242 def __init__(self):
243 self.last_timestamp = None
244
245 def catchall(self, event, rec):
246 timestamp = rec[1]
247 if self.last_timestamp is None:
248 self.last_timestamp = timestamp
249 delta_ns = timestamp - self.last_timestamp
250 self.last_timestamp = timestamp
251
252 fields = [event.name, '%0.3f' % (delta_ns / 1000.0),
253 'pid=%d' % rec[2]]
254 i = 3
255 for type, name in event.args:
256 if is_string(type):
257 fields.append('%s=%s' % (name, rec[i]))
258 else:
259 fields.append('%s=0x%x' % (name, rec[i]))
260 i += 1
261 print(' '.join(fields))
262
263 run(Formatter())