[PATCH v5 00/12] python/machine.py: refactor shutdown

[PATCH v5 00/12] python/machine.py: refactor shutdown

[John Snow]

v5: More or less rewritten.

This series is motivated by a desire to move python/qemu onto a strict
mypy/pylint regime to help prevent regressions in the python codebase.

1. Remove the "bare except" pattern in the existing shutdown code, which
   can mask problems and make debugging difficult.

2. Ensure that post-shutdown cleanup is always performed, even when
   graceful termination fails.

3. Unify cleanup paths such that no matter how the VM is terminated, the
   same functions and steps are always taken to reset the object state.

4. Rewrite shutdown() such that any error encountered when attempting a
   graceful shutdown will be raised as an AbnormalShutdown exception.
   The pythonic idiom is to allow the caller to decide if this is a
   problem or not.

Previous versions of this series did not engage the fourth goal, and ran
into race conditions. When I was trying to allow shutdown to succeed if
QEMU was already closed, it became impossible to tell in which cases
QEMU not being present was "OK" and in which cases it was evidence of a
problem.

This refactoring is even more explicit. If a graceful shutdown is
requested and cannot be performed, an exception /will/ be raised.

In cases where the test writer expects QEMU to already have exited,
vm.wait() should be used in preference to vm.shutdown(). In cases where
a graceful shutdown is not interesting or necessary to the test,
vm.kill() should be used.

John Snow (12):
  python/machine.py: consolidate _post_shutdown()
  python/machine.py: Close QMP socket in cleanup
  python/machine.py: Add _early_cleanup hook
  python/machine.py: Perform early cleanup for wait() calls, too
  python/machine.py: Prohibit multiple shutdown() calls
  python/machine.py: Add a configurable timeout to shutdown()
  python/machine.py: Make wait() call shutdown()
  tests/acceptance: wait() instead of shutdown() where appropriate
  tests/acceptance: Don't test reboot on cubieboard
  python/machine.py: split shutdown into hard and soft flavors
  python/machine.py: re-add sigkill warning suppression
  python/machine.py: change default wait timeout to 3 seconds

 python/qemu/machine.py                   | 166 ++++++++++++++++++-----
 tests/acceptance/boot_linux_console.py   |  14 +-
 tests/acceptance/linux_ssh_mips_malta.py |   2 +
 3 files changed, 141 insertions(+), 41 deletions(-)

-- 
2.21.3

[PATCH v5 01/12] python/machine.py: consolidate _post_shutdown()

[John Snow]

Move more cleanup actions into _post_shutdown. As a change, if QEMU
should so happen to be terminated during a call to wait(), that event
will now be logged.

This is not likely to occur during normative use.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine.py | 27 +++++++++++++--------------
 1 file changed, 13 insertions(+), 14 deletions(-)

diff --git a/python/qemu/machine.py b/python/qemu/machine.py
index 041c615052..f7e68191c2 100644
--- a/python/qemu/machine.py
+++ b/python/qemu/machine.py
@@ -283,6 +283,8 @@ def _post_launch(self):
             self._qmp.accept()
 
     def _post_shutdown(self):
+        self._load_io_log()
+
         if self._qemu_log_file is not None:
             self._qemu_log_file.close()
             self._qemu_log_file = None
@@ -296,6 +298,17 @@ def _post_shutdown(self):
         while len(self._remove_files) > 0:
             self._remove_if_exists(self._remove_files.pop())
 
+        exitcode = self.exitcode()
+        if exitcode is not None and exitcode < 0:
+            msg = 'qemu received signal %i; command: "%s"'
+            if self._qemu_full_args:
+                command = ' '.join(self._qemu_full_args)
+            else:
+                command = ''
+            LOG.warning(msg, -int(exitcode), command)
+
+        self._launched = False
+
     def launch(self):
         """
         Launch the VM and make sure we cleanup and expose the
@@ -344,7 +357,6 @@ def wait(self):
         self._popen.wait()
         if self._qmp:
             self._qmp.close()
-        self._load_io_log()
         self._post_shutdown()
 
     def shutdown(self, has_quit=False, hard=False):
@@ -371,21 +383,8 @@ def shutdown(self, has_quit=False, hard=False):
                     self._popen.kill()
             self._popen.wait()
 
-        self._load_io_log()
         self._post_shutdown()
 
-        exitcode = self.exitcode()
-        if exitcode is not None and exitcode < 0 and \
-                not (exitcode == -9 and hard):
-            msg = 'qemu received signal %i: %s'
-            if self._qemu_full_args:
-                command = ' '.join(self._qemu_full_args)
-            else:
-                command = ''
-            LOG.warning(msg, -int(exitcode), command)
-
-        self._launched = False
-
     def kill(self):
         self.shutdown(hard=True)
 
-- 
2.21.3

[PATCH v5 02/12] python/machine.py: Close QMP socket in cleanup

[John Snow]

It's not important to do this before waiting for the process to exit, so
it can be done during generic post-shutdown cleanup.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine.py | 7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/python/qemu/machine.py b/python/qemu/machine.py
index f7e68191c2..938c891b1d 100644
--- a/python/qemu/machine.py
+++ b/python/qemu/machine.py
@@ -283,6 +283,10 @@ def _post_launch(self):
             self._qmp.accept()
 
     def _post_shutdown(self):
+        if self._qmp:
+            self._qmp.close()
+            self._qmp = None
+
         self._load_io_log()
 
         if self._qemu_log_file is not None:
@@ -355,8 +359,6 @@ def wait(self):
         Wait for the VM to power off
         """
         self._popen.wait()
-        if self._qmp:
-            self._qmp.close()
         self._post_shutdown()
 
     def shutdown(self, has_quit=False, hard=False):
@@ -377,7 +379,6 @@ def shutdown(self, has_quit=False, hard=False):
                 try:
                     if not has_quit:
                         self._qmp.cmd('quit')
-                    self._qmp.close()
                     self._popen.wait(timeout=3)
                 except:
                     self._popen.kill()
-- 
2.21.3

[PATCH v5 03/12] python/machine.py: Add _early_cleanup hook

[John Snow]

Some parts of cleanup need to occur prior to shutdown, otherwise
shutdown might break. Move this into a suitably named method/callback.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine.py | 24 +++++++++++++++---------
 1 file changed, 15 insertions(+), 9 deletions(-)

diff --git a/python/qemu/machine.py b/python/qemu/machine.py
index 938c891b1d..4280aab380 100644
--- a/python/qemu/machine.py
+++ b/python/qemu/machine.py
@@ -354,16 +354,9 @@ def _launch(self):
                                        close_fds=False)
         self._post_launch()
 
-    def wait(self):
+    def _early_cleanup(self) -> None:
         """
-        Wait for the VM to power off
-        """
-        self._popen.wait()
-        self._post_shutdown()
-
-    def shutdown(self, has_quit=False, hard=False):
-        """
-        Terminate the VM and clean up
+        Perform any cleanup that needs to happen before the VM exits.
         """
         # If we keep the console socket open, we may deadlock waiting
         # for QEMU to exit, while QEMU is waiting for the socket to
@@ -372,6 +365,19 @@ def shutdown(self, has_quit=False, hard=False):
             self._console_socket.close()
             self._console_socket = None
 
+    def wait(self):
+        """
+        Wait for the VM to power off
+        """
+        self._popen.wait()
+        self._post_shutdown()
+
+    def shutdown(self, has_quit=False, hard=False):
+        """
+        Terminate the VM and clean up
+        """
+        self._early_cleanup()
+
         if self.is_running():
             if hard:
                 self._popen.kill()
-- 
2.21.3

[PATCH v5 04/12] python/machine.py: Perform early cleanup for wait() calls, too

[John Snow]

This is primarily for consistency, and is a step towards wait() and
shutdown() sharing the same implementation so that the two cleanup paths
cannot diverge.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine.py | 1 +
 1 file changed, 1 insertion(+)

diff --git a/python/qemu/machine.py b/python/qemu/machine.py
index 4280aab380..cac466fbe6 100644
--- a/python/qemu/machine.py
+++ b/python/qemu/machine.py
@@ -369,6 +369,7 @@ def wait(self):
         """
         Wait for the VM to power off
         """
+        self._early_cleanup()
         self._popen.wait()
         self._post_shutdown()
 
-- 
2.21.3

[PATCH v5 05/12] python/machine.py: Prohibit multiple shutdown() calls

[John Snow]

If the VM is not launched, don't try to shut it down. As a change,
_post_shutdown now unconditionally also calls _early_cleanup in order to
offer comprehensive object cleanup in failure cases.

As a courtesy, treat it as a NOP instead of rejecting it as an
error. This is slightly nicer for acceptance tests where vm.shutdown()
is issued unconditionally in tearDown callbacks.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine.py | 14 +++++++++++++-
 1 file changed, 13 insertions(+), 1 deletion(-)

diff --git a/python/qemu/machine.py b/python/qemu/machine.py
index cac466fbe6..e66a7d66dd 100644
--- a/python/qemu/machine.py
+++ b/python/qemu/machine.py
@@ -283,6 +283,13 @@ def _post_launch(self):
             self._qmp.accept()
 
     def _post_shutdown(self):
+        """
+        Called to cleanup the VM instance after the process has exited.
+        May also be called after a failed launch.
+        """
+        # Comprehensive reset for the failed launch case:
+        self._early_cleanup()
+
         if self._qmp:
             self._qmp.close()
             self._qmp = None
@@ -328,7 +335,7 @@ def launch(self):
             self._launch()
             self._launched = True
         except:
-            self.shutdown()
+            self._post_shutdown()
 
             LOG.debug('Error launching VM')
             if self._qemu_full_args:
@@ -357,6 +364,8 @@ def _launch(self):
     def _early_cleanup(self) -> None:
         """
         Perform any cleanup that needs to happen before the VM exits.
+
+        Called additionally by _post_shutdown for comprehensive cleanup.
         """
         # If we keep the console socket open, we may deadlock waiting
         # for QEMU to exit, while QEMU is waiting for the socket to
