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