Detect and log stale package-manager lock holders during apt operations

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>)
+            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)

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()