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