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