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
14 from __future__ import division, print_function
15
16 import io
17 import os
18 import sys
19 import struct
20 import argparse
21 import contextlib
22
23 from libxed import LibXED
24 from ctypes import create_string_buffer, addressof
25
26 sys.path.append(os.environ['PERF_EXEC_PATH'] + \
27 '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
28
29 from perf_trace_context import perf_set_itrace_options, \
30 perf_sample_insn, perf_sample_srccode
31
32 try:
33 broken_pipe_exception = BrokenPipeError
34 except:
35 broken_pipe_exception = IOError
36
37 glb_switch_str = {}
38 glb_insn = False
39 glb_disassembler = None
40 glb_src = False
41 glb_source_file_name = None
42 glb_line_number = None
43 glb_dso = None
44 glb_stash_dict = {}
45 glb_output = None
46 glb_output_pos = 0
47 glb_cpu = -1
48 glb_time = 0
49
50 def get_optional_null(perf_dict, field):
51 if field in perf_dict:
52 return perf_dict[field]
53 return ""
54
55 def get_optional_zero(perf_dict, field):
56 if field in perf_dict:
57 return perf_dict[field]
58 return 0
59
60 def get_optional_bytes(perf_dict, field):
61 if field in perf_dict:
62 return perf_dict[field]
63 return bytes()
64
65 def get_optional(perf_dict, field):
66 if field in perf_dict:
67 return perf_dict[field]
68 return "[unknown]"
69
70 def get_offset(perf_dict, field):
71 if field in perf_dict:
72 return "+%#x" % perf_dict[field]
73 return ""
74
75 def 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
104 def trace_end():
105 if glb_args.interleave:
106 flush_stashed_output()
107 print("End")
108
109 def 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
112 def 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
123 def 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
138 def 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
151 def 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
158 def 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
165 def 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
174 def 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
180 def 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
189 def print_psb(raw_buf):
190 data = struct.unpack_from("<IQ", raw_buf)
191 offset = data[1]
192 print("offset: %#x" % (offset), end=' ')
193
194 glb_cfe = ["", "INTR", "IRET", "SMI", "RSM", "SIPI", "INIT", "VMENTRY", "VMEXIT",
195 "VMEXIT_INTR", "SHUTDOWN", "", "UINT", "UIRET"] + [""] * 18
196 glb_evd = ["", "PFA", "VMXQ", "VMXR"] + [""] * 60
197
198 def 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
219 def 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
231 def 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
243 def 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
253 def 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
259 def 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
266 def 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
299 def 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
342 def 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
414 def 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
434 def 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
445 def 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
466 def 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
Linux® is a registered trademark of Linus Torvalds in the United States and other countries.
TOMOYO® is a registered trademark of NTT DATA CORPORATION.