Merge branch 'tests-20171020'

* tests-20171020:
  tests: fix asyncio usage some more places
  tests: fix reporting in network tests
  tests: domain-shutdown event race condition
  tests: improve events tests
  tests: fix logic error in wait_for_window()
  tests: cleanup QubesDB connection on domain remove

qubes/tests/__init__.py

@@ -656,6 +656,16 @@ class SystemTestCase(QubesTestCase):
 
         self.addCleanup(self.cleanup_app)
 
+        self.app.add_handler('domain-delete', self.close_qdb_on_remove)
+
+    def close_qdb_on_remove(self, app, event, vm, **kwargs):
+        # only close QubesDB connection, do not perform other (destructive)
+        # actions of vm.close()
+        if vm._qdb_connection_watch is not None:
+            asyncio.get_event_loop().remove_reader(
+                vm._qdb_connection_watch.watch_fd())
+            vm._qdb_connection_watch.close()
+            vm._qdb_connection_watch = None
 
     def cleanup_app(self):
         self.remove_test_vms()
@@ -943,7 +953,7 @@ class SystemTestCase(QubesTestCase):
         wait_count = 0
         while subprocess.call(['xdotool', 'search', '--name', title],
                 stdout=subprocess.DEVNULL, stderr=subprocess.STDOUT) \