@@ -377,6 +386,9 @@ def shutdown(self, has_quit=False, hard=False):
         """
         Terminate the VM and clean up
         """
+        if not self._launched:
+            return
+
         self._early_cleanup()
 
         if self.is_running():
-- 
2.21.3

[PATCH v5 06/12] python/machine.py: Add a configurable timeout to shutdown()

[John Snow]

Three seconds is hardcoded. Use it as a default parameter instead, and use that
value for both waits that may occur in the function.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine.py | 8 +++++---
 1 file changed, 5 insertions(+), 3 deletions(-)

diff --git a/python/qemu/machine.py b/python/qemu/machine.py
index e66a7d66dd..120e0df3ee 100644
--- a/python/qemu/machine.py
+++ b/python/qemu/machine.py
@@ -382,7 +382,9 @@ def wait(self):
         self._popen.wait()
         self._post_shutdown()
 
-    def shutdown(self, has_quit=False, hard=False):
+    def shutdown(self, has_quit: bool = False,
+                 hard: bool = False,
+                 timeout: Optional[int] = 3) -> None:
         """
         Terminate the VM and clean up
         """
@@ -398,10 +400,10 @@ def shutdown(self, has_quit=False, hard=False):
                 try:
                     if not has_quit:
                         self._qmp.cmd('quit')
-                    self._popen.wait(timeout=3)
+                    self._popen.wait(timeout=timeout)
                 except:
                     self._popen.kill()
-            self._popen.wait()
+            self._popen.wait(timeout=timeout)
 
         self._post_shutdown()
 
-- 
2.21.3

[PATCH v5 07/12] python/machine.py: Make wait() call shutdown()

[John Snow]

At this point, shutdown(has_quit=True) and wait() do essentially the
same thing; they perform cleanup without actually instructing QEMU to
quit.

Define one in terms of the other.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine.py | 17 +++++++++--------
 1 file changed, 9 insertions(+), 8 deletions(-)

diff --git a/python/qemu/machine.py b/python/qemu/machine.py
index 120e0df3ee..aaa173f046 100644
--- a/python/qemu/machine.py
+++ b/python/qemu/machine.py
@@ -374,14 +374,6 @@ def _early_cleanup(self) -> None:
             self._console_socket.close()
             self._console_socket = None
 
-    def wait(self):
-        """
-        Wait for the VM to power off
-        """
-        self._early_cleanup()
-        self._popen.wait()
-        self._post_shutdown()
-
     def shutdown(self, has_quit: bool = False,
                  hard: bool = False,
                  timeout: Optional[int] = 3) -> None:
@@ -410,6 +402,15 @@ def shutdown(self, has_quit: bool = False,
     def kill(self):
         self.shutdown(hard=True)
 
+    def wait(self, timeout: Optional[int] = None) -> None:
+        """
+        Wait for the VM to power off and perform post-shutdown cleanup.
+
+        :param timeout: Optional timeout in seconds.
+                        Default None, an infinite wait.
+        """
+        self.shutdown(has_quit=True, timeout=timeout)
+
     def set_qmp_monitor(self, enabled=True):
         """
         Set the QMP monitor.
-- 
2.21.3

[PATCH v5 08/12] tests/acceptance: wait() instead of shutdown() where appropriate

[John Snow]

When issuing 'reboot' to a VM with the no-reboot option, that VM will
exit. When then issuing a shutdown command, the cleanup may race.

Add calls to vm.wait() which will gracefully mark the VM as having
exited. Subsequent vm.shutdown() calls in generic tearDown code will not
race when called after completion of the call.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 tests/acceptance/boot_linux_console.py   | 10 ++++++++++
 tests/acceptance/linux_ssh_mips_malta.py |  2 ++
 2 files changed, 12 insertions(+)

diff --git a/tests/acceptance/boot_linux_console.py b/tests/acceptance/boot_linux_console.py
index 3d02519660..5867ef760c 100644
--- a/tests/acceptance/boot_linux_console.py
+++ b/tests/acceptance/boot_linux_console.py
@@ -191,6 +191,8 @@ def test_mips_malta_cpio(self):
                                                 'Debian')
         exec_command_and_wait_for_pattern(self, 'reboot',
                                                 'reboot: Restarting system')
+        # Wait for VM to shut down gracefully
+        self.vm.wait()
 
     @skipUnless(os.getenv('AVOCADO_ALLOW_UNTRUSTED_CODE'), 'untrusted code')
     def test_mips64el_malta_5KEc_cpio(self):
@@ -231,6 +233,8 @@ def test_mips64el_malta_5KEc_cpio(self):
                                                 '3.19.3.mtoman.20150408')
         exec_command_and_wait_for_pattern(self, 'reboot',
                                                 'reboot: Restarting system')
+        # Wait for VM to shut down gracefully
+        self.vm.wait()
 
     def do_test_mips_malta32el_nanomips(self, kernel_url, kernel_hash):
         kernel_path_xz = self.fetch_asset(kernel_url, asset_hash=kernel_hash)
@@ -506,6 +510,7 @@ def test_arm_cubieboard_initrd(self):
                                                 'system-control@1c00000')
         exec_command_and_wait_for_pattern(self, 'reboot',
                                                 'reboot: Restarting system')
+        # NB: Do not issue vm.wait() here, cubieboard's reboot does not exit!
 
     def test_arm_cubieboard_sata(self):
         """
@@ -550,6 +555,7 @@ def test_arm_cubieboard_sata(self):
                                                 'sda')
         exec_command_and_wait_for_pattern(self, 'reboot',
                                                 'reboot: Restarting system')
+        # NB: Do not issue vm.wait() here, cubieboard's reboot does not exit!
 
     def test_arm_orangepi(self):
         """
@@ -615,6 +621,8 @@ def test_arm_orangepi_initrd(self):
                                                 'system-control@1c00000')
         exec_command_and_wait_for_pattern(self, 'reboot',
                                                 'reboot: Restarting system')
+        # Wait for VM to shut down gracefully
+        self.vm.wait()
 
     def test_arm_orangepi_sd(self):
         """
@@ -662,6 +670,8 @@ def test_arm_orangepi_sd(self):
             '3 packets transmitted, 3 packets received, 0% packet loss')
         exec_command_and_wait_for_pattern(self, 'reboot',
                                                 'reboot: Restarting system')
+        # Wait for VM to shut down gracefully
+        self.vm.wait()
 
     @skipUnless(os.getenv('AVOCADO_ALLOW_LARGE_STORAGE'), 'storage limited')
     @skipUnless(P7ZIP_AVAILABLE, '7z not installed')
diff --git a/tests/acceptance/linux_ssh_mips_malta.py b/tests/acceptance/linux_ssh_mips_malta.py
index 90d7f2f167..25c5c5f741 100644
--- a/tests/acceptance/linux_ssh_mips_malta.py
+++ b/tests/acceptance/linux_ssh_mips_malta.py
@@ -212,6 +212,8 @@ def check_mips_malta(self, uname_m, endianess):
 
         self.run_common_commands(wordsize)
         self.shutdown_via_ssh()
+        # Wait for VM to shut down gracefully
+        self.vm.wait()
 
     def test_mips_malta32eb_kernel3_2_0(self):
         """
-- 
2.21.3

[PATCH v5 09/12] tests/acceptance: Don't test reboot on cubieboard

[John Snow]

cubieboard does not have a functioning reboot, it halts and QEMU does
not exit.

vm.shutdown() is modified in a forthcoming patch that makes it less tolerant
of race conditions on shutdown; tests should consciously decide to WAIT
or to SHUTDOWN qemu.

So long as this test is attempting to reboot, the correct choice would
be to WAIT for the VM to exit. However, since that's broken, we should
SHUTDOWN instead.

SHUTDOWN is indeed what already happens when the test performs teardown,
however, if anyone fixes cubieboard reboot in the future, this test will
develop a new race condition that might be hard to debug.

Therefore: remove the reboot test and make it obvious that the VM is
still running when the test concludes, where the test teardown will do
the right thing.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 tests/acceptance/boot_linux_console.py | 8 ++------
 1 file changed, 2 insertions(+), 6 deletions(-)

diff --git a/tests/acceptance/boot_linux_console.py b/tests/acceptance/boot_linux_console.py
index 5867ef760c..8b8b828bc5 100644
--- a/tests/acceptance/boot_linux_console.py
+++ b/tests/acceptance/boot_linux_console.py
@@ -508,9 +508,7 @@ def test_arm_cubieboard_initrd(self):
                                                 'Allwinner sun4i/sun5i')
         exec_command_and_wait_for_pattern(self, 'cat /proc/iomem',
                                                 'system-control@1c00000')
-        exec_command_and_wait_for_pattern(self, 'reboot',
-                                                'reboot: Restarting system')
-        # NB: Do not issue vm.wait() here, cubieboard's reboot does not exit!
+        # cubieboard's reboot is not functioning; omit reboot test.
 
     def test_arm_cubieboard_sata(self):
         """
@@ -553,9 +551,7 @@ def test_arm_cubieboard_sata(self):
                                                 'Allwinner sun4i/sun5i')
         exec_command_and_wait_for_pattern(self, 'cat /proc/partitions',
                                                 'sda')
