scripts/python/intel-pt-events.py

0001 # SPDX-License-Identifier: GPL-2.0
0002 # intel-pt-events.py: Print Intel PT Events including Power Events and PTWRITE
0003 # Copyright (c) 2017-2021, Intel Corporation.
0004 #
0005 # This program is free software; you can redistribute it and/or modify it
0006 # under the terms and conditions of the GNU General Public License,
0007 # version 2, as published by the Free Software Foundation.
0008 #
0009 # This program is distributed in the hope it will be useful, but WITHOUT
0010 # ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
0011 # FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License for
0012 # more details.
0013
0014 from __future__ import print_function
0015
0016 import os
0017 import sys
0018 import struct
0019 import argparse
0020
0021 from libxed import LibXED
0022 from ctypes import create_string_buffer, addressof
0023
0024 sys.path.append(os.environ['PERF_EXEC_PATH'] + \
0025     '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
0026
0027 from perf_trace_context import perf_set_itrace_options, \
0028     perf_sample_insn, perf_sample_srccode
0029
0030 try:
0031     broken_pipe_exception = BrokenPipeError
0032 except:
0033     broken_pipe_exception = IOError
0034
0035 glb_switch_str      = {}
0036 glb_insn        = False
0037 glb_disassembler    = None
0038 glb_src         = False
0039 glb_source_file_name    = None
0040 glb_line_number     = None
0041 glb_dso         = None
0042
0043 def get_optional_null(perf_dict, field):
0044     if field in perf_dict:
0045         return perf_dict[field]
0046     return ""
0047
0048 def get_optional_zero(perf_dict, field):
0049     if field in perf_dict:
0050         return perf_dict[field]
0051     return 0
0052
0053 def get_optional_bytes(perf_dict, field):
0054     if field in perf_dict:
0055         return perf_dict[field]
0056     return bytes()
0057
0058 def get_optional(perf_dict, field):
0059     if field in perf_dict:
0060         return perf_dict[field]
0061     return "[unknown]"
0062
0063 def get_offset(perf_dict, field):
0064     if field in perf_dict:
0065         return "+%#x" % perf_dict[field]
0066     return ""
0067
0068 def trace_begin():
0069     ap = argparse.ArgumentParser(usage = "", add_help = False)
0070     ap.add_argument("--insn-trace", action='store_true')
0071     ap.add_argument("--src-trace", action='store_true')
0072     ap.add_argument("--all-switch-events", action='store_true')
0073     global glb_args
0074     global glb_insn
0075     global glb_src
0076     glb_args = ap.parse_args()
0077     if glb_args.insn_trace:
0078         print("Intel PT Instruction Trace")
0079         itrace = "i0nsepwxI"
0080         glb_insn = True
0081     elif glb_args.src_trace:
0082         print("Intel PT Source Trace")
0083         itrace = "i0nsepwxI"
0084         glb_insn = True
0085         glb_src = True
0086     else:
0087         print("Intel PT Branch Trace, Power Events, Event Trace and PTWRITE")
0088         itrace = "bepwxI"
0089     global glb_disassembler
0090     try:
0091         glb_disassembler = LibXED()
0092     except:
0093         glb_disassembler = None
0094     perf_set_itrace_options(perf_script_context, itrace)
0095
0096 def trace_end():
0097     print("End")
0098
0099 def trace_unhandled(event_name, context, event_fields_dict):
0100         print(' '.join(['%s=%s'%(k,str(v))for k,v in sorted(event_fields_dict.items())]))
0101
0102 def print_ptwrite(raw_buf):
0103     data = struct.unpack_from("<IQ", raw_buf)
0104     flags = data[0]
0105     payload = data[1]
0106     exact_ip = flags & 1
0107     try:
0108         s = payload.to_bytes(8, "little").decode("ascii").rstrip("\x00")
0109         if not s.isprintable():
0110             s = ""
0111     except:
0112         s = ""
0113     print("IP: %u payload: %#x" % (exact_ip, payload), s, end=' ')
0114
0115 def print_cbr(raw_buf):
0116     data = struct.unpack_from("<BBBBII", raw_buf)
0117     cbr = data[0]
0118     f = (data[4] + 500) / 1000
0119     p = ((cbr * 1000 / data[2]) + 5) / 10
0120     print("%3u  freq: %4u MHz  (%3u%%)" % (cbr, f, p), end=' ')
0121
0122 def print_mwait(raw_buf):
0123     data = struct.unpack_from("<IQ", raw_buf)
0124     payload = data[1]
0125     hints = payload & 0xff
0126     extensions = (payload >> 32) & 0x3
0127     print("hints: %#x extensions: %#x" % (hints, extensions), end=' ')
0128
0129 def print_pwre(raw_buf):
0130     data = struct.unpack_from("<IQ", raw_buf)
0131     payload = data[1]
0132     hw = (payload >> 7) & 1
0133     cstate = (payload >> 12) & 0xf
0134     subcstate = (payload >> 8) & 0xf
0135     print("hw: %u cstate: %u sub-cstate: %u" % (hw, cstate, subcstate),
0136         end=' ')
0137
0138 def print_exstop(raw_buf):
0139     data = struct.unpack_from("<I", raw_buf)
0140     flags = data[0]
0141     exact_ip = flags & 1
0142     print("IP: %u" % (exact_ip), end=' ')
0143
0144 def print_pwrx(raw_buf):
0145     data = struct.unpack_from("<IQ", raw_buf)
0146     payload = data[1]
0147     deepest_cstate = payload & 0xf
0148     last_cstate = (payload >> 4) & 0xf
0149     wake_reason = (payload >> 8) & 0xf
0150     print("deepest cstate: %u last cstate: %u wake reason: %#x" %
0151         (deepest_cstate, last_cstate, wake_reason), end=' ')
0152
0153 def print_psb(raw_buf):
0154     data = struct.unpack_from("<IQ", raw_buf)
0155     offset = data[1]
0156     print("offset: %#x" % (offset), end=' ')
0157
0158 glb_cfe = ["", "INTR", "IRET", "SMI", "RSM", "SIPI", "INIT", "VMENTRY", "VMEXIT",
0159         "VMEXIT_INTR", "SHUTDOWN", "", "UINT", "UIRET"] + [""] * 18
0160 glb_evd = ["", "PFA", "VMXQ", "VMXR"] + [""] * 60
0161
0162 def print_evt(raw_buf):
0163     data = struct.unpack_from("<BBH", raw_buf)
0164     typ = data[0] & 0x1f
0165     ip_flag = (data[0] & 0x80) >> 7
0166     vector = data[1]
0167     evd_cnt = data[2]
0168     s = glb_cfe[typ]
0169     if s:
0170         print(" cfe: %s IP: %u vector: %u" % (s, ip_flag, vector), end=' ')
0171     else:
0172         print(" cfe: %u IP: %u vector: %u" % (typ, ip_flag, vector), end=' ')
0173     pos = 4
0174     for i in range(evd_cnt):
0175         data = struct.unpack_from("<QQ", raw_buf)
0176         et = data[0] & 0x3f
0177         s = glb_evd[et]
0178         if s:
0179             print("%s: %#x" % (s, data[1]), end=' ')
0180         else:
0181             print("EVD_%u: %#x" % (et, data[1]), end=' ')
0182
0183 def print_iflag(raw_buf):
0184     data = struct.unpack_from("<IQ", raw_buf)
0185     iflag = data[0] & 1
0186     old_iflag = iflag ^ 1
0187     via_branch = data[0] & 2
0188     branch_ip = data[1]
0189     if via_branch:
0190         s = "via"
0191     else:
0192         s = "non"
0193     print("IFLAG: %u->%u %s branch" % (old_iflag, iflag, s), end=' ')
0194
0195 def common_start_str(comm, sample):
0196     ts = sample["time"]
0197     cpu = sample["cpu"]
0198     pid = sample["pid"]
0199     tid = sample["tid"]
0200     if "machine_pid" in sample:
0201         machine_pid = sample["machine_pid"]
0202         vcpu = sample["vcpu"]
0203         return "VM:%5d VCPU:%03d %16s %5u/%-5u [%03u] %9u.%09u  " % (machine_pid, vcpu, comm, pid, tid, cpu, ts / 1000000000, ts %1000000000)
0204     else:
0205         return "%16s %5u/%-5u [%03u] %9u.%09u  " % (comm, pid, tid, cpu, ts / 1000000000, ts %1000000000)
0206
0207 def print_common_start(comm, sample, name):
0208     flags_disp = get_optional_null(sample, "flags_disp")
0209     # Unused fields:
0210     # period      = sample["period"]
0211     # phys_addr   = sample["phys_addr"]
0212     # weight      = sample["weight"]
0213     # transaction = sample["transaction"]
0214     # cpumode     = get_optional_zero(sample, "cpumode")
0215     print(common_start_str(comm, sample) + "%8s  %21s" % (name, flags_disp), end=' ')
0216
0217 def print_instructions_start(comm, sample):
0218     if "x" in get_optional_null(sample, "flags"):
0219         print(common_start_str(comm, sample) + "x", end=' ')
0220     else:
0221         print(common_start_str(comm, sample), end='  ')
0222
0223 def disassem(insn, ip):
0224     inst = glb_disassembler.Instruction()
0225     glb_disassembler.SetMode(inst, 0) # Assume 64-bit
0226     buf = create_string_buffer(64)
0227     buf.value = insn
0228     return glb_disassembler.DisassembleOne(inst, addressof(buf), len(insn), ip)
0229
0230 def print_common_ip(param_dict, sample, symbol, dso):
0231     ip   = sample["ip"]
0232     offs = get_offset(param_dict, "symoff")
0233     if "cyc_cnt" in sample:
0234         cyc_cnt = sample["cyc_cnt"]
0235         insn_cnt = get_optional_zero(sample, "insn_cnt")
0236         ipc_str = "  IPC: %#.2f (%u/%u)" % (insn_cnt / cyc_cnt, insn_cnt, cyc_cnt)
0237     else:
0238         ipc_str = ""
0239     if glb_insn and glb_disassembler is not None:
0240         insn = perf_sample_insn(perf_script_context)
0241         if insn and len(insn):
0242             cnt, text = disassem(insn, ip)
0243             byte_str = ("%x" % ip).rjust(16)
0244             if sys.version_info.major >= 3:
0245                 for k in range(cnt):
0246                     byte_str += " %02x" % insn[k]
0247             else:
0248                 for k in xrange(cnt):
0249                     byte_str += " %02x" % ord(insn[k])
0250             print("%-40s  %-30s" % (byte_str, text), end=' ')
0251         print("%s%s (%s)" % (symbol, offs, dso), end=' ')
0252     else:
0253         print("%16x %s%s (%s)" % (ip, symbol, offs, dso), end=' ')
0254     if "addr_correlates_sym" in sample:
0255         addr   = sample["addr"]
0256         dso    = get_optional(sample, "addr_dso")
0257         symbol = get_optional(sample, "addr_symbol")
0258         offs   = get_offset(sample, "addr_symoff")
0259         print("=> %x %s%s (%s)%s" % (addr, symbol, offs, dso, ipc_str))
0260     else:
0261         print(ipc_str)
0262
0263 def print_srccode(comm, param_dict, sample, symbol, dso, with_insn):
0264     ip = sample["ip"]
0265     if symbol == "[unknown]":
0266         start_str = common_start_str(comm, sample) + ("%x" % ip).rjust(16).ljust(40)
0267     else:
0268         offs = get_offset(param_dict, "symoff")
0269         start_str = common_start_str(comm, sample) + (symbol + offs).ljust(40)
0270
0271     if with_insn and glb_insn and glb_disassembler is not None:
0272         insn = perf_sample_insn(perf_script_context)
0273         if insn and len(insn):
0274             cnt, text = disassem(insn, ip)
0275         start_str += text.ljust(30)
0276
0277     global glb_source_file_name
0278     global glb_line_number
0279     global glb_dso
0280
0281     source_file_name, line_number, source_line = perf_sample_srccode(perf_script_context)
0282     if source_file_name:
0283         if glb_line_number == line_number and glb_source_file_name == source_file_name:
0284             src_str = ""
0285         else:
0286             if len(source_file_name) > 40:
0287                 src_file = ("..." + source_file_name[-37:]) + " "
0288             else:
0289                 src_file = source_file_name.ljust(41)
0290             if source_line is None:
0291                 src_str = src_file + str(line_number).rjust(4) + " <source not found>"
0292             else:
0293                 src_str = src_file + str(line_number).rjust(4) + " " + source_line
0294         glb_dso = None
0295     elif dso == glb_dso:
0296         src_str = ""
0297     else:
0298         src_str = dso
0299         glb_dso = dso
0300
0301     glb_line_number = line_number
0302     glb_source_file_name = source_file_name
0303
0304     print(start_str, src_str)
0305
0306 def do_process_event(param_dict):
0307     event_attr = param_dict["attr"]
0308     sample     = param_dict["sample"]
0309     raw_buf    = param_dict["raw_buf"]
0310     comm       = param_dict["comm"]
0311     name       = param_dict["ev_name"]
0312     # Unused fields:
0313     # callchain  = param_dict["callchain"]
0314     # brstack    = param_dict["brstack"]
0315     # brstacksym = param_dict["brstacksym"]
0316
0317     # Symbol and dso info are not always resolved
0318     dso    = get_optional(param_dict, "dso")
0319     symbol = get_optional(param_dict, "symbol")
0320
0321     cpu = sample["cpu"]
0322     if cpu in glb_switch_str:
0323         print(glb_switch_str[cpu])
0324         del glb_switch_str[cpu]
0325
0326     if name[0:12] == "instructions":
0327         if glb_src:
0328             print_srccode(comm, param_dict, sample, symbol, dso, True)
0329         else:
0330             print_instructions_start(comm, sample)
0331             print_common_ip(param_dict, sample, symbol, dso)
0332     elif name[0:8] == "branches":
0333         if glb_src:
0334             print_srccode(comm, param_dict, sample, symbol, dso, False)
0335         else:
0336             print_common_start(comm, sample, name)
0337             print_common_ip(param_dict, sample, symbol, dso)
0338     elif name == "ptwrite":
0339         print_common_start(comm, sample, name)
0340         print_ptwrite(raw_buf)
0341         print_common_ip(param_dict, sample, symbol, dso)
0342     elif name == "cbr":
0343         print_common_start(comm, sample, name)
0344         print_cbr(raw_buf)
0345         print_common_ip(param_dict, sample, symbol, dso)
0346     elif name == "mwait":
0347         print_common_start(comm, sample, name)
0348         print_mwait(raw_buf)
0349         print_common_ip(param_dict, sample, symbol, dso)
0350     elif name == "pwre":
0351         print_common_start(comm, sample, name)
0352         print_pwre(raw_buf)
0353         print_common_ip(param_dict, sample, symbol, dso)
0354     elif name == "exstop":
0355         print_common_start(comm, sample, name)
0356         print_exstop(raw_buf)
0357         print_common_ip(param_dict, sample, symbol, dso)
0358     elif name == "pwrx":
0359         print_common_start(comm, sample, name)
0360         print_pwrx(raw_buf)
0361         print_common_ip(param_dict, sample, symbol, dso)
0362     elif name == "psb":
0363         print_common_start(comm, sample, name)
0364         print_psb(raw_buf)
0365         print_common_ip(param_dict, sample, symbol, dso)
0366     elif name == "evt":
0367         print_common_start(comm, sample, name)
0368         print_evt(raw_buf)
0369         print_common_ip(param_dict, sample, symbol, dso)
0370     elif name == "iflag":
0371         print_common_start(comm, sample, name)
0372         print_iflag(raw_buf)
0373         print_common_ip(param_dict, sample, symbol, dso)
0374     else:
0375         print_common_start(comm, sample, name)
0376         print_common_ip(param_dict, sample, symbol, dso)
0377
0378 def process_event(param_dict):
0379     try:
0380         do_process_event(param_dict)
0381     except broken_pipe_exception:
0382         # Stop python printing broken pipe errors and traceback
0383         sys.stdout = open(os.devnull, 'w')
0384         sys.exit(1)
0385
0386 def auxtrace_error(typ, code, cpu, pid, tid, ip, ts, msg, cpumode, *x):
0387     if len(x) >= 2 and x[0]:
0388         machine_pid = x[0]
0389         vcpu = x[1]
0390     else:
0391         machine_pid = 0
0392         vcpu = -1
0393     try:
0394         if machine_pid:
0395             print("VM:%5d VCPU:%03d %16s %5u/%-5u [%03u] %9u.%09u  error type %u code %u: %s ip 0x%16x" %
0396                 (machine_pid, vcpu, "Trace error", pid, tid, cpu, ts / 1000000000, ts %1000000000, typ, code, msg, ip))
0397         else:
0398             print("%16s %5u/%-5u [%03u] %9u.%09u  error type %u code %u: %s ip 0x%16x" %
0399                 ("Trace error", pid, tid, cpu, ts / 1000000000, ts %1000000000, typ, code, msg, ip))
0400     except broken_pipe_exception:
0401         # Stop python printing broken pipe errors and traceback
0402         sys.stdout = open(os.devnull, 'w')
0403         sys.exit(1)
0404
0405 def context_switch(ts, cpu, pid, tid, np_pid, np_tid, machine_pid, out, out_preempt, *x):
0406     if out:
0407         out_str = "Switch out "
0408     else:
0409         out_str = "Switch In  "
0410     if out_preempt:
0411         preempt_str = "preempt"
0412     else:
0413         preempt_str = ""
0414     if len(x) >= 2 and x[0]:
0415         machine_pid = x[0]
0416         vcpu = x[1]
0417     else:
0418         vcpu = None;
0419     if machine_pid == -1:
0420         machine_str = ""
0421     elif vcpu is None:
0422         machine_str = "machine PID %d" % machine_pid
0423     else:
0424         machine_str = "machine PID %d VCPU %d" % (machine_pid, vcpu)
0425     switch_str = "%16s %5d/%-5d [%03u] %9u.%09u %5d/%-5d %s %s" % \
0426         (out_str, pid, tid, cpu, ts / 1000000000, ts %1000000000, np_pid, np_tid, machine_str, preempt_str)
0427     if glb_args.all_switch_events:
0428         print(switch_str)
0429     else:
0430         global glb_switch_str
0431         glb_switch_str[cpu] = switch_str