lldb/examples/python/gdbremote.py - llvm-project - Git at Google

 #!/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)
     parser.add_option('-c', '--sort-by-count', action='store_true', dest='sort_count', 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 = {}
     packet_count = {}
     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
                     packet_count[packet_name] += 1
                 else:
                     packet_total_times[packet_name] = delta
                     packet_count[packet_name] = 1
                 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
         total_packet_count = 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
         for key, vvv in packet_count.items():
             total_packet_count += vvv

         print '#---------------------------------------------------'
         print '# Packet timing summary:'
         print '# Totals: time - %6f count %6d' % (total_packet_time, total_packet_count)
         print '#---------------------------------------------------'
         print '# Packet                   Time (sec) Percent Count '
         print '#------------------------- ---------- ------- ------'
         if options and options.sort_count:
             res = sorted(packet_count, key=packet_count.__getitem__, reverse=True)
         else:
             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%% %6d" % (item, packet_total_time, packet_percent, packet_count[item])
                 else:
                     print "  %24s %.6f   %.2f%%  %6d" % (item, packet_total_time, packet_percent, packet_count[item])


 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[1:]:
         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'
	#!/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)
	parser.add_option('-c', '--sort-by-count', action='store_true', dest='sort_count', 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 = {}
	packet_count = {}
	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
	packet_count[packet_name] += 1
	else:
	packet_total_times[packet_name] = delta
	packet_count[packet_name] = 1
	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
	total_packet_count = 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
	for key, vvv in packet_count.items():
	total_packet_count += vvv

	print '#---------------------------------------------------'
	print '# Packet timing summary:'
	print '# Totals: time - %6f count %6d' % (total_packet_time, total_packet_count)
	print '#---------------------------------------------------'
	print '# Packet Time (sec) Percent Count '
	print '#------------------------- ---------- ------- ------'
	if options and options.sort_count:
	res = sorted(packet_count, key=packet_count.__getitem__, reverse=True)
	else:
	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%% %6d" % (item, packet_total_time, packet_percent, packet_count[item])
	else:
	print " %24s %.6f %.2f%% %6d" % (item, packet_total_time, packet_percent, packet_count[item])



	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[1:]:
	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'