|
1 #!/usr/bin/env python |
|
2 # |
|
3 # Copyright (c) 2012 The Chromium Authors. All rights reserved. |
|
4 # Use of this source code is governed by a BSD-style license that can be |
|
5 # found in the LICENSE file. |
|
6 |
|
7 """Shutdown adb_logcat_monitor and print accumulated logs. |
|
8 |
|
9 To test, call './adb_logcat_printer.py <base_dir>' where |
|
10 <base_dir> contains 'adb logcat -v threadtime' files named as |
|
11 logcat_<deviceID>_<sequenceNum> |
|
12 |
|
13 The script will print the files to out, and will combine multiple |
|
14 logcats from a single device if there is overlap. |
|
15 |
|
16 Additionally, if a <base_dir>/LOGCAT_MONITOR_PID exists, the script |
|
17 will attempt to terminate the contained PID by sending a SIGINT and |
|
18 monitoring for the deletion of the aforementioned file. |
|
19 """ |
|
20 |
|
21 import cStringIO |
|
22 import logging |
|
23 import os |
|
24 import re |
|
25 import signal |
|
26 import sys |
|
27 import time |
|
28 |
|
29 |
|
30 # Set this to debug for more verbose output |
|
31 LOG_LEVEL = logging.INFO |
|
32 |
|
33 |
|
34 def CombineLogFiles(list_of_lists, logger): |
|
35 """Splices together multiple logcats from the same device. |
|
36 |
|
37 Args: |
|
38 list_of_lists: list of pairs (filename, list of timestamped lines) |
|
39 logger: handler to log events |
|
40 |
|
41 Returns: |
|
42 list of lines with duplicates removed |
|
43 """ |
|
44 cur_device_log = [''] |
|
45 for cur_file, cur_file_lines in list_of_lists: |
|
46 # Ignore files with just the logcat header |
|
47 if len(cur_file_lines) < 2: |
|
48 continue |
|
49 common_index = 0 |
|
50 # Skip this step if list just has empty string |
|
51 if len(cur_device_log) > 1: |
|
52 try: |
|
53 line = cur_device_log[-1] |
|
54 # Used to make sure we only splice on a timestamped line |
|
55 if re.match('^\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3} ', line): |
|
56 common_index = cur_file_lines.index(line) |
|
57 else: |
|
58 logger.warning('splice error - no timestamp in "%s"?', line.strip()) |
|
59 except ValueError: |
|
60 # The last line was valid but wasn't found in the next file |
|
61 cur_device_log += ['***** POSSIBLE INCOMPLETE LOGCAT *****'] |
|
62 logger.info('Unable to splice %s. Incomplete logcat?', cur_file) |
|
63 |
|
64 cur_device_log += ['*'*30 + ' %s' % cur_file] |
|
65 cur_device_log.extend(cur_file_lines[common_index:]) |
|
66 |
|
67 return cur_device_log |
|
68 |
|
69 |
|
70 def FindLogFiles(base_dir): |
|
71 """Search a directory for logcat files. |
|
72 |
|
73 Args: |
|
74 base_dir: directory to search |
|
75 |
|
76 Returns: |
|
77 Mapping of device_id to a sorted list of file paths for a given device |
|
78 """ |
|
79 logcat_filter = re.compile('^logcat_(\w+)_(\d+)$') |
|
80 # list of tuples (<device_id>, <seq num>, <full file path>) |
|
81 filtered_list = [] |
|
82 for cur_file in os.listdir(base_dir): |
|
83 matcher = logcat_filter.match(cur_file) |
|
84 if matcher: |
|
85 filtered_list += [(matcher.group(1), int(matcher.group(2)), |
|
86 os.path.join(base_dir, cur_file))] |
|
87 filtered_list.sort() |
|
88 file_map = {} |
|
89 for device_id, _, cur_file in filtered_list: |
|
90 if not device_id in file_map: |
|
91 file_map[device_id] = [] |
|
92 |
|
93 file_map[device_id] += [cur_file] |
|
94 return file_map |
|
95 |
|
96 |
|
97 def GetDeviceLogs(log_filenames, logger): |
|
98 """Read log files, combine and format. |
|
99 |
|
100 Args: |
|
101 log_filenames: mapping of device_id to sorted list of file paths |
|
102 logger: logger handle for logging events |
|
103 |
|
104 Returns: |
|
105 list of formatted device logs, one for each device. |
|
106 """ |
|
107 device_logs = [] |
|
108 |
|
109 for device, device_files in log_filenames.iteritems(): |
|
110 logger.debug('%s: %s', device, str(device_files)) |
|
111 device_file_lines = [] |
|
112 for cur_file in device_files: |
|
113 with open(cur_file) as f: |
|
114 device_file_lines += [(cur_file, f.read().splitlines())] |
|
115 combined_lines = CombineLogFiles(device_file_lines, logger) |
|
116 # Prepend each line with a short unique ID so it's easy to see |
|
117 # when the device changes. We don't use the start of the device |
|
118 # ID because it can be the same among devices. Example lines: |
|
119 # AB324: foo |
|
120 # AB324: blah |
|
121 device_logs += [('\n' + device[-5:] + ': ').join(combined_lines)] |
|
122 return device_logs |
|
123 |
|
124 |
|
125 def ShutdownLogcatMonitor(base_dir, logger): |
|
126 """Attempts to shutdown adb_logcat_monitor and blocks while waiting.""" |
|
127 try: |
|
128 monitor_pid_path = os.path.join(base_dir, 'LOGCAT_MONITOR_PID') |
|
129 with open(monitor_pid_path) as f: |
|
130 monitor_pid = int(f.readline()) |
|
131 |
|
132 logger.info('Sending SIGTERM to %d', monitor_pid) |
|
133 os.kill(monitor_pid, signal.SIGTERM) |
|
134 i = 0 |
|
135 while True: |
|
136 time.sleep(.2) |
|
137 if not os.path.exists(monitor_pid_path): |
|
138 return |
|
139 if not os.path.exists('/proc/%d' % monitor_pid): |
|
140 logger.warning('Monitor (pid %d) terminated uncleanly?', monitor_pid) |
|
141 return |
|
142 logger.info('Waiting for logcat process to terminate.') |
|
143 i += 1 |
|
144 if i >= 10: |
|
145 logger.warning('Monitor pid did not terminate. Continuing anyway.') |
|
146 return |
|
147 |
|
148 except (ValueError, IOError, OSError): |
|
149 logger.exception('Error signaling logcat monitor - continuing') |
|
150 |
|
151 |
|
152 def main(base_dir, output_file): |
|
153 log_stringio = cStringIO.StringIO() |
|
154 logger = logging.getLogger('LogcatPrinter') |
|
155 logger.setLevel(LOG_LEVEL) |
|
156 sh = logging.StreamHandler(log_stringio) |
|
157 sh.setFormatter(logging.Formatter('%(asctime)-2s %(levelname)-8s' |
|
158 ' %(message)s')) |
|
159 logger.addHandler(sh) |
|
160 |
|
161 try: |
|
162 # Wait at least 5 seconds after base_dir is created before printing. |
|
163 # |
|
164 # The idea is that 'adb logcat > file' output consists of 2 phases: |
|
165 # 1 Dump all the saved logs to the file |
|
166 # 2 Stream log messages as they are generated |
|
167 # |
|
168 # We want to give enough time for phase 1 to complete. There's no |
|
169 # good method to tell how long to wait, but it usually only takes a |
|
170 # second. On most bots, this code path won't occur at all, since |
|
171 # adb_logcat_monitor.py command will have spawned more than 5 seconds |
|
172 # prior to called this shell script. |
|
173 try: |
|
174 sleep_time = 5 - (time.time() - os.path.getctime(base_dir)) |
|
175 except OSError: |
|
176 sleep_time = 5 |
|
177 if sleep_time > 0: |
|
178 logger.warning('Monitor just started? Sleeping %.1fs', sleep_time) |
|
179 time.sleep(sleep_time) |
|
180 |
|
181 assert os.path.exists(base_dir), '%s does not exist' % base_dir |
|
182 ShutdownLogcatMonitor(base_dir, logger) |
|
183 separator = '\n' + '*' * 80 + '\n\n' |
|
184 for log in GetDeviceLogs(FindLogFiles(base_dir), logger): |
|
185 output_file.write(log) |
|
186 output_file.write(separator) |
|
187 with open(os.path.join(base_dir, 'eventlog')) as f: |
|
188 output_file.write('\nLogcat Monitor Event Log\n') |
|
189 output_file.write(f.read()) |
|
190 except: |
|
191 logger.exception('Unexpected exception') |
|
192 |
|
193 logger.info('Done.') |
|
194 sh.flush() |
|
195 output_file.write('\nLogcat Printer Event Log\n') |
|
196 output_file.write(log_stringio.getvalue()) |
|
197 |
|
198 if __name__ == '__main__': |
|
199 if len(sys.argv) == 1: |
|
200 print 'Usage: %s <base_dir>' % sys.argv[0] |
|
201 sys.exit(1) |
|
202 sys.exit(main(sys.argv[1], sys.stdout)) |