From 9cccb3305a26ee01fea7b3a179eca01c98083e3a Mon Sep 17 00:00:00 2001 From: John Snow Date: Thu, 27 Oct 2022 14:58:35 -0400 Subject: [PATCH 1/5] python/machine: Add debug logging to key state changes When key decisions are made about the lifetime of the VM process being managed, there's no log entry. Juxtaposed with the very verbose runstate change logging of the QMP module, machine seems a bit too introverted now. Season the machine.py module with logging statements to taste to help make a tastier soup. Signed-off-by: John Snow --- python/qemu/machine/machine.py | 25 +++++++++++++++++++++++++ 1 file changed, 25 insertions(+) diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py index 37191f433b..6f1374a755 100644 --- a/python/qemu/machine/machine.py +++ b/python/qemu/machine/machine.py @@ -373,6 +373,7 @@ class QEMUMachine: Called to cleanup the VM instance after the process has exited. May also be called after a failed launch. """ + LOG.debug("Cleaning up after VM process") try: self._close_qmp_connection() except Exception as err: # pylint: disable=broad-except @@ -497,6 +498,7 @@ class QEMUMachine: # for QEMU to exit, while QEMU is waiting for the socket to # become writable. if self._console_socket is not None: + LOG.debug("Closing console socket") self._console_socket.close() self._console_socket = None @@ -507,6 +509,7 @@ class QEMUMachine: :raise subprocess.Timeout: When timeout is exceeds 60 seconds waiting for the QEMU process to terminate. """ + LOG.debug("Performing hard shutdown") self._early_cleanup() self._subp.kill() self._subp.wait(timeout=60) @@ -523,8 +526,18 @@ class QEMUMachine: :raise subprocess.TimeoutExpired: When timeout is exceeded waiting for the QEMU process to terminate. """ + LOG.debug("Attempting graceful termination") + self._early_cleanup() + if self._quit_issued: + LOG.debug( + "Anticipating QEMU termination due to prior 'quit' command, " + "or explicit call to wait()" + ) + else: + LOG.debug("Politely asking QEMU to terminate") + if self._qmp_connection: try: if not self._quit_issued: @@ -536,6 +549,10 @@ class QEMUMachine: self._close_qmp_connection() # May raise subprocess.TimeoutExpired + LOG.debug( + "Waiting (timeout=%s) for QEMU process (pid=%s) to terminate", + timeout, self._subp.pid + ) self._subp.wait(timeout=timeout) def _do_shutdown(self, timeout: Optional[int]) -> None: @@ -553,6 +570,10 @@ class QEMUMachine: try: self._soft_shutdown(timeout) except Exception as exc: + if isinstance(exc, subprocess.TimeoutExpired): + LOG.debug("Timed out waiting for QEMU process to exit") + LOG.debug("Graceful shutdown failed", exc_info=True) + LOG.debug("Falling back to hard shutdown") self._hard_shutdown() raise AbnormalShutdown("Could not perform graceful shutdown") \ from exc @@ -575,6 +596,10 @@ class QEMUMachine: if not self._launched: return + LOG.debug("Shutting down VM appliance; timeout=%s", timeout) + if hard: + LOG.debug("Caller requests immediate termination of QEMU process.") + try: if hard: self._user_killed = True From 3c6e5e8ce13dc3bf286ff977a7806f2b342dfdab Mon Sep 17 00:00:00 2001 From: John Snow Date: Thu, 27 Oct 2022 14:58:36 -0400 Subject: [PATCH 2/5] python/machine: Handle termination cases without QMP If we request a shutdown of a VM without a QMP console, we'll just hang waiting. Not ideal. Add in code that attempts graceful termination in these cases. Tested lightly; it appears to work and I doubt we rely on this case anywhere, but it's a corner you're allowed to wedge yourself in, so it should be handled. Signed-off-by: John Snow --- python/qemu/machine/machine.py | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py index 6f1374a755..748a0d807c 100644 --- a/python/qemu/machine/machine.py +++ b/python/qemu/machine/machine.py @@ -547,6 +547,12 @@ class QEMUMachine: finally: # Regardless, we want to quiesce the connection. self._close_qmp_connection() + elif not self._quit_issued: + LOG.debug( + "Not anticipating QEMU quit and no QMP connection present, " + "issuing SIGTERM" + ) + self._subp.terminate() # May raise subprocess.TimeoutExpired LOG.debug( From 745d58f77d5f951a220a595c73ae30154ed0d50a Mon Sep 17 00:00:00 2001 From: John Snow Date: Fri, 2 Dec 2022 19:52:32 -0500 Subject: [PATCH 3/5] Python: fix flake8 config Newer flake8 versions are a bit pickier about the config file, and my in-line comment confuses the parser. Fix it. Signed-off-by: John Snow Reviewed-by: Wilfred Mallawa Message-id: 20221203005234.620788-2-jsnow@redhat.com Signed-off-by: John Snow --- python/setup.cfg | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/python/setup.cfg b/python/setup.cfg index c2c61c7519..c0d7bab168 100644 --- a/python/setup.cfg +++ b/python/setup.cfg @@ -71,7 +71,8 @@ console_scripts = qmp-tui = qemu.qmp.qmp_tui:main [tui] [flake8] -extend-ignore = E722 # Prefer pylint's bare-except checks to flake8's +# Prefer pylint's bare-except checks to flake8's +extend-ignore = E722 exclude = __pycache__, [mypy] From 5bcf18b0ac2e95ed4490dd63976b9f7831272819 Mon Sep 17 00:00:00 2001 From: John Snow Date: Fri, 2 Dec 2022 19:52:33 -0500 Subject: [PATCH 4/5] iotests/check: Fix typing for sys.exit() value Signed-off-by: John Snow Reviewed-by: Wilfred Mallawa Message-id: 20221203005234.620788-3-jsnow@redhat.com Signed-off-by: John Snow --- tests/qemu-iotests/check | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/qemu-iotests/check b/tests/qemu-iotests/check index 75de1b4691..9bdda1394e 100755 --- a/tests/qemu-iotests/check +++ b/tests/qemu-iotests/check @@ -159,7 +159,7 @@ if __name__ == '__main__': if not tests: raise ValueError('No tests selected') except ValueError as e: - sys.exit(e) + sys.exit(str(e)) if args.dry_run: print('\n'.join(tests)) From 519f3cfce07a067971ff39d4a989b77e7100a947 Mon Sep 17 00:00:00 2001 From: John Snow Date: Fri, 2 Dec 2022 19:52:34 -0500 Subject: [PATCH 5/5] python: add 3.11 to supported list Signed-off-by: John Snow Reviewed-by: Wilfred Mallawa Message-id: 20221203005234.620788-4-jsnow@redhat.com Signed-off-by: John Snow --- python/setup.cfg | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/python/setup.cfg b/python/setup.cfg index c0d7bab168..5641815706 100644 --- a/python/setup.cfg +++ b/python/setup.cfg @@ -19,6 +19,7 @@ classifiers = Programming Language :: Python :: 3.8 Programming Language :: Python :: 3.9 Programming Language :: Python :: 3.10 + Programming Language :: Python :: 3.11 Typing :: Typed [options] @@ -159,7 +160,7 @@ multi_line_output=3 # of python available on your system to run this test. [tox:tox] -envlist = py36, py37, py38, py39, py310 +envlist = py36, py37, py38, py39, py310, py311 skip_missing_interpreters = true [testenv]