-        exec_command_and_wait_for_pattern(self, 'reboot',
-                                                'reboot: Restarting system')
-        # NB: Do not issue vm.wait() here, cubieboard's reboot does not exit!
+        # cubieboard's reboot is not functioning; omit reboot test.
 
     def test_arm_orangepi(self):
         """
-- 
2.21.3

[PATCH v5 10/12] python/machine.py: split shutdown into hard and soft flavors

[John Snow]

This is done primarily to avoid the 'bare except' pattern, which
suppresses all exceptions during shutdown and can obscure errors.

Replace this with a pattern that isolates the different kind of shutdown
paradigms (_hard_shutdown and _soft_shutdown), and a new fallback shutdown
handler (_do_shutdown) that gracefully attempts one before the other.

This split now also ensures that no matter what happens,
_post_shutdown() is always invoked.

shutdown() changes in behavior such that if it attempts to do a graceful
shutdown and is unable to, it will now always raise an exception to
indicate this. This can be avoided by the test writer in three ways:

1. If the VM is expected to have already exited or is in the process of
exiting, wait() can be used instead of shutdown() to clean up resources
instead. This helps avoid race conditions in shutdown.

2. If a test writer is expecting graceful shutdown to fail, shutdown
should be called in a try...except block.

3. If the test writer has no interest in performing a graceful shutdown
at all, kill() can be used instead.


Handling shutdown in this way makes it much more explicit which type of
shutdown we want and allows the library to report problems with this
process.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine.py | 95 +++++++++++++++++++++++++++++++++++-------
 1 file changed, 80 insertions(+), 15 deletions(-)

diff --git a/python/qemu/machine.py b/python/qemu/machine.py
index aaa173f046..b24ce8a268 100644
--- a/python/qemu/machine.py
+++ b/python/qemu/machine.py
@@ -48,6 +48,12 @@ class QEMUMachineAddDeviceError(QEMUMachineError):
     """
 
 
+class AbnormalShutdown(QEMUMachineError):
+    """
+    Exception raised when a graceful shutdown was requested, but not performed.
+    """
+
+
 class MonitorResponseError(qmp.QMPError):
     """
     Represents erroneous QMP monitor reply
@@ -365,6 +371,7 @@ def _early_cleanup(self) -> None:
         """
         Perform any cleanup that needs to happen before the VM exits.
 
+        May be invoked by both soft and hard shutdown in failover scenarios.
         Called additionally by _post_shutdown for comprehensive cleanup.
         """
         # If we keep the console socket open, we may deadlock waiting
@@ -374,32 +381,90 @@ def _early_cleanup(self) -> None:
             self._console_socket.close()
             self._console_socket = None
 
+    def _hard_shutdown(self) -> None:
+        """
+        Perform early cleanup, kill the VM, and wait for it to terminate.
+
+        :raise subprocess.Timeout: When timeout is exceeds 60 seconds
+            waiting for the QEMU process to terminate.
+        """
+        self._early_cleanup()
+        self._popen.kill()
+        self._popen.wait(timeout=60)
+
+    def _soft_shutdown(self, has_quit: bool = False,
+                       timeout: Optional[int] = 3) -> None:
+        """
+        Perform early cleanup, attempt to gracefully shut down the VM, and wait
+        for it to terminate.
+
+        :param has_quit: When True, don't attempt to issue 'quit' QMP command
+        :param timeout: Optional timeout in seconds for graceful shutdown.
+                        Default 3 seconds, A value of None is an infinite wait.
+
+        :raise ConnectionReset: On QMP communication errors
+        :raise subprocess.TimeoutExpired: When timeout is exceeded waiting for
+            the QEMU process to terminate.
+        """
+        self._early_cleanup()
+
+        if self._qmp is not None:
+            if not has_quit:
+                # Might raise ConnectionReset
+                self._qmp.cmd('quit')
+
+        # May raise subprocess.TimeoutExpired
+        self._popen.wait(timeout=timeout)
+
+    def _do_shutdown(self, has_quit: bool = False,
+                     timeout: Optional[int] = 3) -> None:
+        """
+        Attempt to shutdown the VM gracefully; fallback to a hard shutdown.
+
+        :param has_quit: When True, don't attempt to issue 'quit' QMP command
+        :param timeout: Optional timeout in seconds for graceful shutdown.
+                        Default 3 seconds, A value of None is an infinite wait.
+
+        :raise AbnormalShutdown: When the VM could not be shut down gracefully.
+            The inner exception will likely be ConnectionReset or
+            subprocess.TimeoutExpired. In rare cases, non-graceful termination
+            may result in its own exceptions, likely subprocess.TimeoutExpired.
+        """
+        try:
+            self._soft_shutdown(has_quit, timeout)
+        except Exception as exc:
+            self._hard_shutdown()
+            raise AbnormalShutdown("Could not perform graceful shutdown") \
+                from exc
+
     def shutdown(self, has_quit: bool = False,
                  hard: bool = False,
                  timeout: Optional[int] = 3) -> None:
         """
-        Terminate the VM and clean up
+        Terminate the VM (gracefully if possible) and perform cleanup.
+        Cleanup will always be performed.
+
+        :param has_quit: When true, do not attempt to issue 'quit' QMP command.
+        :param hard: When true, do not attempt graceful shutdown, and
+                     suppress the SIGKILL warning log message.
+        :param timeout: Optional timeout in seconds for graceful shutdown.
+                        Default 3 seconds, A value of None is an infinite wait.
         """
         if not self._launched:
             return
 
-        self._early_cleanup()
-
-        if self.is_running():
+        try:
             if hard:
-                self._popen.kill()
-            elif self._qmp:
-                try:
-                    if not has_quit:
-                        self._qmp.cmd('quit')
-                    self._popen.wait(timeout=timeout)
-                except:
-                    self._popen.kill()
-            self._popen.wait(timeout=timeout)
-
-        self._post_shutdown()
+                self._hard_shutdown()
+            else:
+                self._do_shutdown(has_quit, timeout=timeout)
+        finally:
+            self._post_shutdown()
 
     def kill(self):
+        """
+        Terminate the VM forcefully, wait for it to exit, and perform cleanup.
+        """
         self.shutdown(hard=True)
 
     def wait(self, timeout: Optional[int] = None) -> None:
-- 
2.21.3

[PATCH v5 11/12] python/machine.py: re-add sigkill warning suppression

[John Snow]

If the user kills QEMU on purpose, we don't need to warn them about that
having happened: they know already.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine.py | 7 ++++++-
 1 file changed, 6 insertions(+), 1 deletion(-)

diff --git a/python/qemu/machine.py b/python/qemu/machine.py
index b24ce8a268..02d66e3cff 100644
--- a/python/qemu/machine.py
+++ b/python/qemu/machine.py
@@ -22,6 +22,7 @@
 import os
 import subprocess
 import shutil
+import signal
 import socket
 import tempfile
 from typing import Optional, Type
@@ -128,6 +129,7 @@ def __init__(self, binary, args=None, wrapper=None, name=None,
         self._console_address = None
         self._console_socket = None
         self._remove_files = []
+        self._user_killed = False
 
     def __enter__(self):
         return self
@@ -316,7 +318,8 @@ def _post_shutdown(self):
             self._remove_if_exists(self._remove_files.pop())
 
         exitcode = self.exitcode()
-        if exitcode is not None and exitcode < 0:
+        if (exitcode is not None and exitcode < 0
+                and not (self._user_killed and exitcode == -signal.SIGKILL)):
             msg = 'qemu received signal %i; command: "%s"'
             if self._qemu_full_args:
                 command = ' '.join(self._qemu_full_args)
@@ -324,6 +327,7 @@ def _post_shutdown(self):
                 command = ''
             LOG.warning(msg, -int(exitcode), command)
 
+        self._user_killed = False
         self._launched = False
 
     def launch(self):
@@ -455,6 +459,7 @@ def shutdown(self, has_quit: bool = False,
 
         try:
             if hard:
+                self._user_killed = True
                 self._hard_shutdown()
             else:
                 self._do_shutdown(has_quit, timeout=timeout)
-- 
2.21.3

[PATCH v5 12/12] python/machine.py: change default wait timeout to 3 seconds

[John Snow]

Machine.wait() does not appear to be used except in the acceptance tests,
and an infinite timeout by default in a test suite is not the most helpful.

Change it to 3 seconds, like the default shutdown timeout.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine.py | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/python/qemu/machine.py b/python/qemu/machine.py
index 02d66e3cff..d08a8e4a6e 100644
--- a/python/qemu/machine.py
+++ b/python/qemu/machine.py
@@ -472,12 +472,12 @@ def kill(self):
         """
         self.shutdown(hard=True)
 
-    def wait(self, timeout: Optional[int] = None) -> None:
+    def wait(self, timeout: Optional[int] = 3) -> None:
         """
         Wait for the VM to power off and perform post-shutdown cleanup.
 
         :param timeout: Optional timeout in seconds.
-                        Default None, an infinite wait.
+                        Default 3 seconds, A value of None is an infinite wait.
         """
         self.shutdown(has_quit=True, timeout=timeout)
 
-- 
2.21.3

Re: [PATCH v5 02/12] python/machine.py: Close QMP socket in cleanup

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> It's not important to do this before waiting for the process to exit, so
> it can be done during generic post-shutdown cleanup.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 7 ++++---
>  1 file changed, 4 insertions(+), 3 deletions(-)
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 05/12] python/machine.py: Prohibit multiple shutdown() calls

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> If the VM is not launched, don't try to shut it down. As a change,
> _post_shutdown now unconditionally also calls _early_cleanup in order to
> offer comprehensive object cleanup in failure cases.
> 
> As a courtesy, treat it as a NOP instead of rejecting it as an
> error. This is slightly nicer for acceptance tests where vm.shutdown()
> is issued unconditionally in tearDown callbacks.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 14 +++++++++++++-
>  1 file changed, 13 insertions(+), 1 deletion(-)
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 06/12] python/machine.py: Add a configurable timeout to shutdown()

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> Three seconds is hardcoded. Use it as a default parameter instead, and use that
> value for both waits that may occur in the function.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 8 +++++---
>  1 file changed, 5 insertions(+), 3 deletions(-)
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 07/12] python/machine.py: Make wait() call shutdown()

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> At this point, shutdown(has_quit=True) and wait() do essentially the
> same thing; they perform cleanup without actually instructing QEMU to
> quit.
> 
> Define one in terms of the other.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 17 +++++++++--------
>  1 file changed, 9 insertions(+), 8 deletions(-)
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 11/12] python/machine.py: re-add sigkill warning suppression

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> If the user kills QEMU on purpose, we don't need to warn them about that
> having happened: they know already.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 7 ++++++-
>  1 file changed, 6 insertions(+), 1 deletion(-)
> 

