Fixes for GDB remote packet disassembler:

- Add latency timings to GDB packet log summary if timestamps are on log
- Add the ability to plot the latencies for each packet type with --plot
- Don't crash the script when target xml register info is in wierd format

llvm-svn: 343243
This commit is contained in:
Greg Clayton 2018-09-27 17:55:36 +00:00
parent 95c23f6643
commit 141f208e12
1 changed files with 131 additions and 59 deletions

View File

@ -685,32 +685,33 @@ def rsp_qXfer(options, cmd, cmd_args, rsp):
if extension == '.xml': if extension == '.xml':
response = Packet(rsp) response = Packet(rsp)
xml_string = response.get_hex_ascii_str() xml_string = response.get_hex_ascii_str()
ch = xml_string[0] if xml_string:
if ch == 'l': ch = xml_string[0]
xml_string = xml_string[1:] if ch == 'l':
xml_root = ET.fromstring(xml_string) xml_string = xml_string[1:]
for reg_element in xml_root.findall("./feature/reg"): xml_root = ET.fromstring(xml_string)
if not 'value_regnums' in reg_element.attrib: for reg_element in xml_root.findall("./feature/reg"):
reg_info = RegisterInfo([]) if not 'value_regnums' in reg_element.attrib:
if 'name' in reg_element.attrib: reg_info = RegisterInfo([])
reg_info.info[ if 'name' in reg_element.attrib:
'name'] = reg_element.attrib['name'] reg_info.info[
else: 'name'] = reg_element.attrib['name']
reg_info.info['name'] = 'unspecified' else:
if 'encoding' in reg_element.attrib: reg_info.info['name'] = 'unspecified'
reg_info.info['encoding'] = reg_element.attrib[ if 'encoding' in reg_element.attrib:
'encoding'] reg_info.info['encoding'] = reg_element.attrib[
else: 'encoding']
reg_info.info['encoding'] = 'uint' else:
if 'offset' in reg_element.attrib: reg_info.info['encoding'] = 'uint'
reg_info.info[ if 'offset' in reg_element.attrib:
'offset'] = reg_element.attrib['offset'] reg_info.info[
if 'bitsize' in reg_element.attrib: 'offset'] = reg_element.attrib['offset']
reg_info.info[ if 'bitsize' in reg_element.attrib:
'bitsize'] = reg_element.attrib['bitsize'] reg_info.info[
g_register_infos.append(reg_info) 'bitsize'] = reg_element.attrib['bitsize']
print 'XML for "%s":' % (data[2]) g_register_infos.append(reg_info)
ET.dump(xml_root) print 'XML for "%s":' % (data[2])
ET.dump(xml_root)
def cmd_A(options, cmd, args): def cmd_A(options, cmd, args):
@ -810,6 +811,14 @@ def cmd_s(options, cmd, args):
return False return False
def cmd_qSpeedTest(options, cmd, args):
print("qSpeedTest: cmd='%s', args='%s'" % (cmd, args))
def rsp_qSpeedTest(options, cmd, cmd_args, rsp):
print("qSpeedTest: rsp='%s' cmd='%s', args='%s'" % (rsp, cmd, args))
def cmd_vCont(options, cmd, args): def cmd_vCont(options, cmd, args):
if args == '?': if args == '?':
print "%s: get supported extended continue modes" % (cmd) print "%s: get supported extended continue modes" % (cmd)
@ -861,8 +870,10 @@ def rsp_vCont(options, cmd, cmd_args, rsp):
s += 'step' s += 'step'
elif mode == 'S': elif mode == 'S':
s += 'step with signal' s += 'step with signal'
else: elif mode == 't':
s += 'unrecognized vCont mode: ', mode s += 'stop'
# else:
# s += 'unrecognized vCont mode: ', str(mode)
print s print s
elif rsp: elif rsp:
if rsp[0] == 'T' or rsp[0] == 'S' or rsp[0] == 'W' or rsp[0] == 'X': if rsp[0] == 'T' or rsp[0] == 'S' or rsp[0] == 'W' or rsp[0] == 'X':
@ -933,7 +944,7 @@ def rsp_qThreadInfo(options, cmd, cmd_args, rsp):
def rsp_hex_big_endian(options, cmd, cmd_args, rsp): def rsp_hex_big_endian(options, cmd, cmd_args, rsp):
if rsp == '': if rsp == '':
print "%s%s is not supported" % (cmd, cmd_args) print "%s%s is not supported" % (cmd, cmd_args)
else: else:
packet = Packet(rsp) packet = Packet(rsp)
uval = packet.get_hex_uint('big') uval = packet.get_hex_uint('big')
print '%s: 0x%x' % (cmd, uval) print '%s: 0x%x' % (cmd, uval)
@ -1225,6 +1236,7 @@ gdb_remote_commands = {
'qHostInfo': {'cmd': cmd_query_packet, 'rsp': rsp_dump_key_value_pairs, 'name': "get host information"}, 'qHostInfo': {'cmd': cmd_query_packet, 'rsp': rsp_dump_key_value_pairs, 'name': "get host information"},
'qC': {'cmd': cmd_qC, 'rsp': rsp_qC, 'name': "return the current thread ID"}, 'qC': {'cmd': cmd_qC, 'rsp': rsp_qC, 'name': "return the current thread ID"},
'vCont': {'cmd': cmd_vCont, 'rsp': rsp_vCont, 'name': "extended continue command"}, 'vCont': {'cmd': cmd_vCont, 'rsp': rsp_vCont, 'name': "extended continue command"},
'qSpeedTest': {'cmd':cmd_qSpeedTest, 'rsp': rsp_qSpeedTest, 'name': 'speed test packdet'},
'vAttach': {'cmd': cmd_vAttach, 'rsp': rsp_stop_reply, 'name': "attach to process"}, 'vAttach': {'cmd': cmd_vAttach, 'rsp': rsp_stop_reply, 'name': "attach to process"},
'c': {'cmd': cmd_c, 'rsp': rsp_stop_reply, 'name': "continue"}, 'c': {'cmd': cmd_c, 'rsp': rsp_stop_reply, 'name': "continue"},
's': {'cmd': cmd_s, 'rsp': rsp_stop_reply, 'name': "step"}, 's': {'cmd': cmd_s, 'rsp': rsp_stop_reply, 'name': "step"},
@ -1283,6 +1295,49 @@ def parse_gdb_log_file(path, options):
f.close() f.close()
def round_up(n, incr):
return float(((int(n) + incr) / incr) * incr)
def plot_latencies(sec_times):
# import numpy as np
import matplotlib.pyplot as plt
for (i, name) in enumerate(sec_times.keys()):
times = sec_times[name]
if len(times) <= 1:
continue
plt.subplot(2, 1, 1)
plt.title('Packet "%s" Times' % (name))
plt.xlabel('Packet')
units = 'ms'
adj_times = []
max_time = 0.0
for time in times:
time = time * 1000.0
adj_times.append(time)
if time > max_time:
max_time = time
if max_time < 1.0:
units = 'us'
max_time = 0.0
for i in range(len(adj_times)):
adj_times[i] *= 1000.0
if adj_times[i] > max_time:
max_time = adj_times[i]
plt.ylabel('Time (%s)' % (units))
max_y = None
for i in [5.0, 10.0, 25.0, 50.0]:
if max_time < i:
max_y = round_up(max_time, i)
break
if max_y is None:
max_y = round_up(max_time, 100.0)
plt.ylim(0.0, max_y)
plt.plot(adj_times, 'o-')
plt.show()
def parse_gdb_log(file, options): def parse_gdb_log(file, options):
'''Parse a GDB log file that was generated by enabling logging with: '''Parse a GDB log file that was generated by enabling logging with:
(lldb) log enable --threadsafe --timestamp --file <FILE> gdb-remote packets (lldb) log enable --threadsafe --timestamp --file <FILE> gdb-remote packets
@ -1306,10 +1361,11 @@ def parse_gdb_log(file, options):
base_time = 0.0 base_time = 0.0
last_time = 0.0 last_time = 0.0
packet_send_time = 0.0 min_time = 100000000.0
packet_total_times = {} packet_total_times = {}
packet_times = [] all_packet_times = []
packet_count = {} packet_times = {}
packet_counts = {}
lines = file.read().splitlines() lines = file.read().splitlines()
last_command = None last_command = None
last_command_args = None last_command_args = None
@ -1412,32 +1468,39 @@ def parse_gdb_log(file, options):
curr_time = float(match.group(2)) curr_time = float(match.group(2))
if last_time and not is_command: if last_time and not is_command:
delta = curr_time - last_time delta = curr_time - last_time
packet_times.append(delta) all_packet_times.append(delta)
delta = 0.0 delta = 0.0
if base_time: if base_time:
delta = curr_time - last_time delta = curr_time - last_time
else: else:
base_time = curr_time base_time = curr_time
if is_command: if not is_command:
packet_send_time = curr_time if line.find('read packet: $') >= 0 and packet_name:
elif line.find('read packet: $') >= 0 and packet_name: if packet_name in packet_total_times:
if packet_name in packet_total_times: packet_total_times[packet_name] += delta
packet_total_times[packet_name] += delta packet_counts[packet_name] += 1
packet_count[packet_name] += 1 else:
else: packet_total_times[packet_name] = delta
packet_total_times[packet_name] = delta packet_counts[packet_name] = 1
packet_count[packet_name] = 1 if packet_name not in packet_times:
packet_name = None packet_times[packet_name] = []
packet_times[packet_name].append(delta)
packet_name = None
if min_time > delta:
min_time = delta
if not options or not options.quiet: if not options or not options.quiet:
print '%s%.6f %+.6f%s' % (match.group(1), curr_time - base_time, delta, match.group(3)) print '%s%.6f %+.6f%s' % (match.group(1),
curr_time - base_time,
delta,
match.group(3))
last_time = curr_time last_time = curr_time
# else: # else:
# print line # print line
(average, std_dev) = calculate_mean_and_standard_deviation(packet_times) (average, std_dev) = calculate_mean_and_standard_deviation(all_packet_times)
if average and std_dev: if average and std_dev:
print '%u packets with average packet time of %f and standard deviation of %f' % (len(packet_times), average, std_dev) print '%u packets with average packet time of %f and standard deviation of %f' % (len(all_packet_times), average, std_dev)
if packet_total_times: if packet_total_times:
total_packet_time = 0.0 total_packet_time = 0.0
total_packet_count = 0 total_packet_count = 0
@ -1446,19 +1509,21 @@ def parse_gdb_log(file, options):
# print 'value = (%s) %s' % (type(vvv), vvv) # print 'value = (%s) %s' % (type(vvv), vvv)
# if type(vvv) == 'float': # if type(vvv) == 'float':
total_packet_time += vvv total_packet_time += vvv
for key, vvv in packet_count.items(): for key, vvv in packet_counts.items():
total_packet_count += vvv total_packet_count += vvv
print '#---------------------------------------------------' print '#------------------------------------------------------------'
print '# Packet timing summary:' print '# Packet timing summary:'
print '# Totals: time = %6f, count = %6d' % (total_packet_time, total_packet_count) print '# Totals: time = %6f, count = %6d' % (total_packet_time,
print '#---------------------------------------------------' total_packet_count)
print '# Packet Time (sec) Percent Count ' print '# Min packet time: time = %6f' % (min_time)
print '#------------------------- ---------- ------- ------' print '#------------------------------------------------------------'
print '# Packet Time (sec) Percent Count Latency'
print '#------------------------- ----------- ------- ------ -------'
if options and options.sort_count: if options and options.sort_count:
res = sorted( res = sorted(
packet_count, packet_counts,
key=packet_count.__getitem__, key=packet_counts.__getitem__,
reverse=True) reverse=True)
else: else:
res = sorted( res = sorted(
@ -1471,11 +1536,12 @@ def parse_gdb_log(file, options):
packet_total_time = packet_total_times[item] packet_total_time = packet_total_times[item]
packet_percent = ( packet_percent = (
packet_total_time / total_packet_time) * 100.0 packet_total_time / total_packet_time) * 100.0
if packet_percent >= 10.0: packet_count = packet_counts[item]
print " %24s %.6f %.2f%% %6d" % (item, packet_total_time, packet_percent, packet_count[item]) print " %24s %11.6f %5.2f%% %6d %9.6f" % (
else: item, packet_total_time, packet_percent, packet_count,
print " %24s %.6f %.2f%% %6d" % (item, packet_total_time, packet_percent, packet_count[item]) float(packet_total_time) / float(packet_count))
if options.plot:
plot_latencies(packet_times)
if __name__ == '__main__': if __name__ == '__main__':
usage = "usage: gdbremote [options]" usage = "usage: gdbremote [options]"
@ -1491,6 +1557,12 @@ if __name__ == '__main__':
dest='verbose', dest='verbose',
help='display verbose debug info', help='display verbose debug info',
default=False) default=False)
parser.add_option(
'--plot',
action='store_true',
dest='plot',
help='plot packet latencies by packet type',
default=False)
parser.add_option( parser.add_option(
'-q', '-q',
'--quiet', '--quiet',