[PATCH v2 0/6] python/machine: use socketpair() for console socket

[PATCH v2 0/6] python/machine: use socketpair() for console socket

[John Snow]

Like we did for the QMP socket, use socketpair() for the console socket
so that hopefully there isn't a race condition during early boot where
data might get dropped on the floor.

May or may not help with various race conditions where early console
output is not showing up in the logs and/or potentially being missed by
wait_for_console_pattern.

V2:
  - Fixed some Socket ownership/garbage collection problems
  - Fixed callers of now-dropped VM arguments/properties
  - added a dedicated sock_fd arg to ConsoleSocket()
  - now using socketpair() for qtest console, too.
  - dropped sock_dir arg from *all* machine.py classes
  - Tested quite a bit more thoroughly ...

CI: https://gitlab.com/jsnow/qemu/-/pipelines/945067498

John Snow (6):
  python/machine: move socket setup out of _base_args property
  python/machine: close sock_pair in cleanup path
  python/console_socket: accept existing FD in initializer
  python/machine: use socketpair() for console connections
  python/machine: use socketpair() for qtest connection
  python/machine: remove unused sock_dir argument

 python/qemu/machine/console_socket.py      | 29 ++++++++---
 python/qemu/machine/machine.py             | 58 +++++++++++++---------
 python/qemu/machine/qtest.py               | 54 +++++++++++++++-----
 tests/avocado/acpi-bits.py                 |  5 +-
 tests/avocado/avocado_qemu/__init__.py     |  2 +-
 tests/avocado/machine_aspeed.py            |  5 +-
 tests/qemu-iotests/iotests.py              |  2 +-
 tests/qemu-iotests/tests/copy-before-write |  3 +-
 8 files changed, 104 insertions(+), 54 deletions(-)

-- 
2.41.0

[PATCH v2 1/6] python/machine: move socket setup out of _base_args property

[John Snow]

This property isn't meant to do much else besides return a list of
strings, so move this setup back out into _pre_launch().

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

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index c16a0b6fed..8be0f684fe 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -300,9 +300,7 @@ def _base_args(self) -> List[str]:
 
         if self._qmp_set:
             if self._sock_pair:
