diff options
Diffstat (limited to 'tools/perf/scripts/python/intel-pt-events.py')
| -rw-r--r-- | tools/perf/scripts/python/intel-pt-events.py | 426 |
1 files changed, 393 insertions, 33 deletions
diff --git a/tools/perf/scripts/python/intel-pt-events.py b/tools/perf/scripts/python/intel-pt-events.py index a73847c8f548..346c89bd16d6 100644 --- a/tools/perf/scripts/python/intel-pt-events.py +++ b/tools/perf/scripts/python/intel-pt-events.py @@ -1,5 +1,6 @@ -# intel-pt-events.py: Print Intel PT Power Events and PTWRITE -# Copyright (c) 2017, Intel Corporation. +# SPDX-License-Identifier: GPL-2.0 +# intel-pt-events.py: Print Intel PT Events including Power Events and PTWRITE +# Copyright (c) 2017-2021, Intel Corporation. # # This program is free software; you can redistribute it and/or modify it # under the terms and conditions of the GNU General Public License, @@ -10,34 +11,142 @@ # FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for # more details. -from __future__ import print_function +from __future__ import division, print_function +import io import os import sys import struct +import argparse +import contextlib + +from libxed import LibXED +from ctypes import create_string_buffer, addressof sys.path.append(os.environ['PERF_EXEC_PATH'] + \ '/scripts/python/Perf-Trace-Util/lib/Perf/Trace') -# These perf imports are not used at present -#from perf_trace_context import * -#from Core import * +from perf_trace_context import perf_set_itrace_options, \ + perf_sample_insn, perf_sample_srccode + +try: + broken_pipe_exception = BrokenPipeError +except: + broken_pipe_exception = IOError + +glb_switch_str = {} +glb_insn = False +glb_disassembler = None +glb_src = False +glb_source_file_name = None +glb_line_number = None +glb_dso = None +glb_stash_dict = {} +glb_output = None +glb_output_pos = 0 +glb_cpu = -1 +glb_time = 0 + +def get_optional_null(perf_dict, field): + if field in perf_dict: + return perf_dict[field] + return "" + +def get_optional_zero(perf_dict, field): + if field in perf_dict: + return perf_dict[field] + return 0 + +def get_optional_bytes(perf_dict, field): + if field in perf_dict: + return perf_dict[field] + return bytes() + +def get_optional(perf_dict, field): + if field in perf_dict: + return perf_dict[field] + return "[unknown]" + +def get_offset(perf_dict, field): + if field in perf_dict: + return "+%#x" % perf_dict[field] + return "" def trace_begin(): - print("Intel PT Power Events and PTWRITE") + ap = argparse.ArgumentParser(usage = "", add_help = False) + ap.add_argument("--insn-trace", action='store_true') + ap.add_argument("--src-trace", action='store_true') + ap.add_argument("--all-switch-events", action='store_true') + ap.add_argument("--interleave", type=int, nargs='?', const=4, default=0) + global glb_args + global glb_insn + global glb_src + glb_args = ap.parse_args() + if glb_args.insn_trace: + print("Intel PT Instruction Trace") + itrace = "i0nsepwxI" + glb_insn = True + elif glb_args.src_trace: + print("Intel PT Source Trace") + itrace = "i0nsepwxI" + glb_insn = True + glb_src = True + else: + print("Intel PT Branch Trace, Power Events, Event Trace and PTWRITE") + itrace = "bepwxI" + global glb_disassembler + try: + glb_disassembler = LibXED() + except: + glb_disassembler = None + perf_set_itrace_options(perf_script_context, itrace) def trace_end(): + if glb_args.interleave: + flush_stashed_output() print("End") def trace_unhandled(event_name, context, event_fields_dict): print(' '.join(['%s=%s'%(k,str(v))for k,v in sorted(event_fields_dict.items())])) +def stash_output(): + global glb_stash_dict + global glb_output_pos + output_str = glb_output.getvalue()[glb_output_pos:] + n = len(output_str) + if n: + glb_output_pos += n + if glb_cpu not in glb_stash_dict: + glb_stash_dict[glb_cpu] = [] + glb_stash_dict[glb_cpu].append(output_str) + +def flush_stashed_output(): + global glb_stash_dict + while glb_stash_dict: + cpus = list(glb_stash_dict.keys()) + # Output at most glb_args.interleave output strings per cpu + for cpu in cpus: + items = glb_stash_dict[cpu] + countdown = glb_args.interleave + while len(items) and countdown: + sys.stdout.write(items[0]) + del items[0] + countdown -= 1 + if not items: + del glb_stash_dict[cpu] + def print_ptwrite(raw_buf): data = struct.unpack_from("<IQ", raw_buf) flags = data[0] payload = data[1] exact_ip = flags & 1 - print("IP: %u payload: %#x" % (exact_ip, payload), end=' ') + try: + s = payload.to_bytes(8, "little").decode("ascii").rstrip("\x00") + if not s.isprintable(): + s = "" + except: + s = "" + print("IP: %u payload: %#x" % (exact_ip, payload), s, end=' ') def print_cbr(raw_buf): data = struct.unpack_from("<BBBBII", raw_buf) @@ -77,58 +186,309 @@ def print_pwrx(raw_buf): print("deepest cstate: %u last cstate: %u wake reason: %#x" % (deepest_cstate, last_cstate, wake_reason), end=' ') -def print_common_start(comm, sample, name): +def print_psb(raw_buf): + data = struct.unpack_from("<IQ", raw_buf) + offset = data[1] + print("offset: %#x" % (offset), end=' ') + +glb_cfe = ["", "INTR", "IRET", "SMI", "RSM", "SIPI", "INIT", "VMENTRY", "VMEXIT", + "VMEXIT_INTR", "SHUTDOWN", "", "UINT", "UIRET"] + [""] * 18 +glb_evd = ["", "PFA", "VMXQ", "VMXR"] + [""] * 60 + +def print_evt(raw_buf): + data = struct.unpack_from("<BBH", raw_buf) + typ = data[0] & 0x1f + ip_flag = (data[0] & 0x80) >> 7 + vector = data[1] + evd_cnt = data[2] + s = glb_cfe[typ] + if s: + print(" cfe: %s IP: %u vector: %u" % (s, ip_flag, vector), end=' ') + else: + print(" cfe: %u IP: %u vector: %u" % (typ, ip_flag, vector), end=' ') + pos = 4 + for i in range(evd_cnt): + data = struct.unpack_from("<QQ", raw_buf) + et = data[0] & 0x3f + s = glb_evd[et] + if s: + print("%s: %#x" % (s, data[1]), end=' ') + else: + print("EVD_%u: %#x" % (et, data[1]), end=' ') + +def print_iflag(raw_buf): + data = struct.unpack_from("<IQ", raw_buf) + iflag = data[0] & 1 + old_iflag = iflag ^ 1 + via_branch = data[0] & 2 + branch_ip = data[1] + if via_branch: + s = "via" + else: + s = "non" + print("IFLAG: %u->%u %s branch" % (old_iflag, iflag, s), end=' ') + +def common_start_str(comm, sample): ts = sample["time"] cpu = sample["cpu"] pid = sample["pid"] tid = sample["tid"] - print("%16s %5u/%-5u [%03u] %9u.%09u %7s:" % - (comm, pid, tid, cpu, ts / 1000000000, ts %1000000000, name), - end=' ') + if "machine_pid" in sample: + machine_pid = sample["machine_pid"] + vcpu = sample["vcpu"] + return "VM:%5d VCPU:%03d %16s %5u/%-5u [%03u] %9u.%09u " % (machine_pid, vcpu, comm, pid, tid, cpu, ts / 1000000000, ts %1000000000) + else: + return "%16s %5u/%-5u [%03u] %9u.%09u " % (comm, pid, tid, cpu, ts / 1000000000, ts %1000000000) + +def print_common_start(comm, sample, name): + flags_disp = get_optional_null(sample, "flags_disp") + # Unused fields: + # period = sample["period"] + # phys_addr = sample["phys_addr"] + # weight = sample["weight"] + # transaction = sample["transaction"] + # cpumode = get_optional_zero(sample, "cpumode") + print(common_start_str(comm, sample) + "%8s %21s" % (name, flags_disp), end=' ') + +def print_instructions_start(comm, sample): + if "x" in get_optional_null(sample, "flags"): + print(common_start_str(comm, sample) + "x", end=' ') + else: + print(common_start_str(comm, sample), end=' ') + +def disassem(insn, ip): + inst = glb_disassembler.Instruction() + glb_disassembler.SetMode(inst, 0) # Assume 64-bit + buf = create_string_buffer(64) + buf.value = insn + return glb_disassembler.DisassembleOne(inst, addressof(buf), len(insn), ip) + +def print_common_ip(param_dict, sample, symbol, dso): + ip = sample["ip"] + offs = get_offset(param_dict, "symoff") + if "cyc_cnt" in sample: + cyc_cnt = sample["cyc_cnt"] + insn_cnt = get_optional_zero(sample, "insn_cnt") + ipc_str = " IPC: %#.2f (%u/%u)" % (insn_cnt / cyc_cnt, insn_cnt, cyc_cnt) + else: + ipc_str = "" + if glb_insn and glb_disassembler is not None: + insn = perf_sample_insn(perf_script_context) + if insn and len(insn): + cnt, text = disassem(insn, ip) + byte_str = ("%x" % ip).rjust(16) + if sys.version_info.major >= 3: + for k in range(cnt): + byte_str += " %02x" % insn[k] + else: + for k in xrange(cnt): + byte_str += " %02x" % ord(insn[k]) + print("%-40s %-30s" % (byte_str, text), end=' ') + print("%s%s (%s)" % (symbol, offs, dso), end=' ') + else: + print("%16x %s%s (%s)" % (ip, symbol, offs, dso), end=' ') + if "addr_correlates_sym" in sample: + addr = sample["addr"] + dso = get_optional(sample, "addr_dso") + symbol = get_optional(sample, "addr_symbol") + offs = get_offset(sample, "addr_symoff") + print("=> %x %s%s (%s)%s" % (addr, symbol, offs, dso, ipc_str)) + else: + print(ipc_str) -def print_common_ip(sample, symbol, dso): +def print_srccode(comm, param_dict, sample, symbol, dso, with_insn): ip = sample["ip"] - print("%16x %s (%s)" % (ip, symbol, dso)) + if symbol == "[unknown]": + start_str = common_start_str(comm, sample) + ("%x" % ip).rjust(16).ljust(40) + else: + offs = get_offset(param_dict, "symoff") + start_str = common_start_str(comm, sample) + (symbol + offs).ljust(40) -def process_event(param_dict): - event_attr = param_dict["attr"] - sample = param_dict["sample"] - raw_buf = param_dict["raw_buf"] + if with_insn and glb_insn and glb_disassembler is not None: + insn = perf_sample_insn(perf_script_context) + if insn and len(insn): + cnt, text = disassem(insn, ip) + start_str += text.ljust(30) + + global glb_source_file_name + global glb_line_number + global glb_dso + + source_file_name, line_number, source_line = perf_sample_srccode(perf_script_context) + if source_file_name: + if glb_line_number == line_number and glb_source_file_name == source_file_name: + src_str = "" + else: + if len(source_file_name) > 40: + src_file = ("..." + source_file_name[-37:]) + " " + else: + src_file = source_file_name.ljust(41) + if source_line is None: + src_str = src_file + str(line_number).rjust(4) + " <source not found>" + else: + src_str = src_file + str(line_number).rjust(4) + " " + source_line + glb_dso = None + elif dso == glb_dso: + src_str = "" + else: + src_str = dso + glb_dso = dso + + glb_line_number = line_number + glb_source_file_name = source_file_name + + print(start_str, src_str) + +def do_process_event(param_dict): + sample = param_dict["sample"] + raw_buf = param_dict["raw_buf"] comm = param_dict["comm"] name = param_dict["ev_name"] + # Unused fields: + # callchain = param_dict["callchain"] + # brstack = param_dict["brstack"] + # brstacksym = param_dict["brstacksym"] + # event_attr = param_dict["attr"] # Symbol and dso info are not always resolved - if "dso" in param_dict: - dso = param_dict["dso"] - else: - dso = "[unknown]" + dso = get_optional(param_dict, "dso") + symbol = get_optional(param_dict, "symbol") - if "symbol" in param_dict: - symbol = param_dict["symbol"] - else: - symbol = "[unknown]" + cpu = sample["cpu"] + if cpu in glb_switch_str: + print(glb_switch_str[cpu]) + del glb_switch_str[cpu] - if name == "ptwrite": + if name.startswith("instructions"): + if glb_src: + print_srccode(comm, param_dict, sample, symbol, dso, True) + else: + print_instructions_start(comm, sample) + print_common_ip(param_dict, sample, symbol, dso) + elif name.startswith("branches"): + if glb_src: + print_srccode(comm, param_dict, sample, symbol, dso, False) + else: + print_common_start(comm, sample, name) + print_common_ip(param_dict, sample, symbol, dso) + elif name == "ptwrite": print_common_start(comm, sample, name) print_ptwrite(raw_buf) - print_common_ip(sample, symbol, dso) + print_common_ip(param_dict, sample, symbol, dso) elif name == "cbr": print_common_start(comm, sample, name) print_cbr(raw_buf) - print_common_ip(sample, symbol, dso) + print_common_ip(param_dict, sample, symbol, dso) elif name == "mwait": print_common_start(comm, sample, name) print_mwait(raw_buf) - print_common_ip(sample, symbol, dso) + print_common_ip(param_dict, sample, symbol, dso) elif name == "pwre": print_common_start(comm, sample, name) print_pwre(raw_buf) - print_common_ip(sample, symbol, dso) + print_common_ip(param_dict, sample, symbol, dso) elif name == "exstop": print_common_start(comm, sample, name) print_exstop(raw_buf) - print_common_ip(sample, symbol, dso) + print_common_ip(param_dict, sample, symbol, dso) elif name == "pwrx": print_common_start(comm, sample, name) print_pwrx(raw_buf) - print_common_ip(sample, symbol, dso) + print_common_ip(param_dict, sample, symbol, dso) + elif name == "psb": + print_common_start(comm, sample, name) + print_psb(raw_buf) + print_common_ip(param_dict, sample, symbol, dso) + elif name == "evt": + print_common_start(comm, sample, name) + print_evt(raw_buf) + print_common_ip(param_dict, sample, symbol, dso) + elif name == "iflag": + print_common_start(comm, sample, name) + print_iflag(raw_buf) + print_common_ip(param_dict, sample, symbol, dso) + else: + print_common_start(comm, sample, name) + print_common_ip(param_dict, sample, symbol, dso) + +def interleave_events(param_dict): + global glb_cpu + global glb_time + global glb_output + global glb_output_pos + + sample = param_dict["sample"] + glb_cpu = sample["cpu"] + ts = sample["time"] + + if glb_time != ts: + glb_time = ts + flush_stashed_output() + + glb_output_pos = 0 + with contextlib.redirect_stdout(io.StringIO()) as glb_output: + do_process_event(param_dict) + + stash_output() + +def process_event(param_dict): + try: + if glb_args.interleave: + interleave_events(param_dict) + else: + do_process_event(param_dict) + except broken_pipe_exception: + # Stop python printing broken pipe errors and traceback + sys.stdout = open(os.devnull, 'w') + sys.exit(1) + +def auxtrace_error(typ, code, cpu, pid, tid, ip, ts, msg, cpumode, *x): + if glb_args.interleave: + flush_stashed_output() + if len(x) >= 2 and x[0]: + machine_pid = x[0] + vcpu = x[1] + else: + machine_pid = 0 + vcpu = -1 + try: + if machine_pid: + print("VM:%5d VCPU:%03d %16s %5u/%-5u [%03u] %9u.%09u error type %u code %u: %s ip 0x%16x" % + (machine_pid, vcpu, "Trace error", pid, tid, cpu, ts / 1000000000, ts %1000000000, typ, code, msg, ip)) + else: + print("%16s %5u/%-5u [%03u] %9u.%09u error type %u code %u: %s ip 0x%16x" % + ("Trace error", pid, tid, cpu, ts / 1000000000, ts %1000000000, typ, code, msg, ip)) + except broken_pipe_exception: + # Stop python printing broken pipe errors and traceback + sys.stdout = open(os.devnull, 'w') + sys.exit(1) + +def context_switch(ts, cpu, pid, tid, np_pid, np_tid, machine_pid, out, out_preempt, *x): + if glb_args.interleave: + flush_stashed_output() + if out: + out_str = "Switch out " + else: + out_str = "Switch In " + if out_preempt: + preempt_str = "preempt" + else: + preempt_str = "" + if len(x) >= 2 and x[0]: + machine_pid = x[0] + vcpu = x[1] + else: + vcpu = None; + if machine_pid == -1: + machine_str = "" + elif vcpu is None: + machine_str = "machine PID %d" % machine_pid + else: + machine_str = "machine PID %d VCPU %d" % (machine_pid, vcpu) + switch_str = "%16s %5d/%-5d [%03u] %9u.%09u %5d/%-5d %s %s" % \ + (out_str, pid, tid, cpu, ts / 1000000000, ts %1000000000, np_pid, np_tid, machine_str, preempt_str) + if glb_args.all_switch_events: + print(switch_str) + else: + global glb_switch_str + glb_switch_str[cpu] = switch_str |