Loading...
1# intel-pt-events.py: Print Intel PT Power Events and PTWRITE
2# Copyright (c) 2017, Intel Corporation.
3#
4# This program is free software; you can redistribute it and/or modify it
5# under the terms and conditions of the GNU General Public License,
6# version 2, as published by the Free Software Foundation.
7#
8# This program is distributed in the hope it will be useful, but WITHOUT
9# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
10# FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for
11# more details.
12
13from __future__ import print_function
14
15import os
16import sys
17import struct
18
19sys.path.append(os.environ['PERF_EXEC_PATH'] + \
20 '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
21
22# These perf imports are not used at present
23#from perf_trace_context import *
24#from Core import *
25
26def trace_begin():
27 print("Intel PT Power Events and PTWRITE")
28
29def trace_end():
30 print("End")
31
32def trace_unhandled(event_name, context, event_fields_dict):
33 print(' '.join(['%s=%s'%(k,str(v))for k,v in sorted(event_fields_dict.items())]))
34
35def print_ptwrite(raw_buf):
36 data = struct.unpack_from("<IQ", raw_buf)
37 flags = data[0]
38 payload = data[1]
39 exact_ip = flags & 1
40 print("IP: %u payload: %#x" % (exact_ip, payload), end=' ')
41
42def print_cbr(raw_buf):
43 data = struct.unpack_from("<BBBBII", raw_buf)
44 cbr = data[0]
45 f = (data[4] + 500) / 1000
46 p = ((cbr * 1000 / data[2]) + 5) / 10
47 print("%3u freq: %4u MHz (%3u%%)" % (cbr, f, p), end=' ')
48
49def print_mwait(raw_buf):
50 data = struct.unpack_from("<IQ", raw_buf)
51 payload = data[1]
52 hints = payload & 0xff
53 extensions = (payload >> 32) & 0x3
54 print("hints: %#x extensions: %#x" % (hints, extensions), end=' ')
55
56def print_pwre(raw_buf):
57 data = struct.unpack_from("<IQ", raw_buf)
58 payload = data[1]
59 hw = (payload >> 7) & 1
60 cstate = (payload >> 12) & 0xf
61 subcstate = (payload >> 8) & 0xf
62 print("hw: %u cstate: %u sub-cstate: %u" % (hw, cstate, subcstate),
63 end=' ')
64
65def print_exstop(raw_buf):
66 data = struct.unpack_from("<I", raw_buf)
67 flags = data[0]
68 exact_ip = flags & 1
69 print("IP: %u" % (exact_ip), end=' ')
70
71def print_pwrx(raw_buf):
72 data = struct.unpack_from("<IQ", raw_buf)
73 payload = data[1]
74 deepest_cstate = payload & 0xf
75 last_cstate = (payload >> 4) & 0xf
76 wake_reason = (payload >> 8) & 0xf
77 print("deepest cstate: %u last cstate: %u wake reason: %#x" %
78 (deepest_cstate, last_cstate, wake_reason), end=' ')
79
80def print_common_start(comm, sample, name):
81 ts = sample["time"]
82 cpu = sample["cpu"]
83 pid = sample["pid"]
84 tid = sample["tid"]
85 print("%16s %5u/%-5u [%03u] %9u.%09u %7s:" %
86 (comm, pid, tid, cpu, ts / 1000000000, ts %1000000000, name),
87 end=' ')
88
89def print_common_ip(sample, symbol, dso):
90 ip = sample["ip"]
91 print("%16x %s (%s)" % (ip, symbol, dso))
92
93def process_event(param_dict):
94 event_attr = param_dict["attr"]
95 sample = param_dict["sample"]
96 raw_buf = param_dict["raw_buf"]
97 comm = param_dict["comm"]
98 name = param_dict["ev_name"]
99
100 # Symbol and dso info are not always resolved
101 if "dso" in param_dict:
102 dso = param_dict["dso"]
103 else:
104 dso = "[unknown]"
105
106 if "symbol" in param_dict:
107 symbol = param_dict["symbol"]
108 else:
109 symbol = "[unknown]"
110
111 if name == "ptwrite":
112 print_common_start(comm, sample, name)
113 print_ptwrite(raw_buf)
114 print_common_ip(sample, symbol, dso)
115 elif name == "cbr":
116 print_common_start(comm, sample, name)
117 print_cbr(raw_buf)
118 print_common_ip(sample, symbol, dso)
119 elif name == "mwait":
120 print_common_start(comm, sample, name)
121 print_mwait(raw_buf)
122 print_common_ip(sample, symbol, dso)
123 elif name == "pwre":
124 print_common_start(comm, sample, name)
125 print_pwre(raw_buf)
126 print_common_ip(sample, symbol, dso)
127 elif name == "exstop":
128 print_common_start(comm, sample, name)
129 print_exstop(raw_buf)
130 print_common_ip(sample, symbol, dso)
131 elif name == "pwrx":
132 print_common_start(comm, sample, name)
133 print_pwrx(raw_buf)
134 print_common_ip(sample, symbol, dso)
1# SPDX-License-Identifier: GPL-2.0
2# intel-pt-events.py: Print Intel PT Events including Power Events and PTWRITE
3# Copyright (c) 2017-2021, Intel Corporation.
4#
5# This program is free software; you can redistribute it and/or modify it
6# under the terms and conditions of the GNU General Public License,
7# version 2, as published by the Free Software Foundation.
8#
9# This program is distributed in the hope it will be useful, but WITHOUT
10# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
11# FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for
12# more details.
13
14from __future__ import division, print_function
15
16import io
17import os
18import sys
19import struct
20import argparse
21import contextlib
22
23from libxed import LibXED
24from ctypes import create_string_buffer, addressof
25
26sys.path.append(os.environ['PERF_EXEC_PATH'] + \
27 '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
28
29from perf_trace_context import perf_set_itrace_options, \
30 perf_sample_insn, perf_sample_srccode
31
32try:
33 broken_pipe_exception = BrokenPipeError
34except:
35 broken_pipe_exception = IOError
36
37glb_switch_str = {}
38glb_insn = False
39glb_disassembler = None
40glb_src = False
41glb_source_file_name = None
42glb_line_number = None
43glb_dso = None
44glb_stash_dict = {}
45glb_output = None
46glb_output_pos = 0
47glb_cpu = -1
48glb_time = 0
49
50def get_optional_null(perf_dict, field):
51 if field in perf_dict:
52 return perf_dict[field]
53 return ""
54
55def get_optional_zero(perf_dict, field):
56 if field in perf_dict:
57 return perf_dict[field]
58 return 0
59
60def get_optional_bytes(perf_dict, field):
61 if field in perf_dict:
62 return perf_dict[field]
63 return bytes()
64
65def get_optional(perf_dict, field):
66 if field in perf_dict:
67 return perf_dict[field]
68 return "[unknown]"
69
70def get_offset(perf_dict, field):
71 if field in perf_dict:
72 return "+%#x" % perf_dict[field]
73 return ""
74
75def trace_begin():
76 ap = argparse.ArgumentParser(usage = "", add_help = False)
77 ap.add_argument("--insn-trace", action='store_true')
78 ap.add_argument("--src-trace", action='store_true')
79 ap.add_argument("--all-switch-events", action='store_true')
80 ap.add_argument("--interleave", type=int, nargs='?', const=4, default=0)
81 global glb_args
82 global glb_insn
83 global glb_src
84 glb_args = ap.parse_args()
85 if glb_args.insn_trace:
86 print("Intel PT Instruction Trace")
87 itrace = "i0nsepwxI"
88 glb_insn = True
89 elif glb_args.src_trace:
90 print("Intel PT Source Trace")
91 itrace = "i0nsepwxI"
92 glb_insn = True
93 glb_src = True
94 else:
95 print("Intel PT Branch Trace, Power Events, Event Trace and PTWRITE")
96 itrace = "bepwxI"
97 global glb_disassembler
98 try:
99 glb_disassembler = LibXED()
100 except:
101 glb_disassembler = None
102 perf_set_itrace_options(perf_script_context, itrace)
103
104def trace_end():
105 if glb_args.interleave:
106 flush_stashed_output()
107 print("End")
108
109def trace_unhandled(event_name, context, event_fields_dict):
110 print(' '.join(['%s=%s'%(k,str(v))for k,v in sorted(event_fields_dict.items())]))
111
112def stash_output():
113 global glb_stash_dict
114 global glb_output_pos
115 output_str = glb_output.getvalue()[glb_output_pos:]
116 n = len(output_str)
117 if n:
118 glb_output_pos += n
119 if glb_cpu not in glb_stash_dict:
120 glb_stash_dict[glb_cpu] = []
121 glb_stash_dict[glb_cpu].append(output_str)
122
123def flush_stashed_output():
124 global glb_stash_dict
125 while glb_stash_dict:
126 cpus = list(glb_stash_dict.keys())
127 # Output at most glb_args.interleave output strings per cpu
128 for cpu in cpus:
129 items = glb_stash_dict[cpu]
130 countdown = glb_args.interleave
131 while len(items) and countdown:
132 sys.stdout.write(items[0])
133 del items[0]
134 countdown -= 1
135 if not items:
136 del glb_stash_dict[cpu]
137
138def print_ptwrite(raw_buf):
139 data = struct.unpack_from("<IQ", raw_buf)
140 flags = data[0]
141 payload = data[1]
142 exact_ip = flags & 1
143 try:
144 s = payload.to_bytes(8, "little").decode("ascii").rstrip("\x00")
145 if not s.isprintable():
146 s = ""
147 except:
148 s = ""
149 print("IP: %u payload: %#x" % (exact_ip, payload), s, end=' ')
150
151def print_cbr(raw_buf):
152 data = struct.unpack_from("<BBBBII", raw_buf)
153 cbr = data[0]
154 f = (data[4] + 500) / 1000
155 p = ((cbr * 1000 / data[2]) + 5) / 10
156 print("%3u freq: %4u MHz (%3u%%)" % (cbr, f, p), end=' ')
157
158def print_mwait(raw_buf):
159 data = struct.unpack_from("<IQ", raw_buf)
160 payload = data[1]
161 hints = payload & 0xff
162 extensions = (payload >> 32) & 0x3
163 print("hints: %#x extensions: %#x" % (hints, extensions), end=' ')
164
165def print_pwre(raw_buf):
166 data = struct.unpack_from("<IQ", raw_buf)
167 payload = data[1]
168 hw = (payload >> 7) & 1
169 cstate = (payload >> 12) & 0xf
170 subcstate = (payload >> 8) & 0xf
171 print("hw: %u cstate: %u sub-cstate: %u" % (hw, cstate, subcstate),
172 end=' ')
173
174def print_exstop(raw_buf):
175 data = struct.unpack_from("<I", raw_buf)
176 flags = data[0]
177 exact_ip = flags & 1
178 print("IP: %u" % (exact_ip), end=' ')
179
180def print_pwrx(raw_buf):
181 data = struct.unpack_from("<IQ", raw_buf)
182 payload = data[1]
183 deepest_cstate = payload & 0xf
184 last_cstate = (payload >> 4) & 0xf
185 wake_reason = (payload >> 8) & 0xf
186 print("deepest cstate: %u last cstate: %u wake reason: %#x" %
187 (deepest_cstate, last_cstate, wake_reason), end=' ')
188
189def print_psb(raw_buf):
190 data = struct.unpack_from("<IQ", raw_buf)
191 offset = data[1]
192 print("offset: %#x" % (offset), end=' ')
193
194glb_cfe = ["", "INTR", "IRET", "SMI", "RSM", "SIPI", "INIT", "VMENTRY", "VMEXIT",
195 "VMEXIT_INTR", "SHUTDOWN", "", "UINT", "UIRET"] + [""] * 18
196glb_evd = ["", "PFA", "VMXQ", "VMXR"] + [""] * 60
197
198def print_evt(raw_buf):
199 data = struct.unpack_from("<BBH", raw_buf)
200 typ = data[0] & 0x1f
201 ip_flag = (data[0] & 0x80) >> 7
202 vector = data[1]
203 evd_cnt = data[2]
204 s = glb_cfe[typ]
205 if s:
206 print(" cfe: %s IP: %u vector: %u" % (s, ip_flag, vector), end=' ')
207 else:
208 print(" cfe: %u IP: %u vector: %u" % (typ, ip_flag, vector), end=' ')
209 pos = 4
210 for i in range(evd_cnt):
211 data = struct.unpack_from("<QQ", raw_buf)
212 et = data[0] & 0x3f
213 s = glb_evd[et]
214 if s:
215 print("%s: %#x" % (s, data[1]), end=' ')
216 else:
217 print("EVD_%u: %#x" % (et, data[1]), end=' ')
218
219def print_iflag(raw_buf):
220 data = struct.unpack_from("<IQ", raw_buf)
221 iflag = data[0] & 1
222 old_iflag = iflag ^ 1
223 via_branch = data[0] & 2
224 branch_ip = data[1]
225 if via_branch:
226 s = "via"
227 else:
228 s = "non"
229 print("IFLAG: %u->%u %s branch" % (old_iflag, iflag, s), end=' ')
230
231def common_start_str(comm, sample):
232 ts = sample["time"]
233 cpu = sample["cpu"]
234 pid = sample["pid"]
235 tid = sample["tid"]
236 if "machine_pid" in sample:
237 machine_pid = sample["machine_pid"]
238 vcpu = sample["vcpu"]
239 return "VM:%5d VCPU:%03d %16s %5u/%-5u [%03u] %9u.%09u " % (machine_pid, vcpu, comm, pid, tid, cpu, ts / 1000000000, ts %1000000000)
240 else:
241 return "%16s %5u/%-5u [%03u] %9u.%09u " % (comm, pid, tid, cpu, ts / 1000000000, ts %1000000000)
242
243def print_common_start(comm, sample, name):
244 flags_disp = get_optional_null(sample, "flags_disp")
245 # Unused fields:
246 # period = sample["period"]
247 # phys_addr = sample["phys_addr"]
248 # weight = sample["weight"]
249 # transaction = sample["transaction"]
250 # cpumode = get_optional_zero(sample, "cpumode")
251 print(common_start_str(comm, sample) + "%8s %21s" % (name, flags_disp), end=' ')
252
253def print_instructions_start(comm, sample):
254 if "x" in get_optional_null(sample, "flags"):
255 print(common_start_str(comm, sample) + "x", end=' ')
256 else:
257 print(common_start_str(comm, sample), end=' ')
258
259def disassem(insn, ip):
260 inst = glb_disassembler.Instruction()
261 glb_disassembler.SetMode(inst, 0) # Assume 64-bit
262 buf = create_string_buffer(64)
263 buf.value = insn
264 return glb_disassembler.DisassembleOne(inst, addressof(buf), len(insn), ip)
265
266def print_common_ip(param_dict, sample, symbol, dso):
267 ip = sample["ip"]
268 offs = get_offset(param_dict, "symoff")
269 if "cyc_cnt" in sample:
270 cyc_cnt = sample["cyc_cnt"]
271 insn_cnt = get_optional_zero(sample, "insn_cnt")
272 ipc_str = " IPC: %#.2f (%u/%u)" % (insn_cnt / cyc_cnt, insn_cnt, cyc_cnt)
273 else:
274 ipc_str = ""
275 if glb_insn and glb_disassembler is not None:
276 insn = perf_sample_insn(perf_script_context)
277 if insn and len(insn):
278 cnt, text = disassem(insn, ip)
279 byte_str = ("%x" % ip).rjust(16)
280 if sys.version_info.major >= 3:
281 for k in range(cnt):
282 byte_str += " %02x" % insn[k]
283 else:
284 for k in xrange(cnt):
285 byte_str += " %02x" % ord(insn[k])
286 print("%-40s %-30s" % (byte_str, text), end=' ')
287 print("%s%s (%s)" % (symbol, offs, dso), end=' ')
288 else:
289 print("%16x %s%s (%s)" % (ip, symbol, offs, dso), end=' ')
290 if "addr_correlates_sym" in sample:
291 addr = sample["addr"]
292 dso = get_optional(sample, "addr_dso")
293 symbol = get_optional(sample, "addr_symbol")
294 offs = get_offset(sample, "addr_symoff")
295 print("=> %x %s%s (%s)%s" % (addr, symbol, offs, dso, ipc_str))
296 else:
297 print(ipc_str)
298
299def print_srccode(comm, param_dict, sample, symbol, dso, with_insn):
300 ip = sample["ip"]
301 if symbol == "[unknown]":
302 start_str = common_start_str(comm, sample) + ("%x" % ip).rjust(16).ljust(40)
303 else:
304 offs = get_offset(param_dict, "symoff")
305 start_str = common_start_str(comm, sample) + (symbol + offs).ljust(40)
306
307 if with_insn and glb_insn and glb_disassembler is not None:
308 insn = perf_sample_insn(perf_script_context)
309 if insn and len(insn):
310 cnt, text = disassem(insn, ip)
311 start_str += text.ljust(30)
312
313 global glb_source_file_name
314 global glb_line_number
315 global glb_dso
316
317 source_file_name, line_number, source_line = perf_sample_srccode(perf_script_context)
318 if source_file_name:
319 if glb_line_number == line_number and glb_source_file_name == source_file_name:
320 src_str = ""
321 else:
322 if len(source_file_name) > 40:
323 src_file = ("..." + source_file_name[-37:]) + " "
324 else:
325 src_file = source_file_name.ljust(41)
326 if source_line is None:
327 src_str = src_file + str(line_number).rjust(4) + " <source not found>"
328 else:
329 src_str = src_file + str(line_number).rjust(4) + " " + source_line
330 glb_dso = None
331 elif dso == glb_dso:
332 src_str = ""
333 else:
334 src_str = dso
335 glb_dso = dso
336
337 glb_line_number = line_number
338 glb_source_file_name = source_file_name
339
340 print(start_str, src_str)
341
342def do_process_event(param_dict):
343 sample = param_dict["sample"]
344 raw_buf = param_dict["raw_buf"]
345 comm = param_dict["comm"]
346 name = param_dict["ev_name"]
347 # Unused fields:
348 # callchain = param_dict["callchain"]
349 # brstack = param_dict["brstack"]
350 # brstacksym = param_dict["brstacksym"]
351 # event_attr = param_dict["attr"]
352
353 # Symbol and dso info are not always resolved
354 dso = get_optional(param_dict, "dso")
355 symbol = get_optional(param_dict, "symbol")
356
357 cpu = sample["cpu"]
358 if cpu in glb_switch_str:
359 print(glb_switch_str[cpu])
360 del glb_switch_str[cpu]
361
362 if name.startswith("instructions"):
363 if glb_src:
364 print_srccode(comm, param_dict, sample, symbol, dso, True)
365 else:
366 print_instructions_start(comm, sample)
367 print_common_ip(param_dict, sample, symbol, dso)
368 elif name.startswith("branches"):
369 if glb_src:
370 print_srccode(comm, param_dict, sample, symbol, dso, False)
371 else:
372 print_common_start(comm, sample, name)
373 print_common_ip(param_dict, sample, symbol, dso)
374 elif name == "ptwrite":
375 print_common_start(comm, sample, name)
376 print_ptwrite(raw_buf)
377 print_common_ip(param_dict, sample, symbol, dso)
378 elif name == "cbr":
379 print_common_start(comm, sample, name)
380 print_cbr(raw_buf)
381 print_common_ip(param_dict, sample, symbol, dso)
382 elif name == "mwait":
383 print_common_start(comm, sample, name)
384 print_mwait(raw_buf)
385 print_common_ip(param_dict, sample, symbol, dso)
386 elif name == "pwre":
387 print_common_start(comm, sample, name)
388 print_pwre(raw_buf)
389 print_common_ip(param_dict, sample, symbol, dso)
390 elif name == "exstop":
391 print_common_start(comm, sample, name)
392 print_exstop(raw_buf)
393 print_common_ip(param_dict, sample, symbol, dso)
394 elif name == "pwrx":
395 print_common_start(comm, sample, name)
396 print_pwrx(raw_buf)
397 print_common_ip(param_dict, sample, symbol, dso)
398 elif name == "psb":
399 print_common_start(comm, sample, name)
400 print_psb(raw_buf)
401 print_common_ip(param_dict, sample, symbol, dso)
402 elif name == "evt":
403 print_common_start(comm, sample, name)
404 print_evt(raw_buf)
405 print_common_ip(param_dict, sample, symbol, dso)
406 elif name == "iflag":
407 print_common_start(comm, sample, name)
408 print_iflag(raw_buf)
409 print_common_ip(param_dict, sample, symbol, dso)
410 else:
411 print_common_start(comm, sample, name)
412 print_common_ip(param_dict, sample, symbol, dso)
413
414def interleave_events(param_dict):
415 global glb_cpu
416 global glb_time
417 global glb_output
418 global glb_output_pos
419
420 sample = param_dict["sample"]
421 glb_cpu = sample["cpu"]
422 ts = sample["time"]
423
424 if glb_time != ts:
425 glb_time = ts
426 flush_stashed_output()
427
428 glb_output_pos = 0
429 with contextlib.redirect_stdout(io.StringIO()) as glb_output:
430 do_process_event(param_dict)
431
432 stash_output()
433
434def process_event(param_dict):
435 try:
436 if glb_args.interleave:
437 interleave_events(param_dict)
438 else:
439 do_process_event(param_dict)
440 except broken_pipe_exception:
441 # Stop python printing broken pipe errors and traceback
442 sys.stdout = open(os.devnull, 'w')
443 sys.exit(1)
444
445def auxtrace_error(typ, code, cpu, pid, tid, ip, ts, msg, cpumode, *x):
446 if glb_args.interleave:
447 flush_stashed_output()
448 if len(x) >= 2 and x[0]:
449 machine_pid = x[0]
450 vcpu = x[1]
451 else:
452 machine_pid = 0
453 vcpu = -1
454 try:
455 if machine_pid:
456 print("VM:%5d VCPU:%03d %16s %5u/%-5u [%03u] %9u.%09u error type %u code %u: %s ip 0x%16x" %
457 (machine_pid, vcpu, "Trace error", pid, tid, cpu, ts / 1000000000, ts %1000000000, typ, code, msg, ip))
458 else:
459 print("%16s %5u/%-5u [%03u] %9u.%09u error type %u code %u: %s ip 0x%16x" %
460 ("Trace error", pid, tid, cpu, ts / 1000000000, ts %1000000000, typ, code, msg, ip))
461 except broken_pipe_exception:
462 # Stop python printing broken pipe errors and traceback
463 sys.stdout = open(os.devnull, 'w')
464 sys.exit(1)
465
466def context_switch(ts, cpu, pid, tid, np_pid, np_tid, machine_pid, out, out_preempt, *x):
467 if glb_args.interleave:
468 flush_stashed_output()
469 if out:
470 out_str = "Switch out "
471 else:
472 out_str = "Switch In "
473 if out_preempt:
474 preempt_str = "preempt"
475 else:
476 preempt_str = ""
477 if len(x) >= 2 and x[0]:
478 machine_pid = x[0]
479 vcpu = x[1]
480 else:
481 vcpu = None;
482 if machine_pid == -1:
483 machine_str = ""
484 elif vcpu is None:
485 machine_str = "machine PID %d" % machine_pid
486 else:
487 machine_str = "machine PID %d VCPU %d" % (machine_pid, vcpu)
488 switch_str = "%16s %5d/%-5d [%03u] %9u.%09u %5d/%-5d %s %s" % \
489 (out_str, pid, tid, cpu, ts / 1000000000, ts %1000000000, np_pid, np_tid, machine_str, preempt_str)
490 if glb_args.all_switch_events:
491 print(switch_str)
492 else:
493 global glb_switch_str
494 glb_switch_str[cpu] = switch_str