diff options
Diffstat (limited to 'startop/scripts/lib')
| -rw-r--r-- | startop/scripts/lib/cmd_utils.py | 184 | ||||
| -rw-r--r-- | startop/scripts/lib/logcat_utils.py | 104 | ||||
| -rw-r--r-- | startop/scripts/lib/logcat_utils_test.py | 88 | ||||
| -rw-r--r-- | startop/scripts/lib/print_utils.py | 67 |
4 files changed, 443 insertions, 0 deletions
diff --git a/startop/scripts/lib/cmd_utils.py b/startop/scripts/lib/cmd_utils.py new file mode 100644 index 000000000000..6071f145fe1d --- /dev/null +++ b/startop/scripts/lib/cmd_utils.py @@ -0,0 +1,184 @@ +#!/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 command line operations.""" + +import asyncio +import sys +import time +from typing import Tuple, Optional, List + +import lib.print_utils as print_utils + +TIMEOUT = 50 +SIMULATE = False + +def run_command_nofail(cmd: List[str], **kwargs) -> None: + """Runs cmd list with default timeout. + + Throws exception if the execution fails. + """ + my_kwargs = {"timeout": TIMEOUT, "shell": False, "simulate": False} + my_kwargs.update(kwargs) + passed, out = execute_arbitrary_command(cmd, **my_kwargs) + if not passed: + raise RuntimeError( + "Failed to execute %s (kwargs=%s), output=%s" % (cmd, kwargs, out)) + +def run_adb_shell_command(cmd: str) -> Tuple[bool, str]: + """Runs command using adb shell. + + Returns: + A tuple of running status (True=succeeded, False=failed or timed out) and + std output (string contents of stdout with trailing whitespace removed). + """ + return run_shell_command('adb shell "{}"'.format(cmd)) + +def run_shell_func(script_path: str, + func: str, + args: List[str]) -> Tuple[bool, str]: + """Runs shell function with default timeout. + + Returns: + A tuple of running status (True=succeeded, False=failed or timed out) and + std output (string contents of stdout with trailing whitespace removed) . + """ + if args: + cmd = 'bash -c "source {script_path}; {func} {args}"'.format( + script_path=script_path, + func=func, + args=' '.join("'{}'".format(arg) for arg in args)) + else: + cmd = 'bash -c "source {script_path}; {func}"'.format( + script_path=script_path, + func=func) + + print_utils.debug_print(cmd) + return run_shell_command(cmd) + +def run_shell_command(cmd: str) -> Tuple[bool, str]: + """Runs shell command with default timeout. + + Returns: + A tuple of running status (True=succeeded, False=failed or timed out) and + std output (string contents of stdout with trailing whitespace removed) . + """ + return execute_arbitrary_command([cmd], + TIMEOUT, + shell=True, + simulate=SIMULATE) + +def execute_arbitrary_command(cmd: List[str], + timeout: int, + shell: bool, + simulate: bool) -> Tuple[bool, str]: + """Run arbitrary shell command with default timeout. + + Mostly copy from + frameworks/base/startop/scripts/app_startup/app_startup_runner.py. + + Args: + cmd: list of cmd strings. + timeout: the time limit of running cmd. + shell: indicate if the cmd is a shell command. + simulate: if it's true, do not run the command and assume the running is + successful. + + Returns: + A tuple of running status (True=succeeded, False=failed or timed out) and + std output (string contents of stdout with trailing whitespace removed) . + """ + if simulate: + print(cmd) + return True, '' + + print_utils.debug_print('[EXECUTE]', cmd) + # block until either command finishes or the timeout occurs. + loop = asyncio.get_event_loop() + + (return_code, script_output) = loop.run_until_complete( + _run_command(*cmd, shell=shell, timeout=timeout)) + + script_output = script_output.decode() # convert bytes to str + + passed = (return_code == 0) + print_utils.debug_print('[$?]', return_code) + if not passed: + print('[FAILED, code:%s]' % (return_code), script_output, file=sys.stderr) + + return passed, script_output.rstrip() + +async def _run_command(*args: List[str], + shell: bool = False, + timeout: Optional[int] = None) -> Tuple[int, bytes]: + if shell: + process = await asyncio.create_subprocess_shell( + *args, stdout=asyncio.subprocess.PIPE, stderr=asyncio.subprocess.STDOUT) + else: + process = await asyncio.create_subprocess_exec( + *args, stdout=asyncio.subprocess.PIPE, stderr=asyncio.subprocess.STDOUT) + + script_output = b'' + + print_utils.debug_print('[PID]', process.pid) + + timeout_remaining = timeout + time_started = time.time() + + # read line (sequence of bytes ending with b'\n') asynchronously + while True: + try: + line = await asyncio.wait_for(process.stdout.readline(), + timeout_remaining) + print_utils.debug_print('[STDOUT]', line) + script_output += line + + if timeout_remaining: + time_elapsed = time.time() - time_started + timeout_remaining = timeout - time_elapsed + except asyncio.TimeoutError: + print_utils.debug_print('[TIMEDOUT] Process ', process.pid) + + print_utils.debug_print('[TIMEDOUT] Sending SIGTERM.') + process.terminate() + + # 5 second timeout for process to handle SIGTERM nicely. + try: + (remaining_stdout, + remaining_stderr) = await asyncio.wait_for(process.communicate(), 5) + script_output += remaining_stdout + except asyncio.TimeoutError: + print_utils.debug_print('[TIMEDOUT] Sending SIGKILL.') + process.kill() + + # 5 second timeout to finish with SIGKILL. + try: + (remaining_stdout, + remaining_stderr) = await asyncio.wait_for(process.communicate(), 5) + script_output += remaining_stdout + except asyncio.TimeoutError: + # give up, this will leave a zombie process. + print_utils.debug_print('[TIMEDOUT] SIGKILL failed for process ', + process.pid) + time.sleep(100) + + return -1, script_output + else: + if not line: # EOF + break + + code = await process.wait() # wait for child process to exit + return code, script_output diff --git a/startop/scripts/lib/logcat_utils.py b/startop/scripts/lib/logcat_utils.py new file mode 100644 index 000000000000..8a3d00b46771 --- /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 lib.print_utils as 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 UTC -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 diff --git a/startop/scripts/lib/print_utils.py b/startop/scripts/lib/print_utils.py new file mode 100644 index 000000000000..8c5999d99d6e --- /dev/null +++ b/startop/scripts/lib/print_utils.py @@ -0,0 +1,67 @@ +#!/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 debug printing.""" + +import sys + +DEBUG = False + +def debug_print(*args, **kwargs): + """Prints the args to sys.stderr if the DEBUG is set.""" + if DEBUG: + print(*args, **kwargs, file=sys.stderr) + +def error_print(*args, **kwargs): + print('[ERROR]:', *args, file=sys.stderr, **kwargs) + +def _expand_gen_repr(args): + """Like repr but any generator-like object has its iterator consumed + and then called repr on.""" + new_args_list = [] + for i in args: + # detect iterable objects that do not have their own override of __str__ + if hasattr(i, '__iter__'): + to_str = getattr(i, '__str__') + if to_str.__objclass__ == object: + # the repr for a generator is just type+address, expand it out instead. + new_args_list.append([_expand_gen_repr([j])[0] for j in i]) + continue + # normal case: uses the built-in to-string + new_args_list.append(i) + return new_args_list + +def debug_print_gen(*args, **kwargs): + """Like _debug_print but will turn any iterable args into a list.""" + if not DEBUG: + return + + new_args_list = _expand_gen_repr(args) + debug_print(*new_args_list, **kwargs) + +def debug_print_nd(*args, **kwargs): + """Like _debug_print but will turn any NamedTuple-type args into a string.""" + if not DEBUG: + return + + new_args_list = [] + for i in args: + if hasattr(i, '_field_types'): + new_args_list.append("%s: %s" % (i.__name__, i._field_types)) + else: + new_args_list.append(i) + + debug_print(*new_args_list, **kwargs) |