From 9cccb3305a26ee01fea7b3a179eca01c98083e3a Mon Sep 17 00:00:00 2001 From: John Snow Date: Thu, 27 Oct 2022 14:58:35 -0400 Subject: 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(+) (limited to 'python') diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py index 37191f4..6f1374a 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 -- cgit v1.1 From 3c6e5e8ce13dc3bf286ff977a7806f2b342dfdab Mon Sep 17 00:00:00 2001 From: John Snow Date: Thu, 27 Oct 2022 14:58:36 -0400 Subject: 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(+) (limited to 'python') diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py index 6f1374a..748a0d8 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( -- cgit v1.1 From 745d58f77d5f951a220a595c73ae30154ed0d50a Mon Sep 17 00:00:00 2001 From: John Snow Date: Fri, 2 Dec 2022 19:52:32 -0500 Subject: 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(-) (limited to 'python') diff --git a/python/setup.cfg b/python/setup.cfg index c2c61c7..c0d7bab 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] -- cgit v1.1 From 519f3cfce07a067971ff39d4a989b77e7100a947 Mon Sep 17 00:00:00 2001 From: John Snow Date: Fri, 2 Dec 2022 19:52:34 -0500 Subject: 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(-) (limited to 'python') diff --git a/python/setup.cfg b/python/setup.cfg index c0d7bab..5641815 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] -- cgit v1.1