adb_logcat_printer.py 7.3 KB

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