diff --git a/mobly/controllers/android_device_lib/services/logcat.py b/mobly/controllers/android_device_lib/services/logcat.py index 714954b9..6f28e5e8 100644 --- a/mobly/controllers/android_device_lib/services/logcat.py +++ b/mobly/controllers/android_device_lib/services/logcat.py @@ -63,6 +63,7 @@ def __init__(self, android_device, configs=None): self._adb_logcat_process = None self._adb_logcat_file_obj = None self.adb_logcat_file_path = None + self._last_connection_time = None # Logcat service uses a single config obj, using singular internal # name: `_config`. self._config = configs if configs else Config() @@ -247,9 +248,14 @@ def _start(self): # In debugging mode of IntelijIDEA, "patch_args" remove # double quotes in args if starting and ending with it. # Add spaces at beginning and at last to fix this issue. - cmd = ' "%s" -s %s logcat -v threadtime -T 1 %s >> "%s" ' % ( + if self._last_connection_time is not None: + t_argument_value = self._last_connection_time + else: + t_argument_value = '1' + cmd = ' "%s" -s %s logcat -v threadtime -T "%s" %s >> "%s" ' % ( adb.ADB, self._ad.serial, + t_argument_value, self._config.logcat_params, self.adb_logcat_file_path, ) @@ -270,6 +276,7 @@ def _stop(self): except Exception: self._ad.log.exception('Failed to stop adb logcat.') self._adb_logcat_process = None + self._last_connection_time = None def pause(self): """Pauses logcat. @@ -279,6 +286,12 @@ def pause(self): some logs would be lost. """ self._stop() + try: + response = self._ad.adb.shell(['date', '-Is', r'+%Y-%m-%d\ %H:%M:%S.%N']) + if response: + self._last_connection_time = response.decode('utf-8').strip() + except adb.AdbError as e: + self._ad.log.exception('Failed to get host time.') def resume(self): """Resumes a paused logcat service.""" diff --git a/tests/mobly/controllers/android_device_lib/services/logcat_test.py b/tests/mobly/controllers/android_device_lib/services/logcat_test.py index 961b152e..eaa52ecf 100755 --- a/tests/mobly/controllers/android_device_lib/services/logcat_test.py +++ b/tests/mobly/controllers/android_device_lib/services/logcat_test.py @@ -132,7 +132,7 @@ def test_start_and_stop( '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' + 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 ) @@ -206,7 +206,8 @@ def test_update_config( 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" ' + ' "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') @@ -264,8 +265,101 @@ def test_update_config_while_running( 'mobly.controllers.android_device_lib.services.logcat.Logcat.clear_adb_log', return_value=mock_android_device.MockAdbProxy('1'), ) + @mock.patch('mobly.logger.get_log_file_timestamp') def test_pause_and_resume( self, + get_timestamp_mock, + clear_adb_mock, + open_logcat_mock, + stop_proc_mock, + start_proc_mock, + create_dir_mock, + FastbootProxy, + MockAdbProxy, + ): + DATE_COMMAND = ['date', '-Is', r'+%Y-%m-%d\ %H:%M:%S.%N'] + DATE_RESULT_FIRST_PAUSE = '2026-01-14 17:01:02.342' + DATE_RESULT_SECOND_PAUSE = '2026-01-14 17:03:04.789' + date_result = '' + + adb_instance = MockAdbProxy.return_value + adb_instance.shell = mock.MagicMock() + adb_instance.has_shell_command = mock.MagicMock(return_value=True) + + def adb_shell_logic(cmd, *args, **kwargs): + nonlocal date_result + if cmd == DATE_COMMAND: + return date_result.encode('utf-8') + return b'' # Use empty bytes to match ADB's typical return type + adb_instance.shell.side_effect = adb_shell_logic + + mock_serial = '1' + ad = android_device.AndroidDevice(serial=mock_serial) + get_timestamp_mock.return_value = '123' + configs = logcat.Config(clear_log=True) + logcat_service = logcat.Logcat(ad, configs) + logcat_service.start() + expected_log_path = os.path.join( + logging.log_path, + 'AndroidDevice%s' % ad.serial, + 'logcat,%s,fakemodel,123.txt' % ad.serial, + ) + 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 + ) + + clear_adb_mock.assert_called_once_with() + self.assertTrue(logcat_service.is_alive) + + def pause_resume(date): + nonlocal date_result + date_result = date + 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() + adb_cmd = ( + ' "adb" -s %s logcat -v threadtime -T "' + date_result + '" >> %s' + ) + start_proc_mock.assert_called_with( + adb_cmd % (ad.serial, '"%s" ' % expected_log_path), shell=True + ) + + # First pause / resume iteration + pause_resume(DATE_RESULT_FIRST_PAUSE) + # self.assertEqual(adb_instance.shell.call_count, 1) + + # Second pause / resume iteration + pause_resume(DATE_RESULT_SECOND_PAUSE) + + 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'), + ) + @mock.patch('mobly.logger.get_log_file_timestamp') + def test_pause_and_resume_while_raising_exception_when_getting_pause_time( + self, + get_timestamp_mock, clear_adb_mock, open_logcat_mock, stop_proc_mock, @@ -274,20 +368,53 @@ def test_pause_and_resume( FastbootProxy, MockAdbProxy, ): + DATE_COMMAND = ['date', '-Is', r'+%Y-%m-%d\ %H:%M:%S.%N'] + + adb_instance = MockAdbProxy.return_value + adb_instance.shell = mock.MagicMock() + adb_instance.has_shell_command = mock.MagicMock(return_value=True) + + def adb_shell_logic(cmd, *args, **kwargs): + if cmd == DATE_COMMAND: + raise adb.AdbError(cmd, b'', b'Device is disconnected', 1) + return b'' # Use empty bytes to match ADB's typical return type + adb_instance.shell.side_effect = adb_shell_logic + mock_serial = '1' ad = android_device.AndroidDevice(serial=mock_serial) - logcat_service = logcat.Logcat(ad, logcat.Config(clear_log=True)) + get_timestamp_mock.return_value = '123' + configs = logcat.Config(clear_log=True) + logcat_service = logcat.Logcat(ad, configs) logcat_service.start() + expected_log_path = os.path.join( + logging.log_path, + 'AndroidDevice%s' % ad.serial, + 'logcat,%s,fakemodel,123.txt' % ad.serial, + ) + 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 + ) + clear_adb_mock.assert_called_once_with() self.assertTrue(logcat_service.is_alive) + + # Pause should fail to retrieve a valid date 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() + + # Resume should start with the latest logcat message again logcat_service.resume() self.assertTrue(logcat_service.is_alive) clear_adb_mock.assert_not_called() + 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 + ) + logcat_service.stop() @mock.patch( @@ -422,7 +549,7 @@ def test_take_logcat_with_extra_params( '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' + 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 )