diff --git a/Makefile b/Makefile index ac12f0d05..ceefb386e 100644 --- a/Makefile +++ b/Makefile @@ -179,7 +179,6 @@ all: install: ifeq ($(OS),Linux) - $(MAKE) install -C linux/autostart $(MAKE) install -C linux/systemd $(MAKE) install -C linux/aux-tools $(MAKE) install -C linux/system-config diff --git a/linux/autostart/Makefile b/linux/autostart/Makefile deleted file mode 100644 index f0191a651..000000000 --- a/linux/autostart/Makefile +++ /dev/null @@ -1,6 +0,0 @@ -all: - true - -install: - mkdir -p $(DESTDIR)/etc/xdg/autostart - cp qubes-preload-dispvm.desktop $(DESTDIR)/etc/xdg/autostart diff --git a/linux/autostart/qubes-preload-dispvm.desktop b/linux/autostart/qubes-preload-dispvm.desktop deleted file mode 100644 index b70597791..000000000 --- a/linux/autostart/qubes-preload-dispvm.desktop +++ /dev/null @@ -1,9 +0,0 @@ -[Desktop Entry] -Icon=qubes -Name=Qubes Preload Disposables -Comment=Workaround for session monitoring with qubes.WaitForSession -Categories=System;Monitor; -Exec=systemctl start qubes-preload-dispvm.service -Terminal=false -NoDisplay=true -Type=Application diff --git a/qubes/tests/api_admin.py b/qubes/tests/api_admin.py index b4abb78c3..444471533 100644 --- a/qubes/tests/api_admin.py +++ b/qubes/tests/api_admin.py @@ -3861,7 +3861,7 @@ def test_643_vm_create_disposable_preload_autostart( "domain-preload-dispvm-autostart", self._test_event_handler ) self.vm.features["qrexec"] = "1" - self.vm.features["supported-rpc.qubes.WaitForSession"] = "1" + self.vm.features["supported-rpc.qubes.WaitForRunningSystem"] = "1" self.vm.features["preload-dispvm-max"] = "1" for _ in range(10): if len(self.vm.get_feat_preload()) == 1: diff --git a/qubes/tests/integ/dispvm.py b/qubes/tests/integ/dispvm.py index 017d3590c..4b96bdd28 100644 --- a/qubes/tests/integ/dispvm.py +++ b/qubes/tests/integ/dispvm.py @@ -29,11 +29,22 @@ from unittest.mock import patch, mock_open import asyncio import sys +import logging import qubes.config import qubes.tests import qubesadmin.exc +# nose will duplicate this logger. +logger = logging.getLogger(__name__) +logger.setLevel(logging.DEBUG) +handler = logging.StreamHandler() +formatter = logging.Formatter( + "%(asctime)s: %(levelname)s: %(funcName)s: %(message)s" +) +handler.setFormatter(formatter) +logger.addHandler(handler) + class TC_04_DispVM(qubes.tests.SystemTestCase): def setUp(self): @@ -183,11 +194,16 @@ def test_011_failed_start_timeout(self): class TC_20_DispVMMixin(object): def setUp(self): # pylint: disable=invalid-name + logger.info("start") super(TC_20_DispVMMixin, self).setUp() if "whonix-g" in self.template: self.skipTest( "whonix gateway is not supported as DisposableVM Template" ) + self.app.add_handler("domain-add", self._on_domain_add) + self.addCleanup( + self.app.remove_handler, "domain-add", self._on_domain_add + ) self.init_default_template(self.template) self.disp_base = self.app.add_new_vm( qubes.vm.appvm.AppVM, @@ -201,12 +217,16 @@ def setUp(self): # pylint: disable=invalid-name self.preload_cmd = [ "qvm-run", "-p", + "--no-color-output", + "--no-color-stderr", f"--dispvm={self.disp_base.name}", "--", "qubesdb-read /name | tr -d '\n'", ] + logger.info("end") def tearDown(self): # pylint: disable=invalid-name + logger.info("start") if "gui" in self.disp_base.features: del self.disp_base.features["gui"] old_preload = self.disp_base.get_feat_preload() @@ -215,28 +235,96 @@ def tearDown(self): # pylint: disable=invalid-name self.loop.run_until_complete(asyncio.gather(*tasks)) self.disp_base.features["preload-dispvm-max"] = False super(TC_20_DispVMMixin, self).tearDown() + logger.info("end") def _test_event_handler( self, vm, event, *args, **kwargs ): # pylint: disable=unused-argument if not hasattr(self, "event_handler"): self.event_handler = {} - self.event_handler.setdefault(vm.name, {})[event] = True + logger.info("%s[%s]", vm.name, event) + self.event_handler.setdefault(vm.name, {}).setdefault(event, 0) + self.event_handler[vm.name][event] += 1 + + + def _test_event_handler_remove(self, vm, event): + if not hasattr(self, "event_handler"): + self.event_handler = {} + logger.info("%s[%s]", vm.name, event) + self.event_handler.setdefault(vm.name, {})[event] = 0 def _test_event_was_handled(self, vm, event): if not hasattr(self, "event_handler"): self.event_handler = {} return self.event_handler.get(vm, {}).get(event) + def _register_handlers(self, vm): # pylint: disable=unused-argument + events = [ + # appvm + "domain-preload-dispvm-autostart", + "domain-preload-dispvm-start", + "domain-preload-dispvm-used", + # dispvm + "domain-feature-set:preload-dispvm-in-progress", + "domain-feature-delete:preload-dispvm-in-progress", + "domain-feature-set:preload-dispvm-completed", + "domain-paused", + "domain-unpaused", + "domain-feature-delete:internal", + ] + for event in events: + vm.add_handler(event, self._test_event_handler) + + def _on_domain_add(self, app, event, vm): # pylint: disable=unused-argument + self._register_handlers(vm) + async def no_preload(self): # Trick to gather this function as an async task. await asyncio.sleep(0) self.disp_base.features["preload-dispvm-max"] = False + async def wait_preload( + self, + preload_max, + wait_completion=True, + fail_on_timeout=True, + timeout=60, + ): + """Waiting for completion avoids coroutine objects leaking.""" + logger.info("start") + for _ in range(timeout): + preload_dispvm = self.disp_base.get_feat_preload() + if len(preload_dispvm) == preload_max: + break + await asyncio.sleep(1) + else: + if fail_on_timeout: + self.fail("didn't preload in time") + if not wait_completion: + logger.info("end") + return + preload_dispvm = self.disp_base.get_feat_preload() + preload_unfinished = preload_dispvm + for _ in range(timeout): + for qube in preload_unfinished.copy(): + if self.app.domains[qube].preload_complete.is_set(): + logger.info("preload completed for '%s'", qube) + preload_unfinished.remove(qube) + continue + if not preload_unfinished: + break + await asyncio.sleep(1) + else: + if fail_on_timeout: + self.fail("last preloaded didn't complete in time") + logger.info("end") + async def run_preload_proc(self): + logger.info("start") proc = await asyncio.create_subprocess_exec( *self.preload_cmd, stdout=asyncio.subprocess.PIPE, + stdin=asyncio.subprocess.DEVNULL, ) try: stdout, _ = await asyncio.wait_for(proc.communicate(), timeout=60) @@ -245,85 +333,71 @@ async def run_preload_proc(self): proc.terminate() await proc.wait() raise + finally: + logger.info("end") async def run_preload(self): + logger.info("start") appvm = self.disp_base dispvm = appvm.get_feat_preload()[0] dispvm = self.app.domains[dispvm] self.assertTrue(dispvm.is_preload) self.assertTrue(dispvm.features.get("internal", False)) - appvm.add_handler( - "domain-preload-dispvm-autostart", self._test_event_handler - ) - appvm.add_handler( - "domain-preload-dispvm-start", self._test_event_handler - ) - appvm.add_handler( - "domain-preload-dispvm-used", self._test_event_handler - ) - dispvm.add_handler("domain-paused", self._test_event_handler) - dispvm.add_handler("domain-unpaused", self._test_event_handler) - dispvm.add_handler( - "domain-feature-set:preload-dispvm-completed", - self._test_event_handler, - ) - dispvm.add_handler( - "domain-feature-set:preload-dispvm-in-progress", - self._test_event_handler, - ) - dispvm.add_handler( - "domain-feature-delete:preload-dispvm-in-progress", - self._test_event_handler, - ) - dispvm.add_handler( - "domain-feature-delete:internal", self._test_event_handler - ) dispvm_name = dispvm.name + self._test_event_handler_remove(appvm, "domain-preload-dispvm-start") + self._test_event_handler_remove(dispvm, "domain-unpaused") + stdout = await self.run_preload_proc() self.assertEqual(stdout, dispvm_name) - self.assertFalse( - self._test_event_was_handled( - appvm.name, "domain-preload-dispvm-autostart" - ) - ) - self.assertFalse( - self._test_event_was_handled( - appvm.name, "domain-preload-dispvm-start" - ) - ) - self.assertTrue( - self._test_event_was_handled( - appvm.name, "domain-preload-dispvm-used" - ) - ) - self.assertTrue( - self._test_event_was_handled( - dispvm_name, "domain-feature-set:preload-dispvm-completed" - ) - ) - self.assertTrue( - self._test_event_was_handled( - dispvm_name, "domain-feature-set:preload-dispvm-in-progress" - ) - ) - self.assertTrue( - self._test_event_was_handled( - dispvm_name, "domain-feature-delete:preload-dispvm-in-progress" - ) - ) - if self._test_event_was_handled(dispvm_name, "domain-paused"): - self.assertTrue( - self._test_event_was_handled(dispvm_name, "domain-unpaused") - ) - if not appvm.features.get("internal", False): - self.assertTrue( - self._test_event_was_handled( - dispvm_name, "domain-feature-delete:internal" - ) - ) + test_cases = [ + (False, appvm.name, "domain-preload-dispvm-autostart", True), + (False, appvm.name, "domain-preload-dispvm-start", True), + (True, appvm.name, "domain-preload-dispvm-used", True), + ( + True, + dispvm_name, + "domain-feature-set:preload-dispvm-in-progress", + True, + ), + ( + True, + dispvm_name, + "domain-feature-delete:preload-dispvm-in-progress", + True, + ), + ( + True, + dispvm_name, + "domain-feature-set:preload-dispvm-completed", + True, + ), + ( + True, + dispvm_name, + "domain-unpaused", + self._test_event_was_handled(dispvm_name, "domain-paused"), + ), + ( + True, + dispvm_name, + "domain-feature-delete:internal", + not appvm.features.get("internal", False), + ), + ] + for assert_type, qube, event, test in test_cases: + with self.subTest( + assert_type=assert_type, qube=qube, event=event, test=test + ): + if test: + event_result = self._test_event_was_handled(qube, event) + if assert_type: + self.assertTrue(event_result) + else: + self.assertFalse(event_result) next_preload_list = appvm.get_feat_preload() self.assertTrue(next_preload_list) self.assertNotIn(dispvm_name, next_preload_list) + logger.info("end") def test_010_dvm_run_simple(self): dispvm = self.loop.run_until_complete( @@ -353,6 +427,7 @@ def test_012_dvm_run_preload_low_mem(self): async def _test_012_dvm_run_preload_low_mem(self): # pylint: disable=unspecified-encoding + logger.info("start") unpatched_open = open def mock_open_mem(file, *args, **kwargs): @@ -362,69 +437,47 @@ def mock_open_mem(file, *args, **kwargs): return unpatched_open(file, *args, **kwargs) with patch("builtins.open", side_effect=mock_open_mem): - self.disp_base.features["preload-dispvm-max"] = "2" - for _ in range(15): - if len(self.disp_base.get_feat_preload()) == 2: - break - await asyncio.sleep(1) + preload_max = 2 + self.disp_base.features["preload-dispvm-max"] = str(preload_max) + await self.wait_preload( + preload_max, fail_on_timeout=False, timeout=15 + ) self.assertEqual(1, len(self.disp_base.get_feat_preload())) + logger.info("end") def test_013_dvm_run_preload_gui(self): - """Test preloading with GUI feature enabled""" + """Test preloading with GUI feature enabled and use after + completion.""" self.loop.run_until_complete(self._test_013_dvm_run_preload_gui()) async def _test_013_dvm_run_preload_gui(self): + logger.info("start") + preload_max = 1 self.disp_base.features["gui"] = True - self.disp_base.features["preload-dispvm-max"] = "1" - for _ in range(10): - if len(self.disp_base.get_feat_preload()) == 1: - break - await asyncio.sleep(1) - else: - self.fail("didn't preload in time") + self.disp_base.features["preload-dispvm-max"] = str(preload_max) + await self.wait_preload(preload_max) await self.run_preload() + logger.info("end") def test_014_dvm_run_preload_nogui(self): - """Test preloading with GUI feature disabled""" + """Test preloading with GUI feature disabled and use before + completion.""" self.loop.run_until_complete(self._test_014_dvm_run_preload_nogui()) async def _test_014_dvm_run_preload_nogui(self): + logger.info("start") + preload_max = 1 self.disp_base.features["gui"] = False - self.disp_base.features["preload-dispvm-max"] = "1" - for _ in range(10): - if len(self.disp_base.get_feat_preload()) == 1: - break - await asyncio.sleep(1) - else: - self.fail("didn't preload in time") + self.disp_base.features["preload-dispvm-max"] = str(preload_max) + await self.wait_preload(preload_max, wait_completion=False) self.preload_cmd.insert(1, "--no-gui") await self.run_preload() + logger.info("end") def test_015_dvm_run_preload_race_more(self): """Test race requesting multiple preloaded qubes""" self.loop.run_until_complete(self._test_015_dvm_run_preload_race_more()) - async def _test_preload_wait_pause(self, preload_max): - """Waiting for pause avoids objects leaking.""" - for _ in range(60): - if len(self.disp_base.get_feat_preload()) == preload_max: - break - await asyncio.sleep(1) - else: - self.fail("didn't preload in time") - preload_dispvm = self.disp_base.get_feat_preload() - preload_unfinished = preload_dispvm - for _ in range(60): - for qube in preload_unfinished.copy(): - if self.app.domains[qube].is_paused(): - preload_unfinished.remove(qube) - continue - if not preload_unfinished: - break - await asyncio.sleep(1) - else: - self.fail("last preloaded didn't pause in time") - async def _test_015_dvm_run_preload_race_more(self): # The limiting factor is how much memory is available on OpenQA and the # unreasonable memory allocated before the qube is paused due to: @@ -432,39 +485,41 @@ async def _test_015_dvm_run_preload_race_more(self): # Whonix (Kicksecure) 17 fail more due to memory consumption. From the # templates deployed by default, only Debian and Fedora survives due to # using less memory than the other OSes. + logger.info("start") preload_max = 4 os_dist = self.disp_base.features.check_with_template("os-distribution") if os_dist in ["whonix", "kicksecure"]: preload_max -= 1 self.disp_base.features["preload-dispvm-max"] = str(preload_max) - await self._test_preload_wait_pause(preload_max) + await self.wait_preload(preload_max) old_preload = self.disp_base.get_feat_preload() tasks = [self.run_preload_proc() for _ in range(preload_max)] targets = await asyncio.gather(*tasks) - await self._test_preload_wait_pause(preload_max) + await self.wait_preload(preload_max) preload_dispvm = self.disp_base.get_feat_preload() self.assertTrue(set(old_preload).isdisjoint(preload_dispvm)) self.assertEqual(len(targets), preload_max) self.assertEqual(len(targets), len(set(targets))) + logger.info("end") def test_016_dvm_run_preload_race_less(self): """Test race requesting preloaded qube while the maximum is zeroed.""" self.loop.run_until_complete(self._test_016_dvm_run_preload_race_less()) async def _test_016_dvm_run_preload_race_less(self): - self.disp_base.features["preload-dispvm-max"] = "1" - for _ in range(60): - if len(self.disp_base.get_feat_preload()) == 1: - break - await asyncio.sleep(1) - else: - self.fail("didn't preload in time") + logger.info("start") + preload_max = 1 + self.disp_base.features["preload-dispvm-max"] = str(preload_max) + await self.wait_preload(preload_max, wait_completion=False) tasks = [self.run_preload_proc(), self.no_preload()] target = await asyncio.gather(*tasks) target_dispvm = target[0] self.assertTrue(target_dispvm.startswith("disp")) + logger.info("end") def test_017_dvm_run_preload_autostart(self): + logger.info("start") + preload_max = 1 proc = self.loop.run_until_complete( asyncio.create_subprocess_exec("/usr/lib/qubes/preload-dispvm") ) @@ -472,25 +527,21 @@ def test_017_dvm_run_preload_autostart(self): asyncio.wait_for(proc.communicate(), timeout=10) ) self.assertEqual(self.disp_base.get_feat_preload(), []) - self.disp_base.features["preload-dispvm-max"] = "1" - for _ in range(10): - if len(self.disp_base.get_feat_preload()) == 1: - break - self.loop.run_until_complete(asyncio.sleep(1)) - else: - self.fail("didn't preload in time") + self.disp_base.features["preload-dispvm-max"] = str(preload_max) + self.loop.run_until_complete(self.wait_preload(preload_max)) old_preload = self.disp_base.get_feat_preload() proc = self.loop.run_until_complete( asyncio.create_subprocess_exec("/usr/lib/qubes/preload-dispvm") ) self.loop.run_until_complete(asyncio.wait_for(proc.wait(), timeout=30)) preload_dispvm = self.disp_base.get_feat_preload() - self.assertEqual(len(old_preload), 1) - self.assertEqual(len(preload_dispvm), 1) + self.assertEqual(len(old_preload), preload_max) + self.assertEqual(len(preload_dispvm), preload_max) self.assertTrue( set(old_preload).isdisjoint(preload_dispvm), f"old_preload={old_preload} preload_dispvm={preload_dispvm}", ) + logger.info("end") @unittest.skipUnless( spawn.find_executable("xdotool"), "xdotool not installed" diff --git a/qubes/vm/dispvm.py b/qubes/vm/dispvm.py index 4a388e9e5..5fc72f41a 100644 --- a/qubes/vm/dispvm.py +++ b/qubes/vm/dispvm.py @@ -87,8 +87,8 @@ class DispVM(qubes.vm.qubesvm.QubesVM): - Full start: Preloaded disposable must only be interrupted (paused/suspended) or used after all basic services in it have been - started. Autostarted applications allows user interaction before the it - should, that is a bug. + started. Failure to complete this step must remove the qube from the + preload list. - **Prevents accidental tampering**: @@ -102,12 +102,11 @@ class DispVM(qubes.vm.qubesvm.QubesVM): GUI applications, that is a bug because features cannot be set before that event. - - Preloaded qubes must be marked as used when prior to being - unpaused/resumed, even if it was not requested. The goal of - pause/suspend in case of preloaded disposables is mostly detecting - whether a qube was used or not, and not managing resource consumption; - thus, even with abundant system resources, they should not be - unpaused/resumed without being requested. + - Preloaded qubes must be marked as used after being unpaused/resumed, + even if it was not requested. The goal of pause/suspend in case of + preloaded disposables is mostly detecting whether a qube was used or + not, not managing resource consumption; thus, even with abundant system + resources, they should not be unpaused/resumed without being requested. **Features and properties relationship on stages**: @@ -136,14 +135,6 @@ class DispVM(qubes.vm.qubesvm.QubesVM): applicable). Only in this phase, GUI applications treat the qube as any other unnamed disposable and the qube object is returned to the caller if requested. - - **Outstanding bugs**: - - - GUI applications set to autostart can appear on the screen and be - interactive for a brief moment before the qube is allowed to be used - followed by a sudden freeze. - - Can't interrupt qubes before the GUI session has started if the qube's - usage will require a GUI (GUI daemon cannot handle an interrupted qube). """ template = qubes.VMProperty( @@ -341,26 +332,19 @@ async def on_domain_started_dispvm( """ if not self.is_preload: return - # TODO: pause is late for autostarted GUI applications - # https://github.com/QubesOS/qubes-issues/issues/9907 timeout = self.qrexec_timeout - gui = bool(self.guivm and self.features.get("gui", True)) - service = "qubes.WaitForSession" - if not gui: - # https://github.com/QubesOS/qubes-issues/issues/9964 - # service = "qubes.WaitForRunningSystem" - rpc = "qubes.WaitForRunningSystem" - path = "/run/qubes-rpc:/usr/local/etc/qubes-rpc:/etc/qubes-rpc" - service = '$(PATH="' + path + '" command -v ' + rpc + ")" + # https://github.com/QubesOS/qubes-issues/issues/9964 + rpc = "qubes.WaitForRunningSystem" + path = "/run/qubes-rpc:/usr/local/etc/qubes-rpc:/etc/qubes-rpc" + service = '$(PATH="' + path + '" command -v ' + rpc + ")" try: self.log.info( "Preload startup waiting '%s' with '%d' seconds timeout", service, timeout, ) - runner = self.run_service_for_stdio if gui else self.run_for_stdio await asyncio.wait_for( - runner( + self.run_for_stdio( service, stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL, @@ -368,16 +352,13 @@ async def on_domain_started_dispvm( timeout=timeout, ) except asyncio.TimeoutError: - # TODO: if pause occurs before the GUI session starts (on boot - # before login manager), results in an unusable GUI for the qube: - # https://github.com/QubesOS/qubes-issues/issues/9940 raise qubes.exc.QubesException( - "Timed out Qrexec call to '%s' after '%d' seconds during " - "preload startup" % (service, timeout) + "Timed out call to '%s' after '%d' seconds during preload " + "startup" % (service, timeout) ) except (subprocess.CalledProcessError, qubes.exc.QubesException): raise qubes.exc.QubesException( - "Error on Qrexec call to '%s' during preload startup" % service + "Error on call to '%s' during preload startup" % service ) if not self.preload_requested: @@ -397,11 +378,11 @@ def on_domain_paused( if self.is_preload: self.log.info("Paused preloaded qube") - @qubes.events.handler("domain-pre-unpaused") - def on_domain_pre_unpaused( + @qubes.events.handler("domain-unpaused") + def on_domain_unpaused( self, event, **kwargs ): # pylint: disable=unused-argument - """Mark preloaded domains as used before being unpaused.""" + """Mark preloaded disposables as used.""" # Qube start triggers unpause via 'libvirt_domain.resume()'. if self.is_preload and self.is_fully_usable(): self.log.info("Unpaused preloaded qube will be marked as used") diff --git a/qubes/vm/mix/dvmtemplate.py b/qubes/vm/mix/dvmtemplate.py index c6cc1f908..3e574743e 100644 --- a/qubes/vm/mix/dvmtemplate.py +++ b/qubes/vm/mix/dvmtemplate.py @@ -100,16 +100,11 @@ def on_feature_pre_set_preload_dispvm_max( if not self.features.check_with_template("qrexec", None): raise qubes.exc.QubesValueError("Qube does not support qrexec") - gui = bool(self.guivm and self.features.get("gui", True)) - if gui: - service = "qubes.WaitForSession" - else: - service = "qubes.WaitForRunningSystem" + service = "qubes.WaitForRunningSystem" supported_service = "supported-rpc." + service if not self.features.check_with_template(supported_service, False): raise qubes.exc.QubesValueError( - "Qube GUI is '%s' and does not support the RPC '%s'" - % (gui, service) + "Qube does not support the RPC '%s'" % service ) value = value or "0" diff --git a/rpm_spec/core-dom0.spec.in b/rpm_spec/core-dom0.spec.in index 26b96bd51..fdfe526f4 100644 --- a/rpm_spec/core-dom0.spec.in +++ b/rpm_spec/core-dom0.spec.in @@ -368,7 +368,6 @@ done /usr/bin/qubes-* /usr/bin/qmemmand /usr/bin/qubesd* -/etc/xdg/autostart/qubes-preload-dispvm.desktop %{_mandir}/man1/qubes*.1*