-                fd = self._sock_pair[0].fileno()
-                os.set_inheritable(fd, True)
-                moncdev = f"socket,id=mon,fd={fd}"
+                moncdev = f"socket,id=mon,fd={self._sock_pair[0].fileno()}"
             elif isinstance(self._monitor_address, tuple):
                 moncdev = "socket,id=mon,host={},port={}".format(
                     *self._monitor_address
@@ -339,6 +337,7 @@ def _pre_launch(self) -> None:
         if self._qmp_set:
             if self._monitor_address is None:
                 self._sock_pair = socket.socketpair()
+                os.set_inheritable(self._sock_pair[0].fileno(), True)
                 sock = self._sock_pair[1]
             if isinstance(self._monitor_address, str):
                 self._remove_files.append(self._monitor_address)
-- 
2.41.0

[PATCH v2 2/6] python/machine: close sock_pair in cleanup path

[John Snow]

If everything has gone smoothly, we'll already have closed the socket we
gave to the child during post_launch. The other half of the pair that we
gave to the QMP connection should, likewise, be definitively closed by
now.

However, in the cleanup path, it's possible we've created the socketpair
but flubbed the launch and need to clean up resources. These resources
*would* be handled by the garbage collector, but that can happen at
unpredictable times. Nicer to just clean them up synchronously on the
exit path, here.

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

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index 8be0f684fe..26f0fb8a81 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -395,6 +395,11 @@ def _post_shutdown(self) -> None:
         finally:
             assert self._qmp_connection is None
 
+        if self._sock_pair:
+            self._sock_pair[0].close()
+            self._sock_pair[1].close()
+            self._sock_pair = None
+
         self._close_qemu_log_file()
 
         self._load_io_log()
-- 
2.41.0

[PATCH v2 3/6] python/console_socket: accept existing FD in initializer

[John Snow]

Useful if we want to use ConsoleSocket() for a socket created by
socketpair().

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

diff --git a/python/qemu/machine/console_socket.py b/python/qemu/machine/console_socket.py
index 4e28ba9bb2..0a4e09ffc7 100644
--- a/python/qemu/machine/console_socket.py
+++ b/python/qemu/machine/console_socket.py
@@ -24,19 +24,32 @@ class ConsoleSocket(socket.socket):
     """
     ConsoleSocket represents a socket attached to a char device.
 
-    Optionally (if drain==True), drains the socket and places the bytes
-    into an in memory buffer for later processing.
-
-    Optionally a file path can be passed in and we will also
-    dump the characters to this file for debugging purposes.
+    :param address: An AF_UNIX path or address.
+    :param sock_fd: Optionally, an existing socket file descriptor.
+                    One of address or sock_fd must be specified.
+    :param file: Optionally, a filename to log to.
+    :param drain: Optionally, drains the socket and places the bytes
+                  into an in memory buffer for later processing.
     """
-    def __init__(self, address: str, file: Optional[str] = None,
+    def __init__(self,
+                 address: Optional[str] = None,
+                 sock_fd: Optional[int] = None,
+                 file: Optional[str] = None,
                  drain: bool = False):
+        if address is None and sock_fd is None:
+            raise ValueError("one of 'address' or 'sock_fd' must be specified")
+        if address is not None and sock_fd is not None:
+            raise ValueError("can't specify both 'address' and 'sock_fd'")
+
         self._recv_timeout_sec = 300.0
         self._sleep_time = 0.5
         self._buffer: Deque[int] = deque()
-        socket.socket.__init__(self, socket.AF_UNIX, socket.SOCK_STREAM)
-        self.connect(address)
+        if address is not None:
+            socket.socket.__init__(self, socket.AF_UNIX, socket.SOCK_STREAM)
+            self.connect(address)
+        else:
+            assert sock_fd is not None
+            socket.socket.__init__(self, fileno=sock_fd)
         self._logfile = None
         if file:
             # pylint: disable=consider-using-with
-- 
2.41.0

[PATCH v2 4/6] python/machine: use socketpair() for console connections

[John Snow]

Create a socketpair for the console output. This should help eliminate
race conditions around console text early in the boot process that might
otherwise have been dropped on the floor before being able to connect to
QEMU under "server,nowait".

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

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index 26f0fb8a81..09f214c95c 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -159,6 +159,8 @@ def __init__(self,
 
         self._name = name or f"{id(self):x}"
         self._sock_pair: Optional[Tuple[socket.socket, socket.socket]] = None
+        self._cons_sock_pair: Optional[
+            Tuple[socket.socket, socket.socket]] = None
         self._temp_dir: Optional[str] = None
         self._base_temp_dir = base_temp_dir
         self._sock_dir = sock_dir
@@ -315,8 +317,9 @@ def _base_args(self) -> List[str]:
         for _ in range(self._console_index):
             args.extend(['-serial', 'null'])
         if self._console_set:
-            chardev = ('socket,id=console,path=%s,server=on,wait=off' %
-                       self._console_address)
+            assert self._cons_sock_pair is not None
+            fd = self._cons_sock_pair[0].fileno()
+            chardev = f"socket,id=console,fd={fd}"
             args.extend(['-chardev', chardev])
             if self._console_device_type is None:
                 args.extend(['-serial', 'chardev:console'])
@@ -351,6 +354,10 @@ def _pre_launch(self) -> None:
                 nickname=self._name
             )
 
+        if self._console_set:
+            self._cons_sock_pair = socket.socketpair()
+            os.set_inheritable(self._cons_sock_pair[0].fileno(), True)
+
         # NOTE: Make sure any opened resources are *definitely* freed in
         # _post_shutdown()!
         # pylint: disable=consider-using-with
@@ -368,6 +375,9 @@ def _pre_launch(self) -> None:
     def _post_launch(self) -> None:
         if self._sock_pair:
             self._sock_pair[0].close()
+        if self._cons_sock_pair:
+            self._cons_sock_pair[0].close()
+
         if self._qmp_connection:
             if self._sock_pair:
                 self._qmp.connect()
@@ -518,6 +528,11 @@ def _early_cleanup(self) -> None:
             self._console_socket.close()
             self._console_socket = None
 
+        if self._cons_sock_pair:
+            self._cons_sock_pair[0].close()
+            self._cons_sock_pair[1].close()
+            self._cons_sock_pair = None
+
     def _hard_shutdown(self) -> None:
         """
         Perform early cleanup, kill the VM, and wait for it to terminate.
@@ -878,10 +893,19 @@ def console_socket(self) -> socket.socket:
         Returns a socket connected to the console
         """
         if self._console_socket is None:
+            if not self._console_set:
+                raise QEMUMachineError(
+                    "Attempt to access console socket with no connection")
+            assert self._cons_sock_pair is not None
+            # os.dup() is used here for sock_fd because otherwise we'd
+            # have two rich python socket objects that would each try to
+            # close the same underlying fd when either one gets garbage
+            # collected.
             self._console_socket = console_socket.ConsoleSocket(
-                self._console_address,
+                sock_fd=os.dup(self._cons_sock_pair[1].fileno()),
                 file=self._console_log_path,
                 drain=self._drain_console)
+            self._cons_sock_pair[1].close()
         return self._console_socket
 
     @property
-- 
2.41.0

[PATCH v2 5/6] python/machine: use socketpair() for qtest connection

[John Snow]

Like the QMP and console sockets, begin using socketpairs for the qtest
connection, too. After this patch, we'll be able to remove the vestigial
sock_dir argument, but that cleanup is best done in its own patch.

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

diff --git a/python/qemu/machine/qtest.py b/python/qemu/machine/qtest.py
index 1c46138bd0..8180d3ab01 100644
--- a/python/qemu/machine/qtest.py
+++ b/python/qemu/machine/qtest.py
@@ -24,6 +24,7 @@
     Optional,
     Sequence,
     TextIO,
+    Tuple,
 )
 
 from qemu.qmp import SocketAddrT
@@ -38,23 +39,41 @@ class QEMUQtestProtocol:
     :param address: QEMU address, can be either a unix socket path (string)
                     or a tuple in the form ( address, port ) for a TCP
                     connection
-    :param server: server mode, listens on the socket (bool)
+    :param sock: An existing socket can be provided as an alternative to
+                 an address. One of address or sock must be provided.
+    :param server: server mode, listens on the socket. Only meaningful
+                   in conjunction with an address and not an existing
+                   socket.
+
     :raise socket.error: on socket connection errors
 
     .. note::
        No connection is established by __init__(), this is done
        by the connect() or accept() methods.
     """
-    def __init__(self, address: SocketAddrT,
+    def __init__(self,
+                 address: Optional[SocketAddrT] = None,
+                 sock: Optional[socket.socket] = None,
                  server: bool = False):
+        if address is None and sock is None:
+            raise ValueError("Either 'address' or 'sock' must be specified")
+        if address is not None and sock is not None:
+            raise ValueError(
+                "Either 'address' or 'sock' must be specified, but not both")
+        if sock is not None and server:
+            raise ValueError("server=True is meaningless when passing socket")
+
         self._address = address
-        self._sock = self._get_sock()
+        self._sock = sock or self._get_sock()
         self._sockfile: Optional[TextIO] = None
+
         if server:
+            assert self._address is not None
             self._sock.bind(self._address)
             self._sock.listen(1)
 
     def _get_sock(self) -> socket.socket:
+        assert self._address is not None
         if isinstance(self._address, tuple):
             family = socket.AF_INET
         else:
@@ -67,7 +86,8 @@ def connect(self) -> None:
 
         @raise socket.error on socket connection errors
         """
-        self._sock.connect(self._address)
+        if self._address is not None:
+            self._sock.connect(self._address)
         self._sockfile = self._sock.makefile(mode='r')
 
     def accept(self) -> None:
@@ -127,29 +147,40 @@ def __init__(self,
                          base_temp_dir=base_temp_dir,
                          sock_dir=sock_dir, qmp_timer=qmp_timer)
         self._qtest: Optional[QEMUQtestProtocol] = None
-        self._qtest_path = os.path.join(sock_dir, name + "-qtest.sock")
+        self._qtest_sock_pair: Optional[
+            Tuple[socket.socket, socket.socket]] = None
 
     @property
     def _base_args(self) -> List[str]:
         args = super()._base_args
+        assert self._qtest_sock_pair is not None
+        fd = self._qtest_sock_pair[0].fileno()
         args.extend([
-            '-qtest', f"unix:path={self._qtest_path}",
+            '-chardev', f"socket,id=qtest,fd={fd}",
+            '-qtest', 'chardev:qtest',
             '-accel', 'qtest'
         ])
         return args
 
     def _pre_launch(self) -> None:
+        self._qtest_sock_pair = socket.socketpair()
+        os.set_inheritable(self._qtest_sock_pair[0].fileno(), True)
         super()._pre_launch()
-        self._qtest = QEMUQtestProtocol(self._qtest_path, server=True)
+        self._qtest = QEMUQtestProtocol(sock=self._qtest_sock_pair[1])
 
     def _post_launch(self) -> None:
         assert self._qtest is not None
         super()._post_launch()
-        self._qtest.accept()
+        if self._qtest_sock_pair:
+            self._qtest_sock_pair[0].close()
+        self._qtest.connect()
 
     def _post_shutdown(self) -> None:
+        if self._qtest_sock_pair:
+            self._qtest_sock_pair[0].close()
+            self._qtest_sock_pair[1].close()
+            self._qtest_sock_pair = None
         super()._post_shutdown()
-        self._remove_if_exists(self._qtest_path)
 
     def qtest(self, cmd: str) -> str:
         """
-- 
2.41.0

[PATCH v2 6/6] python/machine: remove unused sock_dir argument

[John Snow]

By using a socketpair for all of the sockets managed by the VM class and
its extensions, we don't need the sock_dir argument anymore, so remove
it.

We only added this argument so that we could specify a second, shorter
temporary directory for cases where the temp/log dirs were "too long" as
a socket name on macOS. We don't need it for this class now. In one
case, avocado testing takes over responsibility for creating an
appropriate sockdir.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine/machine.py             | 18 ------------------
 python/qemu/machine/qtest.py               |  5 +----
 tests/avocado/acpi-bits.py                 |  5 +----
 tests/avocado/avocado_qemu/__init__.py     |  2 +-
 tests/avocado/machine_aspeed.py            |  5 ++++-
 tests/qemu-iotests/iotests.py              |  2 +-
 tests/qemu-iotests/tests/copy-before-write |  3 +--
 7 files changed, 9 insertions(+), 31 deletions(-)

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index 09f214c95c..1dd2de6da8 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -127,7 +127,6 @@ def __init__(self,
                  name: Optional[str] = None,
                  base_temp_dir: str = "/var/tmp",
                  monitor_address: Optional[SocketAddrT] = None,
-                 sock_dir: Optional[str] = None,
                  drain_console: bool = False,
                  console_log: Optional[str] = None,
                  log_dir: Optional[str] = None,
@@ -141,7 +140,6 @@ def __init__(self,
         @param name: prefix for socket and log file names (default: qemu-PID)
         @param base_temp_dir: default location where temp files are created
         @param monitor_address: address for QMP monitor
-        @param sock_dir: where to create socket (defaults to base_temp_dir)
         @param drain_console: (optional) True to drain console socket to buffer
         @param console_log: (optional) path to console log file
         @param log_dir: where to create and keep log files
@@ -163,7 +161,6 @@ def __init__(self,
             Tuple[socket.socket, socket.socket]] = None
         self._temp_dir: Optional[str] = None
         self._base_temp_dir = base_temp_dir
-        self._sock_dir = sock_dir
         self._log_dir = log_dir
 
         self._monitor_address = monitor_address
@@ -189,9 +186,6 @@ def __init__(self,
         self._console_index = 0
         self._console_set = False
         self._console_device_type: Optional[str] = None
-        self._console_address = os.path.join(
-            self.sock_dir, f"{self._name}.con"
-        )
         self._console_socket: Optional[socket.socket] = None
         self._remove_files: List[str] = []
         self._user_killed = False
@@ -334,9 +328,6 @@ def args(self) -> List[str]:
         return self._args
 
     def _pre_launch(self) -> None:
-        if self._console_set:
-            self._remove_files.append(self._console_address)
-
         if self._qmp_set:
             if self._monitor_address is None:
                 self._sock_pair = socket.socketpair()
@@ -918,15 +909,6 @@ def temp_dir(self) -> str:
                                               dir=self._base_temp_dir)
         return self._temp_dir
 
-    @property
-    def sock_dir(self) -> str:
-        """
-        Returns the directory used for sockfiles by this machine.
-        """
-        if self._sock_dir:
-            return self._sock_dir
-        return self.temp_dir
-
     @property
     def log_dir(self) -> str:
         """
diff --git a/python/qemu/machine/qtest.py b/python/qemu/machine/qtest.py
index 8180d3ab01..4f5ede85b2 100644
--- a/python/qemu/machine/qtest.py
+++ b/python/qemu/machine/qtest.py
@@ -135,17 +135,14 @@ def __init__(self,
                  wrapper: Sequence[str] = (),
                  name: Optional[str] = None,
                  base_temp_dir: str = "/var/tmp",
-                 sock_dir: Optional[str] = None,
                  qmp_timer: Optional[float] = None):
         # pylint: disable=too-many-arguments
 
         if name is None:
             name = "qemu-%d" % os.getpid()
-        if sock_dir is None:
-            sock_dir = base_temp_dir
         super().__init__(binary, args, wrapper=wrapper, name=name,
                          base_temp_dir=base_temp_dir,
-                         sock_dir=sock_dir, qmp_timer=qmp_timer)
+                         qmp_timer=qmp_timer)
         self._qtest: Optional[QEMUQtestProtocol] = None
         self._qtest_sock_pair: Optional[
             Tuple[socket.socket, socket.socket]] = None
