[PATCH 0/2] python/qemu/machine: fix potential hang in QMP accept

[PATCH 0/2] python/qemu/machine: fix potential hang in QMP accept

[marcandre.lureau]

From: Marc-André Lureau <marcandre.lureau@redhat.com>

Hi,

As reported earlier by Richard Henderson ("virgl avocado hang" thread), avocado
tests may hang when QEMU exits before the QMP connection is established.

My proposal to fix the problem here is to do both accept() and wait()
concurrently by turning some code async. Obviously, there is much larger
work to be done to turn more code into async and avoid _sync() wrappers, but
I do not intend to tackle that.

Please comment/review

Marc-André Lureau (2):
  python/qemu/machine: replace subprocess.Popen with asyncio
  python/qemu/machine: accept QMP connection asynchronously

 python/qemu/machine/machine.py | 58 ++++++++++++++++++++++++----------
 python/qemu/qmp/legacy.py      | 10 ++++++
 2 files changed, 51 insertions(+), 17 deletions(-)

-- 
2.37.0.rc0

[PATCH 1/2] python/qemu/machine: replace subprocess.Popen with asyncio

[marcandre.lureau]

From: Marc-André Lureau <marcandre.lureau@redhat.com>

The following patch is going to wait for both subprocess and accept
tasks concurrently. Switch to using asyncio for subprocess handling.

Signed-off-by: Marc-André Lureau <marcandre.lureau@redhat.com>
---
 python/qemu/machine/machine.py | 47 ++++++++++++++++++++++------------
 1 file changed, 31 insertions(+), 16 deletions(-)

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index 37191f433b2d..55c45f4b1205 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -17,6 +17,7 @@
 # Based on qmp.py.
 #
 
+import asyncio
 import errno
 from itertools import chain
 import locale