Good idea :)

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 12/12] python/machine.py: change default wait timeout to 3 seconds

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> Machine.wait() does not appear to be used except in the acceptance tests,
> and an infinite timeout by default in a test suite is not the most helpful.
> 
> Change it to 3 seconds, like the default shutdown timeout.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
> index 02d66e3cff..d08a8e4a6e 100644
> --- a/python/qemu/machine.py
> +++ b/python/qemu/machine.py
> @@ -472,12 +472,12 @@ def kill(self):
>          """
>          self.shutdown(hard=True)
>  
> -    def wait(self, timeout: Optional[int] = None) -> None:
> +    def wait(self, timeout: Optional[int] = 3) -> None:
>          """
>          Wait for the VM to power off and perform post-shutdown cleanup.
>  
>          :param timeout: Optional timeout in seconds.
> -                        Default None, an infinite wait.
> +                        Default 3 seconds, A value of None is an infinite wait.
>          """
>          self.shutdown(has_quit=True, timeout=timeout)
>  
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 10/12] python/machine.py: split shutdown into hard and soft flavors

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> This is done primarily to avoid the 'bare except' pattern, which
> suppresses all exceptions during shutdown and can obscure errors.
> 
> Replace this with a pattern that isolates the different kind of shutdown
> paradigms (_hard_shutdown and _soft_shutdown), and a new fallback shutdown
> handler (_do_shutdown) that gracefully attempts one before the other.
> 
> This split now also ensures that no matter what happens,
> _post_shutdown() is always invoked.
> 
> shutdown() changes in behavior such that if it attempts to do a graceful
> shutdown and is unable to, it will now always raise an exception to
> indicate this. This can be avoided by the test writer in three ways:
> 
> 1. If the VM is expected to have already exited or is in the process of
> exiting, wait() can be used instead of shutdown() to clean up resources
> instead. This helps avoid race conditions in shutdown.
> 
> 2. If a test writer is expecting graceful shutdown to fail, shutdown
> should be called in a try...except block.
> 
> 3. If the test writer has no interest in performing a graceful shutdown
> at all, kill() can be used instead.
> 
> 
> Handling shutdown in this way makes it much more explicit which type of
> shutdown we want and allows the library to report problems with this
> process.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 95 +++++++++++++++++++++++++++++++++++-------
>  1 file changed, 80 insertions(+), 15 deletions(-)
> 

:))

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 09/12] tests/acceptance: Don't test reboot on cubieboard

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> cubieboard does not have a functioning reboot, it halts and QEMU does
> not exit.
> 
> vm.shutdown() is modified in a forthcoming patch that makes it less tolerant
> of race conditions on shutdown; tests should consciously decide to WAIT
> or to SHUTDOWN qemu.
> 
> So long as this test is attempting to reboot, the correct choice would
> be to WAIT for the VM to exit. However, since that's broken, we should
> SHUTDOWN instead.
> 
> SHUTDOWN is indeed what already happens when the test performs teardown,
> however, if anyone fixes cubieboard reboot in the future, this test will
> develop a new race condition that might be hard to debug.
> 
> Therefore: remove the reboot test and make it obvious that the VM is
> still running when the test concludes, where the test teardown will do
> the right thing.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  tests/acceptance/boot_linux_console.py | 8 ++------
>  1 file changed, 2 insertions(+), 6 deletions(-)
> 
> diff --git a/tests/acceptance/boot_linux_console.py b/tests/acceptance/boot_linux_console.py
> index 5867ef760c..8b8b828bc5 100644
> --- a/tests/acceptance/boot_linux_console.py
> +++ b/tests/acceptance/boot_linux_console.py
> @@ -508,9 +508,7 @@ def test_arm_cubieboard_initrd(self):
>                                                  'Allwinner sun4i/sun5i')
>          exec_command_and_wait_for_pattern(self, 'cat /proc/iomem',
>                                                  'system-control@1c00000')
> -        exec_command_and_wait_for_pattern(self, 'reboot',
> -                                                'reboot: Restarting system')
> -        # NB: Do not issue vm.wait() here, cubieboard's reboot does not exit!
> +        # cubieboard's reboot is not functioning; omit reboot test.
>  
>      def test_arm_cubieboard_sata(self):
>          """
> @@ -553,9 +551,7 @@ def test_arm_cubieboard_sata(self):
>                                                  'Allwinner sun4i/sun5i')
>          exec_command_and_wait_for_pattern(self, 'cat /proc/partitions',
>                                                  'sda')
> -        exec_command_and_wait_for_pattern(self, 'reboot',
> -                                                'reboot: Restarting system')
> -        # NB: Do not issue vm.wait() here, cubieboard's reboot does not exit!
> +        # cubieboard's reboot is not functioning; omit reboot test.
>  
>      def test_arm_orangepi(self):
>          """
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Note, if I do the pull request, I might reorder this one before the
previous one "tests/acceptance: wait() instead of shutdown() where
appropriate".

Re: [PATCH v5 08/12] tests/acceptance: wait() instead of shutdown() where appropriate

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> When issuing 'reboot' to a VM with the no-reboot option, that VM will
> exit. When then issuing a shutdown command, the cleanup may race.
> 
> Add calls to vm.wait() which will gracefully mark the VM as having
> exited. Subsequent vm.shutdown() calls in generic tearDown code will not
> race when called after completion of the call.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  tests/acceptance/boot_linux_console.py   | 10 ++++++++++
>  tests/acceptance/linux_ssh_mips_malta.py |  2 ++
>  2 files changed, 12 insertions(+)
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 01/12] python/machine.py: consolidate _post_shutdown()

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 1906 bytes --]

On Fri, Jul 10, 2020 at 01:06:38AM -0400, John Snow wrote:
> Move more cleanup actions into _post_shutdown. As a change, if QEMU
> should so happen to be terminated during a call to wait(), that event
> will now be logged.
> 
> This is not likely to occur during normative use.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 27 +++++++++++++--------------
>  1 file changed, 13 insertions(+), 14 deletions(-)
> 
> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
> index 041c615052..f7e68191c2 100644
> --- a/python/qemu/machine.py
> +++ b/python/qemu/machine.py
> @@ -283,6 +283,8 @@ def _post_launch(self):
>              self._qmp.accept()
>  
>      def _post_shutdown(self):
> +        self._load_io_log()
> +
>          if self._qemu_log_file is not None:
>              self._qemu_log_file.close()
>              self._qemu_log_file = None
> @@ -296,6 +298,17 @@ def _post_shutdown(self):
>          while len(self._remove_files) > 0:
>              self._remove_if_exists(self._remove_files.pop())
>  
> +        exitcode = self.exitcode()
> +        if exitcode is not None and exitcode < 0:
> +            msg = 'qemu received signal %i; command: "%s"'
> +            if self._qemu_full_args:
> +                command = ' '.join(self._qemu_full_args)
> +            else:
> +                command = ''
> +            LOG.warning(msg, -int(exitcode), command)
> +
> +        self._launched = False
> +
>      def launch(self):
>          """
>          Launch the VM and make sure we cleanup and expose the
> @@ -344,7 +357,6 @@ def wait(self):
>          self._popen.wait()
>          if self._qmp:
>              self._qmp.close()
> -        self._load_io_log()

Nice consolidation of responsibilities!

Reviewed-by: Cleber Rosa <crosa@redhat.com>
Tested-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 09/12] tests/acceptance: Don't test reboot on cubieboard

[John Snow]

On 7/13/20 5:56 AM, Philippe Mathieu-Daudé wrote:
> On 7/10/20 7:06 AM, John Snow wrote:
>> cubieboard does not have a functioning reboot, it halts and QEMU does
>> not exit.
>>
>> vm.shutdown() is modified in a forthcoming patch that makes it less tolerant
>> of race conditions on shutdown; tests should consciously decide to WAIT
>> or to SHUTDOWN qemu.
>>
>> So long as this test is attempting to reboot, the correct choice would
>> be to WAIT for the VM to exit. However, since that's broken, we should
>> SHUTDOWN instead.
>>
>> SHUTDOWN is indeed what already happens when the test performs teardown,
>> however, if anyone fixes cubieboard reboot in the future, this test will
>> develop a new race condition that might be hard to debug.
>>
>> Therefore: remove the reboot test and make it obvious that the VM is
>> still running when the test concludes, where the test teardown will do
>> the right thing.
>>
>> Signed-off-by: John Snow <jsnow@redhat.com>
>> ---
>>  tests/acceptance/boot_linux_console.py | 8 ++------
>>  1 file changed, 2 insertions(+), 6 deletions(-)
>>
>> diff --git a/tests/acceptance/boot_linux_console.py b/tests/acceptance/boot_linux_console.py
>> index 5867ef760c..8b8b828bc5 100644
>> --- a/tests/acceptance/boot_linux_console.py
>> +++ b/tests/acceptance/boot_linux_console.py
>> @@ -508,9 +508,7 @@ def test_arm_cubieboard_initrd(self):
>>                                                  'Allwinner sun4i/sun5i')
>>          exec_command_and_wait_for_pattern(self, 'cat /proc/iomem',
>>                                                  'system-control@1c00000')
>> -        exec_command_and_wait_for_pattern(self, 'reboot',
>> -                                                'reboot: Restarting system')
>> -        # NB: Do not issue vm.wait() here, cubieboard's reboot does not exit!
>> +        # cubieboard's reboot is not functioning; omit reboot test.
>>  
>>      def test_arm_cubieboard_sata(self):
>>          """
>> @@ -553,9 +551,7 @@ def test_arm_cubieboard_sata(self):
>>                                                  'Allwinner sun4i/sun5i')
>>          exec_command_and_wait_for_pattern(self, 'cat /proc/partitions',
>>                                                  'sda')
>> -        exec_command_and_wait_for_pattern(self, 'reboot',
>> -                                                'reboot: Restarting system')
>> -        # NB: Do not issue vm.wait() here, cubieboard's reboot does not exit!
>> +        # cubieboard's reboot is not functioning; omit reboot test.
>>  
>>      def test_arm_orangepi(self):
>>          """
>>
> 
> Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
> 
> Note, if I do the pull request, I might reorder this one before the
> previous one "tests/acceptance: wait() instead of shutdown() where
> appropriate".
> 

