| # Copyright 2018 Google Inc. |
| # |
| # 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. |
| |
| import io |
| import logging |
| import mock |
| import os |
| import shutil |
| import tempfile |
| |
| from future.tests.base import unittest |
| |
| from mobly import utils |
| from mobly import runtime_test_info |
| from mobly.controllers import android_device |
| from mobly.controllers.android_device_lib import adb |
| from mobly.controllers.android_device_lib.services import logcat |
| |
| from tests.lib import mock_android_device |
| |
| # The expected result of the cat adb operation. |
| MOCK_ADB_LOGCAT_CAT_RESULT = [ |
| '02-29 14:02:21.456 4454 Something\n', |
| '02-29 14:02:21.789 4454 Something again\n' |
| ] |
| # A mocked piece of adb logcat output. |
| MOCK_ADB_LOGCAT = (u'02-29 14:02:19.123 4454 Nothing\n' |
| u'%s' |
| u'02-29 14:02:22.123 4454 Something again and again\n' |
| ) % u''.join(MOCK_ADB_LOGCAT_CAT_RESULT) |
| # The expected result of the cat adb operation. |
| MOCK_ADB_UNICODE_LOGCAT_CAT_RESULT = [ |
| '02-29 14:02:21.456 4454 Something \u901a\n', |
| '02-29 14:02:21.789 4454 Something again\n' |
| ] |
| # A mocked piece of adb logcat output. |
| MOCK_ADB_UNICODE_LOGCAT = ( |
| u'02-29 14:02:19.123 4454 Nothing\n' |
| u'%s' |
| u'02-29 14:02:22.123 4454 Something again and again\n' |
| ) % u''.join(MOCK_ADB_UNICODE_LOGCAT_CAT_RESULT) |
| |
| # Mock start and end time of the adb cat. |
| MOCK_ADB_LOGCAT_BEGIN_TIME = '02-29 14:02:20.123' |
| MOCK_ADB_LOGCAT_END_TIME = '02-29 14:02:22.000' |
| |
| # Mock AdbError for missing logpersist scripts |
| MOCK_LOGPERSIST_STOP_MISSING_ADB_ERROR = adb.AdbError( |
| 'logpersist.stop --clear', b'', |
| '/system/bin/sh: logpersist.stop: not found', 0) |
| MOCK_LOGPERSIST_START_MISSING_ADB_ERROR = adb.AdbError( |
| 'logpersist.start --clear', b'', |
| b'/system/bin/sh: logpersist.stop: not found', 0) |
| |
| |
| class LogcatTest(unittest.TestCase): |
| """Tests for Logcat service and its integration with AndroidDevice.""" |
| |
| def setUp(self): |
| # Set log_path to logging since mobly logger setup is not called. |
| if not hasattr(logging, 'log_path'): |
| setattr(logging, 'log_path', '/tmp/logs') |
| # Creates a temp dir to be used by tests in this test class. |
| self.tmp_dir = tempfile.mkdtemp() |
| |
| def tearDown(self): |
| """Removes the temp dir. |
| """ |
| shutil.rmtree(self.tmp_dir) |
| |
| def AssertFileContains(self, content, file_path): |
| with open(file_path, 'r') as f: |
| output = f.read() |
| self.assertIn(content, output) |
| |
| def AssertFileDoesNotContain(self, content, file_path): |
| with open(file_path, 'r') as f: |
| output = f.read() |
| self.assertNotIn(content, output) |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock_android_device.MockAdbProxy('1')) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| @mock.patch('mobly.utils.create_dir') |
| @mock.patch('mobly.utils.start_standing_subprocess', |
| return_value='process') |
| @mock.patch('mobly.utils.stop_standing_subprocess') |
| @mock.patch.object(logcat.Logcat, '_open_logcat_file') |
| @mock.patch('mobly.logger.get_log_file_timestamp') |
| def test_start_and_stop(self, get_timestamp_mock, open_logcat_mock, |
| stop_proc_mock, start_proc_mock, create_dir_mock, |
| FastbootProxy, MockAdbProxy): |
| """Verifies the steps of collecting adb logcat on an AndroidDevice |
| object, including various function calls and the expected behaviors of |
| the calls. |
| """ |
| mock_serial = '1' |
| get_timestamp_mock.return_value = '123' |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad) |
| logcat_service.start() |
| # Verify start did the correct operations. |
| self.assertTrue(logcat_service._adb_logcat_process) |
| expected_log_path = os.path.join( |
| logging.log_path, 'AndroidDevice%s' % ad.serial, |
| 'logcat,%s,fakemodel,123.txt' % ad.serial) |
| create_dir_mock.assert_called_with(os.path.dirname(expected_log_path)) |
| adb_cmd = ' "adb" -s %s logcat -v threadtime -T 1 >> %s' |
| start_proc_mock.assert_called_with( |
| adb_cmd % (ad.serial, '"%s" ' % expected_log_path), shell=True) |
| self.assertEqual(logcat_service.adb_logcat_file_path, |
| expected_log_path) |
| expected_msg = ( |
| 'Logcat thread is already running, cannot start another' |
| ' one.') |
| # Expect error if start is called back to back. |
| with self.assertRaisesRegex(logcat.Error, expected_msg): |
| logcat_service.start() |
| # Verify stop did the correct operations. |
| logcat_service.stop() |
| stop_proc_mock.assert_called_with('process') |
| self.assertIsNone(logcat_service._adb_logcat_process) |
| self.assertEqual(logcat_service.adb_logcat_file_path, |
| expected_log_path) |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock_android_device.MockAdbProxy('1')) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| @mock.patch('mobly.utils.create_dir') |
| @mock.patch('mobly.utils.start_standing_subprocess', |
| return_value='process') |
| @mock.patch('mobly.utils.stop_standing_subprocess') |
| @mock.patch.object(logcat.Logcat, '_open_logcat_file') |
| def test_update_config(self, open_logcat_mock, stop_proc_mock, |
| start_proc_mock, create_dir_mock, FastbootProxy, |
| MockAdbProxy): |
| mock_serial = '1' |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad) |
| logcat_service.start() |
| logcat_service.stop() |
| new_log_params = '-a -b -c' |
| new_file_path = 'some/path/log.txt' |
| new_config = logcat.Config(logcat_params=new_log_params, |
| output_file_path=new_file_path) |
| logcat_service.update_config(new_config) |
| logcat_service.start() |
| self.assertTrue(logcat_service._adb_logcat_process) |
| create_dir_mock.assert_has_calls([mock.call('some/path')]) |
| expected_adb_cmd = (' "adb" -s 1 logcat -v threadtime -T 1 -a -b -c >> ' |
| '"some/path/log.txt" ') |
| start_proc_mock.assert_called_with(expected_adb_cmd, shell=True) |
| self.assertEqual(logcat_service.adb_logcat_file_path, |
| 'some/path/log.txt') |
| logcat_service.stop() |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock_android_device.MockAdbProxy('1')) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| @mock.patch('mobly.utils.create_dir') |
| @mock.patch('mobly.utils.start_standing_subprocess', |
| return_value='process') |
| @mock.patch('mobly.utils.stop_standing_subprocess') |
| @mock.patch.object(logcat.Logcat, '_open_logcat_file') |
| def test_update_config_while_running(self, open_logcat_mock, stop_proc_mock, |
| start_proc_mock, create_dir_mock, |
| FastbootProxy, MockAdbProxy): |
| mock_serial = '1' |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad) |
| logcat_service.start() |
| new_config = logcat.Config(logcat_params='-blah', |
| output_file_path='some/path/file.txt') |
| with self.assertRaisesRegex( |
| logcat.Error, |
| 'Logcat thread is already running, cannot start another one'): |
| logcat_service.update_config(new_config) |
| self.assertTrue(logcat_service.is_alive) |
| logcat_service.stop() |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock_android_device.MockAdbProxy('1')) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| @mock.patch('mobly.utils.create_dir') |
| @mock.patch('mobly.utils.start_standing_subprocess', |
| return_value='process') |
| @mock.patch('mobly.utils.stop_standing_subprocess') |
| @mock.patch.object(logcat.Logcat, '_open_logcat_file') |
| @mock.patch( |
| 'mobly.controllers.android_device_lib.services.logcat.Logcat.clear_adb_log', |
| return_value=mock_android_device.MockAdbProxy('1')) |
| def test_pause_and_resume(self, clear_adb_mock, open_logcat_mock, |
| stop_proc_mock, start_proc_mock, create_dir_mock, |
| FastbootProxy, MockAdbProxy): |
| mock_serial = '1' |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad, logcat.Config(clear_log=True)) |
| logcat_service.start() |
| clear_adb_mock.assert_called_once_with() |
| self.assertTrue(logcat_service.is_alive) |
| logcat_service.pause() |
| self.assertFalse(logcat_service.is_alive) |
| stop_proc_mock.assert_called_with('process') |
| self.assertIsNone(logcat_service._adb_logcat_process) |
| clear_adb_mock.reset_mock() |
| logcat_service.resume() |
| self.assertTrue(logcat_service.is_alive) |
| clear_adb_mock.assert_not_called() |
| logcat_service.stop() |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock_android_device.MockAdbProxy('1')) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| @mock.patch('mobly.utils.start_standing_subprocess', |
| return_value='process') |
| @mock.patch('mobly.utils.stop_standing_subprocess') |
| @mock.patch( |
| 'mobly.controllers.android_device_lib.services.logcat.Logcat.clear_adb_log', |
| return_value=mock_android_device.MockAdbProxy('1')) |
| def test_logcat_service_create_output_excerpts(self, clear_adb_mock, |
| stop_proc_mock, |
| start_proc_mock, |
| FastbootProxy, |
| MockAdbProxy): |
| mock_serial = '1' |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad) |
| logcat_service._start() |
| |
| def _write_logcat_file_and_assert_excerpts_exists(logcat_file_content, |
| test_begin_time, |
| test_name): |
| with open(logcat_service.adb_logcat_file_path, 'a') as f: |
| f.write(logcat_file_content) |
| test_output_dir = os.path.join(self.tmp_dir, test_name) |
| mock_record = mock.MagicMock() |
| mock_record.begin_time = test_begin_time |
| test_run_info = runtime_test_info.RuntimeTestInfo(test_name, |
| test_output_dir, |
| mock_record) |
| actual_path = logcat_service.create_output_excerpts(test_run_info)[0] |
| expected_path = os.path.join( |
| test_output_dir, '{test_name}-{test_begin_time}'.format( |
| test_name=test_name, test_begin_time=test_begin_time), |
| 'logcat,{mock_serial},fakemodel,{test_name}-{test_begin_time}.txt' |
| .format( |
| mock_serial=mock_serial, |
| test_name=test_name, |
| test_begin_time=test_begin_time)) |
| self.assertEqual(actual_path, expected_path) |
| self.assertTrue(os.path.exists(expected_path)) |
| return expected_path |
| |
| # Generate logs before the file pointer is created. |
| # This message will not be captured in the excerpt. |
| NOT_IN_EXCERPT = 'Not in excerpt.\n' |
| with open(logcat_service.adb_logcat_file_path, 'a') as f: |
| f.write(NOT_IN_EXCERPT) |
| # With the file pointer created, generate logs and make an excerpt. |
| logcat_service._open_logcat_file() |
| FILE_CONTENT = 'Some log.\n' |
| expected_path1 = _write_logcat_file_and_assert_excerpts_exists( |
| logcat_file_content=FILE_CONTENT, |
| test_begin_time=123, |
| test_name='test_foo', |
| ) |
| self.AssertFileContains(FILE_CONTENT, expected_path1) |
| self.AssertFileDoesNotContain(NOT_IN_EXCERPT, expected_path1) |
| # Generate some new logs and do another excerpt. |
| FILE_CONTENT = 'Some more logs!!!\n' |
| expected_path2 = _write_logcat_file_and_assert_excerpts_exists( |
| logcat_file_content=FILE_CONTENT, |
| test_begin_time=456, |
| test_name='test_bar', |
| ) |
| self.AssertFileContains(FILE_CONTENT, expected_path2) |
| self.AssertFileDoesNotContain(FILE_CONTENT, expected_path1) |
| # Simulate devices accidentally go offline, logcat service stopped. |
| logcat_service.stop() |
| FILE_CONTENT = 'Whatever logs\n' |
| expected_path3 = _write_logcat_file_and_assert_excerpts_exists( |
| logcat_file_content=FILE_CONTENT, |
| test_begin_time=789, |
| test_name='test_offline', |
| ) |
| self.assertEqual(os.stat(expected_path3).st_size, 0) |
| |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock_android_device.MockAdbProxy('1')) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| @mock.patch('mobly.utils.create_dir') |
| @mock.patch('mobly.utils.start_standing_subprocess', |
| return_value='process') |
| @mock.patch('mobly.utils.stop_standing_subprocess') |
| @mock.patch.object(logcat.Logcat, '_open_logcat_file') |
| @mock.patch('mobly.logger.get_log_file_timestamp') |
| def test_take_logcat_with_extra_params(self, get_timestamp_mock, |
| open_logcat_mock, stop_proc_mock, |
| start_proc_mock, create_dir_mock, |
| FastbootProxy, MockAdbProxy): |
| """Verifies the steps of collecting adb logcat on an AndroidDevice |
| object, including various function calls and the expected behaviors of |
| the calls. |
| """ |
| mock_serial = '1' |
| get_timestamp_mock.return_value = '123' |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| configs = logcat.Config() |
| configs.logcat_params = '-b radio' |
| logcat_service = logcat.Logcat(ad, configs) |
| logcat_service.start() |
| # Verify start did the correct operations. |
| self.assertTrue(logcat_service._adb_logcat_process) |
| expected_log_path = os.path.join( |
| logging.log_path, 'AndroidDevice%s' % ad.serial, |
| 'logcat,%s,fakemodel,123.txt' % ad.serial) |
| create_dir_mock.assert_called_with(os.path.dirname(expected_log_path)) |
| adb_cmd = ' "adb" -s %s logcat -v threadtime -T 1 -b radio >> %s' |
| start_proc_mock.assert_called_with( |
| adb_cmd % (ad.serial, '"%s" ' % expected_log_path), shell=True) |
| self.assertEqual(logcat_service.adb_logcat_file_path, |
| expected_log_path) |
| logcat_service.stop() |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock_android_device.MockAdbProxy('1')) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| def test_instantiation(self, MockFastboot, MockAdbProxy): |
| """Verifies the AndroidDevice object's basic attributes are correctly |
| set after instantiation. |
| """ |
| mock_serial = 1 |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad) |
| self.assertIsNone(logcat_service._adb_logcat_process) |
| self.assertIsNone(logcat_service.adb_logcat_file_path) |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock.MagicMock()) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| def test__enable_logpersist_with_logpersist(self, MockFastboot, |
| MockAdbProxy): |
| mock_serial = '1' |
| mock_adb_proxy = MockAdbProxy.return_value |
| mock_adb_proxy.getprops.return_value = { |
| 'ro.build.id': 'AB42', |
| 'ro.build.type': 'userdebug', |
| 'ro.debuggable': '1', |
| } |
| mock_adb_proxy.has_shell_command.side_effect = lambda command: { |
| 'logpersist.start': True, |
| 'logpersist.stop': True, |
| }[command] |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad) |
| logcat_service._enable_logpersist() |
| mock_adb_proxy.shell.assert_has_calls([ |
| mock.call('logpersist.stop --clear'), |
| mock.call('logpersist.start'), |
| ]) |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock.MagicMock()) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| def test__enable_logpersist_with_user_build_device(self, MockFastboot, |
| MockAdbProxy): |
| mock_serial = '1' |
| mock_adb_proxy = MockAdbProxy.return_value |
| mock_adb_proxy.getprops.return_value = { |
| 'ro.build.id': 'AB42', |
| 'ro.build.type': 'user', |
| 'ro.debuggable': '0', |
| } |
| mock_adb_proxy.has_shell_command.side_effect = lambda command: { |
| 'logpersist.start': True, |
| 'logpersist.stop': True, |
| }[command] |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad) |
| logcat_service._enable_logpersist() |
| mock_adb_proxy.shell.assert_not_called() |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock.MagicMock()) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| def test__enable_logpersist_with_missing_all_logpersist( |
| self, MockFastboot, MockAdbProxy): |
| def adb_shell_helper(command): |
| if command == 'logpersist.start': |
| raise MOCK_LOGPERSIST_START_MISSING_ADB_ERROR |
| elif command == 'logpersist.stop --clear': |
| raise MOCK_LOGPERSIST_STOP_MISSING_ADB_ERROR |
| else: |
| return b'' |
| |
| mock_serial = '1' |
| mock_adb_proxy = MockAdbProxy.return_value |
| mock_adb_proxy.getprops.return_value = { |
| 'ro.build.id': 'AB42', |
| 'ro.build.type': 'userdebug', |
| 'ro.debuggable': '1', |
| } |
| mock_adb_proxy.has_shell_command.side_effect = lambda command: { |
| 'logpersist.start': False, |
| 'logpersist.stop': False, |
| }[command] |
| mock_adb_proxy.shell.side_effect = adb_shell_helper |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad) |
| logcat_service._enable_logpersist() |
| mock_adb_proxy.shell.assert_not_called() |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock.MagicMock()) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| def test__enable_logpersist_with_missing_logpersist_stop( |
| self, MockFastboot, MockAdbProxy): |
| def adb_shell_helper(command): |
| if command == 'logpersist.stop --clear': |
| raise MOCK_LOGPERSIST_STOP_MISSING_ADB_ERROR |
| else: |
| return b'' |
| |
| mock_serial = '1' |
| mock_adb_proxy = MockAdbProxy.return_value |
| mock_adb_proxy.getprops.return_value = { |
| 'ro.build.id': 'AB42', |
| 'ro.build.type': 'userdebug', |
| 'ro.debuggable': '1', |
| } |
| mock_adb_proxy.has_shell_command.side_effect = lambda command: { |
| 'logpersist.start': True, |
| 'logpersist.stop': False, |
| }[command] |
| mock_adb_proxy.shell.side_effect = adb_shell_helper |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad) |
| logcat_service._enable_logpersist() |
| mock_adb_proxy.shell.assert_has_calls([ |
| mock.call('logpersist.stop --clear'), |
| ]) |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy', |
| return_value=mock.MagicMock()) |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| def test__enable_logpersist_with_missing_logpersist_start( |
| self, MockFastboot, MockAdbProxy): |
| def adb_shell_helper(command): |
| if command == 'logpersist.start': |
| raise MOCK_LOGPERSIST_START_MISSING_ADB_ERROR |
| else: |
| return b'' |
| |
| mock_serial = '1' |
| mock_adb_proxy = MockAdbProxy.return_value |
| mock_adb_proxy.getprops.return_value = { |
| 'ro.build.id': 'AB42', |
| 'ro.build.type': 'userdebug', |
| 'ro.debuggable': '1', |
| } |
| mock_adb_proxy.has_shell_command.side_effect = lambda command: { |
| 'logpersist.start': False, |
| 'logpersist.stop': True, |
| }[command] |
| mock_adb_proxy.shell.side_effect = adb_shell_helper |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| logcat_service = logcat.Logcat(ad) |
| logcat_service._enable_logpersist() |
| mock_adb_proxy.shell.assert_not_called() |
| |
| @mock.patch('mobly.controllers.android_device_lib.adb.AdbProxy') |
| @mock.patch('mobly.controllers.android_device_lib.fastboot.FastbootProxy', |
| return_value=mock_android_device.MockFastbootProxy('1')) |
| def test_clear_adb_log(self, MockFastboot, MockAdbProxy): |
| mock_serial = '1' |
| ad = android_device.AndroidDevice(serial=mock_serial) |
| ad.adb.logcat = mock.MagicMock() |
| ad.adb.logcat.side_effect = adb.AdbError( |
| cmd='cmd', |
| stdout=b'', |
| stderr=b'failed to clear "main" log', |
| ret_code=1) |
| logcat_service = logcat.Logcat(ad) |
| logcat_service.clear_adb_log() |
| |
| |
| if __name__ == '__main__': |
| unittest.main() |