diff --git a/tests/avocado/acpi-bits.py b/tests/avocado/acpi-bits.py
index 3ed286dcbd..bc2b29671e 100644
--- a/tests/avocado/acpi-bits.py
+++ b/tests/avocado/acpi-bits.py
@@ -92,17 +92,14 @@ def __init__(self,
                  base_temp_dir: str = "/var/tmp",
                  debugcon_log: str = "debugcon-log.txt",
                  debugcon_addr: str = "0x403",
-                 sock_dir: Optional[str] = None,
                  qmp_timer: Optional[float] = None):
         # pylint: disable=too-many-arguments
 
         if name is None:
             name = "qemu-bits-%d" % os.getpid()
-        if sock_dir is None:
-            sock_dir = base_temp_dir
         super().__init__(binary, args, wrapper=wrapper, name=name,
                          base_temp_dir=base_temp_dir,
-                         sock_dir=sock_dir, qmp_timer=qmp_timer)
+                         qmp_timer=qmp_timer)
         self.debugcon_log = debugcon_log
         self.debugcon_addr = debugcon_addr
         self.base_temp_dir = base_temp_dir
diff --git a/tests/avocado/avocado_qemu/__init__.py b/tests/avocado/avocado_qemu/__init__.py
index 33090903f1..cfdaf9dab7 100644
--- a/tests/avocado/avocado_qemu/__init__.py
+++ b/tests/avocado/avocado_qemu/__init__.py
@@ -322,7 +322,7 @@ def require_multiprocess(self):
     def _new_vm(self, name, *args):
         self._sd = tempfile.TemporaryDirectory(prefix="qemu_")
         vm = QEMUMachine(self.qemu_bin, base_temp_dir=self.workdir,
-                         sock_dir=self._sd.name, log_dir=self.logdir)
+                         log_dir=self.logdir)
         self.log.debug('QEMUMachine "%s" created', name)
         self.log.debug('QEMUMachine "%s" temp_dir: %s', name, vm.temp_dir)
         self.log.debug('QEMUMachine "%s" log_dir: %s', name, vm.log_dir)
diff --git a/tests/avocado/machine_aspeed.py b/tests/avocado/machine_aspeed.py
index 724ee72c02..3e8a3b0da7 100644
--- a/tests/avocado/machine_aspeed.py
+++ b/tests/avocado/machine_aspeed.py
@@ -247,7 +247,10 @@ def test_arm_ast2600_evb_buildroot_tpm(self):
         image_path = self.fetch_asset(image_url, asset_hash=image_hash,
                                       algorithm='sha256')
 
-        socket = os.path.join(self.vm.sock_dir, 'swtpm-socket')
+        # force creation of VM object, which also defines self._sd
+        vm = self.vm
+
+        socket = os.path.join(self._sd.name, 'swtpm-socket')
 
         subprocess.run(['swtpm', 'socket', '-d', '--tpm2',
                         '--tpmstate', f'dir={self.vm.temp_dir}',
diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
index ef66fbd62b..145c682713 100644
--- a/tests/qemu-iotests/iotests.py
+++ b/tests/qemu-iotests/iotests.py
@@ -823,7 +823,7 @@ def __init__(self, path_suffix=''):
         super().__init__(qemu_prog, qemu_opts, wrapper=wrapper,
                          name=name,
                          base_temp_dir=test_dir,
-                         sock_dir=sock_dir, qmp_timer=timer)
+                         qmp_timer=timer)
         self._num_drives = 0
 
     def _post_shutdown(self) -> None:
diff --git a/tests/qemu-iotests/tests/copy-before-write b/tests/qemu-iotests/tests/copy-before-write
index 2ffe092b31..d3987db942 100755
--- a/tests/qemu-iotests/tests/copy-before-write
+++ b/tests/qemu-iotests/tests/copy-before-write
@@ -44,8 +44,7 @@ class TestCbwError(iotests.QMPTestCase):
 
         opts = ['-nodefaults', '-display', 'none', '-machine', 'none']
         self.vm = QEMUMachine(iotests.qemu_prog, opts,
-                              base_temp_dir=iotests.test_dir,
-                              sock_dir=iotests.sock_dir)
+                              base_temp_dir=iotests.test_dir)
         self.vm.launch()
 
     def do_cbw_error(self, on_cbw_error):
-- 
2.41.0

Re: [PATCH v2 1/6] python/machine: move socket setup out of _base_args property

[Daniel P. Berrangé]

On Tue, Jul 25, 2023 at 02:03:32PM -0400, John Snow wrote:
> This property isn't meant to do much else besides return a list of
> strings, so move this setup back out into _pre_launch().
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine/machine.py | 5 ++---
>  1 file changed, 2 insertions(+), 3 deletions(-)

Reviewed-by: Daniel P. Berrangé <berrange@redhat.com>


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 v2 2/6] python/machine: close sock_pair in cleanup path

[Daniel P. Berrangé]

On Tue, Jul 25, 2023 at 02:03:33PM -0400, John Snow wrote:
> If everything has gone smoothly, we'll already have closed the socket we
> gave to the child during post_launch. The other half of the pair that we
> gave to the QMP connection should, likewise, be definitively closed by
> now.
> 
> However, in the cleanup path, it's possible we've created the socketpair
> but flubbed the launch and need to clean up resources. These resources
> *would* be handled by the garbage collector, but that can happen at
> unpredictable times. Nicer to just clean them up synchronously on the
> exit path, here.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine/machine.py | 5 +++++
>  1 file changed, 5 insertions(+)
> 
> diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
> index 8be0f684fe..26f0fb8a81 100644
> --- a/python/qemu/machine/machine.py
> +++ b/python/qemu/machine/machine.py
> @@ -395,6 +395,11 @@ def _post_shutdown(self) -> None:
>          finally:
>              assert self._qmp_connection is None
>  
> +        if self._sock_pair:
> +            self._sock_pair[0].close()
> +            self._sock_pair[1].close()
> +            self._sock_pair = None
> +

Reviewed-by: Daniel P. Berrangé <berrange@redhat.com>

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 v2 3/6] python/console_socket: accept existing FD in initializer

[Daniel P. Berrangé]

On Tue, Jul 25, 2023 at 02:03:34PM -0400, John Snow wrote:
> Useful if we want to use ConsoleSocket() for a socket created by
> socketpair().
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine/console_socket.py | 29 +++++++++++++++++++--------
>  1 file changed, 21 insertions(+), 8 deletions(-)

Reviewed-by: Daniel P. Berrangé <berrange@redhat.com>

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 v2 4/6] python/machine: use socketpair() for console connections

[Daniel P. Berrangé]

On Tue, Jul 25, 2023 at 02:03:35PM -0400, John Snow wrote:
> Create a socketpair for the console output. This should help eliminate
> race conditions around console text early in the boot process that might
> otherwise have been dropped on the floor before being able to connect to
> QEMU under "server,nowait".
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine/machine.py | 30 +++++++++++++++++++++++++++---
>  1 file changed, 27 insertions(+), 3 deletions(-)

Reviewed-by: Daniel P. Berrangé <berrange@redhat.com>

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 v2 5/6] python/machine: use socketpair() for qtest connection

[Daniel P. Berrangé]

On Tue, Jul 25, 2023 at 02:03:36PM -0400, John Snow wrote:
> Like the QMP and console sockets, begin using socketpairs for the qtest
> connection, too. After this patch, we'll be able to remove the vestigial
> sock_dir argument, but that cleanup is best done in its own patch.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine/qtest.py | 49 +++++++++++++++++++++++++++++-------
>  1 file changed, 40 insertions(+), 9 deletions(-)

Reviewed-by: Daniel P. Berrangé <berrange@redhat.com>

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 v2 6/6] python/machine: remove unused sock_dir argument

[Daniel P. Berrangé]

On Tue, Jul 25, 2023 at 02:03:37PM -0400, John Snow wrote:
> By using a socketpair for all of the sockets managed by the VM class and
> its extensions, we don't need the sock_dir argument anymore, so remove
> it.
> 
> We only added this argument so that we could specify a second, shorter
> temporary directory for cases where the temp/log dirs were "too long" as
> a socket name on macOS. We don't need it for this class now. In one
> case, avocado testing takes over responsibility for creating an
> appropriate sockdir.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/machine/machine.py             | 18 ------------------
>  python/qemu/machine/qtest.py               |  5 +----
>  tests/avocado/acpi-bits.py                 |  5 +----
>  tests/avocado/avocado_qemu/__init__.py     |  2 +-
>  tests/avocado/machine_aspeed.py            |  5 ++++-
>  tests/qemu-iotests/iotests.py              |  2 +-
>  tests/qemu-iotests/tests/copy-before-write |  3 +--
>  7 files changed, 9 insertions(+), 31 deletions(-)

