adb_logcat_printer.py 6.6 KB

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