15821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#!/usr/bin/env python 25821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)# 35821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)# Copyright (c) 2012 The Chromium Authors. All rights reserved. 45821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)# Use of this source code is governed by a BSD-style license that can be 55821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)# found in the LICENSE file. 65821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 75821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)"""Shutdown adb_logcat_monitor and print accumulated logs. 85821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 95821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)To test, call './adb_logcat_printer.py <base_dir>' where 105821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)<base_dir> contains 'adb logcat -v threadtime' files named as 115821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)logcat_<deviceID>_<sequenceNum> 125821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 135821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)The script will print the files to out, and will combine multiple 145821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)logcats from a single device if there is overlap. 155821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 165821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)Additionally, if a <base_dir>/LOGCAT_MONITOR_PID exists, the script 175821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)will attempt to terminate the contained PID by sending a SIGINT and 185821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)monitoring for the deletion of the aforementioned file. 195821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)""" 205821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 215821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)import cStringIO 225821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)import logging 235821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)import os 245821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)import re 255821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)import signal 265821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)import sys 275821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)import time 285821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 295821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 305821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)# Set this to debug for more verbose output 315821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)LOG_LEVEL = logging.INFO 325821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 335821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 345821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)def CombineLogFiles(list_of_lists, logger): 355821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) """Splices together multiple logcats from the same device. 365821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 375821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Args: 385821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) list_of_lists: list of pairs (filename, list of timestamped lines) 395821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger: handler to log events 405821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 415821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Returns: 425821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) list of lines with duplicates removed 435821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) """ 445821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) cur_device_log = [''] 455821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) for cur_file, cur_file_lines in list_of_lists: 465821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # Ignore files with just the logcat header 475821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if len(cur_file_lines) < 2: 485821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) continue 495821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) common_index = 0 505821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # Skip this step if list just has empty string 515821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if len(cur_device_log) > 1: 525821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) try: 535821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) line = cur_device_log[-1] 545821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # Used to make sure we only splice on a timestamped line 555821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if re.match('^\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3} ', line): 565821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) common_index = cur_file_lines.index(line) 575821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) else: 585821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.warning('splice error - no timestamp in "%s"?', line.strip()) 595821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) except ValueError: 605821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # The last line was valid but wasn't found in the next file 615821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) cur_device_log += ['***** POSSIBLE INCOMPLETE LOGCAT *****'] 625821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.info('Unable to splice %s. Incomplete logcat?', cur_file) 635821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 645821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) cur_device_log += ['*'*30 + ' %s' % cur_file] 655821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) cur_device_log.extend(cur_file_lines[common_index:]) 665821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 675821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return cur_device_log 685821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 695821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 705821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)def FindLogFiles(base_dir): 715821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) """Search a directory for logcat files. 725821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 735821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Args: 745821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) base_dir: directory to search 755821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 765821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Returns: 775821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Mapping of device_id to a sorted list of file paths for a given device 785821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) """ 795821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logcat_filter = re.compile('^logcat_(\w+)_(\d+)$') 805821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # list of tuples (<device_id>, <seq num>, <full file path>) 815821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) filtered_list = [] 825821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) for cur_file in os.listdir(base_dir): 835821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) matcher = logcat_filter.match(cur_file) 845821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if matcher: 855821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) filtered_list += [(matcher.group(1), int(matcher.group(2)), 865821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) os.path.join(base_dir, cur_file))] 875821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) filtered_list.sort() 885821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) file_map = {} 895821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) for device_id, _, cur_file in filtered_list: 905821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if not device_id in file_map: 915821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) file_map[device_id] = [] 925821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 935821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) file_map[device_id] += [cur_file] 945821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return file_map 955821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 965821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 975821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)def GetDeviceLogs(log_filenames, logger): 985821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) """Read log files, combine and format. 995821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1005821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Args: 1015821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) log_filenames: mapping of device_id to sorted list of file paths 1025821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger: logger handle for logging events 1035821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1045821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Returns: 1055821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) list of formatted device logs, one for each device. 1065821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) """ 1075821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) device_logs = [] 1085821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1095821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) for device, device_files in log_filenames.iteritems(): 1105821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.debug('%s: %s', device, str(device_files)) 1115821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) device_file_lines = [] 1125821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) for cur_file in device_files: 1135821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) with open(cur_file) as f: 1145821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) device_file_lines += [(cur_file, f.read().splitlines())] 1155821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) combined_lines = CombineLogFiles(device_file_lines, logger) 1165821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # Prepend each line with a short unique ID so it's easy to see 1175821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # when the device changes. We don't use the start of the device 1185821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # ID because it can be the same among devices. Example lines: 1195821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # AB324: foo 1205821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # AB324: blah 1215821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) device_logs += [('\n' + device[-5:] + ': ').join(combined_lines)] 1225821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return device_logs 1235821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1245821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1255821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)def ShutdownLogcatMonitor(base_dir, logger): 1265821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) """Attempts to shutdown adb_logcat_monitor and blocks while waiting.""" 1275821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) try: 1285821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) monitor_pid_path = os.path.join(base_dir, 'LOGCAT_MONITOR_PID') 1295821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) with open(monitor_pid_path) as f: 1305821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) monitor_pid = int(f.readline()) 1315821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1325821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.info('Sending SIGTERM to %d', monitor_pid) 1335821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) os.kill(monitor_pid, signal.SIGTERM) 1345821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) i = 0 1355821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) while True: 1365821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) time.sleep(.2) 1375821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if not os.path.exists(monitor_pid_path): 1385821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return 1395821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if not os.path.exists('/proc/%d' % monitor_pid): 1405821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.warning('Monitor (pid %d) terminated uncleanly?', monitor_pid) 1415821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return 1425821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.info('Waiting for logcat process to terminate.') 1435821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) i += 1 1445821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if i >= 10: 1455821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.warning('Monitor pid did not terminate. Continuing anyway.') 1465821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return 1475821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1485821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) except (ValueError, IOError, OSError): 1495821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.exception('Error signaling logcat monitor - continuing') 1505821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1515821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1525821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)def main(base_dir, output_file): 1535821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) log_stringio = cStringIO.StringIO() 1545821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger = logging.getLogger('LogcatPrinter') 1555821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.setLevel(LOG_LEVEL) 1565821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) sh = logging.StreamHandler(log_stringio) 1575821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) sh.setFormatter(logging.Formatter('%(asctime)-2s %(levelname)-8s' 1585821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) ' %(message)s')) 1595821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.addHandler(sh) 1605821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1615821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) try: 1625821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # Wait at least 5 seconds after base_dir is created before printing. 1635821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # 1645821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # The idea is that 'adb logcat > file' output consists of 2 phases: 1655821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # 1 Dump all the saved logs to the file 1665821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # 2 Stream log messages as they are generated 1675821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # 1685821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # We want to give enough time for phase 1 to complete. There's no 1695821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # good method to tell how long to wait, but it usually only takes a 1705821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # second. On most bots, this code path won't occur at all, since 1715821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # adb_logcat_monitor.py command will have spawned more than 5 seconds 1725821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) # prior to called this shell script. 1735821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) try: 1745821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) sleep_time = 5 - (time.time() - os.path.getctime(base_dir)) 1755821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) except OSError: 1765821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) sleep_time = 5 1775821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if sleep_time > 0: 1785821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.warning('Monitor just started? Sleeping %.1fs', sleep_time) 1795821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) time.sleep(sleep_time) 1805821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1815821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) assert os.path.exists(base_dir), '%s does not exist' % base_dir 1825821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) ShutdownLogcatMonitor(base_dir, logger) 1835821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) separator = '\n' + '*' * 80 + '\n\n' 1845821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) for log in GetDeviceLogs(FindLogFiles(base_dir), logger): 1855821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) output_file.write(log) 1865821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) output_file.write(separator) 1875821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) with open(os.path.join(base_dir, 'eventlog')) as f: 1885821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) output_file.write('\nLogcat Monitor Event Log\n') 1895821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) output_file.write(f.read()) 1905821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) except: 1915821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.exception('Unexpected exception') 1925821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1935821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) logger.info('Done.') 1945821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) sh.flush() 1955821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) output_file.write('\nLogcat Printer Event Log\n') 1965821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) output_file.write(log_stringio.getvalue()) 1975821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1985821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)if __name__ == '__main__': 1995821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if len(sys.argv) == 1: 2005821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) print 'Usage: %s <base_dir>' % sys.argv[0] 2015821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) sys.exit(1) 2025821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) sys.exit(main(sys.argv[1], sys.stdout)) 203