diff --git a/src/core/src/package_managers/AptitudePackageManager.py b/src/core/src/package_managers/AptitudePackageManager.py index cb591daa..aab98314 100644 --- a/src/core/src/package_managers/AptitudePackageManager.py +++ b/src/core/src/package_managers/AptitudePackageManager.py @@ -291,6 +291,7 @@ def invoke_package_manager_advanced(self, command, raise_on_exception=True): raise Exception(error_msg, "[{0}]".format(Constants.ERROR_ADDED_TO_STATUS)) elif code != self.apt_exitcode_ok: self.composite_logger.log_warning('[ERROR] Customer environment error. [Command={0}][Code={1}][Output={2}]'.format(command, str(code), str(out))) + self.__log_stale_lock_holder_if_present(out) # NEW: best-effort, log-only lock diagnostics error_msg = "Customer environment error: Investigate and resolve unexpected return code ({0}) from package manager on command: {1}".format(str(code), command) self.status_handler.add_error_to_status(error_msg, Constants.PatchOperationErrorCodes.PACKAGE_MANAGER_FAILURE) if raise_on_exception: @@ -300,6 +301,47 @@ def invoke_package_manager_advanced(self, command, raise_on_exception=True): self.composite_logger.log_debug('[APM] Invoked package manager. [Command={0}][Code={1}][Output={2}]'.format(command, str(code), str(out))) return out, code + def __log_stale_lock_holder_if_present(self, command_output): + """ Best-effort, log-only detection of a package-manager lock held by another process. + Identifies whether the holder is an orphaned LinuxPatchExtension process from an older + version. Does NOT kill the process or remove the lock. """ + try: + if command_output is None or ("Could not get lock" not in command_output and "Unable to lock" not in command_output): + return # not a lock-contention failure, nothing to diagnose + + # apt reports the holder PID directly, e.g. "It is held by process 123456 (apt-get)" + pid_match = re.search(r'held by process (\d+)', command_output) + if pid_match is None: + self.composite_logger.log_warning("[APM] Package manager lock is held, but the holding process id could not be determined from the output.") + return + holder_pid = pid_match.group(1) + + # Read the holder's elapsed run time (etime) and full command line + code, out = self.env_layer.run_command_output("ps -p {0} -o pid=,etime=,cmd=".format(holder_pid), False, False) + fields = out.strip().split(None, 2) if code == 0 else [] + if len(fields) < 2: + self.composite_logger.log_warning("[APM] Package manager lock is held by process {0}, but its details could not be read (it may have already exited).".format(holder_pid)) + return + holder_metadata = "Pid={0}, Etime={1}".format(fields[0], fields[1]) # allowlisted only + holder_cmdline = fields[2] if len(fields) == 3 else "" # internal use only; never logged + + # Was the holder launched by a LinuxPatchExtension version? (path contains LinuxPatchExtension-) + version_match = re.search(r'LinuxPatchExtension-(\d+(?:\.\d+)*)', holder_cmdline) + if version_match is None: + self.composite_logger.log_warning("[APM] Package manager lock is held by a non-extension process. [HolderPid={0}]".format(holder_pid)) + return + + holder_version = self.version_comparator.extract_version_from_version_str(version_match.group(1)) + current_version = self.version_comparator.extract_version_from_version_str(str(Constants.EXT_VERSION)) + is_older_version = current_version != "" and self.version_comparator.compare_versions(holder_version, current_version) < 0 + + self.composite_logger.log_warning("[APM] Detected package manager lock held by a LinuxPatchExtension process. No action taken (detection only). " + "[HolderPid={0}][HolderVersion={1}][CurrentVersion={2}][IsOlderVersion={3}][Holder={4}]" + .format(holder_pid, holder_version, current_version, str(is_older_version), holder_metadata)) + except Exception as error: + # detection is best-effort and must not affect the main patch flow + self.composite_logger.log_verbose("[APM] Non-fatal: failed while inspecting package manager lock holder. [Error={0}]".format(repr(error))) + def invoke_apt_cache(self, command): """Invoke apt-cache using the command input""" self.composite_logger.log_verbose('[APM] Invoking apt-cache using: ' + command) diff --git a/src/core/tests/Test_AptitudePackageManager.py b/src/core/tests/Test_AptitudePackageManager.py index a0956461..146cfd6b 100644 --- a/src/core/tests/Test_AptitudePackageManager.py +++ b/src/core/tests/Test_AptitudePackageManager.py @@ -249,6 +249,35 @@ def mock_add_error_to_status_to_capture_errors(self, error_msg, error_code=None) def mock_ensure_mokutil_available_returns_false(self): """Mock ensure_mokutil_available_for_cert_checks to return False""" return False + + def mock_run_command_output_apt_lock_held_by_stale_lpe_process(self, cmd, no_output=False, chk_err=True): + """ Simulates apt-get failing because the lock is held, and the holder being an older-version LPE process. """ + if cmd.find("ps -p") > -1: + # pid, etime (78 days), cmd -> cmd carries the older LinuxPatchExtension-1.6.64 path + return 0, "2324709 78-00:14:50 apt-get -q update -oDir::Etc::SourceParts=/var/lib/waagent/Microsoft.CPlat.Core.LinuxPatchExtension-1.6.64/tmp/azgps-src" + return 100, "E: Could not get lock /var/lib/apt/lists/lock. It is held by process 2324709 (apt-get)\nE: Unable to lock directory /var/lib/apt/lists/" + + def mock_run_command_output_apt_lock_held_by_non_extension_process(self, cmd, no_output=False, chk_err=True): + """ Simulates apt-get failing on a held lock, with the holder being an unrelated (non-extension) process. """ + if cmd.find("ps -p") > -1: + return 0, "2324709 01:02:03 apt-get -q update" # no LinuxPatchExtension path + return 100, "E: Could not get lock /var/lib/apt/lists/lock. It is held by process 2324709 (apt-get)" + + def mock_run_command_output_apt_lock_held_without_pid(self, cmd, no_output=False, chk_err=True): + """ apt reports a lock error but with no resolvable holder PID. """ + return 100, "Reading package lists...\nE: Could not get lock /var/lib/apt/lists/lock\nE: Unable to lock directory /var/lib/apt/lists/" + + def mock_run_command_output_apt_lock_holder_details_unreadable(self, cmd, no_output=False, chk_err=True): + """ Holder PID is known, but ps returns nothing (e.g. the process already exited). """ + if cmd.find("ps -p") > -1: + return 1, "" + return 100, "Reading package lists...\nE: Could not get lock /var/lib/apt/lists/lock. It is held by process 999999 (apt-get)\nE: Unable to lock directory /var/lib/apt/lists/" + + def mock_run_command_output_apt_lock_holder_inspection_raises(self, cmd, no_output=False, chk_err=True): + """ Forces an exception during holder inspection to exercise the best-effort guard. """ + if cmd.find("ps -p") > -1: + raise Exception("simulated ps failure") + return 100, "Reading package lists...\nE: Could not get lock /var/lib/apt/lists/lock. It is held by process 123 (apt-get)\nE: Unable to lock directory /var/lib/apt/lists/" # endregion Mocks # region Utility Functions @@ -1735,6 +1764,76 @@ def test_is_cert_update_supported__with_various_use_cases(self): package_manager.execution_config.enable_uefi_cert_update_for_all_patching = backup_enable_all # endregion + #Lock detection + def test_stale_lock_holder_from_older_extension_version_is_logged(self): + package_manager = self.container.get('package_manager') + self.runtime.env_layer.run_command_output = self.mock_run_command_output_apt_lock_held_by_stale_lpe_process + + # pin current version so the older/newer comparison is deterministic (dev build has a placeholder) + saved_ext_version = Constants.EXT_VERSION + Constants.EXT_VERSION = "1.6.71" + captured_output, original_stdout = self.__capture_std_io() + try: + with self.assertRaises(Exception): + package_manager.invoke_package_manager("sudo apt-get -q update") + finally: + sys.stdout = original_stdout + Constants.EXT_VERSION = saved_ext_version + + self.__assert_std_io(captured_output, "Detected package manager lock held by a LinuxPatchExtension process") + self.__assert_std_io(captured_output, "HolderPid=2324709") + self.__assert_std_io(captured_output, "HolderVersion=1.6.64") + self.__assert_std_io(captured_output, "CurrentVersion=1.6.71") + self.__assert_std_io(captured_output, "IsOlderVersion=True") + + def test_lock_holder_that_is_not_an_extension_process_is_left_untouched(self): + package_manager = self.container.get('package_manager') + self.runtime.env_layer.run_command_output = self.mock_run_command_output_apt_lock_held_by_non_extension_process + + captured_output, original_stdout = self.__capture_std_io() + try: + with self.assertRaises(Exception): + package_manager.invoke_package_manager("sudo apt-get -q update") + finally: + sys.stdout = original_stdout + + self.__assert_std_io(captured_output, "held by a non-extension process") + + def test_lock_held_but_holder_pid_not_determinable_is_logged(self): + # covers the "PID could not be determined" branch (no 'held by process N' in output) + package_manager = self.container.get('package_manager') + self.runtime.env_layer.run_command_output = self.mock_run_command_output_apt_lock_held_without_pid + + captured_output, original_stdout = self.__capture_std_io() + try: + with self.assertRaises(Exception): + package_manager.invoke_package_manager("sudo apt-get -q update") + finally: + sys.stdout = original_stdout + + self.__assert_std_io(captured_output, "the holding process id could not be determined") + + def test_lock_holder_details_unreadable_is_logged(self): + # covers the "details could not be read" branch (ps returns nothing) + package_manager = self.container.get('package_manager') + self.runtime.env_layer.run_command_output = self.mock_run_command_output_apt_lock_holder_details_unreadable + + captured_output, original_stdout = self.__capture_std_io() + try: + with self.assertRaises(Exception): + package_manager.invoke_package_manager("sudo apt-get -q update") + finally: + sys.stdout = original_stdout + + self.__assert_std_io(captured_output, "its details could not be read") + + def test_lock_holder_inspection_failure_is_non_fatal(self): + # covers the best-effort except guard: an inspection failure must not change normal failure behavior + package_manager = self.container.get('package_manager') + self.runtime.env_layer.run_command_output = self.mock_run_command_output_apt_lock_holder_inspection_raises + + self.assertRaises(Exception, package_manager.invoke_package_manager, "sudo apt-get -q update") + #end region if __name__ == '__main__': unittest.main()