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