1fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton#!/usr/bin/python
2fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
3fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton#----------------------------------------------------------------------
4fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# This module will enable GDB remote packet logging when the
5fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# 'start_gdb_log' command is called with a filename to log to. When the
6fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# 'stop_gdb_log' command is called, it will disable the logging and
7fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# print out statistics about how long commands took to execute and also
8fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# will primnt ou
9fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# Be sure to add the python path that points to the LLDB shared library.
10fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton#
11fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# To use this in the embedded python interpreter using "lldb" just
12fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# import it with the full path using the "command script import"
13fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# command. This can be done from the LLDB command line:
14fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton#   (lldb) command script import /path/to/gdbremote.py
15fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# Or it can be added to your ~/.lldbinit file so this module is always
16fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton# available.
17fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton#----------------------------------------------------------------------
18fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
19fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytonimport commands
20fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytonimport optparse
21fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytonimport os
22fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytonimport shlex
23fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytonimport re
24fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytonimport tempfile
25fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
26fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytondef start_gdb_log(debugger, command, result, dict):
27fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    '''Start logging GDB remote packets by enabling logging with timestamps and
28fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    thread safe logging. Follow a call to this function with a call to "stop_gdb_log"
29fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    in order to dump out the commands.'''
30fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    global log_file
31fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    if log_file:
32fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        result.PutCString ('error: logging is already in progress with file "%s"', log_file)
33fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    else:
34fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        args_len = len(args)
35fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        if args_len == 0:
36fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            log_file = tempfile.mktemp()
37fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        elif len(args) == 1:
38fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            log_file = args[0]
39fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
40fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        if log_file:
41fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            debugger.HandleCommand('log enable --threadsafe --timestamp --file "%s" gdb-remote packets' % log_file);
42fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            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)
43fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            return
44fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
45fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        result.PutCString ('error: invalid log file path')
46fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    result.PutCString (usage)
47fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
48fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytondef parse_time_log(debugger, command, result, dict):
49fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    # Any commands whose names might be followed by more valid C identifier
50fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    # characters must be listed here
51fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    command_args = shlex.split(command)
52ee5daf3db4e8a8cb4cc45e3abdf7c6e6e4bfba16Greg Clayton    parse_time_log_args (command_args)
53ee5daf3db4e8a8cb4cc45e3abdf7c6e6e4bfba16Greg Clayton
54ee5daf3db4e8a8cb4cc45e3abdf7c6e6e4bfba16Greg Claytondef parse_time_log_args(command_args):
55fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    usage = "usage: parse_time_log [options] [<LOGFILEPATH>]"
56fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    description='''Parse a log file that contains timestamps and convert the timestamps to delta times between log lines.'''
57fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    parser = optparse.OptionParser(description=description, prog='parse_time_log',usage=usage)
58fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    parser.add_option('-v', '--verbose', action='store_true', dest='verbose', help='display verbose debug info', default=False)
59fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    try:
60fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        (options, args) = parser.parse_args(command_args)
61fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    except:
62fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        return
63fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    for log_file in args:
64fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        parse_log_file (log_file, options)
65fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
66fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytondef parse_log_file(file, options):
67fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    '''Parse a log file that was contains timestamps. These logs are typically
68fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    generated using:
69fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    (lldb) log enable --threadsafe --timestamp --file <FILE> ....
70fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
71fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    This log file will contain timestamps and this fucntion will then normalize
72fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    those packets to be relative to the first value timestamp that is found and
73fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    show delta times between log lines and also keep track of how long it takes
74fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    for GDB remote commands to make a send/receive round trip. This can be
75fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    handy when trying to figure out why some operation in the debugger is taking
76fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    a long time during a preset set of debugger commands.'''
77fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
78ee5daf3db4e8a8cb4cc45e3abdf7c6e6e4bfba16Greg Clayton    print '#----------------------------------------------------------------------'
79ee5daf3db4e8a8cb4cc45e3abdf7c6e6e4bfba16Greg Clayton    print "# Log file: '%s'" % file
80ee5daf3db4e8a8cb4cc45e3abdf7c6e6e4bfba16Greg Clayton    print '#----------------------------------------------------------------------'
81ee5daf3db4e8a8cb4cc45e3abdf7c6e6e4bfba16Greg Clayton
82fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    timestamp_regex = re.compile('(\s*)([1-9][0-9]+\.[0-9]+)([^0-9].*)$')
83fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
84fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    base_time = 0.0
85fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    last_time = 0.0
86fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    file = open(file)
87fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    lines = file.read().splitlines()
88fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    for line in lines:
89fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        match = timestamp_regex.match (line)
90fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        if match:
91fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            curr_time = float (match.group(2))
92fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            delta = 0.0
93fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            if base_time:
94fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton                delta = curr_time - last_time
95fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            else:
96fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton                base_time = curr_time
97fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
98fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            print '%s%.6f %+.6f%s' % (match.group(1), curr_time - base_time, delta, match.group(3))
99fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            last_time = curr_time
100fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        else:
101fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton            print line
102fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
103fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
104fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
105fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytonif __name__ == '__main__':
106fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    import sys
107ee5daf3db4e8a8cb4cc45e3abdf7c6e6e4bfba16Greg Clayton    parse_time_log_args (sys.argv[1:])
108fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton
109fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Claytonelse:
110fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    import lldb
111fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton    if lldb.debugger:
112fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        # This initializer is being run from LLDB in the embedded command interpreter
113fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        # Add any commands contained in this module to LLDB
114fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        lldb.debugger.HandleCommand('command script add -f delta.parse_time_log parse_time_log')
115fed526768db80ccb4769a1cdc7e1e2ef9d4264ecGreg Clayton        print 'The "parse_time_log" command is now installed and ready for use, type "parse_time_log --help" for more information'
116