Added a 'gdbremote' python module that adds two commands: start_gdb_log and end_gdb_log.
When this is imported into your lldb using the "command script import /path/to/gdbremote.py" these new commands are available within LLDB. 'start_gdb_log' will enable logging with timestamps for GDB remote packets, and 'stop_gdb_log' will then dump the details and also a lot of packet timing data. This allows us to accurately track what packets are taking up the most time when debugging (when using the ProcessGDBRemote debugging plug-in). Also udpated the comments at the top of the cmdtemplate.py to show how to correctly import the module from within LLDB. llvm-svn: 149030
This commit is contained in:
parent
8722fe5a24
commit
e284163990
|
@ -3,10 +3,10 @@
|
||||||
#----------------------------------------------------------------------
|
#----------------------------------------------------------------------
|
||||||
# Be sure to add the python path that points to the LLDB shared library.
|
# Be sure to add the python path that points to the LLDB shared library.
|
||||||
#
|
#
|
||||||
# To use this in the embedded python interpreter using "lldb":
|
# # To use this in the embedded python interpreter using "lldb" just
|
||||||
# % cd /path/containing/cmdtemplate.py
|
# import it with the full path using the "command script import"
|
||||||
# % lldb
|
# command
|
||||||
# (lldb) script import cmdtemplate
|
# (lldb) command script import /path/to/cmdtemplate.py
|
||||||
#
|
#
|
||||||
# For the shells csh, tcsh:
|
# For the shells csh, tcsh:
|
||||||
# ( setenv PYTHONPATH /path/to/LLDB.framework/Resources/Python ; ./cmdtemplate.py )
|
# ( setenv PYTHONPATH /path/to/LLDB.framework/Resources/Python ; ./cmdtemplate.py )
|
||||||
|
|
|
@ -0,0 +1,184 @@
|
||||||
|
#!/usr/bin/python
|
||||||
|
|
||||||
|
#----------------------------------------------------------------------
|
||||||
|
# This module will enable GDB remote packet logging when the
|
||||||
|
# 'start_gdb_log' command is called with a filename to log to. When the
|
||||||
|
# 'stop_gdb_log' command is called, it will disable the logging and
|
||||||
|
# print out statistics about how long commands took to execute and also
|
||||||
|
# will primnt ou
|
||||||
|
# Be sure to add the python path that points to the LLDB shared library.
|
||||||
|
#
|
||||||
|
# To use this in the embedded python interpreter using "lldb" just
|
||||||
|
# import it with the full path using the "command script import"
|
||||||
|
# command. This can be done from the LLDB command line:
|
||||||
|
# (lldb) command script import /path/to/gdbremote.py
|
||||||
|
# Or it can be added to your ~/.lldbinit file so this module is always
|
||||||
|
# available.
|
||||||
|
#----------------------------------------------------------------------
|
||||||
|
|
||||||
|
import commands
|
||||||
|
import optparse
|
||||||
|
import os
|
||||||
|
import shlex
|
||||||
|
import re
|
||||||
|
import tempfile
|
||||||
|
|
||||||
|
log_file = ''
|
||||||
|
|
||||||
|
def start_gdb_log(debugger, command, result, dict):
|
||||||
|
'''Start logging GDB remote packets by enabling logging with timestamps and
|
||||||
|
thread safe logging. Follow a call to this function with a call to "stop_gdb_log"
|
||||||
|
in order to dump out the commands.'''
|
||||||
|
global log_file
|
||||||
|
command_args = shlex.split(command)
|
||||||
|
usage = "usage: start_gdb_log [options] [<LOGFILEPATH>]"
|
||||||
|
description='''The command enables GDB remote packet logging with timestamps. The packets will be logged to <LOGFILEPATH> if supplied, or a temporary file will be used. Logging stops when stop_gdb_log is called and the packet times will
|
||||||
|
be aggregated and displayed.'''
|
||||||
|
parser = optparse.OptionParser(description=description, prog='start_gdb_log',usage=usage)
|
||||||
|
parser.add_option('-v', '--verbose', action='store_true', dest='verbose', help='display verbose debug info', default=False)
|
||||||
|
try:
|
||||||
|
(options, args) = parser.parse_args(command_args)
|
||||||
|
except:
|
||||||
|
return
|
||||||
|
|
||||||
|
if log_file:
|
||||||
|
result.PutCString ('error: logging is already in progress with file "%s"', log_file)
|
||||||
|
else:
|
||||||
|
args_len = len(args)
|
||||||
|
if args_len == 0:
|
||||||
|
log_file = tempfile.mktemp()
|
||||||
|
elif len(args) == 1:
|
||||||
|
log_file = args[0]
|
||||||
|
|
||||||
|
if log_file:
|
||||||
|
debugger.HandleCommand('log enable --threadsafe --timestamp --file "%s" gdb-remote packets' % log_file);
|
||||||
|
result.PutCString ("GDB packet logging enable with log file '%s'\nUse the 'stop_gdb_log' command to stop logging and show packet statistics." % log_file)
|
||||||
|
return
|
||||||
|
|
||||||
|
result.PutCString ('error: invalid log file path')
|
||||||
|
result.PutCString (usage)
|
||||||
|
|
||||||
|
def stop_gdb_log(debugger, command, result, dict):
|
||||||
|
'''Stop logging GDB remote packets to the file that was specified in a call
|
||||||
|
to "start_gdb_log" and normalize the timestamps to be relative to the first
|
||||||
|
timestamp in the log file. Also print out statistics for how long each
|
||||||
|
command took to allow performance bottlenecks to be determined.'''
|
||||||
|
global log_file
|
||||||
|
# Any commands whose names might be followed by more valid C identifier
|
||||||
|
# characters must be listed here
|
||||||
|
command_args = shlex.split(command)
|
||||||
|
usage = "usage: stop_gdb_log [options]"
|
||||||
|
description='''The command stops a previously enabled GDB remote packet logging command. Packet logging must have been previously enabled with a call to start_gdb_log.'''
|
||||||
|
parser = optparse.OptionParser(description=description, prog='stop_gdb_log',usage=usage)
|
||||||
|
parser.add_option('-v', '--verbose', action='store_true', dest='verbose', help='display verbose debug info', default=False)
|
||||||
|
parser.add_option('-q', '--quiet', action='store_true', dest='quiet', help='display verbose debug info', default=False)
|
||||||
|
try:
|
||||||
|
(options, args) = parser.parse_args(command_args)
|
||||||
|
except:
|
||||||
|
return
|
||||||
|
|
||||||
|
if not log_file:
|
||||||
|
result.PutCString ('error: logging must have been previously enabled with a call to "stop_gdb_log"')
|
||||||
|
elif os.path.exists (log_file):
|
||||||
|
if len(args) == 0:
|
||||||
|
debugger.HandleCommand('log disable gdb-remote packets');
|
||||||
|
result.PutCString ("GDB packet logging disabled. Logged packets are in '%s'" % log_file)
|
||||||
|
parse_gdb_log_file (log_file, options)
|
||||||
|
log_file = None
|
||||||
|
else:
|
||||||
|
result.PutCString (usage)
|
||||||
|
else:
|
||||||
|
print 'error: the GDB packet log file "%s" does not exist' % log_file
|
||||||
|
|
||||||
|
def parse_gdb_log_file(file, options):
|
||||||
|
'''Parse a GDB log file that was generated by enabling logging with:
|
||||||
|
(lldb) log enable --threadsafe --timestamp --file <FILE> gdb-remote packets
|
||||||
|
This log file will contain timestamps and this fucntion will then normalize
|
||||||
|
those packets to be relative to the first value timestamp that is found and
|
||||||
|
show delta times between log lines and also keep track of how long it takes
|
||||||
|
for GDB remote commands to make a send/receive round trip. This can be
|
||||||
|
handy when trying to figure out why some operation in the debugger is taking
|
||||||
|
a long time during a preset set of debugger commands.'''
|
||||||
|
|
||||||
|
tricky_commands = [ 'qRegisterInfo' ]
|
||||||
|
timestamp_regex = re.compile('(\s*)([1-9][0-9]+\.[0-9]+)([^0-9].*)$')
|
||||||
|
packet_name_regex = re.compile('([A-Za-z_]+)[^a-z]')
|
||||||
|
base_time = 0.0
|
||||||
|
last_time = 0.0
|
||||||
|
packet_send_time = 0.0
|
||||||
|
packet_name = None
|
||||||
|
packet_total_times = {}
|
||||||
|
file = open(file)
|
||||||
|
lines = file.read().splitlines()
|
||||||
|
for line in lines:
|
||||||
|
match = timestamp_regex.match (line)
|
||||||
|
if match:
|
||||||
|
curr_time = float (match.group(2))
|
||||||
|
delta = 0.0
|
||||||
|
if base_time:
|
||||||
|
delta = curr_time - last_time
|
||||||
|
else:
|
||||||
|
base_time = curr_time
|
||||||
|
idx = line.find('send packet: $')
|
||||||
|
if idx >= 0:
|
||||||
|
packet_send_time = curr_time
|
||||||
|
packet_match = packet_name_regex.match (line[idx+14:])
|
||||||
|
if packet_match:
|
||||||
|
packet_name = packet_match.group(1)
|
||||||
|
for tricky_cmd in tricky_commands:
|
||||||
|
if packet_name.find (tricky_cmd) == 0:
|
||||||
|
packet_name = tricky_cmd
|
||||||
|
elif line.find('read packet: $') >= 0 and packet_name:
|
||||||
|
if packet_name in packet_total_times:
|
||||||
|
packet_total_times[packet_name] += delta
|
||||||
|
else:
|
||||||
|
packet_total_times[packet_name] = delta
|
||||||
|
packet_name = None
|
||||||
|
|
||||||
|
if not options or not options.quiet:
|
||||||
|
print '%s%.6f %+.6f%s' % (match.group(1), curr_time - base_time, delta, match.group(3))
|
||||||
|
last_time = curr_time
|
||||||
|
else:
|
||||||
|
print line
|
||||||
|
if packet_total_times:
|
||||||
|
total_packet_time = 0.0
|
||||||
|
for key, vvv in packet_total_times.items():
|
||||||
|
# print ' key = (%s) "%s"' % (type(key), key)
|
||||||
|
# print 'value = (%s) %s' % (type(vvv), vvv)
|
||||||
|
# if type(vvv) == 'float':
|
||||||
|
total_packet_time += vvv
|
||||||
|
print '#--------------------------------------------'
|
||||||
|
print '# Packet timing summary:'
|
||||||
|
print '#--------------------------------------------'
|
||||||
|
print '# Packet Time (sec) Percent'
|
||||||
|
print '#------------------------- ---------- -------'
|
||||||
|
res = sorted(packet_total_times, key=packet_total_times.__getitem__, reverse=True)
|
||||||
|
if last_time > 0.0:
|
||||||
|
for item in res:
|
||||||
|
packet_total_time = packet_total_times[item]
|
||||||
|
packet_percent = (packet_total_time / total_packet_time)*100.0
|
||||||
|
if packet_percent >= 10.0:
|
||||||
|
print " %24s %.6f %.2f%%" % (item, packet_total_time, packet_percent)
|
||||||
|
else:
|
||||||
|
print " %24s %.6f %.2f%%" % (item, packet_total_time, packet_percent)
|
||||||
|
|
||||||
|
|
||||||
|
|
||||||
|
if __name__ == '__main__':
|
||||||
|
import sys
|
||||||
|
# This script is being run from the command line, create a debugger in case we are
|
||||||
|
# going to use any debugger functions in our function.
|
||||||
|
for file in sys.argv:
|
||||||
|
print '#----------------------------------------------------------------------'
|
||||||
|
print "# GDB remote log file: '%s'" % file
|
||||||
|
print '#----------------------------------------------------------------------'
|
||||||
|
parse_gdb_log_file (file, None)
|
||||||
|
|
||||||
|
else:
|
||||||
|
import lldb
|
||||||
|
if lldb.debugger:
|
||||||
|
# This initializer is being run from LLDB in the embedded command interpreter
|
||||||
|
# Add any commands contained in this module to LLDB
|
||||||
|
lldb.debugger.HandleCommand('command script add -f gdbremote.start_gdb_log start_gdb_log')
|
||||||
|
lldb.debugger.HandleCommand('command script add -f gdbremote.stop_gdb_log stop_gdb_log')
|
||||||
|
print 'The "start_gdb_log" and "stop_gdb_log" commands are now installed and ready for use, type "start_gdb_log --help" or "stop_gdb_log --help" for more information'
|
Loading…
Reference in New Issue