Home | History | Annotate | Download | only in android
      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))
    203