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