Seemingly spurious tps.configuration.mount.IsActiveException when deactivating a Persistent Storage feature

Bug reports:

• wb:a2f7b363844d755a3d16755b195afac5
• wb:fbd91ec767ae8e1f10f5d0735f16ea33
• wb:f6d88c48ddc8d965bb04f5bd955bd75c

At the very least, to debug this class of problems more easily, it would be good if the logs told us:

• which feature failed to deactivate
• which mount was unexpectedly still active

Relevant logs:

Dez 21 02:37:38 amnesia tps[5242]: INFO:feature.py:101: Activating feature WelcomeScreen
Dez 21 02:37:38 amnesia org.boum.tails.PersistentStorage.desktop[31528]: INFO:feature.py:162: Feature successfully activated
Dez 21 02:37:39 amnesia tps[5242]: INFO:feature.py:155: Deactivating feature WelcomeScreen
Dez 21 02:37:39 amnesia systemd[5615]: var-lib-gdm3-settings-persistent.mount: Succeeded.
░░ Subject: Unit succeeded
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ The unit UNIT has successfully entered the 'dead' state.
Dez 21 02:37:39 amnesia systemd[5615]: var-lib-tails\x2dpersistent\x2dstorage-nosymfollow-var-lib-gdm3-settings-persistent.mount: Succeeded.
░░ Subject: Unit succeeded
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ The unit UNIT has successfully entered the 'dead' state.
Dez 21 02:37:39 amnesia systemd[1]: var-lib-gdm3-settings-persistent.mount: Succeeded.
░░ Subject: Unit succeeded
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ The unit var-lib-gdm3-settings-persistent.mount has successfully entered the 'dead' state.
Dez 21 02:37:39 amnesia systemd[1]: var-lib-tails\x2dpersistent\x2dstorage-nosymfollow-var-lib-gdm3-settings-persistent.mount: Succeeded.
░░ Subject: Unit succeeded
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ The unit var-lib-tails\x2dpersistent\x2dstorage-nosymfollow-var-lib-gdm3-settings-persistent.mount has successfully entered the 'dead' state.
Dez 21 02:37:40 amnesia org.boum.tails.PersistentStorage.desktop[31528]: INFO:feature.py:199: Feature successfully deactivated
Dez 21 02:37:40 amnesia tps[5242]: INFO:feature.py:101: Activating feature Printers
Dez 21 02:37:41 amnesia systemd[1]: Stopping Make remote CUPS printers available locally...
░░ Subject: A stop job for unit cups-browsed.service has begun execution
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ A stop job for unit cups-browsed.service has begun execution.
░░ 
░░ The job identifier is 1852.
Dez 21 02:37:42 amnesia tps[5242]: ERROR:object.py:161:
Dez 21 02:37:42 amnesia tps[5242]: Traceback (most recent call last):
Dez 21 02:37:42 amnesia tps[5242]:   File "/usr/lib/python3/dist-packages/tps/dbus/object.py", line 146, in do_handle_method_call
Dez 21 02:37:42 amnesia tps[5242]:     result = func(*parameters)
Dez 21 02:37:42 amnesia tps[5242]:   File "/usr/lib/python3/dist-packages/tps/configuration/feature.py", line 138, in Deactivate
Dez 21 02:37:42 amnesia tps[5242]:     is_active = self.refresh_is_active()
Dez 21 02:37:42 amnesia tps[5242]:   File "/usr/lib/python3/dist-packages/tps/configuration/feature.py", line 266, in refresh_is_active
Dez 21 02:37:42 amnesia tps[5242]:     self.IsActive = is_active
Dez 21 02:37:42 amnesia tps[5242]:   File "/usr/lib/python3/dist-packages/tps/configuration/feature.py", line 194, in IsActive
Dez 21 02:37:42 amnesia tps[5242]:     self.on_deactivated()
Dez 21 02:37:42 amnesia tps[5242]:   File "/usr/lib/python3/dist-packages/tps/configuration/feature.py", line 259, in on_deactivated
Dez 21 02:37:42 amnesia tps[5242]:     for mount in self.Mounts: mount.check_is_inactive()
Dez 21 02:37:42 amnesia tps[5242]:   File "/usr/lib/python3/dist-packages/tps/configuration/mount.py", line 354, in check_is_inactive
Dez 21 02:37:42 amnesia tps[5242]:     raise IsActiveException()
Dez 21 02:37:42 amnesia tps[5242]: tps.configuration.mount.IsActiveException
Dez 21 02:37:42 amnesia org.boum.tails.PersistentStorage.desktop[31528]: ERROR:feature.py:172: error deactivating feature: GDBus.Error:tps.configuration.mount.IsActiveException:
Dez 21 02:37:42 amnesia systemd[1]: cups-browsed.service: Succeeded.
░░ Subject: Unit succeeded
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ The unit cups-browsed.service has successfully entered the 'dead' state.
Dez 21 02:37:42 amnesia systemd[1]: Stopped Make remote CUPS printers available locally.
░░ Subject: A stop job for unit cups-browsed.service has finished
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ A stop job for unit cups-browsed.service has finished.
░░ 
░░ The job identifier is 1852 and the job result is done.
Dez 21 02:37:42 amnesia systemd[1]: Stopping CUPS Scheduler...
░░ Subject: A stop job for unit cups.service has begun execution
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ A stop job for unit cups.service has begun execution.
░░ 
░░ The job identifier is 1786.
Dez 21 02:37:42 amnesia systemd[1]: cups.service: Succeeded.
░░ Subject: Unit succeeded
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ The unit cups.service has successfully entered the 'dead' state.
Dez 21 02:37:42 amnesia systemd[1]: Stopped CUPS Scheduler.
░░ Subject: A stop job for unit cups.service has finished
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ A stop job for unit cups.service has finished.
░░ 
░░ The job identifier is 1786 and the job result is done.
Dez 21 02:37:42 amnesia systemd[1]: cups.service: Consumed 1.278s CPU time.
░░ Subject: Resources consumed by unit runtime
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ The unit cups.service completed and consumed the indicated resources.
Dez 21 02:37:42 amnesia systemd[1]: cups.socket: Succeeded.
░░ Subject: Unit succeeded
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ The unit cups.socket has successfully entered the 'dead' state.
Dez 21 02:37:42 amnesia systemd[1]: Closed CUPS Scheduler.
░░ Subject: A stop job for unit cups.socket has finished
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ A stop job for unit cups.socket has finished.
░░ 
░░ The job identifier is 1854 and the job result is done.
Dez 21 02:37:42 amnesia systemd[1]: Stopping CUPS Scheduler.
░░ Subject: A stop job for unit cups.socket has begun execution
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ A stop job for unit cups.socket has begun execution.
░░ 
░░ The job identifier is 1854.
Dez 21 02:37:42 amnesia systemd[1]: Listening on CUPS Scheduler.
░░ Subject: A start job for unit cups.socket has finished successfully
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ A start job for unit cups.socket has finished successfully.
░░ 
░░ The job identifier is 1854.
Dez 21 02:37:42 amnesia systemd[1]: Starting CUPS Scheduler...
░░ Subject: A start job for unit cups.service has begun execution
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ A start job for unit cups.service has begun execution.
░░ 
░░ The job identifier is 1786.
Dez 21 02:37:42 amnesia audit[31631]: AVC apparmor="DENIED" operation="capable" profile="/usr/sbin/cupsd" pid=31631 comm="cupsd" capability=12  capname="net_admin"
Dez 21 02:37:42 amnesia systemd[1]: Started CUPS Scheduler.
░░ Subject: A start job for unit cups.service has finished successfully
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ A start job for unit cups.service has finished successfully.
░░ 
░░ The job identifier is 1786.
Dez 21 02:37:42 amnesia kernel: audit: type=1400 audit(1671590262.937:52): apparmor="DENIED" operation="capable" profile="/usr/sbin/cupsd" pid=31631 comm="cupsd" capability=12  capname="net_admin"
Dez 21 02:37:42 amnesia systemd[1]: Started Make remote CUPS printers available locally.
░░ Subject: A start job for unit cups-browsed.service has finished successfully
░░ Defined-By: systemd
░░ Support: https://[URL REMOVED]
░░ 
░░ A start job for unit cups-browsed.service has finished successfully.
░░ 
░░ The job identifier is 1852.
Dez 21 02:37:43 amnesia org.boum.tails.PersistentStorage.desktop[31528]: INFO:feature.py:162: Feature successfully activated

I also see failures to activate a feature, no idea which one that was, so here as well, we should at least improve logging:

• wb:b545aa0bce6a0720641a1a942c8001e5
• wb:57450860743171a41d8b07dab4f85fdf
• wb:2f00a42cfc177ca3e4bb1bbbfe2b1f00
• wb:753d9829990c1e6fdaa9a5ec6d9eeb4e (apparently triggered merely by starting tps-frontend)