you could -- in practice it didn't seem to matter. I tested both with
and without this patch.

I was just trying to isolate each intentional semantic change as its own
commit so it could be observed/understood/debated.

--js

Re: [PATCH v5 09/12] tests/acceptance: Don't test reboot on cubieboard

[Philippe Mathieu-Daudé]

On 7/13/20 5:12 PM, John Snow wrote:
> 
> 
> On 7/13/20 5:56 AM, Philippe Mathieu-Daudé wrote:
>> On 7/10/20 7:06 AM, John Snow wrote:
>>> cubieboard does not have a functioning reboot, it halts and QEMU does
>>> not exit.
>>>
>>> vm.shutdown() is modified in a forthcoming patch that makes it less tolerant
>>> of race conditions on shutdown; tests should consciously decide to WAIT
>>> or to SHUTDOWN qemu.
>>>
>>> So long as this test is attempting to reboot, the correct choice would
>>> be to WAIT for the VM to exit. However, since that's broken, we should
>>> SHUTDOWN instead.
>>>
>>> SHUTDOWN is indeed what already happens when the test performs teardown,
>>> however, if anyone fixes cubieboard reboot in the future, this test will
>>> develop a new race condition that might be hard to debug.
>>>
>>> Therefore: remove the reboot test and make it obvious that the VM is
>>> still running when the test concludes, where the test teardown will do
>>> the right thing.
>>>
>>> Signed-off-by: John Snow <jsnow@redhat.com>
>>> ---
>>>  tests/acceptance/boot_linux_console.py | 8 ++------
>>>  1 file changed, 2 insertions(+), 6 deletions(-)
>>>
>>> diff --git a/tests/acceptance/boot_linux_console.py b/tests/acceptance/boot_linux_console.py
>>> index 5867ef760c..8b8b828bc5 100644
>>> --- a/tests/acceptance/boot_linux_console.py
>>> +++ b/tests/acceptance/boot_linux_console.py
>>> @@ -508,9 +508,7 @@ def test_arm_cubieboard_initrd(self):
>>>                                                  'Allwinner sun4i/sun5i')
>>>          exec_command_and_wait_for_pattern(self, 'cat /proc/iomem',
>>>                                                  'system-control@1c00000')
>>> -        exec_command_and_wait_for_pattern(self, 'reboot',
>>> -                                                'reboot: Restarting system')
>>> -        # NB: Do not issue vm.wait() here, cubieboard's reboot does not exit!
>>> +        # cubieboard's reboot is not functioning; omit reboot test.
>>>  
>>>      def test_arm_cubieboard_sata(self):
>>>          """
>>> @@ -553,9 +551,7 @@ def test_arm_cubieboard_sata(self):
>>>                                                  'Allwinner sun4i/sun5i')
>>>          exec_command_and_wait_for_pattern(self, 'cat /proc/partitions',
>>>                                                  'sda')
>>> -        exec_command_and_wait_for_pattern(self, 'reboot',
>>> -                                                'reboot: Restarting system')
>>> -        # NB: Do not issue vm.wait() here, cubieboard's reboot does not exit!
>>> +        # cubieboard's reboot is not functioning; omit reboot test.
>>>  
>>>      def test_arm_orangepi(self):
>>>          """
>>>
>>
>> Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
>>
>> Note, if I do the pull request, I might reorder this one before the
>> previous one "tests/acceptance: wait() instead of shutdown() where
>> appropriate".
>>
> 
> you could -- in practice it didn't seem to matter. I tested both with
> and without this patch.
> 
> I was just trying to isolate each intentional semantic change as its own
> commit so it could be observed/understood/debated.

As both patches are correct, there is no need to debate IMO :)
I'm fine either way. The simpler the easier, and here the simpler
is to take your series as it.

Re: [PATCH v5 02/12] python/machine.py: Close QMP socket in cleanup

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 1562 bytes --]