-                == int(not show):
+                != int(not show):
             wait_count += 1
             if wait_count > timeout*10:
                 self.fail("Timeout while waiting for {} window to {}".format(

qubes/tests/init.py

@@ -83,8 +83,10 @@ class TC_10_property(qubes.tests.QubesTestCase):
 
     def test_010_set(self):
         self.holder.testprop1 = 'testvalue'
-        self.assertEventFired(self.holder, 'property-pre-set:testprop1')
-        self.assertEventFired(self.holder, 'property-set:testprop1')
+        self.assertEventFired(self.holder, 'property-pre-set:testprop1',
+            kwargs={'name': 'testprop1', 'newvalue': 'testvalue'})
+        self.assertEventFired(self.holder, 'property-set:testprop1',
+            kwargs={'name': 'testprop1', 'newvalue': 'testvalue'})
 
     def test_020_get(self):
         self.holder.testprop1 = 'testvalue'
@@ -113,6 +115,14 @@ class TC_10_property(qubes.tests.QubesTestCase):
         self.assertEqual(holder.testprop1, 'defaultvalue')
         holder.testprop1 = 'testvalue'
         self.assertEqual(holder.testprop1, 'testvalue')
+        self.assertEventFired(holder, 'property-pre-set:testprop1',
+            kwargs={'name': 'testprop1',
+                'newvalue': 'testvalue',
+                'oldvalue': 'defaultvalue'})
+        self.assertEventFired(holder, 'property-set:testprop1',
+            kwargs={'name': 'testprop1',
+                'newvalue': 'testvalue',
+                'oldvalue': 'defaultvalue'})
 
     def test_030_set_setter(self):
         def setter(self2, prop, value):
@@ -127,6 +137,10 @@ class TC_10_property(qubes.tests.QubesTestCase):
 
         holder.testprop1 = 'testvalue'
         self.assertEqual(holder.testprop1, 'settervalue')
+        self.assertEventFired(holder, 'property-pre-set:testprop1',
+            kwargs={'name': 'testprop1', 'newvalue': 'settervalue'})
+        self.assertEventFired(holder, 'property-set:testprop1',
+            kwargs={'name': 'testprop1', 'newvalue': 'settervalue'})
 
     def test_031_set_type(self):
         class MyTestHolder(qubes.tests.TestEmitter, qubes.PropertyHolder):
@@ -136,6 +150,10 @@ class TC_10_property(qubes.tests.QubesTestCase):
         holder.testprop1 = '5'
         self.assertEqual(holder.testprop1, 5)
         self.assertNotEqual(holder.testprop1, '5')
+        self.assertEventFired(holder, 'property-pre-set:testprop1',
+            kwargs={'name': 'testprop1', 'newvalue': 5})
+        self.assertEventFired(holder, 'property-set:testprop1',
+            kwargs={'name': 'testprop1', 'newvalue': 5})
 
     def test_080_delete(self):
         self.holder.testprop1 = 'testvalue'
@@ -150,6 +168,11 @@ class TC_10_property(qubes.tests.QubesTestCase):
         with self.assertRaises(AttributeError):
             self.holder.testprop1
 
+        self.assertEventFired(self.holder, 'property-pre-del:testprop1',
+            kwargs={'name': 'testprop1', 'oldvalue': 'testvalue'})
+        self.assertEventFired(self.holder, 'property-del:testprop1',
+            kwargs={'name': 'testprop1', 'oldvalue': 'testvalue'})
+
     def test_081_delete_by_assign(self):
         self.holder.testprop1 = 'testvalue'
         try:
@@ -178,6 +201,10 @@ class TC_10_property(qubes.tests.QubesTestCase):
         del holder.testprop1
 
         self.assertEqual(holder.testprop1, 'defaultvalue')
+        self.assertEventFired(holder, 'property-pre-del:testprop1', kwargs={
+            'name': 'testprop1', 'oldvalue': 'testvalue'})
+        self.assertEventFired(holder, 'property-del:testprop1', kwargs={
+            'name': 'testprop1', 'oldvalue': 'testvalue'})
 
     def test_090_write_once_set(self):
         class MyTestHolder(qubes.tests.TestEmitter, qubes.PropertyHolder):

qubes/tests/integ/basic.py

@@ -124,6 +124,68 @@ class TC_00_Basic(qubes.tests.SystemTestCase):
             # one after another, private volume is gone
             self.loop.run_until_complete(self.vm.storage.verify())
 
+    def _test_201_on_domain_pre_start(self, vm, event, **_kwargs):
+        '''Simulate domain crash just after startup'''
+        if not self.domain_shutdown_handled and not self.test_failure_reason:
+            self.test_failure_reason = \
+                'domain-shutdown event was not dispatched before subsequent ' \
+                'start'
+        self.domain_shutdown_handled = False
+
+    def _test_201_domain_shutdown_handler(self, vm, event, **kwargs):
+        if self.domain_shutdown_handled and not self.test_failure_reason:
+            self.test_failure_reason = 'domain-shutdown event received twice'
+        self.domain_shutdown_handled = True
+
+    @unittest.expectedFailure
+    def test_201_shutdown_event_race(self):
+        '''Regression test for 3164 - pure events edition'''
+        vmname = self.make_vm_name('appvm')
+
+        self.vm = self.app.add_new_vm(qubes.vm.appvm.AppVM,
+            name=vmname, template=self.app.default_template,
+            label='red')
+        # help the luck a little - don't wait for qrexec to easier win the race
+        self.vm.features['qrexec'] = False
+        self.loop.run_until_complete(self.vm.create_on_disk())
+
+        # do not throw exception from inside event handler - test framework
+        # will not recover from it (various objects leaks)
+        self.test_failure_reason = None
+        self.domain_shutdown_handled = False
+        self.vm.add_handler('domain-shutdown',
+            self._test_201_domain_shutdown_handler)
+
+        self.loop.run_until_complete(self.vm.start())
+
+        if self.test_failure_reason:
+            self.fail(self.test_failure_reason)
+
+        self.vm.add_handler('domain-pre-start',
+            self._test_201_on_domain_pre_start)
+
+        # kill it the way it does not give a chance for domain-shutdown it
+        # execute
+        self.vm.libvirt_domain.destroy()
+
+        # now, lets try to start the VM again, before domain-shutdown event
+        # got handled (#3164), and immediately trigger second domain-shutdown
+        self.vm.add_handler('domain-start', self._test_200_on_domain_start)
+        self.loop.run_until_complete(self.vm.start())
+
+        if self.test_failure_reason:
+            self.fail(self.test_failure_reason)
+
+        # and give a chance for both domain-shutdown handlers to execute
+        self.loop.run_until_complete(asyncio.sleep(1))
+
+        if self.test_failure_reason:
+            self.fail(self.test_failure_reason)
+
+        self.assertTrue(self.domain_shutdown_handled,
+            'second domain-shutdown event was not dispatched after domain '
+            'shutdown')
+
 
 class TC_01_Properties(qubes.tests.SystemTestCase):
     # pylint: disable=attribute-defined-outside-init

qubes/tests/integ/dispvm.py

@@ -53,7 +53,6 @@ class TC_04_DispVM(qubes.tests.SystemTestCase):
         self.app.default_dispvm = None
         super(TC_04_DispVM, self).tearDown()
 
-    @unittest.expectedFailure
     def test_002_cleanup(self):
         self.loop.run_until_complete(self.testvm.start())
 
@@ -71,7 +70,6 @@ class TC_04_DispVM(qubes.tests.SystemTestCase):
         self.loop.run_until_complete(asyncio.sleep(1))
         self.assertNotIn(dispvm_name, self.app.domains)
 
-    @unittest.expectedFailure
     def test_003_cleanup_destroyed(self):
         """
         Check if DispVM is properly removed even if it terminated itself (#1660)
@@ -152,6 +150,7 @@ class TC_20_DispVMMixin(object):
                 p.stdin.write("xterm -e "
                     "\"sh -c 'echo \\\"\033]0;{}\007\\\";read x;'\"\n".
                     format(window_title).encode())
+                self.loop.run_until_complete(p.stdin.drain())
                 self.wait_for_window(window_title)
 
                 time.sleep(0.5)
@@ -160,11 +159,15 @@ class TC_20_DispVMMixin(object):
                 self.wait_for_window(window_title, show=False)
             finally:
                 p.stdin.close()
+                del p
         finally:
             self.loop.run_until_complete(dispvm.cleanup())
             dispvm_name = dispvm.name
             del dispvm
 
+        # give it a time for shutdown + cleanup
+        self.loop.run_until_complete(asyncio.sleep(2))
+
         self.assertNotIn(dispvm_name, self.app.domains,
                           "DispVM not removed from qubes.xml")
 
@@ -224,7 +227,6 @@ class TC_20_DispVMMixin(object):
 
     @unittest.skipUnless(spawn.find_executable('xdotool'),
                          "xdotool not installed")
-    @unittest.expectedFailure
     def test_030_edit_file(self):
         self.testvm1 = self.app.add_new_vm(qubes.vm.appvm.AppVM,
                                      name=self.make_vm_name('vm1'),

qubes/tests/integ/network.py

@@ -769,7 +769,8 @@ class VmUpdatesMixin(object):
         self.testvm1 = self.app.domains[self.testvm1.qid]
         self.loop.run_until_complete(self.testvm1.start())
         p = self.loop.run_until_complete(
-            self.testvm1.run(self.update_cmd, user='root'))
+            self.testvm1.run(self.update_cmd, user='root',
+            stdout=subprocess.PIPE, stderr=subprocess.PIPE))
         (stdout, stderr) = self.loop.run_until_complete(p.communicate())
         self.assertIn(p.returncode, self.exit_code_ok,
             '{}: {}\n{}'.format(self.update_cmd, stdout, stderr))
@@ -844,11 +845,13 @@ SHA256:
         if self.template.count("debian") or self.template.count("whonix"):
             self.create_repo_apt()
             self.loop.run_until_complete(self.netvm_repo.run(
-                'cd /tmp/apt-repo && python -m SimpleHTTPServer 8080'))
+                'cd /tmp/apt-repo && python -m SimpleHTTPServer 8080',
+                stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL))
         elif self.template.count("fedora"):
             self.create_repo_yum()
             self.loop.run_until_complete(self.netvm_repo.run(
-                'cd /tmp/yum-repo && python -m SimpleHTTPServer 8080'))
+                'cd /tmp/yum-repo && python -m SimpleHTTPServer 8080',
+                stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL))
         else:
             # not reachable...
             self.skipTest("Template {} not supported by this test".format(
@@ -923,14 +926,16 @@ SHA256:
 
             # install test package
             p = self.loop.run_until_complete(self.testvm1.run(
-                self.install_cmd.format('test-pkg'), user='root'))
+                self.install_cmd.format('test-pkg'), user='root',
+                stdout=subprocess.PIPE, stderr=subprocess.PIPE))
             (stdout, stderr) = self.loop.run_until_complete(p.communicate())
             self.assertIn(self.loop.run_until_complete(p.wait()), self.exit_code_ok,
                 '{}: {}\n{}'.format(self.update_cmd, stdout, stderr))
 
             # verify if it was really installed
             p = self.loop.run_until_complete(self.testvm1.run(
-                self.install_test_cmd.format('test-pkg'), user='root'))
+                self.install_test_cmd.format('test-pkg'), user='root',
+                stdout=subprocess.PIPE, stderr=subprocess.PIPE))
             (stdout, stderr) = self.loop.run_until_complete(p.communicate())
             self.assertIn(self.loop.run_until_complete(p.wait()), self.exit_code_ok,
                 '{}: {}\n{}'.format(self.update_cmd, stdout, stderr))

qubes/tests/integ/vm_qrexec_gui.py

@@ -774,14 +774,14 @@ class TC_00_AppVMMixin(object):
         finally:
             self.app.clockvm = None
 
-    @unittest.expectedFailure
     def test_250_resize_private_img(self):
         """
         Test private.img resize, both offline and online
         :return:
         """
         # First offline test
-        self.testvm1.storage.resize('private', 4*1024**3)
+        self.loop.run_until_complete(
+            self.testvm1.storage.resize('private', 4*1024**3))
         self.loop.run_until_complete(self.testvm1.start())
         df_cmd = '( df --output=size /rw || df /rw | awk \'{print $2}\' )|' \
                  'tail -n 1'
@@ -797,7 +797,7 @@ class TC_00_AppVMMixin(object):
         new_size, _ = self.loop.run_until_complete(
             self.testvm1.run_for_stdio(df_cmd))
         # some safety margin for FS metadata
-        self.assertGreater(int(new_size.strip()), 5.8*1024**2)
+        self.assertGreater(int(new_size.strip()), 5.7*1024**2)
 
     @unittest.skipUnless(spawn.find_executable('xdotool'),
                          "xdotool not installed")
@@ -902,8 +902,11 @@ int main(int argc, char **argv) {
         # passing is unreliable while the process is still running
         alloc1.stdin.write(b'\n')
         yield from alloc1.stdin.drain()
-        alloc_out = yield from alloc1.stdout.read(
-            len('Stage1\nStage2\nStage3\n'))
+        try:
+            alloc_out = yield from alloc1.stdout.readexactly(
+                len('Stage1\nStage2\nStage3\n'))
+        except asyncio.IncompleteReadError as e:
+            alloc_out = e.partial
 
         if b'Stage3' not in alloc_out:
             # read stderr only in case of failed assert (), but still have nice
@@ -923,11 +926,11 @@ int main(int argc, char **argv) {
         # help xdotool a little...
         yield from asyncio.sleep(2)
         # get window ID
-        winid = yield from asyncio.get_event_loop().run_in_executor(
+        winid = (yield from asyncio.get_event_loop().run_in_executor(None,
             subprocess.check_output,
             ['xdotool', 'search', '--sync', '--onlyvisible', '--class',
-                self.testvm1.name + ':.*erminal']).decode()
-        xprop = yield from asyncio.get_event_loop().run_in_executor(
+                self.testvm1.name + ':.*erminal'])).decode()
+        xprop = yield from asyncio.get_event_loop().run_in_executor(None,
             subprocess.check_output,
             ['xprop', '-notype', '-id', winid, '_QUBES_VMWINDOWID'])
         vm_winid = xprop.decode().strip().split(' ')[4]
@@ -943,7 +946,7 @@ int main(int argc, char **argv) {
         # some memory
         alloc2 = yield from self.testvm1.run(
             'ulimit -l unlimited; /home/user/allocator {}'.format(memory_pages),
-            user='root')
+            user='root', stdout=subprocess.PIPE)
         yield from alloc2.stdout.read(len('Stage1\n'))
 
         # wait for damage notify - top updates every 3 sec by default
@@ -955,7 +958,7 @@ int main(int argc, char **argv) {
         vm_image, _ = yield from self.testvm1.run_for_stdio(
             'import -window {} pnm:-'.format(vm_winid))
 
-        dom0_image = yield from asyncio.get_event_loop().run_in_executor(
+        dom0_image = yield from asyncio.get_event_loop().run_in_executor(None,
             subprocess.check_output, ['import', '-window', winid, 'pnm:-'])
 
         if vm_image != dom0_image: