Wait until mount unit is deactivated on unmount (#4733)

* Wait until mount unit is deactivated on unmount

The current code does not wait until the (bind) mount unit has been
actually deactivated (state "inactive"). This is especially problematic
when restoring a backup, where we deactivate all bind mounts before
restoring the target folder. Before the tarball is actually restored,
we delete all contents of the target folder. This lead to the situation
where the "rm -rf" command got executed before the bind mount actually
got unmounted.

The current code polls the state using an exponentially increasing
delay. Wait up to 30s for the bind mount to actually deactivate.

* Fix function name

* Fix missing await

* Address pytest errors

Change state of systemd unit according to use cases. Note that this
is currently rather fragile, and ideally we should have a smarter
mock service instead.

* Fix pylint

* Fix remaining

* Check transition fo failed as well

* Used alternative mocking mechanism

* Remove state lists in test_manager

---------

Co-authored-by: Mike Degatano <[email protected]>

supervisor/mounts/mount.py

@@ -170,6 +170,16 @@ async def load(self) -> None:
         elif self.state != UnitActiveState.ACTIVE:
             await self.reload()
 
+    async def update_state(self) -> None:
+        """Update mount unit state."""
+        try:
+            self._state = await self.unit.get_active_state()
+        except DBusError as err:
+            capture_exception(err)
+            raise MountError(
+                f"Could not get active state of mount due to: {err!s}"
+            ) from err
+
     async def update(self) -> None:
         """Update info about mount from dbus."""
         try:
@@ -182,13 +192,7 @@ async def update(self) -> None:
             capture_exception(err)
             raise MountError(f"Could not get mount unit due to: {err!s}") from err
 
-        try:
-            self._state = await self.unit.get_active_state()
-        except DBusError as err:
-            capture_exception(err)
-            raise MountError(
-                f"Could not get active state of mount due to: {err!s}"
-            ) from err
+        await self.update_state()
 
         # If active, dismiss corresponding failed mount issue if found
         if (
@@ -197,6 +201,20 @@ async def update(self) -> None:
         ):
             self.sys_resolution.dismiss_issue(self.failed_issue)
 
+    async def _update_state_await(self, expected_states: list[UnitActiveState]) -> None:
+        """Update state info about mount from dbus. Wait up to 30 seconds for the state to appear."""
+        for i in range(5):
+            await self.update_state()
+            if self.state in expected_states:
+                return
+            await asyncio.sleep(i**2)
+
+        _LOGGER.warning(
+            "Mount %s still in state %s after waiting for 30 seconods to complete",
+            self.name,
+            str(self.state).lower(),
+        )
+
     async def _update_await_activating(self):
         """Update info about mount from dbus. If 'activating' wait up to 30 seconds."""
         await self.update()
@@ -269,10 +287,15 @@ async def unmount(self) -> None:
         await self.update()
 
         try:
+            if self.state != UnitActiveState.FAILED:
+                await self.sys_dbus.systemd.stop_unit(self.unit_name, StopUnitMode.FAIL)
+
+            await self._update_state_await(
+                [UnitActiveState.INACTIVE, UnitActiveState.FAILED]
+            )
+
             if self.state == UnitActiveState.FAILED:
                 await self.sys_dbus.systemd.reset_failed_unit(self.unit_name)
-            else:
-                await self.sys_dbus.systemd.stop_unit(self.unit_name, StopUnitMode.FAIL)
         except DBusSystemdNoSuchUnit:
             _LOGGER.info("Mount %s is not mounted, skipping unmount", self.name)
         except DBusError as err:

tests/api/test_mounts.py

@@ -142,7 +142,7 @@ async def test_api_create_dbus_error_mount_not_added(
         "/org/freedesktop/systemd1/unit/tmp_2dyellow_2emount",
     ]
     systemd_service.response_start_transient_unit = "/org/freedesktop/systemd1/job/7623"
-    systemd_unit_service.active_state = "failed"
+    systemd_unit_service.active_state = ["failed", "failed", "inactive"]
 
     resp = await api_client.post(
         "/mounts",
@@ -219,8 +219,16 @@ async def test_api_create_mount_fails_missing_mount_propagation(
     )
 
 
-async def test_api_update_mount(api_client: TestClient, coresys: CoreSys, mount):
+async def test_api_update_mount(
+    api_client: TestClient,
+    coresys: CoreSys,
+    all_dbus_services: dict[str, DBusServiceMock],
+    mount,
+):
     """Test updating a mount via API."""
+    systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
+    systemd_service.mock_systemd_unit = systemd_unit_service
     resp = await api_client.put(
         "/mounts/backup_test",
         json={
@@ -280,6 +288,7 @@ async def test_api_update_dbus_error_mount_remains(
     """Test mount remains in list with unsuccessful state if dbus error occurs during update."""
     systemd_service: SystemdService = all_dbus_services["systemd"]
     systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
+    systemd_unit_service.active_state = ["failed", "inactive"]
     systemd_service.response_get_unit = [
         "/org/freedesktop/systemd1/unit/tmp_2dyellow_2emount",
         DBusError("org.freedesktop.systemd1.NoSuchUnit", "error"),
@@ -321,7 +330,13 @@ async def test_api_update_dbus_error_mount_remains(
         "/org/freedesktop/systemd1/unit/tmp_2dyellow_2emount",
     ]
     systemd_service.response_start_transient_unit = "/org/freedesktop/systemd1/job/7623"
-    systemd_unit_service.active_state = "failed"
+    systemd_unit_service.active_state = [
+        "failed",
+        "inactive",
+        "inactive",
+        "failed",
+        "inactive",
+    ]
 
     resp = await api_client.put(
         "/mounts/backup_test",
@@ -385,8 +400,16 @@ async def test_api_reload_error_mount_missing(
     )
 
 
-async def test_api_delete_mount(api_client: TestClient, coresys: CoreSys, mount):
+async def test_api_delete_mount(
+    api_client: TestClient,
+    coresys: CoreSys,
+    all_dbus_services: dict[str, DBusServiceMock],
+    mount,
+):
     """Test deleting a mount via API."""
+    systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
+    systemd_service.mock_systemd_unit = systemd_unit_service
     resp = await api_client.delete("/mounts/backup_test")
     result = await resp.json()
     assert result["result"] == "ok"
@@ -455,9 +478,16 @@ async def test_api_create_backup_mount_sets_default(
 
 
 async def test_update_backup_mount_changes_default(
-    api_client: TestClient, coresys: CoreSys, mount
+    api_client: TestClient,
+    coresys: CoreSys,
+    all_dbus_services: dict[str, DBusServiceMock],
+    mount,
 ):
     """Test updating a backup mount may unset the default."""
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
+    systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_service.mock_systemd_unit = systemd_unit_service
+
     # Make another backup mount for testing
     resp = await api_client.post(
         "/mounts",
@@ -502,9 +532,16 @@ async def test_update_backup_mount_changes_default(
 
 
 async def test_delete_backup_mount_changes_default(
-    api_client: TestClient, coresys: CoreSys, mount
+    api_client: TestClient,
+    coresys: CoreSys,
+    all_dbus_services: dict[str, DBusServiceMock],
+    mount,
 ):
     """Test deleting a backup mount may unset the default."""
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
+    systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_service.mock_systemd_unit = systemd_unit_service
+
     # Make another backup mount for testing
     resp = await api_client.post(
         "/mounts",
@@ -535,11 +572,15 @@ async def test_delete_backup_mount_changes_default(
 async def test_backup_mounts_reload_backups(
     api_client: TestClient,
     coresys: CoreSys,
+    all_dbus_services: dict[str, DBusServiceMock],
     tmp_supervisor_data,
     path_extern,
     mount_propagation,
 ):
     """Test actions on a backup mount reload backups."""
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
+    systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_service.mock_systemd_unit = systemd_unit_service
     await coresys.mounts.load()
 
     with patch.object(BackupManager, "reload") as reload:

tests/backups/test_manager.py

@@ -31,6 +31,7 @@
 from tests.const import TEST_ADDON_SLUG
 from tests.dbus_service_mocks.base import DBusServiceMock
 from tests.dbus_service_mocks.systemd import Systemd as SystemdService
+from tests.dbus_service_mocks.systemd_unit import SystemdUnit as SystemdUnitService
 
 
 async def test_do_backup_full(coresys: CoreSys, backup_mock, install_addon_ssh):
@@ -386,6 +387,7 @@ async def test_backup_media_with_mounts(
 ):
     """Test backing up media folder with mounts."""
     systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
     systemd_service.response_get_unit = [
         DBusError("org.freedesktop.systemd1.NoSuchUnit", "error"),
         "/org/freedesktop/systemd1/unit/tmp_2dyellow_2emount",
@@ -422,6 +424,7 @@ async def test_backup_media_with_mounts(
     backup: Backup = await coresys.backups.do_backup_partial("test", folders=["media"])
 
     # Remove the mount and wipe the media folder
+    systemd_unit_service.active_state = "inactive"
     await coresys.mounts.remove_mount("media_test")
     rmtree(coresys.config.path_media)
     coresys.config.path_media.mkdir()
@@ -445,6 +448,8 @@ async def test_backup_media_with_mounts_retains_files(
 ):
     """Test backing up media folder with mounts retains mount files."""
     systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
+    systemd_unit_service.active_state = ["active", "active", "active", "inactive"]
     systemd_service.response_get_unit = [
         DBusError("org.freedesktop.systemd1.NoSuchUnit", "error"),
         "/org/freedesktop/systemd1/unit/tmp_2dyellow_2emount",
@@ -496,6 +501,15 @@ async def test_backup_share_with_mounts(
 ):
     """Test backing up share folder with mounts."""
     systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
+    systemd_unit_service.active_state = [
+        "active",
+        "active",
+        "active",
+        "inactive",
+        "active",
+        "inactive",
+    ]
     systemd_service.response_get_unit = [
         DBusError("org.freedesktop.systemd1.NoSuchUnit", "error"),
         "/org/freedesktop/systemd1/unit/tmp_2dyellow_2emount",

tests/dbus_service_mocks/systemd.py

@@ -4,6 +4,7 @@
 from dbus_fast.service import PropertyAccess, dbus_property
 
 from .base import DBusServiceMock, dbus_method
+from .systemd_unit import SystemdUnit
 
 BUS_NAME = "org.freedesktop.systemd1"
 
@@ -40,6 +41,7 @@ class Systemd(DBusServiceMock):
     response_start_transient_unit: str | DBusError = (
         "/org/freedesktop/systemd1/job/7623"
     )
+    mock_systemd_unit: SystemdUnit | None = None
 
     @dbus_property(access=PropertyAccess.READ)
     def Version(self) -> "s":
@@ -658,25 +660,33 @@ def PowerOff(self) -> None:
     @dbus_method()
     def StartUnit(self, name: "s", mode: "s") -> "o":
         """Start a service unit."""
+        if self.mock_systemd_unit:
+            self.mock_systemd_unit.active_state = "active"
         return "/org/freedesktop/systemd1/job/7623"
 
     @dbus_method()
     def StopUnit(self, name: "s", mode: "s") -> "o":
         """Stop a service unit."""
         if isinstance(self.response_stop_unit, DBusError):
             raise self.response_stop_unit
+        if self.mock_systemd_unit:
+            self.mock_systemd_unit.active_state = "inactive"
         return self.response_stop_unit
 
     @dbus_method()
     def ReloadOrRestartUnit(self, name: "s", mode: "s") -> "o":
         """Reload or restart a service unit."""
         if isinstance(self.response_reload_or_restart_unit, DBusError):
             raise self.response_reload_or_restart_unit
+        if self.mock_systemd_unit:
+            self.mock_systemd_unit.active_state = "active"
         return self.response_reload_or_restart_unit
 
     @dbus_method()
     def RestartUnit(self, name: "s", mode: "s") -> "o":
         """Restart a service unit."""
+        if self.mock_systemd_unit:
+            self.mock_systemd_unit.active_state = "active"
         return "/org/freedesktop/systemd1/job/7623"
 
     @dbus_method()
@@ -686,11 +696,15 @@ def StartTransientUnit(
         """Start a transient service unit."""
         if isinstance(self.response_start_transient_unit, DBusError):
             raise self.response_start_transient_unit
+        if self.mock_systemd_unit:
+            self.mock_systemd_unit.active_state = "active"
         return self.response_start_transient_unit
 
     @dbus_method()
     def ResetFailedUnit(self, name: "s") -> None:
         """Reset a failed unit."""
+        if self.mock_systemd_unit:
+            self.mock_systemd_unit.active_state = "inactive"
 
     @dbus_method()
     def GetUnit(self, name: "s") -> "s":

tests/mounts/test_manager.py

@@ -371,6 +371,8 @@ async def test_update_mount(
 ):
     """Test updating a mount."""
     systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
+    systemd_service.mock_systemd_unit = systemd_unit_service
     systemd_service.StartTransientUnit.calls.clear()
     systemd_service.StopUnit.calls.clear()
 
@@ -429,6 +431,8 @@ async def test_remove_mount(
 ):
     """Test removing a mount."""
     systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
+    systemd_unit_service.active_state = ["active", "inactive", "active", "inactive"]
     systemd_service.StopUnit.calls.clear()
 
     # Remove the mount
@@ -549,7 +553,7 @@ async def test_create_mount_activation_failure(
         "/org/freedesktop/systemd1/unit/tmp_2dyellow_2emount",
         "/org/freedesktop/systemd1/unit/tmp_2dyellow_2emount",
     ]
-    systemd_unit_service.active_state = "failed"
+    systemd_unit_service.active_state = ["failed", "failed", "failed"]
 
     await coresys.mounts.load()
 
@@ -574,8 +578,6 @@ async def test_reload_mounts(
     systemd_service: SystemdService = all_dbus_services["systemd"]
     systemd_service.ReloadOrRestartUnit.calls.clear()
 
-    await coresys.mounts.load()
-
     assert mount.state == UnitActiveState.ACTIVE
     assert mount.failed_issue not in coresys.resolution.issues
 

tests/mounts/test_mount.py

@@ -52,6 +52,7 @@ async def test_cifs_mount(
 ):
     """Test CIFS mount."""
     systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
     systemd_service.StartTransientUnit.calls.clear()
 
     mount_data = {
@@ -130,6 +131,7 @@ async def test_cifs_mount(
     assert not cred_stat.st_mode & stat.S_IRGRP
     assert not cred_stat.st_mode & stat.S_IROTH
 
+    systemd_unit_service.active_state = ["active", "inactive"]
     await mount.unmount()
     assert not mount.path_credentials.exists()
 
@@ -289,6 +291,7 @@ async def test_unmount(
 ):
     """Test unmounting."""
     systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
     systemd_service.StopUnit.calls.clear()
 
     mount: CIFSMount = Mount.from_dict(
@@ -306,6 +309,7 @@ async def test_unmount(
     assert mount.unit is not None
     assert mount.state == UnitActiveState.ACTIVE
 
+    systemd_unit_service.active_state = ["active", "inactive"]
     await mount.unmount()
 
     assert mount.unit is None

tests/resolution/fixup/test_mount_execute_remove.py

@@ -7,6 +7,7 @@
 
 from tests.dbus_service_mocks.base import DBusServiceMock
 from tests.dbus_service_mocks.systemd import Systemd as SystemdService
+from tests.dbus_service_mocks.systemd_unit import SystemdUnit as SystemdUnitService
 
 
 async def test_fixup(
@@ -17,6 +18,7 @@ async def test_fixup(
 ):
     """Test fixup."""
     systemd_service: SystemdService = all_dbus_services["systemd"]
+    systemd_unit_service: SystemdUnitService = all_dbus_services["systemd_unit"]
     systemd_service.StopUnit.calls.clear()
 
     mount_execute_remove = FixupMountExecuteRemove(coresys)
@@ -42,6 +44,8 @@ async def test_fixup(
         reference="test",
         suggestions=[SuggestionType.EXECUTE_RELOAD, SuggestionType.EXECUTE_REMOVE],
     )
+
+    systemd_unit_service.active_state = ["active", "inactive"]
     await mount_execute_remove()
 
     assert coresys.resolution.issues == []