On Fri, Jul 10, 2020 at 01:06:39AM -0400, John Snow wrote:
> It's not important to do this before waiting for the process to exit, so
> it can be done during generic post-shutdown cleanup.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 7 ++++---
>  1 file changed, 4 insertions(+), 3 deletions(-)
> 
> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
> index f7e68191c2..938c891b1d 100644
> --- a/python/qemu/machine.py
> +++ b/python/qemu/machine.py
> @@ -283,6 +283,10 @@ def _post_launch(self):
>              self._qmp.accept()
>  
>      def _post_shutdown(self):
> +        if self._qmp:
> +            self._qmp.close()
> +            self._qmp = None
> +
>          self._load_io_log()
>  
>          if self._qemu_log_file is not None:
> @@ -355,8 +359,6 @@ def wait(self):
>          Wait for the VM to power off
>          """
>          self._popen.wait()
> -        if self._qmp:
> -            self._qmp.close()
>          self._post_shutdown()
>  
>      def shutdown(self, has_quit=False, hard=False):
> @@ -377,7 +379,6 @@ def shutdown(self, has_quit=False, hard=False):
>                  try:
>                      if not has_quit:
>                          self._qmp.cmd('quit')
> -                    self._qmp.close()
>                      self._popen.wait(timeout=3)
>                  except:
>                      self._popen.kill()
> -- 
> 2.21.3
> 

Reviewed-by: Cleber Rosa <crosa@redhat.com>
Tested-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 03/12] python/machine.py: Add _early_cleanup hook

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> Some parts of cleanup need to occur prior to shutdown, otherwise
> shutdown might break. Move this into a suitably named method/callback.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 24 +++++++++++++++---------
>  1 file changed, 15 insertions(+), 9 deletions(-)

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 01/12] python/machine.py: consolidate _post_shutdown()

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> Move more cleanup actions into _post_shutdown. As a change, if QEMU
> should so happen to be terminated during a call to wait(), that event
> will now be logged.
> 
> This is not likely to occur during normative use.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 27 +++++++++++++--------------
>  1 file changed, 13 insertions(+), 14 deletions(-)

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 04/12] python/machine.py: Perform early cleanup for wait() calls, too

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> This is primarily for consistency, and is a step towards wait() and
> shutdown() sharing the same implementation so that the two cleanup paths
> cannot diverge.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 1 +
>  1 file changed, 1 insertion(+)
> 
> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
> index 4280aab380..cac466fbe6 100644
> --- a/python/qemu/machine.py
> +++ b/python/qemu/machine.py
> @@ -369,6 +369,7 @@ def wait(self):
>          """
>          Wait for the VM to power off
>          """
> +        self._early_cleanup()
>          self._popen.wait()
>          self._post_shutdown()
>  
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v5 03/12] python/machine.py: Add _early_cleanup hook

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 1108 bytes --]

On Fri, Jul 10, 2020 at 01:06:40AM -0400, John Snow wrote:
> Some parts of cleanup need to occur prior to shutdown, otherwise
> shutdown might break. Move this into a suitably named method/callback.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 24 +++++++++++++++---------
>  1 file changed, 15 insertions(+), 9 deletions(-)
> 
> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
> index 938c891b1d..4280aab380 100644
> --- a/python/qemu/machine.py
> +++ b/python/qemu/machine.py
> @@ -354,16 +354,9 @@ def _launch(self):
>                                         close_fds=False)
>          self._post_launch()
>  
> -    def wait(self):
> +    def _early_cleanup(self) -> None:

Inaugurating type hints "around here", huh? :)

WRT method name, up to the end of this series, this method is only about
closing the console socket, so *maybe* just name it accordingly and move
on to an abstract method name when/if the need arises?

Either way,

Reviewed-by: Cleber Rosa <crosa@redhat.com>
Tested-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 04/12] python/machine.py: Perform early cleanup for wait() calls, too

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 445 bytes --]

On Fri, Jul 10, 2020 at 01:06:41AM -0400, John Snow wrote:
> This is primarily for consistency, and is a step towards wait() and
> shutdown() sharing the same implementation so that the two cleanup paths
> cannot diverge.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 1 +
>  1 file changed, 1 insertion(+)
>

Reviewed-by: Cleber Rosa <crosa@redhat.com>
Tested-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 05/12] python/machine.py: Prohibit multiple shutdown() calls

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 3263 bytes --]

On Fri, Jul 10, 2020 at 01:06:42AM -0400, John Snow wrote:
> If the VM is not launched, don't try to shut it down. As a change,
> _post_shutdown now unconditionally also calls _early_cleanup in order to
> offer comprehensive object cleanup in failure cases.
> 
> As a courtesy, treat it as a NOP instead of rejecting it as an
> error. This is slightly nicer for acceptance tests where vm.shutdown()
> is issued unconditionally in tearDown callbacks.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 14 +++++++++++++-
>  1 file changed, 13 insertions(+), 1 deletion(-)
> 
> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
> index cac466fbe6..e66a7d66dd 100644
> --- a/python/qemu/machine.py
> +++ b/python/qemu/machine.py
> @@ -283,6 +283,13 @@ def _post_launch(self):
>              self._qmp.accept()
>  
>      def _post_shutdown(self):
> +        """
> +        Called to cleanup the VM instance after the process has exited.
> +        May also be called after a failed launch.
> +        """
> +        # Comprehensive reset for the failed launch case:
> +        self._early_cleanup()
> +

I'm not following why this is needed here.  AFAICT, the closing of the
console socket file was introduced when the QEMU process was alive,
and doing I/O on the serial device attached to the console file (and
was only necessary because of that).  In those scenarios, a race
between the time of sending the QMP command to quit, and getting a
response from QMP could occur.

But here, IIUC, there's no expectations for the QEMU process to be alive.
To the best of my understanding and testing, this line did not contribute
to the robustness of the shutdown behavior.

Finally, given that currently, only the closing of the console socket
is done within _early_cleanup(), and that is conditional, this also does
no harm AFAICT.  If more early cleanups operations were needed, then I
would feel less bothered about calling it here.

>          if self._qmp:
>              self._qmp.close()
>              self._qmp = None
> @@ -328,7 +335,7 @@ def launch(self):
>              self._launch()
>              self._launched = True
>          except:
> -            self.shutdown()
> +            self._post_shutdown()
>  
>              LOG.debug('Error launching VM')
>              if self._qemu_full_args:
> @@ -357,6 +364,8 @@ def _launch(self):
>      def _early_cleanup(self) -> None:
>          """
>          Perform any cleanup that needs to happen before the VM exits.
> +
> +        Called additionally by _post_shutdown for comprehensive cleanup.
>          """
>          # If we keep the console socket open, we may deadlock waiting
>          # for QEMU to exit, while QEMU is waiting for the socket to
> @@ -377,6 +386,9 @@ def shutdown(self, has_quit=False, hard=False):
>          """
>          Terminate the VM and clean up
>          """
> +        if not self._launched:
> +            return
> +

Because of the additional logic, it'd be a good opportunity to make
the docstring more accurate.  This method may now *not* do *any* of if
termination and cleaning (while previously it would attempt those
anyhow).

- Cleber.

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 06/12] python/machine.py: Add a configurable timeout to shutdown()

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 396 bytes --]

On Fri, Jul 10, 2020 at 01:06:43AM -0400, John Snow wrote:
> Three seconds is hardcoded. Use it as a default parameter instead, and use that
> value for both waits that may occur in the function.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 8 +++++---
>  1 file changed, 5 insertions(+), 3 deletions(-)

Reviewed-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 07/12] python/machine.py: Make wait() call shutdown()

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 508 bytes --]

On Fri, Jul 10, 2020 at 01:06:44AM -0400, John Snow wrote:
> At this point, shutdown(has_quit=True) and wait() do essentially the
> same thing; they perform cleanup without actually instructing QEMU to
> quit.
>
> Define one in terms of the other.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 17 +++++++++--------
>  1 file changed, 9 insertions(+), 8 deletions(-)
> 

Reviewed-by: Cleber Rosa <crosa@redhat.com>
Tested-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 08/12] tests/acceptance: wait() instead of shutdown() where appropriate

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 706 bytes --]

On Fri, Jul 10, 2020 at 01:06:45AM -0400, John Snow wrote:
> When issuing 'reboot' to a VM with the no-reboot option, that VM will
> exit. When then issuing a shutdown command, the cleanup may race.
> 
> Add calls to vm.wait() which will gracefully mark the VM as having
> exited. Subsequent vm.shutdown() calls in generic tearDown code will not
> race when called after completion of the call.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  tests/acceptance/boot_linux_console.py   | 10 ++++++++++
>  tests/acceptance/linux_ssh_mips_malta.py |  2 ++
>  2 files changed, 12 insertions(+)
> 

Reviewed-by: Cleber Rosa <crosa@redhat.com>
Tested-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 09/12] tests/acceptance: Don't test reboot on cubieboard

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 1149 bytes --]

On Fri, Jul 10, 2020 at 01:06:46AM -0400, John Snow wrote:
> cubieboard does not have a functioning reboot, it halts and QEMU does
> not exit.
> 
> vm.shutdown() is modified in a forthcoming patch that makes it less tolerant
> of race conditions on shutdown; tests should consciously decide to WAIT
> or to SHUTDOWN qemu.
> 
> So long as this test is attempting to reboot, the correct choice would
> be to WAIT for the VM to exit. However, since that's broken, we should
> SHUTDOWN instead.
> 
> SHUTDOWN is indeed what already happens when the test performs teardown,
> however, if anyone fixes cubieboard reboot in the future, this test will
> develop a new race condition that might be hard to debug.
> 
> Therefore: remove the reboot test and make it obvious that the VM is
> still running when the test concludes, where the test teardown will do
> the right thing.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  tests/acceptance/boot_linux_console.py | 8 ++------
>  1 file changed, 2 insertions(+), 6 deletions(-)
> 

Reviewed-by: Cleber Rosa <crosa@redhat.com>
Tested-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 10/12] python/machine.py: split shutdown into hard and soft flavors

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 3712 bytes --]

On Fri, Jul 10, 2020 at 01:06:47AM -0400, John Snow wrote:
> This is done primarily to avoid the 'bare except' pattern, which
> suppresses all exceptions during shutdown and can obscure errors.
> 
> Replace this with a pattern that isolates the different kind of shutdown
> paradigms (_hard_shutdown and _soft_shutdown), and a new fallback shutdown
> handler (_do_shutdown) that gracefully attempts one before the other.
> 
> This split now also ensures that no matter what happens,
> _post_shutdown() is always invoked.
> 
> shutdown() changes in behavior such that if it attempts to do a graceful
> shutdown and is unable to, it will now always raise an exception to
> indicate this. This can be avoided by the test writer in three ways:
> 
> 1. If the VM is expected to have already exited or is in the process of
> exiting, wait() can be used instead of shutdown() to clean up resources
> instead. This helps avoid race conditions in shutdown.
> 
> 2. If a test writer is expecting graceful shutdown to fail, shutdown
> should be called in a try...except block.
> 
> 3. If the test writer has no interest in performing a graceful shutdown
> at all, kill() can be used instead.
> 
> 
> Handling shutdown in this way makes it much more explicit which type of
> shutdown we want and allows the library to report problems with this
> process.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 95 +++++++++++++++++++++++++++++++++++-------
>  1 file changed, 80 insertions(+), 15 deletions(-)
> 
> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
> index aaa173f046..b24ce8a268 100644
> --- a/python/qemu/machine.py
> +++ b/python/qemu/machine.py
> @@ -48,6 +48,12 @@ class QEMUMachineAddDeviceError(QEMUMachineError):
>      """
>  
>  
> +class AbnormalShutdown(QEMUMachineError):
> +    """
> +    Exception raised when a graceful shutdown was requested, but not performed.
> +    """
> +
> +
>  class MonitorResponseError(qmp.QMPError):
>      """
>      Represents erroneous QMP monitor reply
> @@ -365,6 +371,7 @@ def _early_cleanup(self) -> None:
>          """
>          Perform any cleanup that needs to happen before the VM exits.
>  
> +        May be invoked by both soft and hard shutdown in failover scenarios.
>          Called additionally by _post_shutdown for comprehensive cleanup.
>          """
>          # If we keep the console socket open, we may deadlock waiting
> @@ -374,32 +381,90 @@ def _early_cleanup(self) -> None:
>              self._console_socket.close()
>              self._console_socket = None
>  
> +    def _hard_shutdown(self) -> None:
> +        """
> +        Perform early cleanup, kill the VM, and wait for it to terminate.
> +
> +        :raise subprocess.Timeout: When timeout is exceeds 60 seconds
> +            waiting for the QEMU process to terminate.
> +        """
> +        self._early_cleanup()

Like I commented on patch 5, I don't think the *current* type of
cleanup done is needed on a scenario like this...

> +        self._popen.kill()

... as I don't remember QEMU's SIGKILL handler to be susceptible to
the race condition that motivated the closing of the console file in
the first place.  But, I also can not prove it's not susceptible at
this time.

Note: I have some old patches that added tests for QEMUMachine itself.
I intend to respin them on top of your work, so we may have a clearer
understanding of the QEMU behaviors we need to handle.  So, feel free
to take the prudent route here, and keep the early cleanup.

Reviewed-by: Cleber Rosa <crosa@redhat.com>
Tested-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 11/12] python/machine.py: re-add sigkill warning suppression

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 374 bytes --]

On Fri, Jul 10, 2020 at 01:06:48AM -0400, John Snow wrote:
> If the user kills QEMU on purpose, we don't need to warn them about that
> having happened: they know already.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 7 ++++++-
>  1 file changed, 6 insertions(+), 1 deletion(-)
> 

Reviewed-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 12/12] python/machine.py: change default wait timeout to 3 seconds

[Cleber Rosa]

[-- Attachment #1: Type: text/plain, Size: 627 bytes --]

On Fri, Jul 10, 2020 at 01:06:49AM -0400, John Snow wrote:
> Machine.wait() does not appear to be used except in the acceptance tests,
> and an infinite timeout by default in a test suite is not the most helpful.
> 
> Change it to 3 seconds, like the default shutdown timeout.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine.py | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 

Well, for the acceptance tests, there's usually a test wide timeout,
but this is indeed a good idea!

Reviewed-by: Cleber Rosa <crosa@redhat.com>
Tested-by: Cleber Rosa <crosa@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [PATCH v5 05/12] python/machine.py: Prohibit multiple shutdown() calls

[John Snow]

On 7/13/20 10:48 PM, Cleber Rosa wrote:
> On Fri, Jul 10, 2020 at 01:06:42AM -0400, John Snow wrote:
>> If the VM is not launched, don't try to shut it down. As a change,
>> _post_shutdown now unconditionally also calls _early_cleanup in order to
>> offer comprehensive object cleanup in failure cases.
>>
>> As a courtesy, treat it as a NOP instead of rejecting it as an
>> error. This is slightly nicer for acceptance tests where vm.shutdown()
>> is issued unconditionally in tearDown callbacks.
>>
>> Signed-off-by: John Snow <jsnow@redhat.com>
>> ---
>>  python/qemu/machine.py | 14 +++++++++++++-
>>  1 file changed, 13 insertions(+), 1 deletion(-)
>>
>> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
>> index cac466fbe6..e66a7d66dd 100644
>> --- a/python/qemu/machine.py
>> +++ b/python/qemu/machine.py
>> @@ -283,6 +283,13 @@ def _post_launch(self):
>>              self._qmp.accept()
>>  
>>      def _post_shutdown(self):
>> +        """
>> +        Called to cleanup the VM instance after the process has exited.
>> +        May also be called after a failed launch.
>> +        """
>> +        # Comprehensive reset for the failed launch case:
>> +        self._early_cleanup()
>> +
> 
> I'm not following why this is needed here.  AFAICT, the closing of the
> console socket file was introduced when the QEMU process was alive,
> and doing I/O on the serial device attached to the console file (and
> was only necessary because of that).  In those scenarios, a race
> between the time of sending the QMP command to quit, and getting a
> response from QMP could occur.
> 
> But here, IIUC, there's no expectations for the QEMU process to be alive.
> To the best of my understanding and testing, this line did not contribute
> to the robustness of the shutdown behavior.
> 
> Finally, given that currently, only the closing of the console socket
> is done within _early_cleanup(), and that is conditional, this also does
> no harm AFAICT.  If more early cleanups operations were needed, then I
> would feel less bothered about calling it here.
> 

Sure, I can tie it up to be a little less abstract, but I'll go over
some of my reasons below to see if any of them resonate for you.

What I wanted was three things:

(1) A single call that comprehensively cleaned up the VM object back to
a known state, no matter what state it was in.

This is the answer to your first paragraph: I wanted a function to
always thoroughly reset an object back to base state. In the current
code, we won't have a console socket object here yet.

I felt this was good as it illustrates to other contributors what the
comprehensive steps to reset the object are.

(It might be considered bad in that it does perform potentially
unnecessary cleanup at times; but as a matter of taste I prefer this to
conditional inconsistency.)


(2) A guarantee that no matter how a VM object was terminated (either
via context handler, shutdown(), or wait()) that the exact same cleanup
steps would be performed for consistency

This is why wait() now points to shutdown(), and why _post_shutdown is
called outside of either of the shutdown handlers. No matter what,
_post_shutdown is getting called and it is going to clean everything.


(3) Avoiding special-casing certain cleanup actions open-coded in the
shutdown handlers.

It's #3 that wound up with me creating the "_early_cleanup" hook. I
created it because I had the idea to create "Console" and "QMP Socket"
as inheritable mixins to help keep the core class simpler.

In these cases, the mixins need a hook for "early cleanup."

No, I didn't finish that work and it's not ready. We could remove it for
now, but that's why this is here and why it's named like it is.

Long term, I think Machine Mixins are the only viable way to add more
features. The upstream version of the code now has more than 10
arguments and 20+ fields. It's getting unwieldy.


(....all that said, we can still do it later. If you prefer, for now, I
can at least rename the function "_close_socket" to make it less abstract.

(I think it should still be called in _post_shutdown, though.))

>>          if self._qmp:
>>              self._qmp.close()
>>              self._qmp = None
>> @@ -328,7 +335,7 @@ def launch(self):
>>              self._launch()
>>              self._launched = True
>>          except:
>> -            self.shutdown()
>> +            self._post_shutdown()
>>  
>>              LOG.debug('Error launching VM')
>>              if self._qemu_full_args:
>> @@ -357,6 +364,8 @@ def _launch(self):
>>      def _early_cleanup(self) -> None:
>>          """
>>          Perform any cleanup that needs to happen before the VM exits.
>> +
>> +        Called additionally by _post_shutdown for comprehensive cleanup.
>>          """
>>          # If we keep the console socket open, we may deadlock waiting
>>          # for QEMU to exit, while QEMU is waiting for the socket to
>> @@ -377,6 +386,9 @@ def shutdown(self, has_quit=False, hard=False):
>>          """
>>          Terminate the VM and clean up
>>          """
>> +        if not self._launched:
>> +            return
>> +
> 
> Because of the additional logic, it'd be a good opportunity to make
> the docstring more accurate.  This method may now *not* do *any* of if
> termination and cleaning (while previously it would attempt those
> anyhow).
> 

Kinda-sorta. The old version used to have "if self.running", which could
race.

I'll amend the docstring(s) as needed to make it clear that it's a NOP
if the machine has been cleaned up already.

> - Cleber.
> 

Re: [PATCH v5 10/12] python/machine.py: split shutdown into hard and soft flavors

[John Snow]

On 7/14/20 12:13 AM, Cleber Rosa wrote:
> On Fri, Jul 10, 2020 at 01:06:47AM -0400, John Snow wrote:
>> This is done primarily to avoid the 'bare except' pattern, which
>> suppresses all exceptions during shutdown and can obscure errors.
>>
>> Replace this with a pattern that isolates the different kind of shutdown
>> paradigms (_hard_shutdown and _soft_shutdown), and a new fallback shutdown
>> handler (_do_shutdown) that gracefully attempts one before the other.
>>
>> This split now also ensures that no matter what happens,
>> _post_shutdown() is always invoked.
>>
>> shutdown() changes in behavior such that if it attempts to do a graceful
>> shutdown and is unable to, it will now always raise an exception to
>> indicate this. This can be avoided by the test writer in three ways:
>>
>> 1. If the VM is expected to have already exited or is in the process of
>> exiting, wait() can be used instead of shutdown() to clean up resources
>> instead. This helps avoid race conditions in shutdown.
>>
>> 2. If a test writer is expecting graceful shutdown to fail, shutdown
>> should be called in a try...except block.
>>
>> 3. If the test writer has no interest in performing a graceful shutdown
>> at all, kill() can be used instead.
>>
>>
>> Handling shutdown in this way makes it much more explicit which type of
>> shutdown we want and allows the library to report problems with this
>> process.
>>
>> Signed-off-by: John Snow <jsnow@redhat.com>
>> ---
>>  python/qemu/machine.py | 95 +++++++++++++++++++++++++++++++++++-------
>>  1 file changed, 80 insertions(+), 15 deletions(-)
>>
>> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
>> index aaa173f046..b24ce8a268 100644
>> --- a/python/qemu/machine.py
>> +++ b/python/qemu/machine.py
>> @@ -48,6 +48,12 @@ class QEMUMachineAddDeviceError(QEMUMachineError):
>>      """
>>  
>>  
>> +class AbnormalShutdown(QEMUMachineError):
>> +    """
>> +    Exception raised when a graceful shutdown was requested, but not performed.
>> +    """
>> +
>> +
>>  class MonitorResponseError(qmp.QMPError):
>>      """
>>      Represents erroneous QMP monitor reply
>> @@ -365,6 +371,7 @@ def _early_cleanup(self) -> None:
>>          """
>>          Perform any cleanup that needs to happen before the VM exits.
>>  
>> +        May be invoked by both soft and hard shutdown in failover scenarios.
>>          Called additionally by _post_shutdown for comprehensive cleanup.
>>          """
>>          # If we keep the console socket open, we may deadlock waiting
>> @@ -374,32 +381,90 @@ def _early_cleanup(self) -> None:
>>              self._console_socket.close()
>>              self._console_socket = None
>>  
>> +    def _hard_shutdown(self) -> None:
>> +        """
>> +        Perform early cleanup, kill the VM, and wait for it to terminate.
>> +
>> +        :raise subprocess.Timeout: When timeout is exceeds 60 seconds
>> +            waiting for the QEMU process to terminate.
>> +        """
>> +        self._early_cleanup()
> 
> Like I commented on patch 5, I don't think the *current* type of
> cleanup done is needed on a scenario like this...
> 
>> +        self._popen.kill()
> 
> ... as I don't remember QEMU's SIGKILL handler to be susceptible to
> the race condition that motivated the closing of the console file in
> the first place.  But, I also can not prove it's not susceptible at
> this time.
> 

It probably isn't. It was for consistency in when and where that hook is
called, again. It does happen to be "pointless" here.

> Note: I have some old patches that added tests for QEMUMachine itself.
> I intend to respin them on top of your work, so we may have a clearer
> understanding of the QEMU behaviors we need to handle.  So, feel free
> to take the prudent route here, and keep the early cleanup.
> 

Oh, adding formal tests to this folder would be incredible; especially
if we wanted to package it on PyPI. Basically a necessity.

> Reviewed-by: Cleber Rosa <crosa@redhat.com>
> Tested-by: Cleber Rosa <crosa@redhat.com>
> 

Re: [PATCH v5 12/12] python/machine.py: change default wait timeout to 3 seconds

[John Snow]

On 7/14/20 12:20 AM, Cleber Rosa wrote:
> On Fri, Jul 10, 2020 at 01:06:49AM -0400, John Snow wrote:
>> Machine.wait() does not appear to be used except in the acceptance tests,
>> and an infinite timeout by default in a test suite is not the most helpful.
>>
>> Change it to 3 seconds, like the default shutdown timeout.
>>
>> Signed-off-by: John Snow <jsnow@redhat.com>
>> ---
>>  python/qemu/machine.py | 4 ++--
>>  1 file changed, 2 insertions(+), 2 deletions(-)
>>
> 
> Well, for the acceptance tests, there's usually a test wide timeout,
> but this is indeed a good idea!
> 
> Reviewed-by: Cleber Rosa <crosa@redhat.com>
> Tested-by: Cleber Rosa <crosa@redhat.com>
> 

Yes, there's a bigger timeout for acceptance tests, but iotests doesn't
have the same just yet.

In general, it helps for most of the python library methods to time out
by default to prevent hangs in the various test suites.

So, anticipating that iotest callers will probably want to use wait()
sooner or later, I just went ahead and made the change primarily for
consistency again.

--js

Re: [PATCH v5 05/12] python/machine.py: Prohibit multiple shutdown() calls

[John Snow]

On 7/13/20 10:48 PM, Cleber Rosa wrote:
> On Fri, Jul 10, 2020 at 01:06:42AM -0400, John Snow wrote:
>> If the VM is not launched, don't try to shut it down. As a change,
>> _post_shutdown now unconditionally also calls _early_cleanup in order to
>> offer comprehensive object cleanup in failure cases.
>>
>> As a courtesy, treat it as a NOP instead of rejecting it as an
>> error. This is slightly nicer for acceptance tests where vm.shutdown()
>> is issued unconditionally in tearDown callbacks.
>>
>> Signed-off-by: John Snow <jsnow@redhat.com>
>> ---
>>  python/qemu/machine.py | 14 +++++++++++++-
>>  1 file changed, 13 insertions(+), 1 deletion(-)
>>
>> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
>> index cac466fbe6..e66a7d66dd 100644
>> --- a/python/qemu/machine.py
>> +++ b/python/qemu/machine.py
>> @@ -283,6 +283,13 @@ def _post_launch(self):
>>              self._qmp.accept()
>>  
>>      def _post_shutdown(self):
>> +        """
>> +        Called to cleanup the VM instance after the process has exited.
>> +        May also be called after a failed launch.
>> +        """
>> +        # Comprehensive reset for the failed launch case:
>> +        self._early_cleanup()
>> +
> 
> I'm not following why this is needed here.  AFAICT, the closing of the
> console socket file was introduced when the QEMU process was alive,
> and doing I/O on the serial device attached to the console file (and
> was only necessary because of that).  In those scenarios, a race
> between the time of sending the QMP command to quit, and getting a
> response from QMP could occur.
> 
> But here, IIUC, there's no expectations for the QEMU process to be alive.
> To the best of my understanding and testing, this line did not contribute
> to the robustness of the shutdown behavior.
> 
> Finally, given that currently, only the closing of the console socket
> is done within _early_cleanup(), and that is conditional, this also does
> no harm AFAICT.  If more early cleanups operations were needed, then I
> would feel less bothered about calling it here.
> 
>>          if self._qmp:
>>              self._qmp.close()
>>              self._qmp = None
>> @@ -328,7 +335,7 @@ def launch(self):
>>              self._launch()
>>              self._launched = True
>>          except:
>> -            self.shutdown()
>> +            self._post_shutdown()
>>  
>>              LOG.debug('Error launching VM')
>>              if self._qemu_full_args:
>> @@ -357,6 +364,8 @@ def _launch(self):
>>      def _early_cleanup(self) -> None:
>>          """
>>          Perform any cleanup that needs to happen before the VM exits.
>> +
>> +        Called additionally by _post_shutdown for comprehensive cleanup.
>>          """
>>          # If we keep the console socket open, we may deadlock waiting
>>          # for QEMU to exit, while QEMU is waiting for the socket to
>> @@ -377,6 +386,9 @@ def shutdown(self, has_quit=False, hard=False):
>>          """
>>          Terminate the VM and clean up
>>          """
>> +        if not self._launched:
>> +            return
>> +
> 
> Because of the additional logic, it'd be a good opportunity to make
> the docstring more accurate.  This method may now *not* do *any* of if
> termination and cleaning (while previously it would attempt those
> anyhow).
> 

The docstring gets hit with a polish beam later in the series, but still
neglects that it might do nothing.

I squashed in a change to patch #10 and pushed to my gitlab to add this
clarification to the docstring.

https://gitlab.com/jsnow/qemu/-/tree/python-package-shutdown

https://gitlab.com/jsnow/qemu/-/commit/b3f14deb730fda9bb2a28a9366a8096d3617f4f4

Re: [PATCH v5 10/12] python/machine.py: split shutdown into hard and soft flavors

[Philippe Mathieu-Daudé]

On 7/14/20 8:13 PM, John Snow wrote:
> 
> 
> On 7/14/20 12:13 AM, Cleber Rosa wrote:
>> On Fri, Jul 10, 2020 at 01:06:47AM -0400, John Snow wrote:
>>> This is done primarily to avoid the 'bare except' pattern, which
>>> suppresses all exceptions during shutdown and can obscure errors.
>>>
>>> Replace this with a pattern that isolates the different kind of shutdown
>>> paradigms (_hard_shutdown and _soft_shutdown), and a new fallback shutdown
>>> handler (_do_shutdown) that gracefully attempts one before the other.
>>>
>>> This split now also ensures that no matter what happens,
>>> _post_shutdown() is always invoked.
>>>
>>> shutdown() changes in behavior such that if it attempts to do a graceful
>>> shutdown and is unable to, it will now always raise an exception to
>>> indicate this. This can be avoided by the test writer in three ways:
>>>
>>> 1. If the VM is expected to have already exited or is in the process of
>>> exiting, wait() can be used instead of shutdown() to clean up resources
>>> instead. This helps avoid race conditions in shutdown.
>>>
>>> 2. If a test writer is expecting graceful shutdown to fail, shutdown
>>> should be called in a try...except block.
>>>
>>> 3. If the test writer has no interest in performing a graceful shutdown
>>> at all, kill() can be used instead.
>>>
>>>
>>> Handling shutdown in this way makes it much more explicit which type of
>>> shutdown we want and allows the library to report problems with this
>>> process.
>>>
>>> Signed-off-by: John Snow <jsnow@redhat.com>
>>> ---
>>>  python/qemu/machine.py | 95 +++++++++++++++++++++++++++++++++++-------
>>>  1 file changed, 80 insertions(+), 15 deletions(-)
>>>
>>> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
>>> index aaa173f046..b24ce8a268 100644
>>> --- a/python/qemu/machine.py
>>> +++ b/python/qemu/machine.py
>>> @@ -48,6 +48,12 @@ class QEMUMachineAddDeviceError(QEMUMachineError):
>>>      """
>>>  
>>>  
>>> +class AbnormalShutdown(QEMUMachineError):
>>> +    """
>>> +    Exception raised when a graceful shutdown was requested, but not performed.
>>> +    """
>>> +
>>> +
>>>  class MonitorResponseError(qmp.QMPError):
>>>      """
>>>      Represents erroneous QMP monitor reply
>>> @@ -365,6 +371,7 @@ def _early_cleanup(self) -> None:
>>>          """
>>>          Perform any cleanup that needs to happen before the VM exits.
>>>  
>>> +        May be invoked by both soft and hard shutdown in failover scenarios.
>>>          Called additionally by _post_shutdown for comprehensive cleanup.
>>>          """
>>>          # If we keep the console socket open, we may deadlock waiting
>>> @@ -374,32 +381,90 @@ def _early_cleanup(self) -> None:
>>>              self._console_socket.close()
>>>              self._console_socket = None
>>>  
>>> +    def _hard_shutdown(self) -> None:
>>> +        """
>>> +        Perform early cleanup, kill the VM, and wait for it to terminate.
>>> +
>>> +        :raise subprocess.Timeout: When timeout is exceeds 60 seconds
>>> +            waiting for the QEMU process to terminate.
>>> +        """
>>> +        self._early_cleanup()
>>
>> Like I commented on patch 5, I don't think the *current* type of
>> cleanup done is needed on a scenario like this...
>>
>>> +        self._popen.kill()
>>
>> ... as I don't remember QEMU's SIGKILL handler to be susceptible to
>> the race condition that motivated the closing of the console file in
>> the first place.  But, I also can not prove it's not susceptible at
>> this time.
>>
> 
> It probably isn't. It was for consistency in when and where that hook is
> called, again. It does happen to be "pointless" here.
> 
>> Note: I have some old patches that added tests for QEMUMachine itself.
>> I intend to respin them on top of your work, so we may have a clearer
>> understanding of the QEMU behaviors we need to handle.  So, feel free
>> to take the prudent route here, and keep the early cleanup.
>>
> 
> Oh, adding formal tests to this folder would be incredible; especially
> if we wanted to package it on PyPI. Basically a necessity.
> 
>> Reviewed-by: Cleber Rosa <crosa@redhat.com>
>> Tested-by: Cleber Rosa <crosa@redhat.com>
>>
> 

Queuing with this hunk from jsnow:

-- >8 --
@@ -455,6 +444,9 @@ def shutdown(self, has_quit: bool = False,
         Terminate the VM (gracefully if possible) and perform cleanup.
         Cleanup will always be performed.

+        If the VM has not yet been launched, or shutdown(), wait(), or
kill()
+        have already been called, this method does nothing.
+
         :param has_quit: When true, do not attempt to issue 'quit' QMP
command.
         :param hard: When true, do not attempt graceful shutdown, and
                      suppress the SIGKILL warning log message.
---

Re: [PATCH v5 00/12] python/machine.py: refactor shutdown

[Philippe Mathieu-Daudé]

On 7/10/20 7:06 AM, John Snow wrote:
> v5: More or less rewritten.
> 
> This series is motivated by a desire to move python/qemu onto a strict
> mypy/pylint regime to help prevent regressions in the python codebase.
> 
> 1. Remove the "bare except" pattern in the existing shutdown code, which
>    can mask problems and make debugging difficult.
> 
> 2. Ensure that post-shutdown cleanup is always performed, even when
>    graceful termination fails.
> 
> 3. Unify cleanup paths such that no matter how the VM is terminated, the
>    same functions and steps are always taken to reset the object state.
> 
> 4. Rewrite shutdown() such that any error encountered when attempting a
>    graceful shutdown will be raised as an AbnormalShutdown exception.
>    The pythonic idiom is to allow the caller to decide if this is a
>    problem or not.
> 
> Previous versions of this series did not engage the fourth goal, and ran
> into race conditions. When I was trying to allow shutdown to succeed if
> QEMU was already closed, it became impossible to tell in which cases
> QEMU not being present was "OK" and in which cases it was evidence of a
> problem.
> 
> This refactoring is even more explicit. If a graceful shutdown is
> requested and cannot be performed, an exception /will/ be raised.
> 
> In cases where the test writer expects QEMU to already have exited,
> vm.wait() should be used in preference to vm.shutdown(). In cases where
> a graceful shutdown is not interesting or necessary to the test,
> vm.kill() should be used.
> 
> John Snow (12):
>   python/machine.py: consolidate _post_shutdown()
>   python/machine.py: Close QMP socket in cleanup
>   python/machine.py: Add _early_cleanup hook
>   python/machine.py: Perform early cleanup for wait() calls, too
>   python/machine.py: Prohibit multiple shutdown() calls
>   python/machine.py: Add a configurable timeout to shutdown()
>   python/machine.py: Make wait() call shutdown()
>   tests/acceptance: wait() instead of shutdown() where appropriate
>   tests/acceptance: Don't test reboot on cubieboard
>   python/machine.py: split shutdown into hard and soft flavors
>   python/machine.py: re-add sigkill warning suppression
>   python/machine.py: change default wait timeout to 3 seconds

Series (finally) queued on python-next, thanks.