Reviewed-by: Daniel P. Berrangé <berrange@redhat.com>

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 v2 6/6] python/machine: remove unused sock_dir argument

[John Snow]

On Tue, Jul 25, 2023 at 2:26 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
>
> On Tue, Jul 25, 2023 at 02:03:37PM -0400, John Snow wrote:
> > By using a socketpair for all of the sockets managed by the VM class and
> > its extensions, we don't need the sock_dir argument anymore, so remove
> > it.
> >
> > We only added this argument so that we could specify a second, shorter
> > temporary directory for cases where the temp/log dirs were "too long" as
> > a socket name on macOS. We don't need it for this class now. In one
> > case, avocado testing takes over responsibility for creating an
> > appropriate sockdir.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >  python/qemu/machine/machine.py             | 18 ------------------
> >  python/qemu/machine/qtest.py               |  5 +----
> >  tests/avocado/acpi-bits.py                 |  5 +----
> >  tests/avocado/avocado_qemu/__init__.py     |  2 +-
> >  tests/avocado/machine_aspeed.py            |  5 ++++-
> >  tests/qemu-iotests/iotests.py              |  2 +-
> >  tests/qemu-iotests/tests/copy-before-write |  3 +--
> >  7 files changed, 9 insertions(+), 31 deletions(-)
>
> Reviewed-by: Daniel P. Berrangé <berrange@redhat.com>
>

Thanks!

I don't know if we want this for *this* cycle or not, it's "only
testing code" and it should hopefully be harmless. If it makes the
tests more reliable, it might be worth it. I don't have strong
feelings one way or the other, we've lived without it for so long
as-is.

I'll see what Peter says.

--js

> 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 v2 6/6] python/machine: remove unused sock_dir argument

[Daniel P. Berrangé]

On Tue, Jul 25, 2023 at 02:33:36PM -0400, John Snow wrote:
> On Tue, Jul 25, 2023 at 2:26 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
> >
> > On Tue, Jul 25, 2023 at 02:03:37PM -0400, John Snow wrote:
> > > By using a socketpair for all of the sockets managed by the VM class and
> > > its extensions, we don't need the sock_dir argument anymore, so remove
> > > it.
> > >
> > > We only added this argument so that we could specify a second, shorter
> > > temporary directory for cases where the temp/log dirs were "too long" as
> > > a socket name on macOS. We don't need it for this class now. In one
> > > case, avocado testing takes over responsibility for creating an
> > > appropriate sockdir.
> > >
> > > Signed-off-by: John Snow <jsnow@redhat.com>
> > > ---
> > >  python/qemu/machine/machine.py             | 18 ------------------
> > >  python/qemu/machine/qtest.py               |  5 +----
> > >  tests/avocado/acpi-bits.py                 |  5 +----
> > >  tests/avocado/avocado_qemu/__init__.py     |  2 +-
> > >  tests/avocado/machine_aspeed.py            |  5 ++++-
> > >  tests/qemu-iotests/iotests.py              |  2 +-
> > >  tests/qemu-iotests/tests/copy-before-write |  3 +--
> > >  7 files changed, 9 insertions(+), 31 deletions(-)
> >
> > Reviewed-by: Daniel P. Berrangé <berrange@redhat.com>
> >
> 
> Thanks!
> 
> I don't know if we want this for *this* cycle or not, it's "only
> testing code" and it should hopefully be harmless. If it makes the
> tests more reliable, it might be worth it. I don't have strong
> feelings one way or the other, we've lived without it for so long
> as-is.
> 
> I'll see what Peter says.

Although it does affect end users, the biggest impact is our own
CI. Once the release is out it would help CI on stable trees,
but the big win is CI on master.

I'd verge towards skipping this during freeze and applying to
master after release. Then propose cherry-pick to stable once
it has had some soak time in our real CI.


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 v2 1/6] python/machine: move socket setup out of _base_args property

[Ani Sinha]

> On 25-Jul-2023, at 11:33 PM, John Snow <jsnow@redhat.com> wrote:
> 
> This property isn't meant to do much else besides return a list of
> strings, so move this setup back out into _pre_launch().
> 
> Signed-off-by: John Snow <jsnow@redhat.com>

Reviewed-by: Ani Sinha <anisinha@redhat.com>

> ---
> python/qemu/machine/machine.py | 5 ++---
> 1 file changed, 2 insertions(+), 3 deletions(-)
> 
> diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
> index c16a0b6fed..8be0f684fe 100644
> --- a/python/qemu/machine/machine.py
> +++ b/python/qemu/machine/machine.py
> @@ -300,9 +300,7 @@ def _base_args(self) -> List[str]:
> 
>         if self._qmp_set:
>             if self._sock_pair:
> -                fd = self._sock_pair[0].fileno()
> -                os.set_inheritable(fd, True)
> -                moncdev = f"socket,id=mon,fd={fd}"
> +                moncdev = f"socket,id=mon,fd={self._sock_pair[0].fileno()}"
>             elif isinstance(self._monitor_address, tuple):
>                 moncdev = "socket,id=mon,host={},port={}".format(
>                     *self._monitor_address
> @@ -339,6 +337,7 @@ def _pre_launch(self) -> None:
>         if self._qmp_set:
>             if self._monitor_address is None:
>                 self._sock_pair = socket.socketpair()
> +                os.set_inheritable(self._sock_pair[0].fileno(), True)
>                 sock = self._sock_pair[1]
>             if isinstance(self._monitor_address, str):
>                 self._remove_files.append(self._monitor_address)
> -- 
> 2.41.0
> 

Re: [PATCH v2 2/6] python/machine: close sock_pair in cleanup path

[Ani Sinha]

> On 25-Jul-2023, at 11:48 PM, Daniel P. Berrangé <berrange@redhat.com> wrote:
> 
> On Tue, Jul 25, 2023 at 02:03:33PM -0400, John Snow wrote:
>> If everything has gone smoothly, we'll already have closed the socket we
>> gave to the child during post_launch. The other half of the pair that we
>> gave to the QMP connection should, likewise, be definitively closed by
>> now.
>> 
>> However, in the cleanup path, it's possible we've created the socketpair
>> but flubbed the launch and need to clean up resources. These resources
>> *would* be handled by the garbage collector, but that can happen at
>> unpredictable times. Nicer to just clean them up synchronously on the
>> exit path, here.
>> 
>> Signed-off-by: John Snow <jsnow@redhat.com>

Reviewed-by: Ani Sinha <anisinha@redhat.com>

>> ---
>> python/qemu/machine/machine.py | 5 +++++
>> 1 file changed, 5 insertions(+)
>> 
>> diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
>> index 8be0f684fe..26f0fb8a81 100644
>> --- a/python/qemu/machine/machine.py
>> +++ b/python/qemu/machine/machine.py
>> @@ -395,6 +395,11 @@ def _post_shutdown(self) -> None:
>>         finally:
>>             assert self._qmp_connection is None
>> 
>> +        if self._sock_pair:
>> +            self._sock_pair[0].close()
>> +            self._sock_pair[1].close()
>> +            self._sock_pair = None
>> +
> 
> Reviewed-by: Daniel P. Berrangé <berrange@redhat.com>
> 
> 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 v2 4/6] python/machine: use socketpair() for console connections

[Ani Sinha]

> On 25-Jul-2023, at 11:33 PM, John Snow <jsnow@redhat.com> wrote:
> 
> Create a socketpair for the console output. This should help eliminate
> race conditions around console text early in the boot process that might
> otherwise have been dropped on the floor before being able to connect to
> QEMU under "server,nowait".
> 
> Signed-off-by: John Snow <jsnow@redhat.com>

Thanks for doing this. I recall we spoke about this late last year in the context of fixing my bios-bits avocado test and adding a console output there.
Except the concern below,

Reviewed-by: Ani Sinha <anisinha@redhat.com>


