michael@0: #!/usr/bin/env python michael@0: # michael@0: # Copyright (c) 2012 The Chromium Authors. All rights reserved. michael@0: # Use of this source code is governed by a BSD-style license that can be michael@0: # found in the LICENSE file. michael@0: michael@0: """Shutdown adb_logcat_monitor and print accumulated logs. michael@0: michael@0: To test, call './adb_logcat_printer.py ' where michael@0: contains 'adb logcat -v threadtime' files named as michael@0: logcat__ michael@0: michael@0: The script will print the files to out, and will combine multiple michael@0: logcats from a single device if there is overlap. michael@0: michael@0: Additionally, if a /LOGCAT_MONITOR_PID exists, the script michael@0: will attempt to terminate the contained PID by sending a SIGINT and michael@0: monitoring for the deletion of the aforementioned file. michael@0: """ michael@0: michael@0: import cStringIO michael@0: import logging michael@0: import os michael@0: import re michael@0: import signal michael@0: import sys michael@0: import time michael@0: michael@0: michael@0: # Set this to debug for more verbose output michael@0: LOG_LEVEL = logging.INFO michael@0: michael@0: michael@0: def CombineLogFiles(list_of_lists, logger): michael@0: """Splices together multiple logcats from the same device. michael@0: michael@0: Args: michael@0: list_of_lists: list of pairs (filename, list of timestamped lines) michael@0: logger: handler to log events michael@0: michael@0: Returns: michael@0: list of lines with duplicates removed michael@0: """ michael@0: cur_device_log = [''] michael@0: for cur_file, cur_file_lines in list_of_lists: michael@0: # Ignore files with just the logcat header michael@0: if len(cur_file_lines) < 2: michael@0: continue michael@0: common_index = 0 michael@0: # Skip this step if list just has empty string michael@0: if len(cur_device_log) > 1: michael@0: try: michael@0: line = cur_device_log[-1] michael@0: # Used to make sure we only splice on a timestamped line michael@0: if re.match('^\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3} ', line): michael@0: common_index = cur_file_lines.index(line) michael@0: else: michael@0: logger.warning('splice error - no timestamp in "%s"?', line.strip()) michael@0: except ValueError: michael@0: # The last line was valid but wasn't found in the next file michael@0: cur_device_log += ['***** POSSIBLE INCOMPLETE LOGCAT *****'] michael@0: logger.info('Unable to splice %s. Incomplete logcat?', cur_file) michael@0: michael@0: cur_device_log += ['*'*30 + ' %s' % cur_file] michael@0: cur_device_log.extend(cur_file_lines[common_index:]) michael@0: michael@0: return cur_device_log michael@0: michael@0: michael@0: def FindLogFiles(base_dir): michael@0: """Search a directory for logcat files. michael@0: michael@0: Args: michael@0: base_dir: directory to search michael@0: michael@0: Returns: michael@0: Mapping of device_id to a sorted list of file paths for a given device michael@0: """ michael@0: logcat_filter = re.compile('^logcat_(\w+)_(\d+)$') michael@0: # list of tuples (, , ) michael@0: filtered_list = [] michael@0: for cur_file in os.listdir(base_dir): michael@0: matcher = logcat_filter.match(cur_file) michael@0: if matcher: michael@0: filtered_list += [(matcher.group(1), int(matcher.group(2)), michael@0: os.path.join(base_dir, cur_file))] michael@0: filtered_list.sort() michael@0: file_map = {} michael@0: for device_id, _, cur_file in filtered_list: michael@0: if not device_id in file_map: michael@0: file_map[device_id] = [] michael@0: michael@0: file_map[device_id] += [cur_file] michael@0: return file_map michael@0: michael@0: michael@0: def GetDeviceLogs(log_filenames, logger): michael@0: """Read log files, combine and format. michael@0: michael@0: Args: michael@0: log_filenames: mapping of device_id to sorted list of file paths michael@0: logger: logger handle for logging events michael@0: michael@0: Returns: michael@0: list of formatted device logs, one for each device. michael@0: """ michael@0: device_logs = [] michael@0: michael@0: for device, device_files in log_filenames.iteritems(): michael@0: logger.debug('%s: %s', device, str(device_files)) michael@0: device_file_lines = [] michael@0: for cur_file in device_files: michael@0: with open(cur_file) as f: michael@0: device_file_lines += [(cur_file, f.read().splitlines())] michael@0: combined_lines = CombineLogFiles(device_file_lines, logger) michael@0: # Prepend each line with a short unique ID so it's easy to see michael@0: # when the device changes. We don't use the start of the device michael@0: # ID because it can be the same among devices. Example lines: michael@0: # AB324: foo michael@0: # AB324: blah michael@0: device_logs += [('\n' + device[-5:] + ': ').join(combined_lines)] michael@0: return device_logs michael@0: michael@0: michael@0: def ShutdownLogcatMonitor(base_dir, logger): michael@0: """Attempts to shutdown adb_logcat_monitor and blocks while waiting.""" michael@0: try: michael@0: monitor_pid_path = os.path.join(base_dir, 'LOGCAT_MONITOR_PID') michael@0: with open(monitor_pid_path) as f: michael@0: monitor_pid = int(f.readline()) michael@0: michael@0: logger.info('Sending SIGTERM to %d', monitor_pid) michael@0: os.kill(monitor_pid, signal.SIGTERM) michael@0: i = 0 michael@0: while True: michael@0: time.sleep(.2) michael@0: if not os.path.exists(monitor_pid_path): michael@0: return michael@0: if not os.path.exists('/proc/%d' % monitor_pid): michael@0: logger.warning('Monitor (pid %d) terminated uncleanly?', monitor_pid) michael@0: return michael@0: logger.info('Waiting for logcat process to terminate.') michael@0: i += 1 michael@0: if i >= 10: michael@0: logger.warning('Monitor pid did not terminate. Continuing anyway.') michael@0: return michael@0: michael@0: except (ValueError, IOError, OSError): michael@0: logger.exception('Error signaling logcat monitor - continuing') michael@0: michael@0: michael@0: def main(base_dir, output_file): michael@0: log_stringio = cStringIO.StringIO() michael@0: logger = logging.getLogger('LogcatPrinter') michael@0: logger.setLevel(LOG_LEVEL) michael@0: sh = logging.StreamHandler(log_stringio) michael@0: sh.setFormatter(logging.Formatter('%(asctime)-2s %(levelname)-8s' michael@0: ' %(message)s')) michael@0: logger.addHandler(sh) michael@0: michael@0: try: michael@0: # Wait at least 5 seconds after base_dir is created before printing. michael@0: # michael@0: # The idea is that 'adb logcat > file' output consists of 2 phases: michael@0: # 1 Dump all the saved logs to the file michael@0: # 2 Stream log messages as they are generated michael@0: # michael@0: # We want to give enough time for phase 1 to complete. There's no michael@0: # good method to tell how long to wait, but it usually only takes a michael@0: # second. On most bots, this code path won't occur at all, since michael@0: # adb_logcat_monitor.py command will have spawned more than 5 seconds michael@0: # prior to called this shell script. michael@0: try: michael@0: sleep_time = 5 - (time.time() - os.path.getctime(base_dir)) michael@0: except OSError: michael@0: sleep_time = 5 michael@0: if sleep_time > 0: michael@0: logger.warning('Monitor just started? Sleeping %.1fs', sleep_time) michael@0: time.sleep(sleep_time) michael@0: michael@0: assert os.path.exists(base_dir), '%s does not exist' % base_dir michael@0: ShutdownLogcatMonitor(base_dir, logger) michael@0: separator = '\n' + '*' * 80 + '\n\n' michael@0: for log in GetDeviceLogs(FindLogFiles(base_dir), logger): michael@0: output_file.write(log) michael@0: output_file.write(separator) michael@0: with open(os.path.join(base_dir, 'eventlog')) as f: michael@0: output_file.write('\nLogcat Monitor Event Log\n') michael@0: output_file.write(f.read()) michael@0: except: michael@0: logger.exception('Unexpected exception') michael@0: michael@0: logger.info('Done.') michael@0: sh.flush() michael@0: output_file.write('\nLogcat Printer Event Log\n') michael@0: output_file.write(log_stringio.getvalue()) michael@0: michael@0: if __name__ == '__main__': michael@0: if len(sys.argv) == 1: michael@0: print 'Usage: %s ' % sys.argv[0] michael@0: sys.exit(1) michael@0: sys.exit(main(sys.argv[1], sys.stdout))