@@ -30,6 +31,7 @@
 from types import TracebackType
 from typing import (
     Any,
+    Awaitable,
     BinaryIO,
     Dict,
     List,
@@ -180,7 +182,7 @@ def __init__(self,
         # Runstate
         self._qemu_log_path: Optional[str] = None
         self._qemu_log_file: Optional[BinaryIO] = None
-        self._popen: Optional['subprocess.Popen[bytes]'] = None
+        self._subproc: Optional['asyncio.subprocess.Process'] = None
         self._events: List[QMPMessage] = []
         self._iolog: Optional[str] = None
         self._qmp_set = True   # Enable QMP monitor by default.
@@ -198,6 +200,7 @@ def __init__(self,
         self._remove_files: List[str] = []
         self._user_killed = False
         self._quit_issued = False
+        self._aloop = asyncio.get_event_loop()
 
     def __enter__(self: _T) -> _T:
         return self
@@ -269,19 +272,19 @@ def _remove_if_exists(path: str) -> None:
 
     def is_running(self) -> bool:
         """Returns true if the VM is running."""
-        return self._popen is not None and self._popen.poll() is None
+        return self._subproc is not None and self._subproc.returncode is None
 
     @property
-    def _subp(self) -> 'subprocess.Popen[bytes]':
-        if self._popen is None:
+    def _subp(self) -> 'asyncio.subprocess.Process':
+        if self._subproc is None:
             raise QEMUMachineError('Subprocess pipe not present')
-        return self._popen
+        return self._subproc
 
     def exitcode(self) -> Optional[int]:
         """Returns the exit code if possible, or None."""
-        if self._popen is None:
+        if self._subproc is None:
             return None
-        return self._popen.poll()
+        return self._subproc.returncode
 
     def get_pid(self) -> Optional[int]:
         """Returns the PID of the running process, or None."""
@@ -443,6 +446,13 @@ def launch(self) -> None:
             # that exception. However, we still want to clean up.
             raise
 
+    def _sync(
+            self, future: Awaitable[_T], timeout: Optional[float] = None
+    ) -> _T:
+        return self._aloop.run_until_complete(
+            asyncio.wait_for(future, timeout=timeout)
+        )
+
     def _launch(self) -> None:
         """
         Launch the VM and establish a QMP connection
@@ -452,12 +462,13 @@ def _launch(self) -> None:
 
         # Cleaning up of this subprocess is guaranteed by _do_shutdown.
         # pylint: disable=consider-using-with
-        self._popen = subprocess.Popen(self._qemu_full_args,
-                                       stdin=subprocess.DEVNULL,
-                                       stdout=self._qemu_log_file,
-                                       stderr=subprocess.STDOUT,
-                                       shell=False,
-                                       close_fds=False)
+        self._subproc = self._sync(
+            asyncio.create_subprocess_exec(*self._qemu_full_args,
+                                           stdin=asyncio.subprocess.DEVNULL,
+                                           stdout=self._qemu_log_file,
+                                           stderr=asyncio.subprocess.STDOUT,
+                                           close_fds=False)
+        )
         self._launched = True
         self._post_launch()
 
@@ -508,8 +519,10 @@ def _hard_shutdown(self) -> None:
             waiting for the QEMU process to terminate.
         """
         self._early_cleanup()
-        self._subp.kill()
-        self._subp.wait(timeout=60)
+        self._sync(
+            self._subp.kill(),
+            asyncio.wait_for(self._subp.wait(), timeout=60)
+        )
 
     def _soft_shutdown(self, timeout: Optional[int]) -> None:
         """
@@ -536,7 +549,9 @@ def _soft_shutdown(self, timeout: Optional[int]) -> None:
                 self._close_qmp_connection()
 
         # May raise subprocess.TimeoutExpired
-        self._subp.wait(timeout=timeout)
+        self._sync(
+            asyncio.wait_for(self._subp.wait(), timeout=timeout)
+        )
 
     def _do_shutdown(self, timeout: Optional[int]) -> None:
         """
-- 
2.37.0.rc0

[PATCH 2/2] python/qemu/machine: accept QMP connection asynchronously

[marcandre.lureau]

From: Marc-André Lureau <marcandre.lureau@redhat.com>

QMP accept is currently synchronous. If qemu dies before the connection
is established, it will wait there. Instead turn the code to do
concurrently accept() and wait(). Returns when the first task is
completed to determine whether a connection was established.

Signed-off-by: Marc-André Lureau <marcandre.lureau@redhat.com>
---
 python/qemu/machine/machine.py | 11 ++++++++++-
 python/qemu/qmp/legacy.py      | 10 ++++++++++
 2 files changed, 20 insertions(+), 1 deletion(-)

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index 55c45f4b1205..5e2df7dc5055 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -362,9 +362,18 @@ def _pre_launch(self) -> None:
             self._args
         ))
 
+    async def _async_accept(self) -> bool:
+        accept = asyncio.create_task(self._qmp.async_accept())
+        wait = asyncio.create_task(self._subproc.wait())
+        done, pending = await asyncio.wait([accept, wait],
+                                           return_when=asyncio.FIRST_COMPLETED)
+        return accept in done
+
     def _post_launch(self) -> None:
         if self._qmp_connection:
-            self._qmp.accept(self._qmp_timer)
+            accepted = self._sync(self._async_accept())
+            if not accepted:
+                raise QEMUMachineError('VM returned before QMP accept')
 
     def _close_qemu_log_file(self) -> None:
         if self._qemu_log_file is not None:
diff --git a/python/qemu/qmp/legacy.py b/python/qemu/qmp/legacy.py
index 03b5574618fa..88bdbfb6e350 100644
--- a/python/qemu/qmp/legacy.py
+++ b/python/qemu/qmp/legacy.py
@@ -167,6 +167,16 @@ def accept(self, timeout: Optional[float] = 15.0) -> QMPMessage:
         assert ret is not None
         return ret
 
+    async def async_accept(self) -> QMPMessage:
+        self._qmp.await_greeting = True
+        self._qmp.negotiate = True
+
+        await self._qmp.accept()
+
+        ret = self._get_greeting()
+        assert ret is not None
+        return ret
+
     def cmd_obj(self, qmp_cmd: QMPMessage) -> QMPMessage:
         """
         Send a QMP command to the QMP Monitor.
-- 
2.37.0.rc0

Re: [PATCH 2/2] python/qemu/machine: accept QMP connection asynchronously

[Daniel P. Berrangé]

On Tue, Jun 28, 2022 at 05:49:39PM +0400, marcandre.lureau@redhat.com wrote:
> From: Marc-André Lureau <marcandre.lureau@redhat.com>
> 
> QMP accept is currently synchronous. If qemu dies before the connection
> is established, it will wait there. Instead turn the code to do
> concurrently accept() and wait(). Returns when the first task is
> completed to determine whether a connection was established.

If the spawned QEMU process was given -daemonize, won't this code
mistakenly think the subprocess has quit ?

> 
> Signed-off-by: Marc-André Lureau <marcandre.lureau@redhat.com>
> ---
>  python/qemu/machine/machine.py | 11 ++++++++++-
>  python/qemu/qmp/legacy.py      | 10 ++++++++++
>  2 files changed, 20 insertions(+), 1 deletion(-)
> 
> diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
> index 55c45f4b1205..5e2df7dc5055 100644
> --- a/python/qemu/machine/machine.py
> +++ b/python/qemu/machine/machine.py
> @@ -362,9 +362,18 @@ def _pre_launch(self) -> None:
>              self._args
>          ))
>  
> +    async def _async_accept(self) -> bool:
> +        accept = asyncio.create_task(self._qmp.async_accept())
> +        wait = asyncio.create_task(self._subproc.wait())
> +        done, pending = await asyncio.wait([accept, wait],
> +                                           return_when=asyncio.FIRST_COMPLETED)
> +        return accept in done
> +
>      def _post_launch(self) -> None:
>          if self._qmp_connection:
> -            self._qmp.accept(self._qmp_timer)
> +            accepted = self._sync(self._async_accept())
> +            if not accepted:
> +                raise QEMUMachineError('VM returned before QMP accept')
>  
>      def _close_qemu_log_file(self) -> None:
>          if self._qemu_log_file is not None:
> diff --git a/python/qemu/qmp/legacy.py b/python/qemu/qmp/legacy.py
> index 03b5574618fa..88bdbfb6e350 100644
> --- a/python/qemu/qmp/legacy.py
> +++ b/python/qemu/qmp/legacy.py
> @@ -167,6 +167,16 @@ def accept(self, timeout: Optional[float] = 15.0) -> QMPMessage:
>          assert ret is not None
>          return ret
>  
> +    async def async_accept(self) -> QMPMessage:
> +        self._qmp.await_greeting = True
> +        self._qmp.negotiate = True
> +
> +        await self._qmp.accept()
> +
> +        ret = self._get_greeting()
> +        assert ret is not None
> +        return ret
> +


With regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: [PATCH 2/2] python/qemu/machine: accept QMP connection asynchronously

[John Snow]

On Tue, Jun 28, 2022 at 10:17 AM Daniel P. Berrangé <berrange@redhat.com> wrote:
>
> On Tue, Jun 28, 2022 at 05:49:39PM +0400, marcandre.lureau@redhat.com wrote:
> > From: Marc-André Lureau <marcandre.lureau@redhat.com>
> >
> > QMP accept is currently synchronous. If qemu dies before the connection
> > is established, it will wait there. Instead turn the code to do
> > concurrently accept() and wait(). Returns when the first task is
> > completed to determine whether a connection was established.
>
> If the spawned QEMU process was given -daemonize, won't this code
> mistakenly think the subprocess has quit ?

Do we use daemonize with this code anywhere? Is it important that we
are able to?

Many of the shutdown routines I wrote expect to work directly with a
launched process ... at least, that expectation exists in my head. I
suppose a lot of this code may actually just coincidentally work with
-daemonize and I wouldn't have noticed. I certainly haven't been
testing it explicitly. I definitely make no accommodations for it, so
I would expect some stale processes in various cases at a minimum.

If we want to expand to accommodate this feature, can we do that
later? Machine needs a bit of a remodel anyway. (I want to write an
'idiomatic' asyncio version to match the QMP lib. I have some
questions to work out WRT which portions of this appliance can be
upstreamed and which need to remain only in our testing tree. We can
talk about those pieces later, just throwing it out there that it's on
my list.)

--js

Re: [PATCH 2/2] python/qemu/machine: accept QMP connection asynchronously

[Daniel P. Berrangé]

On Wed, Jun 29, 2022 at 07:54:08PM -0400, John Snow wrote:
> On Tue, Jun 28, 2022 at 10:17 AM Daniel P. Berrangé <berrange@redhat.com> wrote:
> >
> > On Tue, Jun 28, 2022 at 05:49:39PM +0400, marcandre.lureau@redhat.com wrote:
> > > From: Marc-André Lureau <marcandre.lureau@redhat.com>
> > >
> > > QMP accept is currently synchronous. If qemu dies before the connection
> > > is established, it will wait there. Instead turn the code to do
> > > concurrently accept() and wait(). Returns when the first task is
> > > completed to determine whether a connection was established.
> >
> > If the spawned QEMU process was given -daemonize, won't this code
> > mistakenly think the subprocess has quit ?
> 
> Do we use daemonize with this code anywhere? Is it important that we
> are able to?

Well what's the intended breadth of use cases this code wants to
target ?

If you don't daemonize QEMU, then QEMU will (likely) get killed off
when the parent python process terminates. That can be ok for adhoc
testing scenarios where the QEMU process is transient and throwaway,
or for using QEMU as an embedded technology (think libguestfs). If
you want your QEMU to run full OS workloads, then generally you won't
want it to die when the mgmt app is restarted (eg for software upgrade),
whereupon you want to daemonize.

> Many of the shutdown routines I wrote expect to work directly with a
> launched process ... at least, that expectation exists in my head. I
> suppose a lot of this code may actually just coincidentally work with
> -daemonize and I wouldn't have noticed. I certainly haven't been
> testing it explicitly. I definitely make no accommodations for it, so
> I would expect some stale processes in various cases at a minimum.

Looking at the code it probably works by accident - the shutdown()
methods kinda assumes we're talking to a direct child, but it'll
happen to work right now as it'll simply cleanup the defunct
intermediate child, while QEMU stays running.

> If we want to expand to accommodate this feature, can we do that
> later? Machine needs a bit of a remodel anyway. (I want to write an
> 'idiomatic' asyncio version to match the QMP lib. I have some
> questions to work out WRT which portions of this appliance can be
> upstreamed and which need to remain only in our testing tree. We can
> talk about those pieces later, just throwing it out there that it's on
> my list.)

The machine class is probably the part that looks least ready to be
published as an API on pypi. Its code really shows its origins as an
adhoc testing framework, rather than a general purpose API for running
and managing QEMU from python.

With regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: [PATCH 2/2] python/qemu/machine: accept QMP connection asynchronously

[John Snow]

On Thu, Jun 30, 2022 at 4:23 AM Daniel P. Berrangé <berrange@redhat.com> wrote:
>
> On Wed, Jun 29, 2022 at 07:54:08PM -0400, John Snow wrote:
> > On Tue, Jun 28, 2022 at 10:17 AM Daniel P. Berrangé <berrange@redhat.com> wrote:
> > >
> > > On Tue, Jun 28, 2022 at 05:49:39PM +0400, marcandre.lureau@redhat.com wrote:
> > > > From: Marc-André Lureau <marcandre.lureau@redhat.com>
> > > >
> > > > QMP accept is currently synchronous. If qemu dies before the connection
> > > > is established, it will wait there. Instead turn the code to do
> > > > concurrently accept() and wait(). Returns when the first task is
> > > > completed to determine whether a connection was established.
> > >
> > > If the spawned QEMU process was given -daemonize, won't this code
> > > mistakenly think the subprocess has quit ?
> >
> > Do we use daemonize with this code anywhere? Is it important that we
> > are able to?
>
> Well what's the intended breadth of use cases this code wants to
> target ?

Well, I dunno. I'm going to say that machine.py is something that will
probably stay in-tree as an ad-hoc testing utility. I have some
thoughts about growing it into something "just a little bit more than
that", but I think we can cross that bridge when we get there. I will
probably do like what I did for QMP: write a replacement, test it with
our existing test infrastructure, then do a drop-in switcheroo.

>
> If you don't daemonize QEMU, then QEMU will (likely) get killed off
> when the parent python process terminates. That can be ok for adhoc
> testing scenarios where the QEMU process is transient and throwaway,
> or for using QEMU as an embedded technology (think libguestfs). If
> you want your QEMU to run full OS workloads, then generally you won't
> want it to die when the mgmt app is restarted (eg for software upgrade),
> whereupon you want to daemonize.
>

Yeah, I think that's a case that I wasn't invested in managing.
Certainly it's an expansion of scope.

> > Many of the shutdown routines I wrote expect to work directly with a
> > launched process ... at least, that expectation exists in my head. I
> > suppose a lot of this code may actually just coincidentally work with
> > -daemonize and I wouldn't have noticed. I certainly haven't been
> > testing it explicitly. I definitely make no accommodations for it, so
> > I would expect some stale processes in various cases at a minimum.
>
> Looking at the code it probably works by accident - the shutdown()
> methods kinda assumes we're talking to a direct child, but it'll
> happen to work right now as it'll simply cleanup the defunct
> intermediate child, while QEMU stays running.
>

That's my conclusion, yes.

> > If we want to expand to accommodate this feature, can we do that
> > later? Machine needs a bit of a remodel anyway. (I want to write an
> > 'idiomatic' asyncio version to match the QMP lib. I have some
> > questions to work out WRT which portions of this appliance can be
> > upstreamed and which need to remain only in our testing tree. We can
> > talk about those pieces later, just throwing it out there that it's on
> > my list.)
>
> The machine class is probably the part that looks least ready to be
> published as an API on pypi. Its code really shows its origins as an
> adhoc testing framework, rather than a general purpose API for running
> and managing QEMU from python.

I agree.

It might still be useful in some form, eventually, to use as supported
example code of showing how you can launch QEMU and interact with it
via QMP. In the current form, though, it's definitely just ad-hoc nuts
and bolts for the test suite. I am fine with keeping it like that for
purposes of review and maintenance, etc.

--js

Re: [PATCH 0/2] python/qemu/machine: fix potential hang in QMP accept

[Daniel P. Berrangé]

On Tue, Jun 28, 2022 at 05:49:37PM +0400, marcandre.lureau@redhat.com wrote:
> From: Marc-André Lureau <marcandre.lureau@redhat.com>
> 
> Hi,
> 
> As reported earlier by Richard Henderson ("virgl avocado hang" thread), avocado
> tests may hang when QEMU exits before the QMP connection is established.
> 
> My proposal to fix the problem here is to do both accept() and wait()
> concurrently by turning some code async. Obviously, there is much larger
> work to be done to turn more code into async and avoid _sync() wrappers, but
> I do not intend to tackle that.

IIUC, in this case the Python API has a listener socket, and QEMU is
the client socket. As you say this has a possible designed in hang
since there's not a good way 100% sure whether a client connection is
still pending or not. The plus side is that it means that QEMU should
die when the parent python app goes away and the server end of the
monitor FD closes.

The startup race though could be avoided by using FD passing with a
reversed relationship. ie Python opens a listener socket, and passes
the pre-opened FD to the forkd QEMU process. The python can connect()
and be confident that either connect will (eventually) succeed, or
it will definitely get a failure when QEMU exits (abnormally) because
the pre-opened listener FD will get closed.

There would need to be another means of ensuring cleanup of QEMU
processes though. Probably QEMU itself ought to support a flag to
the monitor to indicate that it is "single connection" mode, such
that when the first client terminates, QEMU exits

With regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: [PATCH 0/2] python/qemu/machine: fix potential hang in QMP accept

[John Snow]

On Tue, Jun 28, 2022 at 9:49 AM <marcandre.lureau@redhat.com> wrote:
>
> From: Marc-André Lureau <marcandre.lureau@redhat.com>
>
> Hi,
>
> As reported earlier by Richard Henderson ("virgl avocado hang" thread), avocado
> tests may hang when QEMU exits before the QMP connection is established.
>
> My proposal to fix the problem here is to do both accept() and wait()
> concurrently by turning some code async. Obviously, there is much larger
> work to be done to turn more code into async and avoid _sync() wrappers, but
> I do not intend to tackle that.
>
> Please comment/review
>

This has been on my list, it's been a problem for a while. If this
series doesn't regress anything, I'm happy to take it. It'd be nice to
get a proper "idiomatic" asyncio Machine class, but that can wait. I
just got back from a vacation trip, please harass me in a few days if
I haven't cleared this off my to-do list.

Thanks,

--js

> Marc-André Lureau (2):
>   python/qemu/machine: replace subprocess.Popen with asyncio
>   python/qemu/machine: accept QMP connection asynchronously
>
>  python/qemu/machine/machine.py | 58 ++++++++++++++++++++++++----------
>  python/qemu/qmp/legacy.py      | 10 ++++++
>  2 files changed, 51 insertions(+), 17 deletions(-)
>
> --
> 2.37.0.rc0
>

Re: [PATCH 0/2] python/qemu/machine: fix potential hang in QMP accept

[Marc-André Lureau]

Hi

On Tue, Jun 28, 2022 at 9:08 PM John Snow <jsnow@redhat.com> wrote:
>
> On Tue, Jun 28, 2022 at 9:49 AM <marcandre.lureau@redhat.com> wrote:
> >
> > From: Marc-André Lureau <marcandre.lureau@redhat.com>
> >
> > Hi,
> >
> > As reported earlier by Richard Henderson ("virgl avocado hang" thread), avocado
> > tests may hang when QEMU exits before the QMP connection is established.
> >
> > My proposal to fix the problem here is to do both accept() and wait()
> > concurrently by turning some code async. Obviously, there is much larger
> > work to be done to turn more code into async and avoid _sync() wrappers, but
> > I do not intend to tackle that.
> >
> > Please comment/review
> >
>
> This has been on my list, it's been a problem for a while. If this
> series doesn't regress anything, I'm happy to take it. It'd be nice to
> get a proper "idiomatic" asyncio Machine class, but that can wait. I
> just got back from a vacation trip, please harass me in a few days if
> I haven't cleared this off my to-do list.
>

It has a few regressions. Plus I am considering Daniel's suggestions.
Let me revisit first.

thanks