tools/perf/scripts/python/intel-pt-events.py

   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 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         event_attr = param_dict["attr"]
 344         sample     = param_dict["sample"]
 345         raw_buf    = param_dict["raw_buf"]
 346         comm       = param_dict["comm"]
 347         name       = param_dict["ev_name"]
 348         # Unused fields:
 349         # callchain  = param_dict["callchain"]
 350         # brstack    = param_dict["brstack"]
 351         # brstacksym = param_dict["brstacksym"]
 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[0:12] == "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[0:8] == "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