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 495