> ---
> python/qemu/machine/machine.py | 30 +++++++++++++++++++++++++++---
> 1 file changed, 27 insertions(+), 3 deletions(-)
> 
> diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
> index 26f0fb8a81..09f214c95c 100644
> --- a/python/qemu/machine/machine.py
> +++ b/python/qemu/machine/machine.py
> @@ -159,6 +159,8 @@ def __init__(self,
> 
>         self._name = name or f"{id(self):x}"
>         self._sock_pair: Optional[Tuple[socket.socket, socket.socket]] = None
> +        self._cons_sock_pair: Optional[
> +            Tuple[socket.socket, socket.socket]] = None
>         self._temp_dir: Optional[str] = None
>         self._base_temp_dir = base_temp_dir
>         self._sock_dir = sock_dir
> @@ -315,8 +317,9 @@ def _base_args(self) -> List[str]:
>         for _ in range(self._console_index):
>             args.extend(['-serial', 'null'])
>         if self._console_set:
> -            chardev = ('socket,id=console,path=%s,server=on,wait=off' %
> -                       self._console_address)
> +            assert self._cons_sock_pair is not None
> +            fd = self._cons_sock_pair[0].fileno()
> +            chardev = f"socket,id=console,fd={fd}"
>             args.extend(['-chardev', chardev])
>             if self._console_device_type is None:
>                 args.extend(['-serial', 'chardev:console'])
> @@ -351,6 +354,10 @@ def _pre_launch(self) -> None:
>                 nickname=self._name
>             )
> 
> +        if self._console_set:
> +            self._cons_sock_pair = socket.socketpair()
> +            os.set_inheritable(self._cons_sock_pair[0].fileno(), True)
> +
>         # NOTE: Make sure any opened resources are *definitely* freed in
>         # _post_shutdown()!
>         # pylint: disable=consider-using-with
> @@ -368,6 +375,9 @@ def _pre_launch(self) -> None:
>     def _post_launch(self) -> None:
>         if self._sock_pair:
>             self._sock_pair[0].close()
> +        if self._cons_sock_pair:
> +            self._cons_sock_pair[0].close()
> +
>         if self._qmp_connection:
>             if self._sock_pair:
>                 self._qmp.connect()
> @@ -518,6 +528,11 @@ def _early_cleanup(self) -> None:
>             self._console_socket.close()
>             self._console_socket = None
> 
> +        if self._cons_sock_pair:
> +            self._cons_sock_pair[0].close()
> +            self._cons_sock_pair[1].close()
> +            self._cons_sock_pair = None
> +
>     def _hard_shutdown(self) -> None:
>         """
>         Perform early cleanup, kill the VM, and wait for it to terminate.
> @@ -878,10 +893,19 @@ def console_socket(self) -> socket.socket:
>         Returns a socket connected to the console
>         """
>         if self._console_socket is None:
> +            if not self._console_set:
> +                raise QEMUMachineError(
> +                    "Attempt to access console socket with no connection")
> +            assert self._cons_sock_pair is not None
> +            # os.dup() is used here for sock_fd because otherwise we'd
> +            # have two rich python socket objects that would each try to
> +            # close the same underlying fd when either one gets garbage
> +            # collected.
>             self._console_socket = console_socket.ConsoleSocket(
> -                self._console_address,
> +                sock_fd=os.dup(self._cons_sock_pair[1].fileno()),
>                 file=self._console_log_path,
>                 drain=self._drain_console)
> +            self._cons_sock_pair[1].close()

I am not 100% sure but should we save the new sock_fd here? Like
self._cons_sock_pair[1] = sock_fd ;

Then next time console_socket() is invoked, the correct fd will be duped.

>         return self._console_socket
> 
>     @property
> -- 
> 2.41.0
> 

Re: [PATCH v2 4/6] python/machine: use socketpair() for console connections

[John Snow]

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

On Wed, Jul 26, 2023, 6:50 AM Ani Sinha <anisinha@redhat.com> wrote:

>
>
> > On 25-Jul-2023, at 11:33 PM, John Snow <jsnow@redhat.com> wrote:
> >
> > Create a socketpair for the console output. This should help eliminate
> > race conditions around console text early in the boot process that might
> > otherwise have been dropped on the floor before being able to connect to
> > QEMU under "server,nowait".
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
>
> Thanks for doing this. I recall we spoke about this late last year in the
> context of fixing my bios-bits avocado test and adding a console output
> there.
>

Yep! I think you need a few more changes to do what you wanted. IIRC, you
also want to be able to drain the console log while waiting for the vm to
terminate of its own accord, which I don't support yet.

(If you use console socket's self draining mode, it should be possible to
forego the early termination of the console socket and allow this behavior.
Maybe I can work that in now...)

Anything else I'm forgetting ...?

Except the concern below,
>
> Reviewed-by: Ani Sinha <anisinha@redhat.com>
>

Thanks 😊


