1# Copyright 2015 The Chromium Authors. All rights reserved. 2# Use of this source code is governed by a BSD-style license that can be 3# found in the LICENSE file. 4 5# pylint: disable=unused-argument 6 7import errno 8import logging 9import os 10import re 11import shutil 12import tempfile 13import threading 14import time 15 16from devil.android import decorators 17from devil.android import device_errors 18from devil.android.sdk import adb_wrapper 19from devil.utils import reraiser_thread 20 21logger = logging.getLogger(__name__) 22 23 24class LogcatMonitor(object): 25 26 _RECORD_ITER_TIMEOUT = 0.2 27 _RECORD_THREAD_JOIN_WAIT = 5.0 28 _WAIT_TIME = 0.2 29 THREADTIME_RE_FORMAT = ( 30 r'(?P<date>\S*) +(?P<time>\S*) +(?P<proc_id>%s) +(?P<thread_id>%s) +' 31 r'(?P<log_level>%s) +(?P<component>%s) *: +(?P<message>%s)$') 32 33 def __init__(self, adb, clear=True, filter_specs=None, output_file=None, 34 transform_func=None): 35 """Create a LogcatMonitor instance. 36 37 Args: 38 adb: An instance of adb_wrapper.AdbWrapper. 39 clear: If True, clear the logcat when monitoring starts. 40 filter_specs: An optional list of '<tag>[:priority]' strings. 41 output_file: File path to save recorded logcat. 42 transform_func: An optional unary callable that takes and returns 43 a list of lines, possibly transforming them in the process. 44 """ 45 if isinstance(adb, adb_wrapper.AdbWrapper): 46 self._adb = adb 47 else: 48 raise ValueError('Unsupported type passed for argument "device"') 49 self._clear = clear 50 self._filter_specs = filter_specs 51 self._output_file = output_file 52 self._record_file = None 53 self._record_file_lock = threading.Lock() 54 self._record_thread = None 55 self._stop_recording_event = threading.Event() 56 self._transform_func = transform_func 57 58 @property 59 def output_file(self): 60 return self._output_file 61 62 @decorators.WithTimeoutAndRetriesDefaults(10, 0) 63 def WaitFor(self, success_regex, failure_regex=None, timeout=None, 64 retries=None): 65 """Wait for a matching logcat line or until a timeout occurs. 66 67 This will attempt to match lines in the logcat against both |success_regex| 68 and |failure_regex| (if provided). Note that this calls re.search on each 69 logcat line, not re.match, so the provided regular expressions don't have 70 to match an entire line. 71 72 Args: 73 success_regex: The regular expression to search for. 74 failure_regex: An optional regular expression that, if hit, causes this 75 to stop looking for a match. Can be None. 76 timeout: timeout in seconds 77 retries: number of retries 78 79 Returns: 80 A match object if |success_regex| matches a part of a logcat line, or 81 None if |failure_regex| matches a part of a logcat line. 82 Raises: 83 CommandFailedError on logcat failure (NOT on a |failure_regex| match). 84 CommandTimeoutError if no logcat line matching either |success_regex| or 85 |failure_regex| is found in |timeout| seconds. 86 DeviceUnreachableError if the device becomes unreachable. 87 LogcatMonitorCommandError when calling |WaitFor| while not recording 88 logcat. 89 """ 90 if self._record_thread is None: 91 raise LogcatMonitorCommandError( 92 'Must be recording logcat when calling |WaitFor|', 93 device_serial=str(self._adb)) 94 if isinstance(success_regex, basestring): 95 success_regex = re.compile(success_regex) 96 if isinstance(failure_regex, basestring): 97 failure_regex = re.compile(failure_regex) 98 99 logger.debug('Waiting %d seconds for "%s"', timeout, success_regex.pattern) 100 101 # NOTE This will continue looping until: 102 # - success_regex matches a line, in which case the match object is 103 # returned. 104 # - failure_regex matches a line, in which case None is returned 105 # - the timeout is hit, in which case a CommandTimeoutError is raised. 106 with open(self._record_file.name, 'r') as f: 107 while True: 108 line = f.readline() 109 if line: 110 m = success_regex.search(line) 111 if m: 112 return m 113 if failure_regex and failure_regex.search(line): 114 return None 115 else: 116 time.sleep(self._WAIT_TIME) 117 118 def FindAll(self, message_regex, proc_id=None, thread_id=None, log_level=None, 119 component=None): 120 """Finds all lines in the logcat that match the provided constraints. 121 122 Args: 123 message_regex: The regular expression that the <message> section must 124 match. 125 proc_id: The process ID to match. If None, matches any process ID. 126 thread_id: The thread ID to match. If None, matches any thread ID. 127 log_level: The log level to match. If None, matches any log level. 128 component: The component to match. If None, matches any component. 129 130 Raises: 131 LogcatMonitorCommandError when calling |FindAll| before recording logcat. 132 133 Yields: 134 A match object for each matching line in the logcat. The match object 135 will always contain, in addition to groups defined in |message_regex|, 136 the following named groups: 'date', 'time', 'proc_id', 'thread_id', 137 'log_level', 'component', and 'message'. 138 """ 139 if self._record_file is None: 140 raise LogcatMonitorCommandError( 141 'Must have recorded or be recording a logcat to call |FindAll|', 142 device_serial=str(self._adb)) 143 if proc_id is None: 144 proc_id = r'\d+' 145 if thread_id is None: 146 thread_id = r'\d+' 147 if log_level is None: 148 log_level = r'[VDIWEF]' 149 if component is None: 150 component = r'[^\s:]+' 151 # pylint: disable=protected-access 152 threadtime_re = re.compile( 153 type(self).THREADTIME_RE_FORMAT % ( 154 proc_id, thread_id, log_level, component, message_regex)) 155 156 with open(self._record_file.name, 'r') as f: 157 for line in f: 158 m = re.match(threadtime_re, line) 159 if m: 160 yield m 161 162 def _StartRecording(self): 163 """Starts recording logcat to file. 164 165 Function spawns a thread that records logcat to file and will not die 166 until |StopRecording| is called. 167 """ 168 def record_to_file(): 169 # Write the log with line buffering so the consumer sees each individual 170 # line. 171 for data in self._adb.Logcat(filter_specs=self._filter_specs, 172 logcat_format='threadtime', 173 iter_timeout=self._RECORD_ITER_TIMEOUT): 174 if self._stop_recording_event.isSet(): 175 return 176 177 if data is None: 178 # Logcat can yield None if the iter_timeout is hit. 179 continue 180 181 with self._record_file_lock: 182 if self._record_file and not self._record_file.closed: 183 if self._transform_func: 184 data = '\n'.join(self._transform_func([data])) 185 self._record_file.write(data + '\n') 186 187 self._stop_recording_event.clear() 188 if not self._record_thread: 189 self._record_thread = reraiser_thread.ReraiserThread(record_to_file) 190 self._record_thread.start() 191 192 def _StopRecording(self): 193 """Finish recording logcat.""" 194 if self._record_thread: 195 self._stop_recording_event.set() 196 self._record_thread.join(timeout=self._RECORD_THREAD_JOIN_WAIT) 197 self._record_thread.ReraiseIfException() 198 self._record_thread = None 199 200 def Start(self): 201 """Starts the logcat monitor. 202 203 Clears the logcat if |clear| was set in |__init__|. 204 """ 205 if self._clear: 206 self._adb.Logcat(clear=True) 207 if not self._record_file: 208 self._record_file = tempfile.NamedTemporaryFile(mode='a', bufsize=1) 209 self._StartRecording() 210 211 def Stop(self): 212 """Stops the logcat monitor. 213 214 Stops recording the logcat. Copies currently recorded logcat to 215 |self._output_file|. 216 """ 217 self._StopRecording() 218 with self._record_file_lock: 219 if self._record_file and self._output_file: 220 try: 221 os.makedirs(os.path.dirname(self._output_file)) 222 except OSError as e: 223 if e.errno != errno.EEXIST: 224 raise 225 shutil.copy(self._record_file.name, self._output_file) 226 227 def Close(self): 228 """Closes logcat recording file. 229 230 Should be called when finished using the logcat monitor. 231 """ 232 with self._record_file_lock: 233 if self._record_file: 234 self._record_file.close() 235 self._record_file = None 236 237 def close(self): 238 """An alias for Close. 239 240 Allows LogcatMonitors to be used with contextlib.closing. 241 """ 242 self.Close() 243 244 def __enter__(self): 245 """Starts the logcat monitor.""" 246 self.Start() 247 return self 248 249 def __exit__(self, exc_type, exc_val, exc_tb): 250 """Stops the logcat monitor.""" 251 self.Stop() 252 253 def __del__(self): 254 """Closes logcat recording file in case |Close| was never called.""" 255 with self._record_file_lock: 256 if self._record_file: 257 logger.warning( 258 'Need to call |Close| on the logcat monitor when done!') 259 self._record_file.close() 260 261 @property 262 def adb(self): 263 return self._adb 264 265 266class LogcatMonitorCommandError(device_errors.CommandFailedError): 267 """Exception for errors with logcat monitor commands.""" 268 pass 269