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