>
> > ---
> > python/qemu/machine/machine.py | 30 +++++++++++++++++++++++++++---
> > 1 file changed, 27 insertions(+), 3 deletions(-)
> >
> > diff --git a/python/qemu/machine/machine.py
> b/python/qemu/machine/machine.py
> > index 26f0fb8a81..09f214c95c 100644
> > --- a/python/qemu/machine/machine.py
> > +++ b/python/qemu/machine/machine.py
> > @@ -159,6 +159,8 @@ def __init__(self,
> >
> >         self._name = name or f"{id(self):x}"
> >         self._sock_pair: Optional[Tuple[socket.socket, socket.socket]] =
> None
> > +        self._cons_sock_pair: Optional[
> > +            Tuple[socket.socket, socket.socket]] = None
> >         self._temp_dir: Optional[str] = None
> >         self._base_temp_dir = base_temp_dir
> >         self._sock_dir = sock_dir
> > @@ -315,8 +317,9 @@ def _base_args(self) -> List[str]:
> >         for _ in range(self._console_index):
> >             args.extend(['-serial', 'null'])
> >         if self._console_set:
> > -            chardev = ('socket,id=console,path=%s,server=on,wait=off' %
> > -                       self._console_address)
> > +            assert self._cons_sock_pair is not None
> > +            fd = self._cons_sock_pair[0].fileno()
> > +            chardev = f"socket,id=console,fd={fd}"
> >             args.extend(['-chardev', chardev])
> >             if self._console_device_type is None:
> >                 args.extend(['-serial', 'chardev:console'])
> > @@ -351,6 +354,10 @@ def _pre_launch(self) -> None:
> >                 nickname=self._name
> >             )
> >
> > +        if self._console_set:
> > +            self._cons_sock_pair = socket.socketpair()
> > +            os.set_inheritable(self._cons_sock_pair[0].fileno(), True)
> > +
> >         # NOTE: Make sure any opened resources are *definitely* freed in
> >         # _post_shutdown()!
> >         # pylint: disable=consider-using-with
> > @@ -368,6 +375,9 @@ def _pre_launch(self) -> None:
> >     def _post_launch(self) -> None:
> >         if self._sock_pair:
> >             self._sock_pair[0].close()
> > +        if self._cons_sock_pair:
> > +            self._cons_sock_pair[0].close()
> > +
> >         if self._qmp_connection:
> >             if self._sock_pair:
> >                 self._qmp.connect()
> > @@ -518,6 +528,11 @@ def _early_cleanup(self) -> None:
> >             self._console_socket.close()
> >             self._console_socket = None
> >
> > +        if self._cons_sock_pair:
> > +            self._cons_sock_pair[0].close()
> > +            self._cons_sock_pair[1].close()
> > +            self._cons_sock_pair = None
> > +
> >     def _hard_shutdown(self) -> None:
> >         """
> >         Perform early cleanup, kill the VM, and wait for it to terminate.
> > @@ -878,10 +893,19 @@ def console_socket(self) -> socket.socket:
> >         Returns a socket connected to the console
> >         """
> >         if self._console_socket is None:
> > +            if not self._console_set:
> > +                raise QEMUMachineError(
> > +                    "Attempt to access console socket with no
> connection")
> > +            assert self._cons_sock_pair is not None
> > +            # os.dup() is used here for sock_fd because otherwise we'd
> > +            # have two rich python socket objects that would each try to
> > +            # close the same underlying fd when either one gets garbage
> > +            # collected.
> >             self._console_socket = console_socket.ConsoleSocket(
> > -                self._console_address,
> > +                sock_fd=os.dup(self._cons_sock_pair[1].fileno()),
> >                 file=self._console_log_path,
> >                 drain=self._drain_console)
> > +            self._cons_sock_pair[1].close()
>
> I am not 100% sure but should we save the new sock_fd here? Like
> self._cons_sock_pair[1] = sock_fd ;
>
> Then next time console_socket() is invoked, the correct fd will be duped.
>

It should be cached to self._console_socket, so it should return the same
instance every time, no second call to os.dup().

self._console_socket takes ownership of the duplicated fd and we retain
ownership of _cons_sock_pair[1] which we then close right after.

All three sockets are closed and None'd if applicable during
_early_cleanup().


> >         return self._console_socket
> >
> >     @property
> > --
> > 2.41.0
> >
>
>

[-- Attachment #2: Type: text/html, Size: 8053 bytes --]

Re: [PATCH v2 3/6] python/console_socket: accept existing FD in initializer

[Ani Sinha]

> On 25-Jul-2023, at 11:33 PM, John Snow <jsnow@redhat.com> wrote:
> 
> Useful if we want to use ConsoleSocket() for a socket created by
> socketpair().
> 
> Signed-off-by: John Snow <jsnow@redhat.com>

Reviewed-by: Ani Sinha <anisinha@redhat.com>

> ---
> python/qemu/machine/console_socket.py | 29 +++++++++++++++++++--------
> 1 file changed, 21 insertions(+), 8 deletions(-)
> 
> diff --git a/python/qemu/machine/console_socket.py b/python/qemu/machine/console_socket.py
> index 4e28ba9bb2..0a4e09ffc7 100644
> --- a/python/qemu/machine/console_socket.py
> +++ b/python/qemu/machine/console_socket.py
> @@ -24,19 +24,32 @@ class ConsoleSocket(socket.socket):
>     """
>     ConsoleSocket represents a socket attached to a char device.
> 
> -    Optionally (if drain==True), drains the socket and places the bytes
> -    into an in memory buffer for later processing.
> -
> -    Optionally a file path can be passed in and we will also
> -    dump the characters to this file for debugging purposes.
> +    :param address: An AF_UNIX path or address.
> +    :param sock_fd: Optionally, an existing socket file descriptor.
> +                    One of address or sock_fd must be specified.
> +    :param file: Optionally, a filename to log to.
> +    :param drain: Optionally, drains the socket and places the bytes
> +                  into an in memory buffer for later processing.
>     """
> -    def __init__(self, address: str, file: Optional[str] = None,
> +    def __init__(self,
> +                 address: Optional[str] = None,
> +                 sock_fd: Optional[int] = None,
> +                 file: Optional[str] = None,
>                  drain: bool = False):
> +        if address is None and sock_fd is None:
> +            raise ValueError("one of 'address' or 'sock_fd' must be specified")
> +        if address is not None and sock_fd is not None:
> +            raise ValueError("can't specify both 'address' and 'sock_fd'")
> +
>         self._recv_timeout_sec = 300.0
>         self._sleep_time = 0.5
>         self._buffer: Deque[int] = deque()
> -        socket.socket.__init__(self, socket.AF_UNIX, socket.SOCK_STREAM)
> -        self.connect(address)
> +        if address is not None:
> +            socket.socket.__init__(self, socket.AF_UNIX, socket.SOCK_STREAM)
> +            self.connect(address)
> +        else:
> +            assert sock_fd is not None
> +            socket.socket.__init__(self, fileno=sock_fd)
>         self._logfile = None
>         if file:
>             # pylint: disable=consider-using-with
> -- 
> 2.41.0
> 

Re: [PATCH v2 4/6] python/machine: use socketpair() for console connections

[Ani Sinha]

> On 26-Jul-2023, at 10:51 PM, John Snow <jsnow@redhat.com> wrote:
> 
> 
> 
> On Wed, Jul 26, 2023, 6:50 AM Ani Sinha <anisinha@redhat.com> wrote:
> 
> 
> > On 25-Jul-2023, at 11:33 PM, John Snow <jsnow@redhat.com> wrote:
> > 
> > Create a socketpair for the console output. This should help eliminate
> > race conditions around console text early in the boot process that might
> > otherwise have been dropped on the floor before being able to connect to
> > QEMU under "server,nowait".
> > 
> > Signed-off-by: John Snow <jsnow@redhat.com>
> 
> Thanks for doing this. I recall we spoke about this late last year in the context of fixing my bios-bits avocado test and adding a console output there.
> 
> Yep! I think you need a few more changes to do what you wanted. IIRC, you also want to be able to drain the console log while waiting for the vm to terminate of its own accord, which I don't support yet.
> 
> (If you use console socket's self draining mode, it should be possible to forego the early termination of the console socket and allow this behavior. Maybe I can work that in now...)

yeah we want to collect all the console logs while the VM is running until it self terminates. Maybe you can add a flag for this behavior to not early terminate the socket. I think we need to add mathods to keep reading the socket and write to a file until the socket is closed. Maybe QemuMachine needs to be enhanced. 

> 
> Anything else I'm forgetting ...?
> 
> Except the concern below,
> 
> Reviewed-by: Ani Sinha <anisinha@redhat.com>
> 
> Thanks 😊 
> 
> 
> 
> > ---
> > python/qemu/machine/machine.py | 30 +++++++++++++++++++++++++++---
> > 1 file changed, 27 insertions(+), 3 deletions(-)
> > 
> > diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
> > index 26f0fb8a81..09f214c95c 100644
> > --- a/python/qemu/machine/machine.py
> > +++ b/python/qemu/machine/machine.py
> > @@ -159,6 +159,8 @@ def __init__(self,
> > 
> >         self._name = name or f"{id(self):x}"
> >         self._sock_pair: Optional[Tuple[socket.socket, socket.socket]] = None
> > +        self._cons_sock_pair: Optional[
> > +            Tuple[socket.socket, socket.socket]] = None
> >         self._temp_dir: Optional[str] = None
> >         self._base_temp_dir = base_temp_dir
> >         self._sock_dir = sock_dir
> > @@ -315,8 +317,9 @@ def _base_args(self) -> List[str]:
> >         for _ in range(self._console_index):
> >             args.extend(['-serial', 'null'])
> >         if self._console_set:
> > -            chardev = ('socket,id=console,path=%s,server=on,wait=off' %
> > -                       self._console_address)
> > +            assert self._cons_sock_pair is not None
> > +            fd = self._cons_sock_pair[0].fileno()
> > +            chardev = f"socket,id=console,fd={fd}"
> >             args.extend(['-chardev', chardev])
> >             if self._console_device_type is None:
> >                 args.extend(['-serial', 'chardev:console'])
> > @@ -351,6 +354,10 @@ def _pre_launch(self) -> None:
> >                 nickname=self._name
> >             )
> > 
> > +        if self._console_set:
> > +            self._cons_sock_pair = socket.socketpair()
> > +            os.set_inheritable(self._cons_sock_pair[0].fileno(), True)
> > +
> >         # NOTE: Make sure any opened resources are *definitely* freed in
> >         # _post_shutdown()!
> >         # pylint: disable=consider-using-with
> > @@ -368,6 +375,9 @@ def _pre_launch(self) -> None:
> >     def _post_launch(self) -> None:
> >         if self._sock_pair:
> >             self._sock_pair[0].close()
> > +        if self._cons_sock_pair:
> > +            self._cons_sock_pair[0].close()
> > +
> >         if self._qmp_connection:
> >             if self._sock_pair:
> >                 self._qmp.connect()
> > @@ -518,6 +528,11 @@ def _early_cleanup(self) -> None:
> >             self._console_socket.close()
> >             self._console_socket = None
> > 
> > +        if self._cons_sock_pair:
> > +            self._cons_sock_pair[0].close()
> > +            self._cons_sock_pair[1].close()
> > +            self._cons_sock_pair = None
> > +
> >     def _hard_shutdown(self) -> None:
> >         """
> >         Perform early cleanup, kill the VM, and wait for it to terminate.
> > @@ -878,10 +893,19 @@ def console_socket(self) -> socket.socket:
> >         Returns a socket connected to the console
> >         """
> >         if self._console_socket is None:
> > +            if not self._console_set:
> > +                raise QEMUMachineError(
> > +                    "Attempt to access console socket with no connection")
> > +            assert self._cons_sock_pair is not None
> > +            # os.dup() is used here for sock_fd because otherwise we'd
> > +            # have two rich python socket objects that would each try to
> > +            # close the same underlying fd when either one gets garbage
> > +            # collected.
> >             self._console_socket = console_socket.ConsoleSocket(
> > -                self._console_address,
> > +                sock_fd=os.dup(self._cons_sock_pair[1].fileno()),
> >                 file=self._console_log_path,
> >                 drain=self._drain_console)
> > +            self._cons_sock_pair[1].close()
> 
> I am not 100% sure but should we save the new sock_fd here? Like
> self._cons_sock_pair[1] = sock_fd ;
> 
> Then next time console_socket() is invoked, the correct fd will be duped.
> 
> It should be cached to self._console_socket, so it should return the same instance every time, no second call to os.dup().

yeah I missed your patch 3. All good now.

> 
> self._console_socket takes ownership of the duplicated fd and we retain ownership of _cons_sock_pair[1] which we then close right after.
> 
> All three sockets are closed and None'd if applicable during _early_cleanup().
> 
> 
> >         return self._console_socket
> > 
> >     @property
> > -- 
> > 2.41.0
> > 

Re: [PATCH v2 4/6] python/machine: use socketpair() for console connections

[Ani Sinha]

> On 27-Jul-2023, at 11:22 AM, Ani Sinha <anisinha@redhat.com> wrote:
> 
> 
> 
>> On 26-Jul-2023, at 10:51 PM, John Snow <jsnow@redhat.com> wrote:
>> 
>> 
>> 
>> On Wed, Jul 26, 2023, 6:50 AM Ani Sinha <anisinha@redhat.com> wrote:
>> 
>> 
>>> On 25-Jul-2023, at 11:33 PM, John Snow <jsnow@redhat.com> wrote:
>>> 
>>> Create a socketpair for the console output. This should help eliminate
>>> race conditions around console text early in the boot process that might
>>> otherwise have been dropped on the floor before being able to connect to
>>> QEMU under "server,nowait".
>>> 
>>> Signed-off-by: John Snow <jsnow@redhat.com>
>> 
>> Thanks for doing this. I recall we spoke about this late last year in the context of fixing my bios-bits avocado test and adding a console output there.
>> 
>> Yep! I think you need a few more changes to do what you wanted. IIRC, you also want to be able to drain the console log while waiting for the vm to terminate of its own accord, which I don't support yet.
>> 
>> (If you use console socket's self draining mode, it should be possible to forego the early termination of the console socket and allow this behavior. Maybe I can work that in now...)
> 
> yeah we want to collect all the console logs while the VM is running until it self terminates. Maybe you can add a flag for this behavior to not early terminate the socket. I think we need to add mathods to keep reading the socket and write to a file until the socket is closed. Maybe QemuMachine needs to be enhanced. 

I see something like

      console_drainer = datadrainer.LineLogger(self.vm.console_socket.fileno(),
                                                 logger=self.log.getChild('console'))
        console_drainer.start()

in LinuxTest. Maybe I would be able to use something similar.

> 
>> 
>> Anything else I'm forgetting ...?
>> 
>> Except the concern below,
>> 
>> Reviewed-by: Ani Sinha <anisinha@redhat.com>
>> 
>> Thanks 😊 
>> 
>> 
>> 
>>> ---
>>> python/qemu/machine/machine.py | 30 +++++++++++++++++++++++++++---
>>> 1 file changed, 27 insertions(+), 3 deletions(-)
>>> 
>>> diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
>>> index 26f0fb8a81..09f214c95c 100644
>>> --- a/python/qemu/machine/machine.py
>>> +++ b/python/qemu/machine/machine.py
>>> @@ -159,6 +159,8 @@ def __init__(self,
>>> 
>>>        self._name = name or f"{id(self):x}"
>>>        self._sock_pair: Optional[Tuple[socket.socket, socket.socket]] = None
>>> +        self._cons_sock_pair: Optional[
>>> +            Tuple[socket.socket, socket.socket]] = None
>>>        self._temp_dir: Optional[str] = None
>>>        self._base_temp_dir = base_temp_dir
>>>        self._sock_dir = sock_dir
>>> @@ -315,8 +317,9 @@ def _base_args(self) -> List[str]:
>>>        for _ in range(self._console_index):
>>>            args.extend(['-serial', 'null'])
>>>        if self._console_set:
>>> -            chardev = ('socket,id=console,path=%s,server=on,wait=off' %
>>> -                       self._console_address)
>>> +            assert self._cons_sock_pair is not None
>>> +            fd = self._cons_sock_pair[0].fileno()
>>> +            chardev = f"socket,id=console,fd={fd}"
>>>            args.extend(['-chardev', chardev])
>>>            if self._console_device_type is None:
>>>                args.extend(['-serial', 'chardev:console'])
>>> @@ -351,6 +354,10 @@ def _pre_launch(self) -> None:
>>>                nickname=self._name
>>>            )
>>> 
>>> +        if self._console_set:
>>> +            self._cons_sock_pair = socket.socketpair()
>>> +            os.set_inheritable(self._cons_sock_pair[0].fileno(), True)
>>> +
>>>        # NOTE: Make sure any opened resources are *definitely* freed in
>>>        # _post_shutdown()!
>>>        # pylint: disable=consider-using-with
>>> @@ -368,6 +375,9 @@ def _pre_launch(self) -> None:
>>>    def _post_launch(self) -> None:
>>>        if self._sock_pair:
>>>            self._sock_pair[0].close()
>>> +        if self._cons_sock_pair:
>>> +            self._cons_sock_pair[0].close()
>>> +
>>>        if self._qmp_connection:
>>>            if self._sock_pair:
>>>                self._qmp.connect()
>>> @@ -518,6 +528,11 @@ def _early_cleanup(self) -> None:
>>>            self._console_socket.close()
>>>            self._console_socket = None
>>> 
>>> +        if self._cons_sock_pair:
>>> +            self._cons_sock_pair[0].close()
>>> +            self._cons_sock_pair[1].close()
>>> +            self._cons_sock_pair = None
>>> +
>>>    def _hard_shutdown(self) -> None:
>>>        """
>>>        Perform early cleanup, kill the VM, and wait for it to terminate.
>>> @@ -878,10 +893,19 @@ def console_socket(self) -> socket.socket:
>>>        Returns a socket connected to the console
>>>        """
>>>        if self._console_socket is None:
>>> +            if not self._console_set:
>>> +                raise QEMUMachineError(
>>> +                    "Attempt to access console socket with no connection")
>>> +            assert self._cons_sock_pair is not None
>>> +            # os.dup() is used here for sock_fd because otherwise we'd
>>> +            # have two rich python socket objects that would each try to
>>> +            # close the same underlying fd when either one gets garbage
>>> +            # collected.
>>>            self._console_socket = console_socket.ConsoleSocket(
>>> -                self._console_address,
>>> +                sock_fd=os.dup(self._cons_sock_pair[1].fileno()),
>>>                file=self._console_log_path,
>>>                drain=self._drain_console)
>>> +            self._cons_sock_pair[1].close()
>> 
>> I am not 100% sure but should we save the new sock_fd here? Like
>> self._cons_sock_pair[1] = sock_fd ;
>> 
>> Then next time console_socket() is invoked, the correct fd will be duped.
>> 
>> It should be cached to self._console_socket, so it should return the same instance every time, no second call to os.dup().
> 
> yeah I missed your patch 3. All good now.
> 
>> 
>> self._console_socket takes ownership of the duplicated fd and we retain ownership of _cons_sock_pair[1] which we then close right after.
>> 
>> All three sockets are closed and None'd if applicable during _early_cleanup().
>> 
>> 
>>>        return self._console_socket
>>> 
>>>    @property
>>> -- 
>>> 2.41.0

Re: [PATCH v2 4/6] python/machine: use socketpair() for console connections

[Daniel P. Berrangé]

On Thu, Jul 27, 2023 at 11:22:35AM +0530, Ani Sinha wrote:
> 
> 
> > On 26-Jul-2023, at 10:51 PM, John Snow <jsnow@redhat.com> wrote:
> > 
> > 
> > 
> > On Wed, Jul 26, 2023, 6:50 AM Ani Sinha <anisinha@redhat.com> wrote:
> > 
> > 
> > > On 25-Jul-2023, at 11:33 PM, John Snow <jsnow@redhat.com> wrote:
> > > 
> > > Create a socketpair for the console output. This should help eliminate
> > > race conditions around console text early in the boot process that might
> > > otherwise have been dropped on the floor before being able to connect to
> > > QEMU under "server,nowait".
> > > 
> > > Signed-off-by: John Snow <jsnow@redhat.com>
> > 
> > Thanks for doing this. I recall we spoke about this late last year in the context of fixing my bios-bits avocado test and adding a console output there.
> > 
> > Yep! I think you need a few more changes to do what you wanted. IIRC, you also want to be able to drain the console log while waiting for the vm to terminate of its own accord, which I don't support yet.
> > 
> > (If you use console socket's self draining mode, it should be possible to forego the early termination of the console socket and allow this behavior. Maybe I can work that in now...)
> 
> yeah we want to collect all the console logs while the VM is running until it self terminates. Maybe you can add a flag for this behavior to not early terminate the socket. I think we need to add mathods to keep reading the socket and write to a file until the socket is closed. Maybe QemuMachine needs to be enhanced.


There's no special code required for that - any -chardev backend can
have logfile=/some/path added to it.


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 v2 0/6] python/machine: use socketpair() for console socket

[Peter Maydell]

On Tue, 25 Jul 2023 at 19:04, John Snow <jsnow@redhat.com> wrote:
>
> Like we did for the QMP socket, use socketpair() for the console socket
> so that hopefully there isn't a race condition during early boot where
> data might get dropped on the floor.
>
> May or may not help with various race conditions where early console
> output is not showing up in the logs and/or potentially being missed by
> wait_for_console_pattern.
>

This seems to improve the test I was having trouble with on s390
(machine_aarch64_sbsaref.py:Aarch64SbsarefMachine.test_sbsaref_edk2_firmware)

However it still fails sometimes, apparently we get the first line
of output from the guest but lose a couple of subsequent lines.
Here's a failing log:

2023-07-27 12:55:29,870 protocol         L0481 DEBUG| Transitioning
from 'Runstate.CONNECTING' to 'Runstate.RUNNING'.
2023-07-27 12:55:29,930 __init__         L0153 DEBUG| NOTICE:  Booting
Trusted Firmware
2023-07-27 12:55:29,955 __init__         L0153 DEBUG| NOTICE:  BL1: Booting BL2
2023-07-27 12:55:29,955 __init__         L0153 DEBUG| NOTICE:  BL2:
v2.9(release):v2.9.0-51-gc0d8ee386
2023-07-27 12:55:29,955 __init__         L0153 DEBUG| NOTICE:  BL2:
Built : 16:44:16, May 30 2023
2023-07-27 12:55:30,092 __init__         L0153 DEBUG| NOTICE:  BL1: Booting BL31
2023-07-27 12:55:30,092 __init__         L0153 DEBUG| NOTICE:  BL31:
v2.9(release):v2.9.0-51-gc0d8ee386
2023-07-27 12:55:30,092 __init__         L0153 DEBUG| NOTICE:  BL31:
Built : 16:44:16, May 30 2023
2023-07-27 12:55:30,092 __init__         L0153 DEBUG| UEFI firmware
(version 1.0 built at 17:14:57 on Mar 21 2023)
2023-07-27 12:55:45,281 __init__         L0153 DEBUG|
ESC[2JESC[04DESC[=3hESC[2JESC[09DESC[2JESC[04DESC[0mESC[30mESC[40m
2023-07-27 12:55:45,538 __init__         L0153 DEBUG|
ESC[01;01HESC[0mESC[34mESC[47m
2023-07-27 12:55:45,642 __init__         L0153 DEBUG|
ESC[01;01HESC[02;02HQEMU SBSA-REF MachineESC[03;02Harm-virtESC[44C2.00
GHzESC[04;02H1.0ESC[49C1024 MB
RAMESC[05;02HESC[52CESC[06;02HESC[52CESC[0mESC[37mESC[40mESC[21;01H
2023-07-27 12:55:45,840 __init__         L0153 DEBUG|
ESC[21;01HESC[0mESC[30mESC[40mESC[25;53H  ESC[01D  ESC[01D  ESC[01D
ESC[01D  ESC[01D  ESC[01D  ESC[01D  ESC[01D  ESC[01D  ESC[01D  ESC[01D
 ESC[01D  ESC[01D  ESC[01D  ESC[01D  ESC[01D  ESC[01D  ESC[01D
ESC[01D  ESC[01D  ESC[0mESC[30mESC[47mESC[07;01H
2023-07-27 12:55:45,926 __init__         L0153 DEBUG| ESC[07;01H
2023-07-27 12:55:46,032 __init__         L0153 DEBUG|
ESC[0mESC[37mESC[40mESC[30C<Standard English>ESC[0mESC[30mESC[47m
   ESC[57D   Select Language            ESC[0mESC[34mESC[47mESC[09;01H

ESC[0mESC[30mESC[47mESC[10;01H   ESC[02D>ESC[01CDevice Manager
                               ESC[11;01H   ESC[02D>ESC[01CBoot
Manager                                          ESC[12;01H
ESC[02D>ESC[01CBoot Maintenance Manager
ESC[0mESC[34mESC[47mESC[13;01H
                ESC[0mESC[30mESC[47mESC[14;01H   Continue
                                ESC[15;01H   Reset
                            ESC[16;01H
                        ESC[17;01H
                    ESC[18;01H
                ESC[19;01H
            ESC[20;01H
2023-07-27 12:55:46,067 __init__         L0153 DEBUG|
ESC[0mESC[37mESC[40mESC[23;02H ESC[22;02H ESC[50C
   ESC[51D                          ESC[23;53H
  ESC[77D^v=Move Highlight       ESC[22;03H
ESC[23;27H<Enter>=Select Entry      ESC[0mESC[34mESC[47mESC[08;58HThis
is the option
2023-07-27 12:55:46,076 __init__         L0153 DEBUG| ESC[57Cone
adjusts to change
2023-07-27 12:55:46,076 __init__         L0153 DEBUG| ESC[57Cthe
language for the
2023-07-27 12:55:46,080 __init__         L0153 DEBUG| ESC[57Ccurrent system
2023-07-27 12:55:46,085 __init__         L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,085 __init__         L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,087 __init__         L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,090 __init__         L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,094 __init__         L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,094 __init__         L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,100 __init__         L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,101 __init__         L0153 DEBUG| ESC[57C
2023-07-27 12:58:25,379 stacktrace       L0039 ERROR|
2023-07-27 12:58:25,380 stacktrace       L0041 ERROR| Reproduced
traceback from:
/home/linux1/qemu/build/aarch64/tests/venv/lib/python3.8/site-packages/avocado/core/test.py:770
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR| Traceback (most
recent call last):
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|   File
"/home/linux1/qemu/build/aarch64/tests/venv/lib/python3.8/site-packages/avocado/core/decorators.py",
line 90, in wrapper
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|     return
function(obj, *args, **kwargs)
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|   File
"/home/linux1/qemu/build/aarch64/tests/avocado/machine_aarch64_sbsaref.py",
line 96, in test_sbsaref_edk2_firmware
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|
wait_for_console_pattern(self, "BL1: v2.9(release):v2.9")
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|   File
"/home/linux1/qemu/build/aarch64/tests/avocado/avocado_qemu/__init__.py",
line 199, in wait_for_console_pattern
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|
_console_interaction(test, success_message, failure_message, None,
vm=vm)
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|   File
"/home/linux1/qemu/build/aarch64/tests/avocado/avocado_qemu/__init__.py",
line 148, in _console_interaction
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|     msg =
console.readline().decode().strip()
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|   File
"/usr/lib/python3.8/socket.py", line 669, in readinto
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|     return
self._sock.recv_into(b)
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|   File
"/home/linux1/qemu/build/aarch64/tests/venv/lib/python3.8/site-packages/avocado/plugins/runner.py",
line 77, in sigterm_handler
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR|     raise
RuntimeError("Test interrupted by SIGTERM")
2023-07-27 12:58:25,381 stacktrace       L0045 ERROR| RuntimeError:
Test interrupted by SIGTERM

Compared to the output logs for a passing run, you can see that
although we captured the first line of output from the guest
("Booting Trusted Firmware") we missed lines 2 and 3 (the
BL1 version line and the BL1 Built: line).

2023-07-27 12:54:07,676 protocol         L0481 DEBUG| Transitioning
from 'Runstate.CONNECTING' to 'Runstate.RUNNING'.
2023-07-27 12:54:07,690 __init__         L0153 DEBUG| NOTICE:  Booting
Trusted Firmware
2023-07-27 12:54:07,691 __init__         L0153 DEBUG| NOTICE:  BL1:
v2.9(release):v2.9.0-51-gc0d8ee386
2023-07-27 12:54:07,691 __init__         L0153 DEBUG| BL1: Built :
16:44:16, May 30 2023
2023-07-27 12:54:07,754 __init__         L0153 DEBUG| NOTICE:  BL1: Booting BL2
2023-07-27 12:54:07,828 __init__         L0153 DEBUG| NOTICE:  BL2:
v2.9(release):v2.9.0-51-gc0d8ee386
2023-07-27 12:54:07,828 __init__         L0153 DEBUG| NOTICE:  BL2:
Built : 16:44:16, May 30 2023
2023-07-27 12:54:07,855 __init__         L0153 DEBUG| NOTICE:  BL1: Booting BL31
2023-07-27 12:54:07,877 __init__         L0153 DEBUG| NOTICE:  BL31:
v2.9(release):v2.9.0-51-gc0d8ee386
2023-07-27 12:54:07,883 __init__         L0153 DEBUG| NOTICE:  BL31:
Built : 16:44:16, May 30 2023
2023-07-27 12:54:07,891 __init__         L0153 DEBUG| UEFI firmware
(version 1.0 built at 17:14:57 on Mar 21 2023)
2023-07-27 12:54:18,354 __init__         L0153 DEBUG|
ESC[2JESC[04DESC[=3hESC[2JESC[09DESC[2JESC[04DESC[0mESC[30mESC[40m
2023-07-27 12:54:18,539 __init__         L0153 DEBUG|
ESC[01;01HESC[0mESC[34mESC[47m
2023-07-27 12:54:18,631 __init__         L0153 DEBUG|
ESC[01;01HESC[02;02HQEMU SBSA-REF MachineESC[03;02Harm-virtESC[44C2.00
GHzESC[04;02H1.0ESC[49C1024 MB
RAMESC[05;02HESC[52CESC[06;02HESC[52CESC[0mESC[37mESC[40mESC[21;01H
2023-07-27 12:54:18,639 machine          L0627 DEBUG| Shutting down VM
appliance; timeout=30
2023-07-27 12:54:18,639 machine          L0551 DEBUG| Attempting
graceful termination
2023-07-27 12:54:18,639 machine          L0518 DEBUG| Closing console socket
2023-07-27 12:54:18,640 machine          L0561 DEBUG| Politely asking
QEMU to terminate


thanks
-- PMM