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 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	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
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