tools: acrntrace: Add new tool acrntrace_format

acrntrace_format.py is used for parsing raw trace data to human-readable file on
given format. A sample format file for acrntrace predefined trace events is available
in tools/acrntrace/scripts/formats in acrn source tree.

Signed-off-by: Kaige Fu <kaige.fu@intel.com>
Reviewed-by: Yan, Like <like.yan@intel.com>
Reviewed-by: Geoffroy Van Cutsem <geoffroy.vancutsem@intel.com>
This commit is contained in:
Kaige Fu 2018-06-25 22:40:14 +08:00 committed by lijinxia
parent a35a650f5f
commit 0d9b163875
2 changed files with 176 additions and 0 deletions

View File

@ -0,0 +1,154 @@
#!/usr/bin/python3
# -*- coding: UTF-8 -*-
import os
import re
import sys
import string
import signal
import struct
import getopt
def usage():
print >> sys.stderr, \
"""
Usage:
acrntrace_format.py [options] [formats] [trace_data]
[options]
-h: print this message
Parses trace_data in binary format generated by acrntrace and
reformats it according to the rules in the [formats] file.
The rules in formats should have the format ({ and } show grouping
and are not part of the syntax):
{event_id}{whitespace}{text format string}
The textual format string may include format specifiers, such as
%(cpu)d, %(tsc)d, %(event)d, %(1)d, %(2)d, ....
The 'd' format specifier outputs in decimal, alternatively 'x' will
output in hexadecimal and 'o' will output in octal.
These respectively correspond to the CPU number (cpu), timestamp
counter (tsc), event ID (event) and the data logged in the trace file.
There can be only one such rule for each type of event.
"""
def read_format(format_file):
formats = {}
fd = open(format_file)
reg = re.compile('(\S+)\s+(\S.*)')
while True:
line = fd.readline()
if not line:
break
if line[0] == '#' or line[0] == '\n':
continue
m = reg.match(line)
if not m: print >> sys.stderr, "Wrong format file"; sys.exit(1)
formats[str(eval(m.group(1)))] = m.group(2)
return formats
exit = 0
# structure of trace data (as output by acrntrace)
# TSC(Q) HDR(Q) D1 D2 ...
# HDR consists of event:48:, n_data:8:, cpu:8:
# event means Event ID
# n_data means number of data in trace entry (like D1, D2, ...)
# cpu means cpu id this trace entry belong to
TSCREC = "Q"
HDRREC = "Q"
D2REC = "QQ"
D4REC = "IIII"
def main_loop(formats, fd):
global exit
i = 0
while not exit:
try:
i = i + 1
line = fd.read(struct.calcsize(TSCREC))
if not line:
break
tsc = struct.unpack(TSCREC, line)[0]
line = fd.read(struct.calcsize(HDRREC))
if not line:
break
event = struct.unpack(HDRREC, line)[0]
n_data = event >> 48 & 0xff
cpu = event >> 56
event = event & 0xffffffffffff
d1 = 0
d2 = 0
d3 = 0
d4 = 0
if n_data == 2:
line = fd.read(struct.calcsize(D2REC))
if not line:
break
(d1, d2) = struct.unpack(D2REC, line)
if n_data == 4:
line = fd.read(struct.calcsize(D4REC))
if not line:
break
(d1, d2, d3, d4) = struct.unpack(D4REC, line)
args = {'cpu' : cpu,
'tsc' : tsc,
'event' : event,
'1' : d1,
'2' : d2,
'3' : d3,
'4' : d4 }
try:
if str(event) in formats.keys():
print (formats[str(event)] % args)
except TypeError:
if str(event) in formats.key():
print (formats[str(event)])
print (args)
except struct.error:
sys.exit()
def main(argv):
try:
opts, arg = getopt.getopt(sys.argv[1:], "h")
for opt in opts:
if opt[0] == '-h':
usage()
sys.exit()
except getopt.GetoptError:
usage()
sys.exit(1)
try:
formats = read_format(arg[0])
fd = open(arg[1], 'rb')
except IOError:
sys.exit(1)
main_loop(formats, fd)
if __name__ == "__main__":
main(sys.argv[1:])

View File

@ -0,0 +1,22 @@
# For TRACE_2L
0x00000001 CPU%(cpu)d 0x%(event)016x %(tsc)d timer added [fire_tsc = 0x%(1)08x]
0x00000002 CPU%(cpu)d 0x%(event)016x %(tsc)d timer pickup [fire tsc = 0x%(1)08x]
0x00000010 CPU%(cpu)d 0x%(event)016x %(tsc)d vmexit [exit reason = 0x%(1)08x, rIP = 0x%(2)08x]
0x00000011 CPU%(cpu)d 0x%(event)016x %(tsc)d vmenter
0x00010001 CPU%(cpu)d 0x%(event)016x %(tsc)d external intr [vector = 0x%(1)08x]
0x00010002 CPU%(cpu)d 0x%(event)016x %(tsc)d intr window
0x00010004 CPU%(cpu)d 0x%(event)016x %(tsc)d cpuid [vcpuid = %(1)d]
0x00010012 CPU%(cpu)d 0x%(event)016x %(tsc)d hypercall [vmid = %(1)d, hypercall id = 0x%(2)08x]
0x0001001C CPU%(cpu)d 0x%(event)016x %(tsc)d cr access [access type = 0x%(1)08x, cr num = %(2)d]
0x0001001F CPU%(cpu)d 0x%(event)016x %(tsc)d read msr [msr = 0x%(1)08x, val = 0x%(2)016x]
0x00010020 CPU%(cpu)d 0x%(event)016x %(tsc)d write msr [msr = 0x%(1)08x, val = 0x%(2)016x]
0x00010030 CPU%(cpu)d 0x%(event)016x %(tsc)d ept violation [exit qual = 0x%(1)08x, gpa = 0x%(2)08x]
0x00010031 CPU%(cpu)d 0x%(event)016x %(tsc)d ept misconfiguration
0x00010038 CPU%(cpu)d 0x%(event)016x %(tsc)d apicv write [offset = 0x%(1)08x]
0x00010039 CPU%(cpu)d 0x%(event)016x %(tsc)d apicv access [qual = 0x%(1)08x, vlapic = 0x%(2)08x]
0x0001003A CPU%(cpu)d 0x%(event)016x %(tsc)d apicv virt EOI [vector = 0x%(1)08x]
0x00020000 CPU%(cpu)d 0x%(event)016x %(tsc)d vmexit unhandled [exit reason = 0x%(1)08x]
# For TRACE_4I
0x0001001E CPU%(cpu)d 0x%(event)016x %(tsc)d IO instruction [port = %(1)d, direction = %(2)d, sz = %(3)d, cur_context_idx = %(4)d]
0x00010000 CPU%(cpu)d 0x%(event)016x %(tsc)d exception or nmi [vector = 0x%(1)08x, err = %(2)d, d3 = %(1)d, d4 = %(2)d]