2 files changed, 192 insertions, 0 deletions
diff --git a/startop/scripts/lib/logcat_utils.py b/startop/scripts/lib/logcat_utils.py
new file mode 100644
index 000000000000..13b1c3a5cff7
--- /dev/null
+++ b/startop/scripts/lib/logcat_utils.py
@@ -0,0 +1,104 @@
+#!/usr/bin/env python3
+#
+# Copyright 2019, The Android Open Source Project
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+"""Helper util libraries for parsing logcat logs."""
+
+import asyncio
+import re
+from datetime import datetime
+from typing import Optional, Pattern
+
+# local import
+import print_utils
+
+def parse_logcat_datetime(timestamp: str) -> Optional[datetime]:
+  """Parses the timestamp of logcat.
+
+  Params:
+    timestamp: for example "2019-07-01 16:13:55.221".
+
+  Returns:
+    a datetime of timestamp with the year now.
+  """
+  try:
+    # Match the format of logcat. For example: "2019-07-01 16:13:55.221",
+    # because it doesn't have year, set current year to it.
+    timestamp = datetime.strptime(timestamp,
+                                  '%Y-%m-%d %H:%M:%S.%f')
+    return timestamp
+  except ValueError as ve:
+    print_utils.debug_print('Invalid line: ' + timestamp)
+    return None
+
+def _is_time_out(timeout: datetime, line: str) -> bool:
+  """Checks if the timestamp of this line exceeds the timeout.
+
+  Returns:
+    true if the timestamp exceeds the timeout.
+  """
+  # Get the timestampe string.
+  cur_timestamp_str = ' '.join(re.split(r'\s+', line)[0:2])
+  timestamp = parse_logcat_datetime(cur_timestamp_str)
+  if not timestamp:
+    return False
+
+  return timestamp > timeout
+
+async def _blocking_wait_for_logcat_pattern(timestamp: datetime,
+                                            pattern: Pattern,
+                                            timeout: datetime) -> Optional[str]:
+  # Show the year in the timestampe.
+  logcat_cmd = 'adb logcat -v year -v threadtime -T'.split()
+  logcat_cmd.append(str(timestamp))
+  print_utils.debug_print('[LOGCAT]:' + ' '.join(logcat_cmd))
+
+  # Create subprocess
+  process = await asyncio.create_subprocess_exec(
+      *logcat_cmd,
+      # stdout must a pipe to be accessible as process.stdout
+      stdout=asyncio.subprocess.PIPE)
+
+  while (True):
+    # Read one line of output.
+    data = await process.stdout.readline()
+    line = data.decode('utf-8').rstrip()
+
+    # 2019-07-01 14:54:21.946 27365 27392 I ActivityTaskManager: Displayed
+    # com.android.settings/.Settings: +927ms
+    # TODO: Detect timeouts even when there is no logcat output.
+    if _is_time_out(timeout, line):
+      print_utils.debug_print('DID TIMEOUT BEFORE SEEING ANYTHING ('
+                              'timeout={timeout} seconds << {pattern} '
+                              '>>'.format(timeout=timeout, pattern=pattern))
+      return None
+
+    if pattern.match(line):
+      print_utils.debug_print(
+          'WE DID SEE PATTERN << "{}" >>.'.format(pattern))
+      return line
+
+def blocking_wait_for_logcat_pattern(timestamp: datetime,
+                                     pattern: Pattern,
+                                     timeout: datetime) -> Optional[str]:
+  """Selects the line that matches the pattern and within the timeout.
+
+  Returns:
+    the line that matches the pattern and within the timeout.
+  """
+  loop = asyncio.get_event_loop()
+  result = loop.run_until_complete(
+      _blocking_wait_for_logcat_pattern(timestamp, pattern, timeout))
+  return result
diff --git a/startop/scripts/lib/logcat_utils_test.py b/startop/scripts/lib/logcat_utils_test.py
new file mode 100644
index 000000000000..ab82515bc4fa
--- /dev/null
+++ b/startop/scripts/lib/logcat_utils_test.py
@@ -0,0 +1,88 @@
+#!/usr/bin/env python3
+#
+# Copyright 2019, The Android Open Source Project
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+#
+"""Unit tests for the logcat_utils.py script."""
+
+import asyncio
+import datetime
+import re
+
+import logcat_utils
+from mock import MagicMock, patch
+
+def test_parse_logcat_datatime():
+  # Act
+  result = logcat_utils.parse_logcat_datetime('2019-07-01 16:13:55.221')
+
+  # Assert
+  assert result == datetime.datetime(2019, 7, 1, 16, 13, 55, 221000)
+
+class AsyncMock(MagicMock):
+  async def __call__(self, *args, **kwargs):
+    return super(AsyncMock, self).__call__(*args, **kwargs)
+
+def _async_return():
+  f = asyncio.Future()
+  f.set_result(
+      b'2019-07-01 15:51:53.290 27365 27392 I ActivityTaskManager: '
+      b'Displayed com.google.android.music/com.android.music.activitymanagement.'
+      b'TopLevelActivity: +1s7ms')
+  return f
+
+def test_parse_displayed_time_succeed():
+  # Act
+  with patch('asyncio.create_subprocess_exec',
+             new_callable=AsyncMock) as asyncio_mock:
+    asyncio_mock.return_value.stdout.readline = _async_return
+    timestamp = datetime.datetime(datetime.datetime.now().year, 7, 1, 16, 13,
+                                  55, 221000)
+    timeout_dt = timestamp + datetime.timedelta(0, 10)
+    pattern = re.compile('.*ActivityTaskManager: Displayed '
+                         'com.google.android.music/com.android.music.*')
+    result = logcat_utils.blocking_wait_for_logcat_pattern(timestamp,
+                                                           pattern,
+                                                           timeout_dt)
+
+    # Assert
+    assert result == '2019-07-01 15:51:53.290 27365 27392 I ' \
+                     'ActivityTaskManager: ' \
+                     'Displayed com.google.android.music/com.android.music.' \
+                     'activitymanagement.TopLevelActivity: +1s7ms'
+
+def _async_timeout_return():
+  f = asyncio.Future()
+  f.set_result(
+      b'2019-07-01 17:51:53.290 27365 27392 I ActivityTaskManager: '
+      b'Displayed com.google.android.music/com.android.music.activitymanagement.'
+      b'TopLevelActivity: +1s7ms')
+  return f
+
+def test_parse_displayed_time_timeout():
+  # Act
+  with patch('asyncio.create_subprocess_exec',
+             new_callable=AsyncMock) as asyncio_mock:
+    asyncio_mock.return_value.stdout.readline = _async_timeout_return
+    timestamp = datetime.datetime(datetime.datetime.now().year,
+                                  7, 1, 16, 13, 55, 221000)
+    timeout_dt = timestamp + datetime.timedelta(0, 10)
+    pattern = re.compile('.*ActivityTaskManager: Displayed '
+                         'com.google.android.music/com.android.music.*')
+    result = logcat_utils.blocking_wait_for_logcat_pattern(timestamp,
+                                                           pattern,
+                                                           timeout_dt)
+
+    # Assert
+    assert result == None