[PATCH 00/15] Switch iotests to using Async QMP

[PATCH 00/15] Switch iotests to using Async QMP

[John Snow]

Based-on: <20210916220716.1353698-1-jsnow@redhat.com>
Based-on: <20210915162955.333025-1-jsnow@redhat.com>
          [PULL 0/2] Python patches
          [PATCH v4 00/27] python: introduce Asynchronous QMP package

Hiya,

This series continues where the first AQMP series left off and adds a
synchronous 'legacy' wrapper around the new AQMP interface, then drops
it straight into iotests to prove that AQMP is functional and totally
cool and fine.

In the event that a regression happens and I am not physically proximate
to inflict damage upon, one may set the QEMU_PYTHON_LEGACY_QMP variable
to any non-empty string as it pleases you to engage the QMP machinery
you are used to.

I'd like to try and get this committed early in the 6.2 development
cycle to give ample time to smooth over any possible regressions.
I've tested it locally and via gitlab CI and "worksforme".

John Snow (15):
  python/aqmp: add greeting property to QMPClient
  python/aqmp: add .empty() method to EventListener
  python/aqmp: Return cleared events from EventListener.clear()
  python/qmp: clear events on get_events() call
  python/qmp: add send_fd_scm directly to QEMUMonitorProtocol
  python, iotests: remove socket_scm_helper
  python/aqmp: add send_fd_scm
  python/aqmp: Create MessageModel and StandaloneModel classes
  python/machine: remove has_quit argument
  python/machine: Add support for AQMP backend
  python/aqmp: Create sync QMP wrapper for iotests
  iotests: Disable AQMP logging under non-debug modes
  iotests: Accommodate async QMP Exception classes
  python/aqmp: Remove scary message
  python, iotests: replace qmp with aqmp

 tests/qemu-iotests/socket_scm_helper.c    | 136 ---------------------
 python/qemu/aqmp/__init__.py              |  14 ---
 python/qemu/aqmp/events.py                |  15 ++-
 python/qemu/aqmp/legacy.py                | 131 ++++++++++++++++++++
 python/qemu/aqmp/models.py                |  67 ++++++++---
 python/qemu/aqmp/qmp_client.py            |  22 ++++
 python/qemu/machine/machine.py            | 139 +++++++++++++---------
 python/qemu/machine/qtest.py              |   2 -
 python/qemu/qmp/__init__.py               |  25 ++--
 python/qemu/qmp/qmp_shell.py              |   1 -
 scripts/simplebench/bench_block_job.py    |   3 +-
 tests/Makefile.include                    |   1 -
 tests/meson.build                         |   4 -
 tests/qemu-iotests/040                    |   7 +-
 tests/qemu-iotests/218                    |   2 +-
 tests/qemu-iotests/255                    |   2 +-
 tests/qemu-iotests/iotests.py             |   5 +-
 tests/qemu-iotests/meson.build            |   5 -
 tests/qemu-iotests/testenv.py             |   8 +-
 tests/qemu-iotests/tests/mirror-top-perms |   6 +-
 20 files changed, 321 insertions(+), 274 deletions(-)
 delete mode 100644 tests/qemu-iotests/socket_scm_helper.c
 create mode 100644 python/qemu/aqmp/legacy.py
 delete mode 100644 tests/qemu-iotests/meson.build

-- 
2.31.1

[PATCH 01/15] python/aqmp: add greeting property to QMPClient

[John Snow]

Expose the greeting as a read-only property of QMPClient so it can be
retrieved at-will.

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

diff --git a/python/qemu/aqmp/qmp_client.py b/python/qemu/aqmp/qmp_client.py
index 82e9dab124..d2ad7459f9 100644
--- a/python/qemu/aqmp/qmp_client.py
+++ b/python/qemu/aqmp/qmp_client.py
@@ -224,6 +224,11 @@ def __init__(self, name: Optional[str] = None) -> None:
             'asyncio.Queue[QMPClient._PendingT]'
         ] = {}
 
+    @property
+    def greeting(self) -> Optional[Greeting]:
+        """The `Greeting` from the QMP server, if any."""
+        return self._greeting
+
     @upper_half
     async def _establish_session(self) -> None:
         """
-- 
2.31.1

[PATCH 02/15] python/aqmp: add .empty() method to EventListener

[John Snow]

Synchronous clients may want to know if they're about to block waiting
for an event or not. A method such as this is necessary to implement a
compatible interface for the old QEMUMonitorProtocol using the new async
internals.

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

diff --git a/python/qemu/aqmp/events.py b/python/qemu/aqmp/events.py
index fb81d21610..271899f6b8 100644
--- a/python/qemu/aqmp/events.py
+++ b/python/qemu/aqmp/events.py
@@ -556,6 +556,12 @@ async def get(self) -> Message:
         """
         return await self._queue.get()
 
+    def empty(self) -> bool:
+        """
+        Return `True` if there are no pending events.
+        """
+        return self._queue.empty()
+
     def clear(self) -> None:
         """
         Clear this listener of all pending events.
-- 
2.31.1

[PATCH 03/15] python/aqmp: Return cleared events from EventListener.clear()

[John Snow]

This serves two purposes:

(1) It is now possible to discern whether or not clear() removed any
event(s) from the queue with absolute certainty, and

(2) It is now very easy to get a List of all pending events in one
chunk, which is useful for the sync bridge.

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

diff --git a/python/qemu/aqmp/events.py b/python/qemu/aqmp/events.py
index 271899f6b8..5f7150c78d 100644
--- a/python/qemu/aqmp/events.py
+++ b/python/qemu/aqmp/events.py
@@ -562,7 +562,7 @@ def empty(self) -> bool:
         """
         return self._queue.empty()
 
-    def clear(self) -> None:
+    def clear(self) -> List[Message]:
         """
         Clear this listener of all pending events.
 
@@ -570,17 +570,22 @@ def clear(self) -> None:
         pending FIFO queue synchronously. It can be also be used to
         manually clear any pending events, if desired.
 
+        :return: The cleared events, if any.
+
         .. warning::
             Take care when discarding events. Cleared events will be
             silently tossed on the floor. All events that were ever
             accepted by this listener are visible in `history()`.
         """
+        events = []
         while True:
             try:
-                self._queue.get_nowait()
+                events.append(self._queue.get_nowait())
             except asyncio.QueueEmpty:
                 break
 
+        return events
+
     def __aiter__(self) -> AsyncIterator[Message]:
         return self
 
-- 
2.31.1

[PATCH 04/15] python/qmp: clear events on get_events() call

[John Snow]

All callers in the tree *already* clear the events after a call to
get_events(). Do it automatically instead and update callsites to remove
the manual clear call.

These semantics are quite a bit easier to emulate with async QMP, and
nobody appears to be abusing some emergent properties of what happens if
you decide not to clear them, so let's dial down to the dumber, simpler
thing.

Specifically: callers of clear() right after a call to get_events() are
more likely expressing their desire to not see any events they just
retrieved, whereas callers of clear_events() not in relation to a recent
call to pull_event/get_events are likely expressing their desire to
simply drop *all* pending events straight onto the floor. In the sync
world, this is safe enough; in the async world it's nearly impossible to
promise that nothing happens between getting and clearing the
events.

Making the retrieval also clear the queue is vastly simpler.

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

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index 34131884a5..ae945ca3c9 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -631,7 +631,6 @@ def get_qmp_events(self, wait: bool = False) -> List[QMPMessage]:
         events = self._qmp.get_events(wait=wait)
         events.extend(self._events)
         del self._events[:]
-        self._qmp.clear_events()
         return events
 
     @staticmethod
diff --git a/python/qemu/qmp/__init__.py b/python/qemu/qmp/__init__.py
index 269516a79b..ba15668c25 100644
--- a/python/qemu/qmp/__init__.py
+++ b/python/qemu/qmp/__init__.py
@@ -374,7 +374,9 @@ def get_events(self, wait: bool = False) -> List[QMPMessage]:
         @return The list of available QMP events.
         """
         self.__get_events(wait)
-        return self.__events
+        events = self.__events
+        self.__events = []
+        return events
 
     def clear_events(self) -> None:
         """
diff --git a/python/qemu/qmp/qmp_shell.py b/python/qemu/qmp/qmp_shell.py
index 337acfce2d..e7d7eb18f1 100644
--- a/python/qemu/qmp/qmp_shell.py
+++ b/python/qemu/qmp/qmp_shell.py
@@ -381,7 +381,6 @@ def read_exec_command(self) -> bool:
         if cmdline == '':
             for event in self.get_events():
                 print(event)
-            self.clear_events()
             return True
 
         return self._execute_cmd(cmdline)
-- 
2.31.1

[PATCH 05/15] python/qmp: add send_fd_scm directly to QEMUMonitorProtocol

[John Snow]

It turns out you can do this directly from Python ... and because of
this, you don't need to worry about setting the inheritability of the
fds or spawning another process.

Doing this is helpful because it allows QEMUMonitorProtocol to keep its
file descriptor and socket object as private implementation details.

*that* is helpful in turn because it allows me to write a compatible,
 alternative implementation.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine/machine.py | 44 +++++++---------------------------
 python/qemu/qmp/__init__.py    | 21 +++++++---------
 2 files changed, 18 insertions(+), 47 deletions(-)

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index ae945ca3c9..1c6532a3d6 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -213,48 +213,22 @@ def add_fd(self: _T, fd: int, fdset: int,
     def send_fd_scm(self, fd: Optional[int] = None,
                     file_path: Optional[str] = None) -> int:
         """
-        Send an fd or file_path to socket_scm_helper.
+        Send an fd or file_path to the remote via SCM_RIGHTS.
 
-        Exactly one of fd and file_path must be given.
-        If it is file_path, the helper will open that file and pass its own fd.
+        Exactly one of fd and file_path must be given.  If it is
+        file_path, the file will be opened read-only and the new file
+        descriptor will be sent to the remote.
         """
-        # In iotest.py, the qmp should always use unix socket.
-        assert self._qmp.is_scm_available()
-        if self._socket_scm_helper is None:
-            raise QEMUMachineError("No path to socket_scm_helper set")
-        if not os.path.exists(self._socket_scm_helper):
-            raise QEMUMachineError("%s does not exist" %
-                                   self._socket_scm_helper)
-
-        # This did not exist before 3.4, but since then it is
-        # mandatory for our purpose
-        if hasattr(os, 'set_inheritable'):
-            os.set_inheritable(self._qmp.get_sock_fd(), True)
-            if fd is not None:
-                os.set_inheritable(fd, True)
-
-        fd_param = ["%s" % self._socket_scm_helper,
-                    "%d" % self._qmp.get_sock_fd()]
-
         if file_path is not None:
             assert fd is None
-            fd_param.append(file_path)
+            with open(file_path, "rb") as passfile:
+                fd = passfile.fileno()
+                self._qmp.send_fd_scm(fd)
         else:
             assert fd is not None
-            fd_param.append(str(fd))
+            self._qmp.send_fd_scm(fd)
 
-        proc = subprocess.run(
-            fd_param,
-            stdin=subprocess.DEVNULL,
-            stdout=subprocess.PIPE,
-            stderr=subprocess.STDOUT,
-            check=False,
-            close_fds=False,
-        )
-        if proc.stdout:
-            LOG.debug(proc.stdout)
-
-        return proc.returncode
+        return 0
 
     @staticmethod
     def _remove_if_exists(path: str) -> None:
diff --git a/python/qemu/qmp/__init__.py b/python/qemu/qmp/__init__.py
index ba15668c25..c3b8a70ec9 100644
--- a/python/qemu/qmp/__init__.py
+++ b/python/qemu/qmp/__init__.py
@@ -21,6 +21,7 @@
 import json
 import logging
 import socket
+import struct
 from types import TracebackType
 from typing import (
     Any,
@@ -408,18 +409,14 @@ def settimeout(self, timeout: Optional[float]) -> None:
             raise ValueError(msg)
         self.__sock.settimeout(timeout)
 
-    def get_sock_fd(self) -> int:
+    def send_fd_scm(self, fd: int) -> None:
         """
-        Get the socket file descriptor.
-
-        @return The file descriptor number.
-        """
-        return self.__sock.fileno()
-
-    def is_scm_available(self) -> bool:
+        Send a file descriptor to the remote via SCM_RIGHTS.
         """
-        Check if the socket allows for SCM_RIGHTS.
+        if self.__sock.family != socket.AF_UNIX:
+            raise RuntimeError("Can't use SCM_RIGHTS on non-AF_UNIX socket.")
 
-        @return True if SCM_RIGHTS is available, otherwise False.
-        """
-        return self.__sock.family == socket.AF_UNIX
+        self.__sock.sendmsg(
+            [b' '],
+            [(socket.SOL_SOCKET, socket.SCM_RIGHTS, struct.pack('@i', fd))]
+        )
-- 
2.31.1

[PATCH 06/15] python, iotests: remove socket_scm_helper

[John Snow]

It's not used anymore, now.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 tests/qemu-iotests/socket_scm_helper.c | 136 -------------------------
 python/qemu/machine/machine.py         |   3 -
 python/qemu/machine/qtest.py           |   2 -
 tests/Makefile.include                 |   1 -
 tests/meson.build                      |   4 -
 tests/qemu-iotests/iotests.py          |   3 -
 tests/qemu-iotests/meson.build         |   5 -
 tests/qemu-iotests/testenv.py          |   8 +-
 8 files changed, 1 insertion(+), 161 deletions(-)
 delete mode 100644 tests/qemu-iotests/socket_scm_helper.c
 delete mode 100644 tests/qemu-iotests/meson.build

diff --git a/tests/qemu-iotests/socket_scm_helper.c b/tests/qemu-iotests/socket_scm_helper.c
deleted file mode 100644
index eb76d31aa9..0000000000
--- a/tests/qemu-iotests/socket_scm_helper.c
+++ /dev/null
@@ -1,136 +0,0 @@
-/*
- * SCM_RIGHTS with unix socket help program for test
- *
- * Copyright IBM, Inc. 2013
- *
- * Authors:
- *  Wenchao Xia    <xiawenc@linux.vnet.ibm.com>
- *
- * This work is licensed under the terms of the GNU LGPL, version 2 or later.
- * See the COPYING.LIB file in the top-level directory.
- */
-
-#include "qemu/osdep.h"
-#include <sys/socket.h>
-#include <sys/un.h>
-
-/* #define SOCKET_SCM_DEBUG */
-
-/*
- * @fd and @fd_to_send will not be checked for validation in this function,
- * a blank will be sent as iov data to notify qemu.
- */
-static int send_fd(int fd, int fd_to_send)
-{
-    struct msghdr msg;
-    struct iovec iov[1];
-    int ret;
-    char control[CMSG_SPACE(sizeof(int))];
-    struct cmsghdr *cmsg;
-
-    memset(&msg, 0, sizeof(msg));
-    memset(control, 0, sizeof(control));
-
-    /* Send a blank to notify qemu */
-    iov[0].iov_base = (void *)" ";
-    iov[0].iov_len = 1;
-
-    msg.msg_iov = iov;
-    msg.msg_iovlen = 1;
-
-    msg.msg_control = control;
-    msg.msg_controllen = sizeof(control);
-
-    cmsg = CMSG_FIRSTHDR(&msg);
-
-    cmsg->cmsg_len = CMSG_LEN(sizeof(int));
-    cmsg->cmsg_level = SOL_SOCKET;
-    cmsg->cmsg_type = SCM_RIGHTS;
-    memcpy(CMSG_DATA(cmsg), &fd_to_send, sizeof(int));
-
-    do {
-        ret = sendmsg(fd, &msg, 0);
-    } while (ret < 0 && errno == EINTR);
-
-    if (ret < 0) {
-        fprintf(stderr, "Failed to send msg, reason: %s\n", strerror(errno));
-    }
-
-    return ret;
-}
-
-/* Convert string to fd number. */
-static int get_fd_num(const char *fd_str, bool silent)
-{
-    int sock;
-    char *err;
-
-    errno = 0;
-    sock = strtol(fd_str, &err, 10);
-    if (errno) {
-        if (!silent) {
-            fprintf(stderr, "Failed in strtol for socket fd, reason: %s\n",
-                    strerror(errno));
-        }
-        return -1;
-    }
-    if (!*fd_str || *err || sock < 0) {
-        if (!silent) {
-            fprintf(stderr, "bad numerical value for socket fd '%s'\n", fd_str);
-        }
-        return -1;
-    }
-
-    return sock;
-}
-
-/*
- * To make things simple, the caller needs to specify:
- * 1. socket fd.
- * 2. path of the file to be sent.
- */
-int main(int argc, char **argv, char **envp)
-{
-    int sock, fd, ret;
-
-#ifdef SOCKET_SCM_DEBUG
-    int i;
-    for (i = 0; i < argc; i++) {
-        fprintf(stderr, "Parameter %d: %s\n", i, argv[i]);
-    }
-#endif
-
-    if (argc != 3) {
-        fprintf(stderr,
-                "Usage: %s < socket-fd > < file-path >\n",
-                argv[0]);
-        return EXIT_FAILURE;
-    }
-
-
-    sock = get_fd_num(argv[1], false);
-    if (sock < 0) {
-        return EXIT_FAILURE;
-    }
-
-    fd = get_fd_num(argv[2], true);
-    if (fd < 0) {
-        /* Now only open a file in readonly mode for test purpose. If more
-           precise control is needed, use python script in file operation, which
-           is supposed to fork and exec this program. */
-        fd = open(argv[2], O_RDONLY);
-        if (fd < 0) {
-            fprintf(stderr, "Failed to open file '%s'\n", argv[2]);
-            return EXIT_FAILURE;
-        }
-    }
-
-    ret = send_fd(sock, fd);
-    if (ret < 0) {
-        close(fd);
-        return EXIT_FAILURE;
-    }
-
-    close(fd);
-    return EXIT_SUCCESS;
-}
diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index 1c6532a3d6..056d340e35 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -98,7 +98,6 @@ def __init__(self,
                  name: Optional[str] = None,
                  base_temp_dir: str = "/var/tmp",
                  monitor_address: Optional[SocketAddrT] = None,
-                 socket_scm_helper: Optional[str] = None,
                  sock_dir: Optional[str] = None,
                  drain_console: bool = False,
                  console_log: Optional[str] = None,
@@ -113,7 +112,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 socket_scm_helper: helper program, required for send_fd_scm()
         @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
@@ -134,7 +132,6 @@ def __init__(self,
         self._base_temp_dir = base_temp_dir
         self._sock_dir = sock_dir or self._base_temp_dir
         self._log_dir = log_dir
-        self._socket_scm_helper = socket_scm_helper
 
         if monitor_address is not None:
             self._monitor_address = monitor_address
diff --git a/python/qemu/machine/qtest.py b/python/qemu/machine/qtest.py
index 395cc8fbfe..f2f9aaa5e5 100644
--- a/python/qemu/machine/qtest.py
+++ b/python/qemu/machine/qtest.py
@@ -115,7 +115,6 @@ def __init__(self,
                  wrapper: Sequence[str] = (),
                  name: Optional[str] = None,
                  base_temp_dir: str = "/var/tmp",
-                 socket_scm_helper: Optional[str] = None,
                  sock_dir: Optional[str] = None,
                  qmp_timer: Optional[float] = None):
         # pylint: disable=too-many-arguments
@@ -126,7 +125,6 @@ def __init__(self,
             sock_dir = base_temp_dir
         super().__init__(binary, args, wrapper=wrapper, name=name,
                          base_temp_dir=base_temp_dir,
-                         socket_scm_helper=socket_scm_helper,
                          sock_dir=sock_dir, qmp_timer=qmp_timer)
         self._qtest: Optional[QEMUQtestProtocol] = None
         self._qtest_path = os.path.join(sock_dir, name + "-qtest.sock")
diff --git a/tests/Makefile.include b/tests/Makefile.include
index 6e16c05f10..5bd487a403 100644
--- a/tests/Makefile.include
+++ b/tests/Makefile.include
@@ -139,7 +139,6 @@ check-acceptance: check-venv $(TESTS_RESULTS_DIR) get-vm-images
 check:
 
 ifeq ($(CONFIG_TOOLS)$(CONFIG_POSIX),yy)
-QEMU_IOTESTS_HELPERS-$(CONFIG_LINUX) = tests/qemu-iotests/socket_scm_helper$(EXESUF)
 check: check-block
 export PYTHON
 check-block: $(SRC_PATH)/tests/check-block.sh qemu-img$(EXESUF) \
diff --git a/tests/meson.build b/tests/meson.build
index 55a7b08275..3f3882748a 100644
--- a/tests/meson.build
+++ b/tests/meson.build
@@ -67,10 +67,6 @@ if have_tools and 'CONFIG_VHOST_USER' in config_host and 'CONFIG_LINUX' in confi
              dependencies: [qemuutil, vhost_user])
 endif
 
-if have_system and 'CONFIG_POSIX' in config_host
-  subdir('qemu-iotests')
-endif
-
 test('decodetree', sh,
      args: [ files('decode/check.sh'), config_host['PYTHON'], files('../scripts/decodetree.py') ],
      workdir: meson.current_source_dir() / 'decode',
diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
index 11276f380a..273d2777ae 100644
--- a/tests/qemu-iotests/iotests.py
+++ b/tests/qemu-iotests/iotests.py
@@ -109,8 +109,6 @@
 
     qemu_valgrind = ['valgrind', valgrind_logfile, '--error-exitcode=99']
 
-socket_scm_helper = os.environ.get('SOCKET_SCM_HELPER', 'socket_scm_helper')
-
 luks_default_secret_object = 'secret,id=keysec0,data=' + \
                              os.environ.get('IMGKEYSECRET', '')
 luks_default_key_secret_opt = 'key-secret=keysec0'
@@ -600,7 +598,6 @@ def __init__(self, path_suffix=''):
         super().__init__(qemu_prog, qemu_opts, wrapper=wrapper,
                          name=name,
                          base_temp_dir=test_dir,
-                         socket_scm_helper=socket_scm_helper,
                          sock_dir=sock_dir, qmp_timer=timer)
         self._num_drives = 0
 
diff --git a/tests/qemu-iotests/meson.build b/tests/qemu-iotests/meson.build
deleted file mode 100644
index 67aed1e492..0000000000
--- a/tests/qemu-iotests/meson.build
+++ /dev/null
@@ -1,5 +0,0 @@
-if 'CONFIG_LINUX' in config_host
-    socket_scm_helper = executable('socket_scm_helper', 'socket_scm_helper.c')
-else
-    socket_scm_helper = []
-endif
diff --git a/tests/qemu-iotests/testenv.py b/tests/qemu-iotests/testenv.py
index 70da0d60c8..207bafb649 100644
--- a/tests/qemu-iotests/testenv.py
+++ b/tests/qemu-iotests/testenv.py
@@ -68,7 +68,7 @@ class TestEnv(ContextManager['TestEnv']):
     env_variables = ['PYTHONPATH', 'TEST_DIR', 'SOCK_DIR', 'SAMPLE_IMG_DIR',
                      'OUTPUT_DIR', 'PYTHON', 'QEMU_PROG', 'QEMU_IMG_PROG',
                      'QEMU_IO_PROG', 'QEMU_NBD_PROG', 'QSD_PROG',
-                     'SOCKET_SCM_HELPER', 'QEMU_OPTIONS', 'QEMU_IMG_OPTIONS',
+                     'QEMU_OPTIONS', 'QEMU_IMG_OPTIONS',
                      'QEMU_IO_OPTIONS', 'QEMU_IO_OPTIONS_NO_FMT',
                      'QEMU_NBD_OPTIONS', 'IMGOPTS', 'IMGFMT', 'IMGPROTO',
                      'AIOMODE', 'CACHEMODE', 'VALGRIND_QEMU',
@@ -137,7 +137,6 @@ def init_binaries(self) -> None:
         """Init binary path variables:
              PYTHON (for bash tests)
              QEMU_PROG, QEMU_IMG_PROG, QEMU_IO_PROG, QEMU_NBD_PROG, QSD_PROG
-             SOCKET_SCM_HELPER
         """
         self.python = sys.executable
 
@@ -171,10 +170,6 @@ def root(*names: str) -> str:
             if not isxfile(b):
                 sys.exit('Not executable: ' + b)
 
-        helper_path = os.path.join(self.build_iotests, 'socket_scm_helper')
-        if isxfile(helper_path):
-            self.socket_scm_helper = helper_path  # SOCKET_SCM_HELPER
-
     def __init__(self, imgfmt: str, imgproto: str, aiomode: str,
                  cachemode: Optional[str] = None,
                  imgopts: Optional[str] = None,
@@ -300,7 +295,6 @@ def print_env(self) -> None:
 PLATFORM      -- {platform}
 TEST_DIR      -- {TEST_DIR}
 SOCK_DIR      -- {SOCK_DIR}
-SOCKET_SCM_HELPER -- {SOCKET_SCM_HELPER}
 GDB_OPTIONS   -- {GDB_OPTIONS}
 VALGRIND_QEMU -- {VALGRIND_QEMU}
 PRINT_QEMU_OUTPUT -- {PRINT_QEMU}
-- 
2.31.1

[PATCH 07/15] python/aqmp: add send_fd_scm

[John Snow]

The single space is indeed required to successfully transmit the file
descriptor to QEMU.

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

diff --git a/python/qemu/aqmp/qmp_client.py b/python/qemu/aqmp/qmp_client.py
index d2ad7459f9..58f85990bc 100644
--- a/python/qemu/aqmp/qmp_client.py
+++ b/python/qemu/aqmp/qmp_client.py
@@ -9,6 +9,8 @@
 
 import asyncio
 import logging
+import socket
+import struct
 from typing import (
     Dict,
     List,
@@ -624,3 +626,18 @@ async def execute(self, cmd: str,
         """
         msg = self.make_execute_msg(cmd, arguments, oob=oob)
         return await self.execute_msg(msg)
+
+    @upper_half
+    @require(Runstate.RUNNING)
+    def send_fd_scm(self, fd: int) -> None:
+        """
+        Send a file descriptor to the remote via SCM_RIGHTS.
+        """
+        assert self._writer is not None
+        sock = self._writer.transport.get_extra_info('socket')
+
+        # Python 3.9+ adds socket.send_fds(...)
+        sock.sendmsg(
+            [b' '],
+            [(socket.SOL_SOCKET, socket.SCM_RIGHTS, struct.pack('@i', fd))]
+        )
-- 
2.31.1

[PATCH 08/15] python/aqmp: Create MessageModel and StandaloneModel classes

[John Snow]

This allows 'Greeting' to be subclass of 'Message'. We need the adapter
classes to avoid some typing problems that occur if we try to put too
much into the 'Model' class itself; the exact details of why are left as
an exercise to the reader.

Why bother? This makes 'Greeting' ⊆ 'Message', which is taxonomically
true; but the real motivation is to be able to inherit and abuse all of
the Mapping dunders so that we can call dict(greeting) or
bytes(greeting), for example.

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

diff --git a/python/qemu/aqmp/models.py b/python/qemu/aqmp/models.py
index 24c94123ac..eaeeebc25c 100644
--- a/python/qemu/aqmp/models.py
+++ b/python/qemu/aqmp/models.py
@@ -15,23 +15,22 @@
     Sequence,
 )
 
+from .message import Message
+
 
 class Model:
     """
-    Abstract data model, representing some QMP object of some kind.
-
-    :param raw: The raw object to be validated.
-    :raise KeyError: If any required fields are absent.
-    :raise TypeError: If any required fields have the wrong type.
+    Abstract data model, representing a QMP object of some kind.
     """
-    def __init__(self, raw: Mapping[str, Any]):
-        self._raw = raw
+    @property
+    def _raw(self) -> Mapping[str, Any]:
+        raise NotImplementedError
 
     def _check_key(self, key: str) -> None:
         if key not in self._raw:
             raise KeyError(f"'{self._name}' object requires '{key}' member")
 
-    def _check_value(self, key: str, type_: type, typestr: str) -> None:
+    def _check_type(self, key: str, type_: type, typestr: str) -> None:
         assert key in self._raw
         if not isinstance(self._raw[key], type_):
             raise TypeError(
@@ -40,7 +39,7 @@ def _check_value(self, key: str, type_: type, typestr: str) -> None:
 
     def _check_member(self, key: str, type_: type, typestr: str) -> None:
         self._check_key(key)
-        self._check_value(key, type_, typestr)
+        self._check_type(key, type_, typestr)
 
     @property
     def _name(self) -> str:
@@ -50,7 +49,37 @@ def __repr__(self) -> str:
         return f"{self._name}({self._raw!r})"
 
 
-class Greeting(Model):
+class MessageModel(Message, Model):
+    """
+    Abstract data model, representing a QMP Message of some sort.
+
+    Adapter class that glues together `Model` and `Message`.
+    """
+    def __init__(self, raw: Mapping[str, object]):
+        super().__init__(raw)
+
+    @property
+    def _raw(self) -> Mapping[str, Any]:
+        return self._object
+
+    def __setitem__(self, key: str, value: object) -> None:
+        # This is not good OO, but this turns off mutability here.
+        raise RuntimeError("Cannot mutate MessageModel")
+
+
+class StandaloneModel(Model):
+    """
+    Abstract data model, representing a (non-Message) QMP object of some sort.
+    """
+    def __init__(self, raw: Mapping[str, object]):
+        self._raw_mapping = raw
+
+    @property
+    def _raw(self) -> Mapping[str, Any]:
+        return self._raw_mapping
+
+
+class Greeting(MessageModel):
     """
     Defined in qmp-spec.txt, section 2.2, "Server Greeting".
 
@@ -58,8 +87,9 @@ class Greeting(Model):
     :raise KeyError: If any required fields are absent.
     :raise TypeError: If any required fields have the wrong type.
     """
-    def __init__(self, raw: Mapping[str, Any]):
+    def __init__(self, raw: Mapping[str, object]):
         super().__init__(raw)
+
         #: 'QMP' member
         self.QMP: QMPGreeting  # pylint: disable=invalid-name
 
@@ -67,7 +97,7 @@ def __init__(self, raw: Mapping[str, Any]):
         self.QMP = QMPGreeting(self._raw['QMP'])
 
 
-class QMPGreeting(Model):
+class QMPGreeting(StandaloneModel):
     """
     Defined in qmp-spec.txt, section 2.2, "Server Greeting".
 
@@ -75,8 +105,9 @@ class QMPGreeting(Model):
     :raise KeyError: If any required fields are absent.
     :raise TypeError: If any required fields have the wrong type.
     """
-    def __init__(self, raw: Mapping[str, Any]):
+    def __init__(self, raw: Mapping[str, object]):
         super().__init__(raw)
+
         #: 'version' member
         self.version: Mapping[str, object]
         #: 'capabilities' member
@@ -89,7 +120,7 @@ def __init__(self, raw: Mapping[str, Any]):
         self.capabilities = self._raw['capabilities']
 
 
-class ErrorResponse(Model):
+class ErrorResponse(MessageModel):
     """
     Defined in qmp-spec.txt, section 2.4.2, "error".
 
@@ -97,8 +128,9 @@ class ErrorResponse(Model):
     :raise KeyError: If any required fields are absent.
     :raise TypeError: If any required fields have the wrong type.
     """
-    def __init__(self, raw: Mapping[str, Any]):
+    def __init__(self, raw: Mapping[str, object]):
         super().__init__(raw)
+
         #: 'error' member
         self.error: ErrorInfo
         #: 'id' member
@@ -111,7 +143,7 @@ def __init__(self, raw: Mapping[str, Any]):
             self.id = raw['id']
 
 
-class ErrorInfo(Model):
+class ErrorInfo(StandaloneModel):
     """
     Defined in qmp-spec.txt, section 2.4.2, "error".
 
@@ -119,8 +151,9 @@ class ErrorInfo(Model):
     :raise KeyError: If any required fields are absent.
     :raise TypeError: If any required fields have the wrong type.
     """
-    def __init__(self, raw: Mapping[str, Any]):
+    def __init__(self, raw: Mapping[str, object]):
         super().__init__(raw)
+
         #: 'class' member, with an underscore to avoid conflicts in Python.
         self.class_: str
         #: 'desc' member
-- 
2.31.1

[PATCH 09/15] python/machine: remove has_quit argument

[John Snow]

If we spy on the QMP commands instead, we don't need callers to remember
to pass it. Seems like a fair trade-off.

The one slightly weird bit is overloading this instance variable for
wait(), where we use it to mean "don't issue the qmp 'quit'
command". This means that wait() will "fail" if the QEMU process does
not terminate of its own accord.

In most cases, we probably did already actually issue quit -- some
iotests do this -- but in some others, we may be waiting for QEMU to
terminate for some other reason.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/machine/machine.py | 35 +++++++++++++++++++---------------
 tests/qemu-iotests/040         |  7 +------
 tests/qemu-iotests/218         |  2 +-
 tests/qemu-iotests/255         |  2 +-
 4 files changed, 23 insertions(+), 23 deletions(-)

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index 056d340e35..6e58d2f951 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -170,6 +170,7 @@ def __init__(self,
         self._console_socket: Optional[socket.socket] = None
         self._remove_files: List[str] = []
         self._user_killed = False
+        self._has_quit = False
 
     def __enter__(self: _T) -> _T:
         return self
@@ -368,6 +369,7 @@ def _post_shutdown(self) -> None:
                 command = ''
             LOG.warning(msg, -int(exitcode), command)
 
+        self._has_quit = False
         self._user_killed = False
         self._launched = False
 
@@ -443,15 +445,13 @@ def _hard_shutdown(self) -> None:
         self._subp.kill()
         self._subp.wait(timeout=60)
 
-    def _soft_shutdown(self, timeout: Optional[int],
-                       has_quit: bool = False) -> None:
+    def _soft_shutdown(self, timeout: Optional[int]) -> None:
         """
         Perform early cleanup, attempt to gracefully shut down the VM, and wait
         for it to terminate.
 
         :param timeout: Timeout in seconds for graceful shutdown.
                         A value of None is an infinite wait.
-        :param has_quit: When True, don't attempt to issue 'quit' QMP command
 
         :raise ConnectionReset: On QMP communication errors
         :raise subprocess.TimeoutExpired: When timeout is exceeded waiting for
@@ -460,21 +460,19 @@ def _soft_shutdown(self, timeout: Optional[int],
         self._early_cleanup()
 
         if self._qmp_connection:
-            if not has_quit:
+            if not self._has_quit:
                 # Might raise ConnectionReset
-                self._qmp.cmd('quit')
+                self.qmp('quit')
 
         # May raise subprocess.TimeoutExpired
         self._subp.wait(timeout=timeout)
 
-    def _do_shutdown(self, timeout: Optional[int],
-                     has_quit: bool = False) -> None:
+    def _do_shutdown(self, timeout: Optional[int]) -> None:
         """
         Attempt to shutdown the VM gracefully; fallback to a hard shutdown.
 
         :param timeout: Timeout in seconds for graceful shutdown.
                         A value of None is an infinite wait.
-        :param has_quit: When True, don't attempt to issue 'quit' QMP command
 
         :raise AbnormalShutdown: When the VM could not be shut down gracefully.
             The inner exception will likely be ConnectionReset or
@@ -482,13 +480,13 @@ def _do_shutdown(self, timeout: Optional[int],
             may result in its own exceptions, likely subprocess.TimeoutExpired.
         """
         try:
-            self._soft_shutdown(timeout, has_quit)
+            self._soft_shutdown(timeout)
         except Exception as exc:
             self._hard_shutdown()
             raise AbnormalShutdown("Could not perform graceful shutdown") \
                 from exc
 
-    def shutdown(self, has_quit: bool = False,
+    def shutdown(self,
                  hard: bool = False,
                  timeout: Optional[int] = 30) -> None:
         """
@@ -498,7 +496,6 @@ def shutdown(self, has_quit: bool = False,
         If the VM has not yet been launched, or shutdown(), wait(), or kill()
         have already been called, this method does nothing.
 
-        :param has_quit: When true, do not attempt to issue 'quit' QMP command.
         :param hard: When true, do not attempt graceful shutdown, and
                      suppress the SIGKILL warning log message.
         :param timeout: Optional timeout in seconds for graceful shutdown.
@@ -512,7 +509,7 @@ def shutdown(self, has_quit: bool = False,
                 self._user_killed = True
                 self._hard_shutdown()
             else:
-                self._do_shutdown(timeout, has_quit)
+                self._do_shutdown(timeout)
         finally:
             self._post_shutdown()
 
@@ -529,7 +526,9 @@ def wait(self, timeout: Optional[int] = 30) -> None:
         :param timeout: Optional timeout in seconds. Default 30 seconds.
                         A value of `None` is an infinite wait.
         """
-        self.shutdown(has_quit=True, timeout=timeout)
+        # In case QEMU was stopped without issuing 'quit':
+        self._has_quit = True
+        self.shutdown(timeout=timeout)
 
     def set_qmp_monitor(self, enabled: bool = True) -> None:
         """
@@ -574,7 +573,10 @@ def qmp(self, cmd: str,
             conv_keys = True
 
         qmp_args = self._qmp_args(conv_keys, args)
-        return self._qmp.cmd(cmd, args=qmp_args)
+        ret = self._qmp.cmd(cmd, args=qmp_args)
+        if cmd == 'quit' and 'error' not in ret and 'return' in ret:
+            self._has_quit = True
+        return ret
 
     def command(self, cmd: str,
                 conv_keys: bool = True,
@@ -585,7 +587,10 @@ def command(self, cmd: str,
         On failure raise an exception.
         """
         qmp_args = self._qmp_args(conv_keys, args)
-        return self._qmp.command(cmd, **qmp_args)
+        ret = self._qmp.command(cmd, **qmp_args)
+        if cmd == 'quit':
+            self._has_quit = True
+        return ret
 
     def get_qmp_event(self, wait: bool = False) -> Optional[QMPMessage]:
         """
diff --git a/tests/qemu-iotests/040 b/tests/qemu-iotests/040
index f3677de9df..6af5ab9e76 100755
--- a/tests/qemu-iotests/040
+++ b/tests/qemu-iotests/040
@@ -92,10 +92,9 @@ class TestSingleDrive(ImageCommitTestCase):
         self.vm.add_device('virtio-scsi')
         self.vm.add_device("scsi-hd,id=scsi0,drive=drive0")
         self.vm.launch()
-        self.has_quit = False
 
     def tearDown(self):
-        self.vm.shutdown(has_quit=self.has_quit)
+        self.vm.shutdown()
         os.remove(test_img)
         os.remove(mid_img)
         os.remove(backing_img)
@@ -127,8 +126,6 @@ class TestSingleDrive(ImageCommitTestCase):
         result = self.vm.qmp('quit')
         self.assert_qmp(result, 'return', {})
 
-        self.has_quit = True
-
     # Same as above, but this time we add the filter after starting the job
     @iotests.skip_if_unsupported(['throttle'])
     def test_commit_plus_filter_and_quit(self):
@@ -147,8 +144,6 @@ class TestSingleDrive(ImageCommitTestCase):
         result = self.vm.qmp('quit')
         self.assert_qmp(result, 'return', {})
 
-        self.has_quit = True
-
     def test_device_not_found(self):
         result = self.vm.qmp('block-commit', device='nonexistent', top='%s' % mid_img)
         self.assert_qmp(result, 'error/class', 'DeviceNotFound')
diff --git a/tests/qemu-iotests/218 b/tests/qemu-iotests/218
index 325d8244fb..4922b4d3b6 100755
--- a/tests/qemu-iotests/218
+++ b/tests/qemu-iotests/218
@@ -187,4 +187,4 @@ with iotests.VM() as vm, \
     log(vm.qmp('quit'))
 
     with iotests.Timeout(5, 'Timeout waiting for VM to quit'):
-        vm.shutdown(has_quit=True)
+        vm.shutdown()
diff --git a/tests/qemu-iotests/255 b/tests/qemu-iotests/255
index c43aa9c67a..3d6d0e80cb 100755
--- a/tests/qemu-iotests/255
+++ b/tests/qemu-iotests/255
@@ -123,4 +123,4 @@ with iotests.FilePath('src.qcow2') as src_path, \
     vm.qmp_log('block-job-cancel', device='job0')
     vm.qmp_log('quit')
 
-    vm.shutdown(has_quit=True)
+    vm.shutdown()
-- 
2.31.1

[PATCH 10/15] python/machine: Add support for AQMP backend

[John Snow]

To use the AQMP backend, Machine just needs to be a little more diligent
about what happens when closing a QMP connection. The operation is no
longer a freebie in the async world.

Because async QMP continues to check for messages asynchronously, it's
almost certainly likely that the loop will have exited due to EOF after
issuing the last 'quit' command. That error will ultimately be bubbled
up when attempting to close the QMP connection. The manager class here
then is free to discard it if it was expected.

Signed-off-by: John Snow <jsnow@redhat.com>

---

Yes, I regret that this class has become quite a dumping ground for
complexity around the exit path. It's in need of a refactor to help
separate out the exception handling and cleanup mechanisms from the
VM-related stuff, but it's not a priority to do that just yet -- but
it's on the list.

---
 python/qemu/machine/machine.py | 51 ++++++++++++++++++++++++++++++----
 1 file changed, 46 insertions(+), 5 deletions(-)

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index 6e58d2f951..8f5a6649e5 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -342,9 +342,15 @@ def _post_shutdown(self) -> None:
         # Comprehensive reset for the failed launch case:
         self._early_cleanup()
 
-        if self._qmp_connection:
-            self._qmp.close()
-            self._qmp_connection = None
+        try:
+            self._close_qmp_connection()
+        except Exception as err:  # pylint: disable=broad-except
+            LOG.warning(
+                "Exception closing QMP connection: %s",
+                str(err) if str(err) else type(err).__name__
+            )
+        finally:
+            assert self._qmp_connection is None
 
         self._close_qemu_log_file()
 
@@ -420,6 +426,31 @@ def _launch(self) -> None:
                                        close_fds=False)
         self._post_launch()
 
+    def _close_qmp_connection(self) -> None:
+        """
+        Close the underlying QMP connection, if any.
+
+        Dutifully report errors that occurred while closing, but assume
+        that any error encountered indicates an abnormal termination
+        process and not a failure to close.
+        """
+        if self._qmp_connection is None:
+            return
+
+        try:
+            self._qmp.close()
+        except EOFError:
+            # EOF can occur as an Exception here when using the Async
+            # QMP backend. It indicates that the server closed the
+            # stream. If we successfully issued 'quit' at any point,
+            # then this was expected. If the remote went away without
+            # our permission, it's worth reporting that as an abnormal
+            # shutdown case.
+            if not self._has_quit:
+                raise
+        finally:
+            self._qmp_connection = None
+
     def _early_cleanup(self) -> None:
         """
         Perform any cleanup that needs to happen before the VM exits.
@@ -461,8 +492,18 @@ def _soft_shutdown(self, timeout: Optional[int]) -> None:
 
         if self._qmp_connection:
             if not self._has_quit:
-                # Might raise ConnectionReset
-                self.qmp('quit')
+                try:
+                    # May raise ExecInterruptedError or StateError if the
+                    # connection dies or has already died.
+                    self.qmp('quit')
+                finally:
+                    # If 'quit' fails, we'll still want to call close(),
+                    # which will raise any final errors that may have
+                    # occurred while trying to send 'quit'.
+                    self._close_qmp_connection()
+            else:
+                # Regardless, we want to tidy up the socket.
+                self._close_qmp_connection()
 
         # May raise subprocess.TimeoutExpired
         self._subp.wait(timeout=timeout)
-- 
2.31.1

[PATCH 11/15] python/aqmp: Create sync QMP wrapper for iotests

[John Snow]

This is a wrapper around the async QMPClient that mimics the old,
synchronous QEMUMonitorProtocol class. It is designed to be
interchangeable with the old implementation.

It does not, however, attempt to mimic Exception compatibility.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/aqmp/legacy.py | 131 +++++++++++++++++++++++++++++++++++++
 1 file changed, 131 insertions(+)
 create mode 100644 python/qemu/aqmp/legacy.py

diff --git a/python/qemu/aqmp/legacy.py b/python/qemu/aqmp/legacy.py
new file mode 100644
index 0000000000..b8544083ad
--- /dev/null
+++ b/python/qemu/aqmp/legacy.py
@@ -0,0 +1,131 @@
+"""
+Sync QMP Wrapper
+
+This class pretends to be qemu.qmp.QEMUMonitorProtocol.
+"""
+
+import asyncio
+from typing import (
+    Awaitable,
+    List,
+    Optional,
+    TypeVar,
+    Union,
+)
+
+import qemu.qmp
+from qemu.qmp import QMPMessage, QMPReturnValue, SocketAddrT
+
+from .qmp_client import QMPClient
+
+
+# pylint: disable=missing-docstring
+
+
+class QEMUMonitorProtocol(qemu.qmp.QEMUMonitorProtocol):
+    def __init__(self, address: SocketAddrT,
+                 server: bool = False,
+                 nickname: Optional[str] = None):
+
+        # pylint: disable=super-init-not-called
+        self._aqmp = QMPClient(nickname)
+        self._aloop = asyncio.get_event_loop()
+        self._address = address
+        self._timeout: Optional[float] = None
+
+    _T = TypeVar('_T')
+
+    def _sync(
+            self, future: Awaitable[_T], timeout: Optional[float] = None
+    ) -> _T:
+        return self._aloop.run_until_complete(
+            asyncio.wait_for(future, timeout=timeout)
+        )
+
+    # __enter__ and __exit__ need no changes
+    # parse_address needs no changes
+
+    def connect(self, negotiate: bool = True) -> Optional[QMPMessage]:
+        self._aqmp.await_greeting = negotiate
+        self._aqmp.negotiate = negotiate
+
+        self._sync(
+            self._aqmp.connect(self._address)
+        )
+
+        if self._aqmp.greeting is not None:
+            return dict(self._aqmp.greeting)
+        return None
+
+    def accept(self, timeout: Optional[float] = 15.0) -> QMPMessage:
+        self._aqmp.await_greeting = True
+        self._aqmp.negotiate = True
+
+        self._sync(
+            self._aqmp.accept(self._address),
+            timeout
+        )
+
+        assert self._aqmp.greeting is not None
+        return dict(self._aqmp.greeting)
+
+    def cmd_obj(self, qmp_cmd: QMPMessage) -> QMPMessage:
+        return dict(
+            self._sync(
+                # pylint: disable=protected-access
+
+                # _raw() isn't a public API, because turning off
+                # automatic ID assignment is discouraged. For
+                # compatibility with iotests *only*, do it anyway.
+                self._aqmp._raw(qmp_cmd, assign_id=False),
+                self._timeout
+            )
+        )
+
+    # Default impl of cmd() delegates to cmd_obj
+
+    def command(self, cmd: str, **kwds: object) -> QMPReturnValue:
+        return self._sync(
+            self._aqmp.execute(cmd, kwds),
+            self._timeout
+        )
+
+    def pull_event(self,
+                   wait: Union[bool, float] = False) -> Optional[QMPMessage]:
+        if wait is False:
+            # Return None if there's no event ready to go
+            if self._aqmp.events.empty():
+                return None
+
+        timeout = None
+        if isinstance(wait, float):
+            timeout = wait
+
+        return dict(
+            self._sync(
+                self._aqmp.events.get(),
+                timeout
+            )
+        )
+
+    def get_events(self, wait: Union[bool, float] = False) -> List[QMPMessage]:
+        events = [dict(x) for x in self._aqmp.events.clear()]
+        if events:
+            return events
+
+        event = self.pull_event(wait)
+        return [event] if event is not None else []
+
+    def clear_events(self) -> None:
+        self._aqmp.events.clear()
+
+    def close(self) -> None:
+        self._sync(
+            self._aqmp.disconnect()
+        )
+
+    def settimeout(self, timeout: Optional[float]) -> None:
+        self._timeout = timeout
+
+    def send_fd_scm(self, fd: int) -> None:
+        self._aqmp.send_fd_scm(fd)
-- 
2.31.1

[PATCH 12/15] iotests: Disable AQMP logging under non-debug modes

[John Snow]

Disable the aqmp logger, which likes to (at the moment) print out
intermediate warnings and errors that cause session termination; disable
them so they don't interfere with the job output.

Leave any "CRITICAL" warnings enabled though, those are ones that we
should never see, no matter what.

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

diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
index 273d2777ae..47e5f9738b 100644
--- a/tests/qemu-iotests/iotests.py
+++ b/tests/qemu-iotests/iotests.py
@@ -1383,6 +1383,8 @@ def execute_setup_common(supported_fmts: Sequence[str] = (),
     if debug:
         sys.argv.remove('-d')
     logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN))
+    if not debug:
+        logging.getLogger("qemu.aqmp.qmp_client").setLevel(logging.CRITICAL)
 
     _verify_image_format(supported_fmts, unsupported_fmts)
     _verify_protocol(supported_protocols, unsupported_protocols)
-- 
2.31.1

[PATCH 13/15] iotests: Accommodate async QMP Exception classes

[John Snow]

(But continue to support the old ones for now, too.)

There are very few cases of any user of QEMUMachine or a subclass
thereof relying on a QMP Exception type. If you'd like to check for
yourself, you want to grep for all of the derivatives of QMPError,
excluding 'AQMPError' and its derivatives. That'd be these:

- QMPError
- QMPConnectError
- QMPCapabilitiesError
- QMPTimeoutError
- QMPProtocolError
- QMPResponseError
- QMPBadPortError


Signed-off-by: John Snow <jsnow@redhat.com>
---
 scripts/simplebench/bench_block_job.py    | 3 ++-
 tests/qemu-iotests/tests/mirror-top-perms | 6 +++++-
 2 files changed, 7 insertions(+), 2 deletions(-)

diff --git a/scripts/simplebench/bench_block_job.py b/scripts/simplebench/bench_block_job.py
index 4f03c12169..a403c35b08 100755
--- a/scripts/simplebench/bench_block_job.py
+++ b/scripts/simplebench/bench_block_job.py
@@ -28,6 +28,7 @@
 sys.path.append(os.path.join(os.path.dirname(__file__), '..', '..', 'python'))
 from qemu.machine import QEMUMachine
 from qemu.qmp import QMPConnectError
+from qemu.aqmp import ConnectError
 
 
 def bench_block_job(cmd, cmd_args, qemu_args):
@@ -49,7 +50,7 @@ def bench_block_job(cmd, cmd_args, qemu_args):
         vm.launch()
     except OSError as e:
         return {'error': 'popen failed: ' + str(e)}
-    except (QMPConnectError, socket.timeout):
+    except (QMPConnectError, ConnectError, socket.timeout):
         return {'error': 'qemu failed: ' + str(vm.get_log())}
 
     try:
diff --git a/tests/qemu-iotests/tests/mirror-top-perms b/tests/qemu-iotests/tests/mirror-top-perms
index 451a0666f8..7d448f4d23 100755
--- a/tests/qemu-iotests/tests/mirror-top-perms
+++ b/tests/qemu-iotests/tests/mirror-top-perms
@@ -103,7 +103,11 @@ class TestMirrorTopPerms(iotests.QMPTestCase):
             print('ERROR: VM B launched successfully, this should not have '
                   'happened')
         except qemu.qmp.QMPConnectError:
-            assert 'Is another process using the image' in self.vm_b.get_log()
+            pass
+        except qemu.aqmp.ConnectError:
+            pass
+
+        assert 'Is another process using the image' in self.vm_b.get_log()
 
         result = self.vm.qmp('block-job-cancel',
                              device='mirror')
-- 
2.31.1

[PATCH 14/15] python/aqmp: Remove scary message

[John Snow]

The scary message interferes with the iotests output. Coincidentally, if
iotests works by removing this, then it's good evidence that we don't
really need to scare people away from using it.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 python/qemu/aqmp/__init__.py | 14 --------------
 1 file changed, 14 deletions(-)

diff --git a/python/qemu/aqmp/__init__.py b/python/qemu/aqmp/__init__.py
index ab1782999c..4b7df53e00 100644
--- a/python/qemu/aqmp/__init__.py
+++ b/python/qemu/aqmp/__init__.py
@@ -21,8 +21,6 @@
 # This work is licensed under the terms of the GNU GPL, version 2.  See
 # the COPYING file in the top-level directory.
 
-import warnings
-
 from .error import AQMPError
 from .events import EventListener
 from .message import Message
@@ -30,18 +28,6 @@
 from .qmp_client import ExecInterruptedError, ExecuteError, QMPClient
 
 
-_WMSG = """
-
-The Asynchronous QMP library is currently in development and its API
-should be considered highly fluid and subject to change. It should
-not be used by any other scripts checked into the QEMU tree.
-
-Proceed with caution!
-"""
-
-warnings.warn(_WMSG, FutureWarning)
-
-
 # The order of these fields impact the Sphinx documentation order.
 __all__ = (
     # Classes, most to least important
-- 
2.31.1

[PATCH 15/15] python, iotests: replace qmp with aqmp

[John Snow]

Swap out the synchronous QEMUMonitorProtocol from qemu.qmp with the sync
wrapper from qemu.aqmp instead.

Add an escape hatch in the form of the environment variable
QEMU_PYTHON_LEGACY_QMP which allows you to cajole QEMUMachine into using
the old interface, proving that both implementations work concurrently.

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

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index 8f5a6649e5..6b005dd5d1 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -41,7 +41,6 @@
 )
 
 from qemu.qmp import (  # pylint: disable=import-error
-    QEMUMonitorProtocol,
     QMPMessage,
     QMPReturnValue,
     SocketAddrT,
@@ -50,6 +49,12 @@
 from . import console_socket
 
 
+if os.environ.get('QEMU_PYTHON_LEGACY_QMP'):
+    from qemu.qmp import QEMUMonitorProtocol
+else:
+    from qemu.aqmp.legacy import QEMUMonitorProtocol
+
+
 LOG = logging.getLogger(__name__)
 
 
-- 
2.31.1

Re: [PATCH 01/15] python/aqmp: add greeting property to QMPClient

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> Expose the greeting as a read-only property of QMPClient so it can be
> retrieved at-will.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/aqmp/qmp_client.py | 5 +++++
>   1 file changed, 5 insertions(+)

Reviewed-by: Hanna Reitz <hreitz@redhat.com>

Re: [PATCH 02/15] python/aqmp: add .empty() method to EventListener

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> Synchronous clients may want to know if they're about to block waiting
> for an event or not. A method such as this is necessary to implement a
> compatible interface for the old QEMUMonitorProtocol using the new async
> internals.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/aqmp/events.py | 6 ++++++
>   1 file changed, 6 insertions(+)

Reviewed-by: Hanna Reitz <hreitz@redhat.com>

Re: [PATCH 03/15] python/aqmp: Return cleared events from EventListener.clear()

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> This serves two purposes:
>
> (1) It is now possible to discern whether or not clear() removed any
> event(s) from the queue with absolute certainty, and
>
> (2) It is now very easy to get a List of all pending events in one
> chunk, which is useful for the sync bridge.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/aqmp/events.py | 9 +++++++--
>   1 file changed, 7 insertions(+), 2 deletions(-)

Not sure if `clear` is an ideal name then, but `drain` sounds like 
something that would block, and `drop` is really much different from 
`clear`.  Also, doesn’t matter, having Collection.delete return the 
deleted element is a common thing in any language’s standard library, so 
why not have `clear` do the same.

Reviewed-by: Hanna Reitz <hreitz@redhat.com>

Re: [PATCH 04/15] python/qmp: clear events on get_events() call

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> All callers in the tree *already* clear the events after a call to
> get_events(). Do it automatically instead and update callsites to remove
> the manual clear call.
>
> These semantics are quite a bit easier to emulate with async QMP, and
> nobody appears to be abusing some emergent properties of what happens if
> you decide not to clear them, so let's dial down to the dumber, simpler
> thing.
>
> Specifically: callers of clear() right after a call to get_events() are
> more likely expressing their desire to not see any events they just
> retrieved, whereas callers of clear_events() not in relation to a recent
> call to pull_event/get_events are likely expressing their desire to
> simply drop *all* pending events straight onto the floor. In the sync
> world, this is safe enough; in the async world it's nearly impossible to
> promise that nothing happens between getting and clearing the
> events.
>
> Making the retrieval also clear the queue is vastly simpler.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/machine/machine.py | 1 -
>   python/qemu/qmp/__init__.py    | 4 +++-
>   python/qemu/qmp/qmp_shell.py   | 1 -
>   3 files changed, 3 insertions(+), 3 deletions(-)

[...]

> diff --git a/python/qemu/qmp/__init__.py b/python/qemu/qmp/__init__.py
> index 269516a79b..ba15668c25 100644
> --- a/python/qemu/qmp/__init__.py
> +++ b/python/qemu/qmp/__init__.py
> @@ -374,7 +374,9 @@ def get_events(self, wait: bool = False) -> List[QMPMessage]:
>           @return The list of available QMP events.
>           """
>           self.__get_events(wait)
> -        return self.__events
> +        events = self.__events
> +        self.__events = []
> +        return events

Maybe it’s worth updating the doc string that right now just says “Get a 
list of available QMP events”?

(Also, perhaps renaming it to get_new_events, but that’s an even weaker 
suggestion.)

Anyway:

Reviewed-by: Hanna Reitz <hreitz@redhat.com>

Re: [PATCH 05/15] python/qmp: add send_fd_scm directly to QEMUMonitorProtocol

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> It turns out you can do this directly from Python ... and because of
> this, you don't need to worry about setting the inheritability of the
> fds or spawning another process.
>
> Doing this is helpful because it allows QEMUMonitorProtocol to keep its
> file descriptor and socket object as private implementation details.
>
> *that* is helpful in turn because it allows me to write a compatible,
>   alternative implementation.

Bit of a weird indentation here.

> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/machine/machine.py | 44 +++++++---------------------------
>   python/qemu/qmp/__init__.py    | 21 +++++++---------
>   2 files changed, 18 insertions(+), 47 deletions(-)
>
> diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
> index ae945ca3c9..1c6532a3d6 100644
> --- a/python/qemu/machine/machine.py
> +++ b/python/qemu/machine/machine.py
> @@ -213,48 +213,22 @@ def add_fd(self: _T, fd: int, fdset: int,
>       def send_fd_scm(self, fd: Optional[int] = None,
>                       file_path: Optional[str] = None) -> int:

[...]

>           if file_path is not None:
>               assert fd is None
> -            fd_param.append(file_path)
> +            with open(file_path, "rb") as passfile:
> +                fd = passfile.fileno()
> +                self._qmp.send_fd_scm(fd)

Seems a bit strange to send an fd that is then immediately closed, but 
that’s what socket_scm_helper did, and so it looks like the fd is 
effectively duplicated.  OK then.

Reviewed-by: Hanna Reitz <hreitz@redhat.com>

Re: [PATCH 06/15] python, iotests: remove socket_scm_helper

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> It's not used anymore, now.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   tests/qemu-iotests/socket_scm_helper.c | 136 -------------------------
>   python/qemu/machine/machine.py         |   3 -
>   python/qemu/machine/qtest.py           |   2 -
>   tests/Makefile.include                 |   1 -
>   tests/meson.build                      |   4 -
>   tests/qemu-iotests/iotests.py          |   3 -
>   tests/qemu-iotests/meson.build         |   5 -
>   tests/qemu-iotests/testenv.py          |   8 +-
>   8 files changed, 1 insertion(+), 161 deletions(-)
>   delete mode 100644 tests/qemu-iotests/socket_scm_helper.c
>   delete mode 100644 tests/qemu-iotests/meson.build

Oh, huh.  Nice.

Reviewed-by: Hanna Reitz <hreitz@redhat.com>

Re: [PATCH 07/15] python/aqmp: add send_fd_scm

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> The single space is indeed required to successfully transmit the file
> descriptor to QEMU.

Yeah, socket_scm_helper.c said “Send a blank to notify qemu”.

> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/aqmp/qmp_client.py | 17 +++++++++++++++++
>   1 file changed, 17 insertions(+)
>
> diff --git a/python/qemu/aqmp/qmp_client.py b/python/qemu/aqmp/qmp_client.py
> index d2ad7459f9..58f85990bc 100644
> --- a/python/qemu/aqmp/qmp_client.py
> +++ b/python/qemu/aqmp/qmp_client.py
> @@ -9,6 +9,8 @@
>   
>   import asyncio
>   import logging
> +import socket
> +import struct
>   from typing import (
>       Dict,
>       List,
> @@ -624,3 +626,18 @@ async def execute(self, cmd: str,
>           """
>           msg = self.make_execute_msg(cmd, arguments, oob=oob)
>           return await self.execute_msg(msg)
> +
> +    @upper_half
> +    @require(Runstate.RUNNING)
> +    def send_fd_scm(self, fd: int) -> None:
> +        """
> +        Send a file descriptor to the remote via SCM_RIGHTS.
> +        """
> +        assert self._writer is not None
> +        sock = self._writer.transport.get_extra_info('socket')
> +
> +        # Python 3.9+ adds socket.send_fds(...)
> +        sock.sendmsg(
> +            [b' '],
> +            [(socket.SOL_SOCKET, socket.SCM_RIGHTS, struct.pack('@i', fd))]
> +        )

AFAIU the socket can be either TCP or a UNIX socket 
(AsyncProtocol._do_accept’s docstring sounds this way), so should we 
check that this is a UNIX socket?  (Or is it fine to just run into the 
error that I suspect we would get with a TCP socket?)

Hanna

Re: [PATCH 08/15] python/aqmp: Create MessageModel and StandaloneModel classes

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> This allows 'Greeting' to be subclass of 'Message'. We need the adapter
> classes to avoid some typing problems that occur if we try to put too
> much into the 'Model' class itself; the exact details of why are left as
> an exercise to the reader.
>
> Why bother? This makes 'Greeting' ⊆ 'Message', which is taxonomically
> true; but the real motivation is to be able to inherit and abuse all of
> the Mapping dunders so that we can call dict(greeting) or
> bytes(greeting), for example.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/aqmp/models.py | 67 ++++++++++++++++++++++++++++----------
>   1 file changed, 50 insertions(+), 17 deletions(-)

(I feel like this is a bit much outside of my scope, so this’ll have to 
do without my R-b.)

Re: [PATCH 09/15] python/machine: remove has_quit argument

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> If we spy on the QMP commands instead, we don't need callers to remember
> to pass it. Seems like a fair trade-off.
>
> The one slightly weird bit is overloading this instance variable for
> wait(), where we use it to mean "don't issue the qmp 'quit'
> command". This means that wait() will "fail" if the QEMU process does
> not terminate of its own accord.
>
> In most cases, we probably did already actually issue quit -- some
> iotests do this -- but in some others, we may be waiting for QEMU to
> terminate for some other reason.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/machine/machine.py | 35 +++++++++++++++++++---------------
>   tests/qemu-iotests/040         |  7 +------
>   tests/qemu-iotests/218         |  2 +-
>   tests/qemu-iotests/255         |  2 +-
>   4 files changed, 23 insertions(+), 23 deletions(-)

Looks good overall, some bikeshedding below.

> diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
> index 056d340e35..6e58d2f951 100644
> --- a/python/qemu/machine/machine.py
> +++ b/python/qemu/machine/machine.py
> @@ -170,6 +170,7 @@ def __init__(self,
>           self._console_socket: Optional[socket.socket] = None
>           self._remove_files: List[str] = []
>           self._user_killed = False
> +        self._has_quit = False

Sounds a bit weird, because evidently it has quit.

I mean, it was always more of a has_sent_quit or quit_issued, but now it 
really seems a bit wrong.

[...]

> @@ -529,7 +526,9 @@ def wait(self, timeout: Optional[int] = 30) -> None:
>           :param timeout: Optional timeout in seconds. Default 30 seconds.
>                           A value of `None` is an infinite wait.
>           """
> -        self.shutdown(has_quit=True, timeout=timeout)
> +        # In case QEMU was stopped without issuing 'quit':

This comment confused me more than anything and only looking at the 
function’s name and doc string was I able to understand why we have 
has_quit = True here, and only by scratching my head asking myself why 
you’d write the comment did I understand the comment’s purpose.

What isn’t quite clear in the comment is that we kind of expect 
_has_quit to already be True, because the VM was probably exited with 
`quit`.  But we don’t know for sure, so we have to force _has_quit to True.

But it’s also not necessary to explain, I think.  The idea is simply 
that this function should do nothing to make the VM quit, so it’s 
absolutely natural that we’d set _has_quit to True, because the caller 
guarantees that they already made the VM quit.  No need to explain why 
this might already be True, and why it’s still OK.

So I’d just say something like “Do not send a `quit` to the VM, just 
wait for it to exit”.

Hanna

> +        self._has_quit = True
> +        self.shutdown(timeout=timeout)
>   
>       def set_qmp_monitor(self, enabled: bool = True) -> None:
>           """

Re: [PATCH 10/15] python/machine: Add support for AQMP backend

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> To use the AQMP backend, Machine just needs to be a little more diligent
> about what happens when closing a QMP connection. The operation is no
> longer a freebie in the async world.
>
> Because async QMP continues to check for messages asynchronously, it's
> almost certainly likely that the loop will have exited due to EOF after
> issuing the last 'quit' command. That error will ultimately be bubbled
> up when attempting to close the QMP connection. The manager class here
> then is free to discard it if it was expected.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
>
> ---
>
> Yes, I regret that this class has become quite a dumping ground for
> complexity around the exit path. It's in need of a refactor to help
> separate out the exception handling and cleanup mechanisms from the
> VM-related stuff, but it's not a priority to do that just yet -- but
> it's on the list.
>
> ---
>   python/qemu/machine/machine.py | 51 ++++++++++++++++++++++++++++++----
>   1 file changed, 46 insertions(+), 5 deletions(-)
>
> diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
> index 6e58d2f951..8f5a6649e5 100644
> --- a/python/qemu/machine/machine.py
> +++ b/python/qemu/machine/machine.py
> @@ -342,9 +342,15 @@ def _post_shutdown(self) -> None:
>           # Comprehensive reset for the failed launch case:
>           self._early_cleanup()
>   
> -        if self._qmp_connection:
> -            self._qmp.close()
> -            self._qmp_connection = None
> +        try:
> +            self._close_qmp_connection()
> +        except Exception as err:  # pylint: disable=broad-except
> +            LOG.warning(
> +                "Exception closing QMP connection: %s",
> +                str(err) if str(err) else type(err).__name__
> +            )
> +        finally:
> +            assert self._qmp_connection is None
>   
>           self._close_qemu_log_file()
>   
> @@ -420,6 +426,31 @@ def _launch(self) -> None:
>                                          close_fds=False)
>           self._post_launch()
>   
> +    def _close_qmp_connection(self) -> None:
> +        """
> +        Close the underlying QMP connection, if any.
> +
> +        Dutifully report errors that occurred while closing, but assume
> +        that any error encountered indicates an abnormal termination
> +        process and not a failure to close.
> +        """
> +        if self._qmp_connection is None:
> +            return
> +
> +        try:
> +            self._qmp.close()
> +        except EOFError:
> +            # EOF can occur as an Exception here when using the Async
> +            # QMP backend. It indicates that the server closed the
> +            # stream. If we successfully issued 'quit' at any point,
> +            # then this was expected. If the remote went away without
> +            # our permission, it's worth reporting that as an abnormal
> +            # shutdown case.
> +            if not self._has_quit:
> +                raise
> +        finally:
> +            self._qmp_connection = None
> +
>       def _early_cleanup(self) -> None:
>           """
>           Perform any cleanup that needs to happen before the VM exits.
> @@ -461,8 +492,18 @@ def _soft_shutdown(self, timeout: Optional[int]) -> None:
>   
>           if self._qmp_connection:
>               if not self._has_quit:
> -                # Might raise ConnectionReset
> -                self.qmp('quit')
> +                try:
> +                    # May raise ExecInterruptedError or StateError if the
> +                    # connection dies or has already died.
> +                    self.qmp('quit')
> +                finally:
> +                    # If 'quit' fails, we'll still want to call close(),
> +                    # which will raise any final errors that may have
> +                    # occurred while trying to send 'quit'.
> +                    self._close_qmp_connection()
> +            else:
> +                # Regardless, we want to tidy up the socket.
> +                self._close_qmp_connection()

Why can’t we wait for _post_shutdown to do that?  Has it something to do 
with this operation being “no longer a freeby” (I’m not quite sure what 
this refers to, execution time, or the set of possible exceptions, or 
perhaps something else entirely), and so we want to do it in the 
already-not-instantaneous _soft_shutdown?

Hanna

>   
>           # May raise subprocess.TimeoutExpired
>           self._subp.wait(timeout=timeout)

Re: [PATCH 11/15] python/aqmp: Create sync QMP wrapper for iotests

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> This is a wrapper around the async QMPClient that mimics the old,
> synchronous QEMUMonitorProtocol class. It is designed to be
> interchangeable with the old implementation.
>
> It does not, however, attempt to mimic Exception compatibility.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/aqmp/legacy.py | 131 +++++++++++++++++++++++++++++++++++++
>   1 file changed, 131 insertions(+)
>   create mode 100644 python/qemu/aqmp/legacy.py

Looks reasonable to me, although I can’t give an R-b in good 
conscience.  I’m tempted to give a neo-tag (“Looks-okay-to:”), but let’s 
just be boring and do an

Acked-by: Hanna Reitz <hreitz@redhat.com>

Re: [PATCH 12/15] iotests: Disable AQMP logging under non-debug modes

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> Disable the aqmp logger, which likes to (at the moment) print out
> intermediate warnings and errors that cause session termination; disable
> them so they don't interfere with the job output.
>
> Leave any "CRITICAL" warnings enabled though, those are ones that we
> should never see, no matter what.

I mean, looks OK to me, but from what I understand (i.e. little), 
qmp_client doesn’t log CRITICAL messages, at least I can’t see any. Only 
ERRORs.

I guess I’m missing some CRITICAL messages in external functions called 
from qmp_client.py, but shouldn’t we still keep ERRORs?

Hanna

> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   tests/qemu-iotests/iotests.py | 2 ++
>   1 file changed, 2 insertions(+)
>
> diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
> index 273d2777ae..47e5f9738b 100644
> --- a/tests/qemu-iotests/iotests.py
> +++ b/tests/qemu-iotests/iotests.py
> @@ -1383,6 +1383,8 @@ def execute_setup_common(supported_fmts: Sequence[str] = (),
>       if debug:
>           sys.argv.remove('-d')
>       logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN))
> +    if not debug:
> +        logging.getLogger("qemu.aqmp.qmp_client").setLevel(logging.CRITICAL)
>   
>       _verify_image_format(supported_fmts, unsupported_fmts)
>       _verify_protocol(supported_protocols, unsupported_protocols)

Re: [PATCH 13/15] iotests: Accommodate async QMP Exception classes

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> (But continue to support the old ones for now, too.)
>
> There are very few cases of any user of QEMUMachine or a subclass
> thereof relying on a QMP Exception type. If you'd like to check for
> yourself, you want to grep for all of the derivatives of QMPError,
> excluding 'AQMPError' and its derivatives. That'd be these:
>
> - QMPError
> - QMPConnectError
> - QMPCapabilitiesError
> - QMPTimeoutError
> - QMPProtocolError
> - QMPResponseError
> - QMPBadPortError
>
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   scripts/simplebench/bench_block_job.py    | 3 ++-
>   tests/qemu-iotests/tests/mirror-top-perms | 6 +++++-
>   2 files changed, 7 insertions(+), 2 deletions(-)
>
> diff --git a/scripts/simplebench/bench_block_job.py b/scripts/simplebench/bench_block_job.py
> index 4f03c12169..a403c35b08 100755
> --- a/scripts/simplebench/bench_block_job.py
> +++ b/scripts/simplebench/bench_block_job.py
> @@ -28,6 +28,7 @@
>   sys.path.append(os.path.join(os.path.dirname(__file__), '..', '..', 'python'))
>   from qemu.machine import QEMUMachine
>   from qemu.qmp import QMPConnectError
> +from qemu.aqmp import ConnectError
>   
>   
>   def bench_block_job(cmd, cmd_args, qemu_args):
> @@ -49,7 +50,7 @@ def bench_block_job(cmd, cmd_args, qemu_args):
>           vm.launch()
>       except OSError as e:
>           return {'error': 'popen failed: ' + str(e)}
> -    except (QMPConnectError, socket.timeout):
> +    except (QMPConnectError, ConnectError, socket.timeout):
>           return {'error': 'qemu failed: ' + str(vm.get_log())}
>   
>       try:
> diff --git a/tests/qemu-iotests/tests/mirror-top-perms b/tests/qemu-iotests/tests/mirror-top-perms
> index 451a0666f8..7d448f4d23 100755
> --- a/tests/qemu-iotests/tests/mirror-top-perms
> +++ b/tests/qemu-iotests/tests/mirror-top-perms
> @@ -103,7 +103,11 @@ class TestMirrorTopPerms(iotests.QMPTestCase):
>               print('ERROR: VM B launched successfully, this should not have '
>                     'happened')
>           except qemu.qmp.QMPConnectError:
> -            assert 'Is another process using the image' in self.vm_b.get_log()
> +            pass
> +        except qemu.aqmp.ConnectError:
> +            pass
> +
> +        assert 'Is another process using the image' in self.vm_b.get_log()

But this assertion will fail if there was no exception, and so we won’t 
get to see the real problem, which is the original VM aborting (see the 
doc string).

It doesn’t really matter that much that VM B can start (hence it being a 
logged error message, not a fatal error), and when it can start, of 
course it won’t print an error – but what’s important is that the 
original VM will then abort.

I mean, not an absolute showstopper by any means, but still, the 
assertion was deliberately placed into the `except` block.

Hanna

Re: [PATCH 14/15] python/aqmp: Remove scary message

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> The scary message interferes with the iotests output. Coincidentally, if
> iotests works by removing this, then it's good evidence that we don't
> really need to scare people away from using it.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/aqmp/__init__.py | 14 --------------
>   1 file changed, 14 deletions(-)

I definitely won’t give an R-b for this one, because that would require 
me reviewing the AQMP series, and, well, you know.

Also, if I were to review the AQMP series and could actually give R-bs 
in good faith, why would I accept adding this message?  I mean, if I’d 
reviewed it, I’d’ve had to trust it.

So, öhm, I’m fine with dropping this message because evidently I’d’ve 
never agreed to adding it in the first place (had I reviewed the AQMP 
series).

Hanna

Re: [PATCH 15/15] python, iotests: replace qmp with aqmp

[Hanna Reitz]

On 17.09.21 07:40, John Snow wrote:
> Swap out the synchronous QEMUMonitorProtocol from qemu.qmp with the sync
> wrapper from qemu.aqmp instead.
>
> Add an escape hatch in the form of the environment variable
> QEMU_PYTHON_LEGACY_QMP which allows you to cajole QEMUMachine into using
> the old interface, proving that both implementations work concurrently.
>
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>   python/qemu/machine/machine.py | 7 ++++++-
>   1 file changed, 6 insertions(+), 1 deletion(-)
>
> diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
> index 8f5a6649e5..6b005dd5d1 100644
> --- a/python/qemu/machine/machine.py
> +++ b/python/qemu/machine/machine.py
> @@ -41,7 +41,6 @@
>   )
>   
>   from qemu.qmp import (  # pylint: disable=import-error
> -    QEMUMonitorProtocol,
>       QMPMessage,
>       QMPReturnValue,
>       SocketAddrT,
> @@ -50,6 +49,12 @@
>   from . import console_socket
>   
>   
> +if os.environ.get('QEMU_PYTHON_LEGACY_QMP'):
> +    from qemu.qmp import QEMUMonitorProtocol
> +else:
> +    from qemu.aqmp.legacy import QEMUMonitorProtocol
> +
> +
>   LOG = logging.getLogger(__name__)

Black magic.

Reviewed-by: Hanna Reitz <hreitz@redhat.com>
Tested-by: Hanna Reitz <hreitz@redhat.com>

Re: [PATCH 15/15] python, iotests: replace qmp with aqmp

[John Snow]

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

On Fri, Sep 17, 2021 at 10:40 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > Swap out the synchronous QEMUMonitorProtocol from qemu.qmp with the sync
> > wrapper from qemu.aqmp instead.
> >
> > Add an escape hatch in the form of the environment variable
> > QEMU_PYTHON_LEGACY_QMP which allows you to cajole QEMUMachine into using
> > the old interface, proving that both implementations work concurrently.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >   python/qemu/machine/machine.py | 7 ++++++-
> >   1 file changed, 6 insertions(+), 1 deletion(-)
> >
> > diff --git a/python/qemu/machine/machine.py
> b/python/qemu/machine/machine.py
> > index 8f5a6649e5..6b005dd5d1 100644
> > --- a/python/qemu/machine/machine.py
> > +++ b/python/qemu/machine/machine.py
> > @@ -41,7 +41,6 @@
> >   )
> >
> >   from qemu.qmp import (  # pylint: disable=import-error
> > -    QEMUMonitorProtocol,
> >       QMPMessage,
> >       QMPReturnValue,
> >       SocketAddrT,
> > @@ -50,6 +49,12 @@
> >   from . import console_socket
> >
> >
> > +if os.environ.get('QEMU_PYTHON_LEGACY_QMP'):
> > +    from qemu.qmp import QEMUMonitorProtocol
> > +else:
> > +    from qemu.aqmp.legacy import QEMUMonitorProtocol
> > +
> > +
> >   LOG = logging.getLogger(__name__)
>
> Black magic.
>
> Reviewed-by: Hanna Reitz <hreitz@redhat.com>
> Tested-by: Hanna Reitz <hreitz@redhat.com>
>
>
Thanks for taking a look! Sorry for making you look at python :)

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

Re: [PATCH 14/15] python/aqmp: Remove scary message

[John Snow]

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

On Fri, Sep 17, 2021 at 10:39 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > The scary message interferes with the iotests output. Coincidentally, if
> > iotests works by removing this, then it's good evidence that we don't
> > really need to scare people away from using it.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >   python/qemu/aqmp/__init__.py | 14 --------------
> >   1 file changed, 14 deletions(-)
>
> I definitely won’t give an R-b for this one, because that would require
> me reviewing the AQMP series, and, well, you know.
>
>
Yep, no worries. I'd feel bad if you started digging into it. Not the best
use of your time. I am trying to shield you from this junk, not pull you
into it.

(but, I hope the new library is easy to use. I went out of my way to make
sure the transition would be as seamless as possible for iotest writers,
and I genuinely hope I achieved that. Though as you've seen, there's a few
messy bits -- One of the reasons for sending this series out to list so
soon was precisely to force someone to witness the ugly bits so I could
align my thinking on how best to address them.)

Also, if I were to review the AQMP series and could actually give R-bs
> in good faith, why would I accept adding this message?  I mean, if I’d
> reviewed it, I’d’ve had to trust it.
>
> So, öhm, I’m fine with dropping this message because evidently I’d’ve
> never agreed to adding it in the first place (had I reviewed the AQMP
> series).
>
> Hanna
>
>
I added as a pre-emptive mollification, it's been in my series for a while.
I jokingly refer to it as "tech preview". The asyncio stuff is fairly new
(even to Python programmers) and though I have tried my very hardest to
test that library as thoroughly as I possibly could, it seems like
everyone's reaction has been "Ah jeez, I dunno if I can truly review this"
so I added a little warning to ease minds a bit and try to make people feel
like they were committing to less.

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

Re: [PATCH 03/15] python/aqmp: Return cleared events from EventListener.clear()

[John Snow]

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

On Fri, Sep 17, 2021 at 8:36 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > This serves two purposes:
> >
> > (1) It is now possible to discern whether or not clear() removed any
> > event(s) from the queue with absolute certainty, and
> >
> > (2) It is now very easy to get a List of all pending events in one
> > chunk, which is useful for the sync bridge.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >   python/qemu/aqmp/events.py | 9 +++++++--
> >   1 file changed, 7 insertions(+), 2 deletions(-)
>
> Not sure if `clear` is an ideal name then, but `drain` sounds like
> something that would block, and `drop` is really much different from
> `clear`.  Also, doesn’t matter, having Collection.delete return the
> deleted element is a common thing in any language’s standard library, so
> why not have `clear` do the same.
>
>
It isn't too late to change the name, but it sounds like you don't
necessarily prefer any of those others over what's there now.


> Reviewed-by: Hanna Reitz <hreitz@redhat.com>
>
>
Thanks!

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

Re: [PATCH 04/15] python/qmp: clear events on get_events() call

[John Snow]

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

On Fri, Sep 17, 2021 at 8:51 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > All callers in the tree *already* clear the events after a call to
> > get_events(). Do it automatically instead and update callsites to remove
> > the manual clear call.
> >
> > These semantics are quite a bit easier to emulate with async QMP, and
> > nobody appears to be abusing some emergent properties of what happens if
> > you decide not to clear them, so let's dial down to the dumber, simpler
> > thing.
> >
> > Specifically: callers of clear() right after a call to get_events() are
> > more likely expressing their desire to not see any events they just
> > retrieved, whereas callers of clear_events() not in relation to a recent
> > call to pull_event/get_events are likely expressing their desire to
> > simply drop *all* pending events straight onto the floor. In the sync
> > world, this is safe enough; in the async world it's nearly impossible to
> > promise that nothing happens between getting and clearing the
> > events.
> >
> > Making the retrieval also clear the queue is vastly simpler.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >   python/qemu/machine/machine.py | 1 -
> >   python/qemu/qmp/__init__.py    | 4 +++-
> >   python/qemu/qmp/qmp_shell.py   | 1 -
> >   3 files changed, 3 insertions(+), 3 deletions(-)
>
> [...]
>
> > diff --git a/python/qemu/qmp/__init__.py b/python/qemu/qmp/__init__.py
> > index 269516a79b..ba15668c25 100644
> > --- a/python/qemu/qmp/__init__.py
> > +++ b/python/qemu/qmp/__init__.py
> > @@ -374,7 +374,9 @@ def get_events(self, wait: bool = False) ->
> List[QMPMessage]:
> >           @return The list of available QMP events.
> >           """
> >           self.__get_events(wait)
> > -        return self.__events
> > +        events = self.__events
> > +        self.__events = []
> > +        return events
>
> Maybe it’s worth updating the doc string that right now just says “Get a
> list of available QMP events”?
>
>
Yes, that's an oversight on my part. I'm updating it to:
"Get a list of available QMP events and clear the list of pending events."
and adding your RB.

(Also, perhaps renaming it to get_new_events, but that’s an even weaker
> suggestion.)
>

I tried to avoid churn in the iotests as much as I could manage, so I think
I will leave this be for now. I have an impression that the number of cases
where one might wish to see events that have already been witnessed is
actually quite low, so I am not sure that it needs disambiguation from a
case that is essentially never used. (I have certainly been wrong before,
though.)


> Anyway:
>
> Reviewed-by: Hanna Reitz <hreitz@redhat.com>
>
>
~ thankyou ~

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

Re: [PATCH 05/15] python/qmp: add send_fd_scm directly to QEMUMonitorProtocol

[John Snow]

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

On Fri, Sep 17, 2021 at 9:21 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > It turns out you can do this directly from Python ... and because of
> > this, you don't need to worry about setting the inheritability of the
> > fds or spawning another process.
> >
> > Doing this is helpful because it allows QEMUMonitorProtocol to keep its
> > file descriptor and socket object as private implementation details.
> >
> > *that* is helpful in turn because it allows me to write a compatible,
> >   alternative implementation.
>
> Bit of a weird indentation here.
>
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >   python/qemu/machine/machine.py | 44 +++++++---------------------------
> >   python/qemu/qmp/__init__.py    | 21 +++++++---------
> >   2 files changed, 18 insertions(+), 47 deletions(-)
> >
> > diff --git a/python/qemu/machine/machine.py
> b/python/qemu/machine/machine.py
> > index ae945ca3c9..1c6532a3d6 100644
> > --- a/python/qemu/machine/machine.py
> > +++ b/python/qemu/machine/machine.py
> > @@ -213,48 +213,22 @@ def add_fd(self: _T, fd: int, fdset: int,
> >       def send_fd_scm(self, fd: Optional[int] = None,
> >                       file_path: Optional[str] = None) -> int:
>
> [...]
>
> >           if file_path is not None:
> >               assert fd is None
> > -            fd_param.append(file_path)
> > +            with open(file_path, "rb") as passfile:
> > +                fd = passfile.fileno()
> > +                self._qmp.send_fd_scm(fd)
>
> Seems a bit strange to send an fd that is then immediately closed, but
> that’s what socket_scm_helper did, and so it looks like the fd is
> effectively duplicated.  OK then.
>
>
Same boat. It's weird, but it seems to work, and it's how the old interface
(ultimately) behaved, so ... https://i.imgur.com/O0CQXoh.png


> Reviewed-by: Hanna Reitz <hreitz@redhat.com>
>
>

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

Re: [PATCH 07/15] python/aqmp: add send_fd_scm

[John Snow]

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

On Fri, Sep 17, 2021 at 9:34 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > The single space is indeed required to successfully transmit the file
> > descriptor to QEMU.
>
> Yeah, socket_scm_helper.c said “Send a blank to notify qemu”.
>
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >   python/qemu/aqmp/qmp_client.py | 17 +++++++++++++++++
> >   1 file changed, 17 insertions(+)
> >
> > diff --git a/python/qemu/aqmp/qmp_client.py
> b/python/qemu/aqmp/qmp_client.py
> > index d2ad7459f9..58f85990bc 100644
> > --- a/python/qemu/aqmp/qmp_client.py
> > +++ b/python/qemu/aqmp/qmp_client.py
> > @@ -9,6 +9,8 @@
> >
> >   import asyncio
> >   import logging
> > +import socket
> > +import struct
> >   from typing import (
> >       Dict,
> >       List,
> > @@ -624,3 +626,18 @@ async def execute(self, cmd: str,
> >           """
> >           msg = self.make_execute_msg(cmd, arguments, oob=oob)
> >           return await self.execute_msg(msg)
> > +
> > +    @upper_half
> > +    @require(Runstate.RUNNING)
> > +    def send_fd_scm(self, fd: int) -> None:
> > +        """
> > +        Send a file descriptor to the remote via SCM_RIGHTS.
> > +        """
> > +        assert self._writer is not None
> > +        sock = self._writer.transport.get_extra_info('socket')
> > +
> > +        # Python 3.9+ adds socket.send_fds(...)
> > +        sock.sendmsg(
> > +            [b' '],
> > +            [(socket.SOL_SOCKET, socket.SCM_RIGHTS, struct.pack('@i',
> fd))]
> > +        )
>
> AFAIU the socket can be either TCP or a UNIX socket
> (AsyncProtocol._do_accept’s docstring sounds this way), so should we
> check that this is a UNIX socket?  (Or is it fine to just run into the
> error that I suspect we would get with a TCP socket?)
>
> Hanna
>
>
Uhh, hm. I was going to say "Yeah, just let it fail!" but ... upon going to
document what error to expect in this case, I am realizing it fails
silently. So, uh, that's not ideal.

I'll fix this to make it bark.

--js

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

Re: [PATCH 08/15] python/aqmp: Create MessageModel and StandaloneModel classes

[John Snow]

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

On Fri, Sep 17, 2021, 9:39 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > This allows 'Greeting' to be subclass of 'Message'. We need the adapter
> > classes to avoid some typing problems that occur if we try to put too
> > much into the 'Model' class itself; the exact details of why are left as
> > an exercise to the reader.
> >
> > Why bother? This makes 'Greeting' ⊆ 'Message', which is taxonomically
> > true; but the real motivation is to be able to inherit and abuse all of
> > the Mapping dunders so that we can call dict(greeting) or
> > bytes(greeting), for example.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >   python/qemu/aqmp/models.py | 67 ++++++++++++++++++++++++++++----------
> >   1 file changed, 50 insertions(+), 17 deletions(-)
>
> (I feel like this is a bit much outside of my scope, so this’ll have to
> do without my R-b.)
>

It's a patch I like the least, too. I shouldn't have included it here in
this series. It needs more time in the oven and it should be included ...
somewhere else.

Sorry about this one.

>

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

Re: [PATCH 09/15] python/machine: remove has_quit argument

[John Snow]

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

On Fri, Sep 17, 2021 at 9:59 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > If we spy on the QMP commands instead, we don't need callers to remember
> > to pass it. Seems like a fair trade-off.
> >
> > The one slightly weird bit is overloading this instance variable for
> > wait(), where we use it to mean "don't issue the qmp 'quit'
> > command". This means that wait() will "fail" if the QEMU process does
> > not terminate of its own accord.
> >
> > In most cases, we probably did already actually issue quit -- some
> > iotests do this -- but in some others, we may be waiting for QEMU to
> > terminate for some other reason.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >   python/qemu/machine/machine.py | 35 +++++++++++++++++++---------------
> >   tests/qemu-iotests/040         |  7 +------
> >   tests/qemu-iotests/218         |  2 +-
> >   tests/qemu-iotests/255         |  2 +-
> >   4 files changed, 23 insertions(+), 23 deletions(-)
>
> Looks good overall, some bikeshedding below.
>
> > diff --git a/python/qemu/machine/machine.py
> b/python/qemu/machine/machine.py
> > index 056d340e35..6e58d2f951 100644
> > --- a/python/qemu/machine/machine.py
> > +++ b/python/qemu/machine/machine.py
> > @@ -170,6 +170,7 @@ def __init__(self,
> >           self._console_socket: Optional[socket.socket] = None
> >           self._remove_files: List[str] = []
> >           self._user_killed = False
> > +        self._has_quit = False
>
> Sounds a bit weird, because evidently it has quit.
>
> I mean, it was always more of a has_sent_quit or quit_issued, but now it
> really seems a bit wrong.
>
>
"quit_issued" seems like it might help overall, I'll do that.


> [...]
>
> > @@ -529,7 +526,9 @@ def wait(self, timeout: Optional[int] = 30) -> None:
> >           :param timeout: Optional timeout in seconds. Default 30
> seconds.
> >                           A value of `None` is an infinite wait.
> >           """
> > -        self.shutdown(has_quit=True, timeout=timeout)
> > +        # In case QEMU was stopped without issuing 'quit':
>
> This comment confused me more than anything and only looking at the
> function’s name and doc string was I able to understand why we have
> has_quit = True here, and only by scratching my head asking myself why
> you’d write the comment did I understand the comment’s purpose.
>
> What isn’t quite clear in the comment is that we kind of expect
> _has_quit to already be True, because the VM was probably exited with
> `quit`.  But we don’t know for sure, so we have to force _has_quit to True.
>
> But it’s also not necessary to explain, I think.  The idea is simply
> that this function should do nothing to make the VM quit, so it’s
> absolutely natural that we’d set _has_quit to True, because the caller
> guarantees that they already made the VM quit.  No need to explain why
> this might already be True, and why it’s still OK.
>
> So I’d just say something like “Do not send a `quit` to the VM, just
> wait for it to exit”.
>
>
I'll just drop the comment, then.


> Hanna
>
> > +        self._has_quit = True
> > +        self.shutdown(timeout=timeout)
> >
> >       def set_qmp_monitor(self, enabled: bool = True) -> None:
> >           """
>
>

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

Re: [PATCH 10/15] python/machine: Add support for AQMP backend

[John Snow]

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

On Fri, Sep 17, 2021 at 10:16 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > To use the AQMP backend, Machine just needs to be a little more diligent
> > about what happens when closing a QMP connection. The operation is no
> > longer a freebie in the async world.
> >
> > Because async QMP continues to check for messages asynchronously, it's
> > almost certainly likely that the loop will have exited due to EOF after
> > issuing the last 'quit' command. That error will ultimately be bubbled
> > up when attempting to close the QMP connection. The manager class here
> > then is free to discard it if it was expected.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> >
> > ---
> >
> > Yes, I regret that this class has become quite a dumping ground for
> > complexity around the exit path. It's in need of a refactor to help
> > separate out the exception handling and cleanup mechanisms from the
> > VM-related stuff, but it's not a priority to do that just yet -- but
> > it's on the list.
> >
> > ---
> >   python/qemu/machine/machine.py | 51 ++++++++++++++++++++++++++++++----
> >   1 file changed, 46 insertions(+), 5 deletions(-)
> >
> > diff --git a/python/qemu/machine/machine.py
> b/python/qemu/machine/machine.py
> > index 6e58d2f951..8f5a6649e5 100644
> > --- a/python/qemu/machine/machine.py
> > +++ b/python/qemu/machine/machine.py
> > @@ -342,9 +342,15 @@ def _post_shutdown(self) -> None:
> >           # Comprehensive reset for the failed launch case:
> >           self._early_cleanup()
> >
> > -        if self._qmp_connection:
> > -            self._qmp.close()
> > -            self._qmp_connection = None
> > +        try:
> > +            self._close_qmp_connection()
> > +        except Exception as err:  # pylint: disable=broad-except
> > +            LOG.warning(
> > +                "Exception closing QMP connection: %s",
> > +                str(err) if str(err) else type(err).__name__
> > +            )
> > +        finally:
> > +            assert self._qmp_connection is None
> >
> >           self._close_qemu_log_file()
> >
> > @@ -420,6 +426,31 @@ def _launch(self) -> None:
> >                                          close_fds=False)
> >           self._post_launch()
> >
> > +    def _close_qmp_connection(self) -> None:
> > +        """
> > +        Close the underlying QMP connection, if any.
> > +
> > +        Dutifully report errors that occurred while closing, but assume
> > +        that any error encountered indicates an abnormal termination
> > +        process and not a failure to close.
> > +        """
> > +        if self._qmp_connection is None:
> > +            return
> > +
> > +        try:
> > +            self._qmp.close()
> > +        except EOFError:
> > +            # EOF can occur as an Exception here when using the Async
> > +            # QMP backend. It indicates that the server closed the
> > +            # stream. If we successfully issued 'quit' at any point,
> > +            # then this was expected. If the remote went away without
> > +            # our permission, it's worth reporting that as an abnormal
> > +            # shutdown case.
> > +            if not self._has_quit:
> > +                raise
> > +        finally:
> > +            self._qmp_connection = None
> > +
> >       def _early_cleanup(self) -> None:
> >           """
> >           Perform any cleanup that needs to happen before the VM exits.
> > @@ -461,8 +492,18 @@ def _soft_shutdown(self, timeout: Optional[int]) ->
> None:
> >
> >           if self._qmp_connection:
> >               if not self._has_quit:
> > -                # Might raise ConnectionReset
> > -                self.qmp('quit')
> > +                try:
> > +                    # May raise ExecInterruptedError or StateError if
> the
> > +                    # connection dies or has already died.
> > +                    self.qmp('quit')
> > +                finally:
> > +                    # If 'quit' fails, we'll still want to call close(),
> > +                    # which will raise any final errors that may have
> > +                    # occurred while trying to send 'quit'.
> > +                    self._close_qmp_connection()
> > +            else:
> > +                # Regardless, we want to tidy up the socket.
> > +                self._close_qmp_connection()
>
> Why can’t we wait for _post_shutdown to do that?  Has it something to do
> with this operation being “no longer a freeby” (I’m not quite sure what
> this refers to, execution time, or the set of possible exceptions, or
> perhaps something else entirely), and so we want to do it in the
> already-not-instantaneous _soft_shutdown?
>
> Hanna
>
>
I wrote that commit message too casually.

By "freebie", I meant that closing a simple sync socket does not have any
potential for raising an error, so we don't really have to worry about that
operation failing. The async machinery, by comparison, uses the
disconnection point as its synchronization point where it gathers the final
results from its various execution contexts (the reader, writer, and
disconnection tasks).

The likeliest error to see here would be something like EOFError for QEMU
hanging up before disconnect() was called. Other possible errors would be
stuff from deep in the internals of AQMP that very likely means there's a
bug I need to resolve -- so I was afraid of just wholesale silencing such
things. (Hence the logged warning in the _post_shutdown method. I genuinely
don't expect to see anything there, but I am paranoid and wanted to be
rock-solid sure that any problems are visible.) It is also possible that if
QEMU were to send a garbled and unprompted message after 'quit' succeeded
(For example, a malformed SHUTDOWN event) that this would also enqueue an
error to be shown here at this point.

One of the design points of AQMP is that calling QMPClient.disconnect() is
necessary to reset the client to a fully IDLE state to where it can be
re-used for a subsequent connection. It serves double-duty as both
disconnect *and* results gathering. So I wanted to make sure to call it
here while we still had the opportunity to report an "Abnormal Shutdown"
instead of potentially choking later during the post-shutdown and failing
to do resource cleanup.

Good: if shutdown() succeeds, you can rest well knowing that definitely
nothing weird happened.
Bad: There's a lot of complexity inherent in promising that.

Clear as mud?

--js

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

Re: [PATCH 11/15] python/aqmp: Create sync QMP wrapper for iotests

[John Snow]

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

On Fri, Sep 17, 2021 at 10:23 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > This is a wrapper around the async QMPClient that mimics the old,
> > synchronous QEMUMonitorProtocol class. It is designed to be
> > interchangeable with the old implementation.
> >
> > It does not, however, attempt to mimic Exception compatibility.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >   python/qemu/aqmp/legacy.py | 131 +++++++++++++++++++++++++++++++++++++
> >   1 file changed, 131 insertions(+)
> >   create mode 100644 python/qemu/aqmp/legacy.py
>
> Looks reasonable to me, although I can’t give an R-b in good
> conscience.  I’m tempted to give a neo-tag (“Looks-okay-to:”), but let’s
> just be boring and do an
>
> Acked-by: Hanna Reitz <hreitz@redhat.com>
>
>
The mischief maker in me wants to add the custom tag, but I suppose I'll be
kind to the people who crunch the stats and use the vanilla tag. :)

Thanks a bunch!

--js

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

Re: [PATCH 12/15] iotests: Disable AQMP logging under non-debug modes

[John Snow]

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

On Fri, Sep 17, 2021 at 10:30 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > Disable the aqmp logger, which likes to (at the moment) print out
> > intermediate warnings and errors that cause session termination; disable
> > them so they don't interfere with the job output.
> >
> > Leave any "CRITICAL" warnings enabled though, those are ones that we
> > should never see, no matter what.
>
> I mean, looks OK to me, but from what I understand (i.e. little),
> qmp_client doesn’t log CRITICAL messages, at least I can’t see any. Only
> ERRORs.
>
>
There's *one* critical message in protocol.py, used for a circumstance that
I *think* should be impossible. I do not think I currently use any WARNING
level statements.


> I guess I’m missing some CRITICAL messages in external functions called
> from qmp_client.py, but shouldn’t we still keep ERRORs?
>

...Mayyyyyybe?

The errors logged by AQMP are *almost always* raised as Exceptions
somewhere else, eventually. Sometimes when we encounter them in one
context, we need to save them and then re-raise them in a different
execution context. There's one good exception to this: My pal, EOFError.

If the reader context encounters EOF, it raises EOFError and this causes a
disconnect to be scheduled asynchronously. *Any* Exception that causes a
disconnect to be scheduled asynchronously is dutifully logged as an ERROR.
At this point in the code, we don't really know if the user of the library
considers this an "error" yet or not. I've waffled a lot on how exactly to
treat this circumstance. ...Hm, I guess that's really the only case where I
have an error that really ought to be suppressed. I suppose what I will do
here is: if the exception happens to be an EOFError I will drop the
severity of the log message down to INFO. I don't know why it takes being
challenged on this stuff to start thinking clearly about it, but here we
are. Thank you for your feedback :~)

--js

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

Re: [PATCH 13/15] iotests: Accommodate async QMP Exception classes

[John Snow]

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

On Fri, Sep 17, 2021 at 10:35 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 17.09.21 07:40, John Snow wrote:
> > (But continue to support the old ones for now, too.)
> >
> > There are very few cases of any user of QEMUMachine or a subclass
> > thereof relying on a QMP Exception type. If you'd like to check for
> > yourself, you want to grep for all of the derivatives of QMPError,
> > excluding 'AQMPError' and its derivatives. That'd be these:
> >
> > - QMPError
> > - QMPConnectError
> > - QMPCapabilitiesError
> > - QMPTimeoutError
> > - QMPProtocolError
> > - QMPResponseError
> > - QMPBadPortError
> >
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >   scripts/simplebench/bench_block_job.py    | 3 ++-
> >   tests/qemu-iotests/tests/mirror-top-perms | 6 +++++-
> >   2 files changed, 7 insertions(+), 2 deletions(-)
> >
> > diff --git a/scripts/simplebench/bench_block_job.py
> b/scripts/simplebench/bench_block_job.py
> > index 4f03c12169..a403c35b08 100755
> > --- a/scripts/simplebench/bench_block_job.py
> > +++ b/scripts/simplebench/bench_block_job.py
> > @@ -28,6 +28,7 @@
> >   sys.path.append(os.path.join(os.path.dirname(__file__), '..', '..',
> 'python'))
> >   from qemu.machine import QEMUMachine
> >   from qemu.qmp import QMPConnectError
> > +from qemu.aqmp import ConnectError
> >
> >
> >   def bench_block_job(cmd, cmd_args, qemu_args):
> > @@ -49,7 +50,7 @@ def bench_block_job(cmd, cmd_args, qemu_args):
> >           vm.launch()
> >       except OSError as e:
> >           return {'error': 'popen failed: ' + str(e)}
> > -    except (QMPConnectError, socket.timeout):
> > +    except (QMPConnectError, ConnectError, socket.timeout):
> >           return {'error': 'qemu failed: ' + str(vm.get_log())}
> >
> >       try:
> > diff --git a/tests/qemu-iotests/tests/mirror-top-perms
> b/tests/qemu-iotests/tests/mirror-top-perms
> > index 451a0666f8..7d448f4d23 100755
> > --- a/tests/qemu-iotests/tests/mirror-top-perms
> > +++ b/tests/qemu-iotests/tests/mirror-top-perms
> > @@ -103,7 +103,11 @@ class TestMirrorTopPerms(iotests.QMPTestCase):
> >               print('ERROR: VM B launched successfully, this should not
> have '
> >                     'happened')
> >           except qemu.qmp.QMPConnectError:
> > -            assert 'Is another process using the image' in
> self.vm_b.get_log()
> > +            pass
> > +        except qemu.aqmp.ConnectError:
> > +            pass
> > +
> > +        assert 'Is another process using the image' in
> self.vm_b.get_log()
>
> But this assertion will fail if there was no exception, and so we won’t
> get to see the real problem, which is the original VM aborting (see the
> doc string).
>

Uh, hm. OK, so the intent was that if vm_b somehow starts successfully that
we will fail the test based on output in the diff, but we'll continue on to
see other kinds of explosions so that the output is more useful for
diagnosing the failure. Gotcha.

It doesn’t really matter that much that VM B can start (hence it being a
> logged error message, not a fatal error), and when it can start, of
> course it won’t print an error – but what’s important is that the
> original VM will then abort.
>

> I mean, not an absolute showstopper by any means, but still, the
> assertion was deliberately placed into the `except` block.
>
> Hanna
>

I misunderstood the "test style" here. I'll fix it.

(Uh, I also forgot to explicitly import qemu.aqmp. It happens to work
anyway because of $reasons, but it's not very good style. I'll fix that,
too.)

--js

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

Re: [PATCH 12/15] iotests: Disable AQMP logging under non-debug modes

[John Snow]

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

On Fri, Sep 17, 2021 at 8:58 PM John Snow <jsnow@redhat.com> wrote:

>
>
> On Fri, Sep 17, 2021 at 10:30 AM Hanna Reitz <hreitz@redhat.com> wrote:
>
>> On 17.09.21 07:40, John Snow wrote:
>> > Disable the aqmp logger, which likes to (at the moment) print out
>> > intermediate warnings and errors that cause session termination; disable
>> > them so they don't interfere with the job output.
>> >
>> > Leave any "CRITICAL" warnings enabled though, those are ones that we
>> > should never see, no matter what.
>>
>> I mean, looks OK to me, but from what I understand (i.e. little),
>> qmp_client doesn’t log CRITICAL messages, at least I can’t see any. Only
>> ERRORs.
>>
>>
> There's *one* critical message in protocol.py, used for a circumstance
> that I *think* should be impossible. I do not think I currently use any
> WARNING level statements.
>
>
>> I guess I’m missing some CRITICAL messages in external functions called
>> from qmp_client.py, but shouldn’t we still keep ERRORs?
>>
>
> ...Mayyyyyybe?
>
> The errors logged by AQMP are *almost always* raised as Exceptions
> somewhere else, eventually. Sometimes when we encounter them in one
> context, we need to save them and then re-raise them in a different
> execution context. There's one good exception to this: My pal, EOFError.
>
> If the reader context encounters EOF, it raises EOFError and this causes a
> disconnect to be scheduled asynchronously. *Any* Exception that causes a
> disconnect to be scheduled asynchronously is dutifully logged as an ERROR.
> At this point in the code, we don't really know if the user of the library
> considers this an "error" yet or not. I've waffled a lot on how exactly to
> treat this circumstance. ...Hm, I guess that's really the only case where I
> have an error that really ought to be suppressed. I suppose what I will do
> here is: if the exception happens to be an EOFError I will drop the
> severity of the log message down to INFO. I don't know why it takes being
> challenged on this stuff to start thinking clearly about it, but here we
> are. Thank you for your feedback :~)
>
> --js
>

Oh, CI testing reminds me of why I am a liar here.

the mirror-top-perms test intentionally expects not to be able to connect,
but we're treated to these two additional lines of output:

+ERROR:qemu.aqmp.qmp_client.qemub-2536319:Negotiation failed: EOFError
+ERROR:qemu.aqmp.qmp_client.qemub-2536319:Failed to establish session:
EOFError

Uh. I guess a temporary suppression in mirror-top-perms, then ...? In most
other cases I rather imagine we do want to see this kind of output to help
give more information about how things have failed -- they ARE errors. We
just happen to not care about them right here. The only thing I don't
exactly like about this is that it requires some knowledge by the caller to
know to disable it. It makes writing negative tests a bit more annoying
because the library leans so heavily on yelling loudly when it encounters
problems.

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

Re: [PATCH 03/15] python/aqmp: Return cleared events from EventListener.clear()

[Hanna Reitz]

On 17.09.21 19:19, John Snow wrote:
>
>
> On Fri, Sep 17, 2021 at 8:36 AM Hanna Reitz <hreitz@redhat.com 
> <mailto:hreitz@redhat.com>> wrote:
>
>     On 17.09.21 07:40, John Snow wrote:
>     > This serves two purposes:
>     >
>     > (1) It is now possible to discern whether or not clear() removed any
>     > event(s) from the queue with absolute certainty, and
>     >
>     > (2) It is now very easy to get a List of all pending events in one
>     > chunk, which is useful for the sync bridge.
>     >
>     > Signed-off-by: John Snow <jsnow@redhat.com
>     <mailto:jsnow@redhat.com>>
>     > ---
>     >   python/qemu/aqmp/events.py | 9 +++++++--
>     >   1 file changed, 7 insertions(+), 2 deletions(-)
>
>     Not sure if `clear` is an ideal name then, but `drain` sounds like
>     something that would block, and `drop` is really much different from
>     `clear`.  Also, doesn’t matter, having Collection.delete return the
>     deleted element is a common thing in any language’s standard
>     library, so
>     why not have `clear` do the same.
>
>
> It isn't too late to change the name, but it sounds like you don't 
> necessarily prefer any of those others over what's there now.

Oh, no, I was just thinking aloud.

Hanna

Re: [PATCH 10/15] python/machine: Add support for AQMP backend

[Hanna Reitz]

On 18.09.21 01:48, John Snow wrote:
>
>
> On Fri, Sep 17, 2021 at 10:16 AM Hanna Reitz <hreitz@redhat.com 
> <mailto:hreitz@redhat.com>> wrote:
>
>     On 17.09.21 07:40, John Snow wrote:
>     > To use the AQMP backend, Machine just needs to be a little more
>     diligent
>     > about what happens when closing a QMP connection. The operation
>     is no
>     > longer a freebie in the async world.
>     >
>     > Because async QMP continues to check for messages
>     asynchronously, it's
>     > almost certainly likely that the loop will have exited due to
>     EOF after
>     > issuing the last 'quit' command. That error will ultimately be
>     bubbled
>     > up when attempting to close the QMP connection. The manager
>     class here
>     > then is free to discard it if it was expected.
>     >
>     > Signed-off-by: John Snow <jsnow@redhat.com
>     <mailto:jsnow@redhat.com>>
>     >
>     > ---
>     >
>     > Yes, I regret that this class has become quite a dumping ground for
>     > complexity around the exit path. It's in need of a refactor to help
>     > separate out the exception handling and cleanup mechanisms from the
>     > VM-related stuff, but it's not a priority to do that just yet -- but
>     > it's on the list.
>     >
>     > ---
>     >   python/qemu/machine/machine.py | 51
>     ++++++++++++++++++++++++++++++----
>     >   1 file changed, 46 insertions(+), 5 deletions(-)
>     >
>     > diff --git a/python/qemu/machine/machine.py
>     b/python/qemu/machine/machine.py
>     > index 6e58d2f951..8f5a6649e5 100644
>     > --- a/python/qemu/machine/machine.py
>     > +++ b/python/qemu/machine/machine.py
>     > @@ -342,9 +342,15 @@ def _post_shutdown(self) -> None:
>     >           # Comprehensive reset for the failed launch case:
>     >           self._early_cleanup()
>     >
>     > -        if self._qmp_connection:
>     > -            self._qmp.close()
>     > -            self._qmp_connection = None
>     > +        try:
>     > +            self._close_qmp_connection()
>     > +        except Exception as err:  # pylint: disable=broad-except
>     > +            LOG.warning(
>     > +                "Exception closing QMP connection: %s",
>     > +                str(err) if str(err) else type(err).__name__
>     > +            )
>     > +        finally:
>     > +            assert self._qmp_connection is None
>     >
>     >           self._close_qemu_log_file()
>     >
>     > @@ -420,6 +426,31 @@ def _launch(self) -> None:
>     > close_fds=False)
>     >           self._post_launch()
>     >
>     > +    def _close_qmp_connection(self) -> None:
>     > +        """
>     > +        Close the underlying QMP connection, if any.
>     > +
>     > +        Dutifully report errors that occurred while closing,
>     but assume
>     > +        that any error encountered indicates an abnormal
>     termination
>     > +        process and not a failure to close.
>     > +        """
>     > +        if self._qmp_connection is None:
>     > +            return
>     > +
>     > +        try:
>     > +            self._qmp.close()
>     > +        except EOFError:
>     > +            # EOF can occur as an Exception here when using the
>     Async
>     > +            # QMP backend. It indicates that the server closed the
>     > +            # stream. If we successfully issued 'quit' at any
>     point,
>     > +            # then this was expected. If the remote went away
>     without
>     > +            # our permission, it's worth reporting that as an
>     abnormal
>     > +            # shutdown case.
>     > +            if not self._has_quit:
>     > +                raise
>     > +        finally:
>     > +            self._qmp_connection = None
>     > +
>     >       def _early_cleanup(self) -> None:
>     >           """
>     >           Perform any cleanup that needs to happen before the VM
>     exits.
>     > @@ -461,8 +492,18 @@ def _soft_shutdown(self, timeout:
>     Optional[int]) -> None:
>     >
>     >           if self._qmp_connection:
>     >               if not self._has_quit:
>     > -                # Might raise ConnectionReset
>     > -                self.qmp('quit')
>     > +                try:
>     > +                    # May raise ExecInterruptedError or
>     StateError if the
>     > +                    # connection dies or has already died.
>     > +                    self.qmp('quit')
>     > +                finally:
>     > +                    # If 'quit' fails, we'll still want to call
>     close(),
>     > +                    # which will raise any final errors that
>     may have
>     > +                    # occurred while trying to send 'quit'.
>     > +                    self._close_qmp_connection()
>     > +            else:
>     > +                # Regardless, we want to tidy up the socket.
>     > +                self._close_qmp_connection()
>
>     Why can’t we wait for _post_shutdown to do that?  Has it something
>     to do
>     with this operation being “no longer a freeby” (I’m not quite sure
>     what
>     this refers to, execution time, or the set of possible exceptions, or
>     perhaps something else entirely), and so we want to do it in the
>     already-not-instantaneous _soft_shutdown?
>
>     Hanna
>
>
> I wrote that commit message too casually.
>
> By "freebie", I meant that closing a simple sync socket does not have 
> any potential for raising an error, so we don't really have to worry 
> about that operation failing. The async machinery, by comparison, uses 
> the disconnection point as its synchronization point where it gathers 
> the final results from its various execution contexts (the reader, 
> writer, and disconnection tasks).
>
> The likeliest error to see here would be something like EOFError for 
> QEMU hanging up before disconnect() was called. Other possible errors 
> would be stuff from deep in the internals of AQMP that very likely 
> means there's a bug I need to resolve -- so I was afraid of just 
> wholesale silencing such things. (Hence the logged warning in the 
> _post_shutdown method. I genuinely don't expect to see anything there, 
> but I am paranoid and wanted to be rock-solid sure that any problems 
> are visible.) It is also possible that if QEMU were to send a garbled 
> and unprompted message after 'quit' succeeded (For example, a 
> malformed SHUTDOWN event) that this would also enqueue an error to be 
> shown here at this point.
>
> One of the design points of AQMP is that calling 
> QMPClient.disconnect() is necessary to reset the client to a fully 
> IDLE state to where it can be re-used for a subsequent connection. It 
> serves double-duty as both disconnect *and* results gathering. So I 
> wanted to make sure to call it here while we still had the opportunity 
> to report an "Abnormal Shutdown" instead of potentially choking later 
> during the post-shutdown and failing to do resource cleanup.
>
> Good: if shutdown() succeeds, you can rest well knowing that 
> definitely nothing weird happened.
> Bad: There's a lot of complexity inherent in promising that.
>
> Clear as mud?

Yep, that makes sense.  Thanks!

(Seems like you intend to send a v2, so I think I’ll refrain from giving 
a rather haphazard R-b now, because two weeks later I forgot whether I 
was originally confident enough to give one were it now for that bit 
here...)

Hanna

Re: [PATCH 12/15] iotests: Disable AQMP logging under non-debug modes

[Hanna Reitz]

On 18.09.21 02:58, John Snow wrote:
>
>
> On Fri, Sep 17, 2021 at 10:30 AM Hanna Reitz <hreitz@redhat.com 
> <mailto:hreitz@redhat.com>> wrote:
>
>     On 17.09.21 07:40, John Snow wrote:
>     > Disable the aqmp logger, which likes to (at the moment) print out
>     > intermediate warnings and errors that cause session termination;
>     disable
>     > them so they don't interfere with the job output.
>     >
>     > Leave any "CRITICAL" warnings enabled though, those are ones that we
>     > should never see, no matter what.
>
>     I mean, looks OK to me, but from what I understand (i.e. little),
>     qmp_client doesn’t log CRITICAL messages, at least I can’t see
>     any. Only
>     ERRORs.
>
>
> There's *one* critical message in protocol.py, used for a circumstance 
> that I *think* should be impossible. I do not think I currently use 
> any WARNING level statements.
>
>     I guess I’m missing some CRITICAL messages in external functions
>     called
>     from qmp_client.py, but shouldn’t we still keep ERRORs?
>
>
> ...Mayyyyyybe?
>
> The errors logged by AQMP are *almost always* raised as Exceptions 
> somewhere else, eventually. Sometimes when we encounter them in one 
> context, we need to save them and then re-raise them in a different 
> execution context. There's one good exception to this: My pal, EOFError.
>
> If the reader context encounters EOF, it raises EOFError and this 
> causes a disconnect to be scheduled asynchronously. *Any* Exception 
> that causes a disconnect to be scheduled asynchronously is dutifully 
> logged as an ERROR. At this point in the code, we don't really know if 
> the user of the library considers this an "error" yet or not. I've 
> waffled a lot on how exactly to treat this circumstance. ...Hm, I 
> guess that's really the only case where I have an error that really 
> ought to be suppressed. I suppose what I will do here is: if the 
> exception happens to be an EOFError I will drop the severity of the 
> log message down to INFO. I don't know why it takes being challenged 
> on this stuff to start thinking clearly about it, but here we are. 
> Thank you for your feedback :~)

Errr... You’re welcome!! *cough*

Hanna

Re: [PATCH 12/15] iotests: Disable AQMP logging under non-debug modes

[Hanna Reitz]

On 18.09.21 04:14, John Snow wrote:
>
>
> On Fri, Sep 17, 2021 at 8:58 PM John Snow <jsnow@redhat.com 
> <mailto:jsnow@redhat.com>> wrote:
>
>
>
>     On Fri, Sep 17, 2021 at 10:30 AM Hanna Reitz <hreitz@redhat.com
>     <mailto:hreitz@redhat.com>> wrote:
>
>         On 17.09.21 07:40, John Snow wrote:
>         > Disable the aqmp logger, which likes to (at the moment)
>         print out
>         > intermediate warnings and errors that cause session
>         termination; disable
>         > them so they don't interfere with the job output.
>         >
>         > Leave any "CRITICAL" warnings enabled though, those are ones
>         that we
>         > should never see, no matter what.
>
>         I mean, looks OK to me, but from what I understand (i.e. little),
>         qmp_client doesn’t log CRITICAL messages, at least I can’t see
>         any. Only
>         ERRORs.
>
>
>     There's *one* critical message in protocol.py, used for a
>     circumstance that I *think* should be impossible. I do not think I
>     currently use any WARNING level statements.
>
>         I guess I’m missing some CRITICAL messages in external
>         functions called
>         from qmp_client.py, but shouldn’t we still keep ERRORs?
>
>
>     ...Mayyyyyybe?
>
>     The errors logged by AQMP are *almost always* raised as Exceptions
>     somewhere else, eventually. Sometimes when we encounter them in
>     one context, we need to save them and then re-raise them in a
>     different execution context. There's one good exception to this:
>     My pal, EOFError.
>
>     If the reader context encounters EOF, it raises EOFError and this
>     causes a disconnect to be scheduled asynchronously. *Any*
>     Exception that causes a disconnect to be scheduled asynchronously
>     is dutifully logged as an ERROR. At this point in the code, we
>     don't really know if the user of the library considers this an
>     "error" yet or not. I've waffled a lot on how exactly to treat
>     this circumstance. ...Hm, I guess that's really the only case
>     where I have an error that really ought to be suppressed. I
>     suppose what I will do here is: if the exception happens to be an
>     EOFError I will drop the severity of the log message down to INFO.
>     I don't know why it takes being challenged on this stuff to start
>     thinking clearly about it, but here we are. Thank you for your
>     feedback :~)
>
>     --js
>
>
> Oh, CI testing reminds me of why I am a liar here.
>
> the mirror-top-perms test intentionally expects not to be able to 
> connect, but we're treated to these two additional lines of output:
>
> +ERROR:qemu.aqmp.qmp_client.qemub-2536319:Negotiation failed: EOFError
> +ERROR:qemu.aqmp.qmp_client.qemub-2536319:Failed to establish session: 
> EOFError
>
> Uh. I guess a temporary suppression in mirror-top-perms, then ...?

Sounds right to me, if that’s simple enough.

(By the way, I understand it right that you want to lower the severity 
of EOFErrors to INFO only on disconnect, right?  Which is why they’re 
still logged as ERRORs here, because they aren’t occurring on disconnects?)

> In most other cases I rather imagine we do want to see this kind of 
> output to help give more information about how things have failed -- 
> they ARE errors. We just happen to not care about them right here.

Well, in fact we do expect them here, so we could even log them, but 
first I don’t know whether they’re stable enough for that, and second 
this would break the “choose the AQMP or legacy QMP back-end via an 
environment variable” thing.

> The only thing I don't exactly like about this is that it requires 
> some knowledge by the caller to know to disable it. It makes writing 
> negative tests a bit more annoying because the library leans so 
> heavily on yelling loudly when it encounters problems.

Yeah.  I’m afraid I don’t have a good idea on how to convey test writers 
how to suppress these errors, even if it were a simple one-liner (like 
`self.vm_b.set_log_threshold(logging.CRITICAL)`)...

We could start an “iotests tips and tricks” document, but do we want to?

Hanna

Re: [PATCH 12/15] iotests: Disable AQMP logging under non-debug modes

[John Snow]

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

On Mon, Oct 4, 2021 at 6:12 AM Hanna Reitz <hreitz@redhat.com> wrote:

> On 18.09.21 04:14, John Snow wrote:
> >
> >
> > On Fri, Sep 17, 2021 at 8:58 PM John Snow <jsnow@redhat.com
> > <mailto:jsnow@redhat.com>> wrote:
> >
> >
> >
> >     On Fri, Sep 17, 2021 at 10:30 AM Hanna Reitz <hreitz@redhat.com
> >     <mailto:hreitz@redhat.com>> wrote:
> >
> >         On 17.09.21 07:40, John Snow wrote:
> >         > Disable the aqmp logger, which likes to (at the moment)
> >         print out
> >         > intermediate warnings and errors that cause session
> >         termination; disable
> >         > them so they don't interfere with the job output.
> >         >
> >         > Leave any "CRITICAL" warnings enabled though, those are ones
> >         that we
> >         > should never see, no matter what.
> >
> >         I mean, looks OK to me, but from what I understand (i.e. little),
> >         qmp_client doesn’t log CRITICAL messages, at least I can’t see
> >         any. Only
> >         ERRORs.
> >
> >
> >     There's *one* critical message in protocol.py, used for a
> >     circumstance that I *think* should be impossible. I do not think I
> >     currently use any WARNING level statements.
> >
> >         I guess I’m missing some CRITICAL messages in external
> >         functions called
> >         from qmp_client.py, but shouldn’t we still keep ERRORs?
> >
> >
> >     ...Mayyyyyybe?
> >
> >     The errors logged by AQMP are *almost always* raised as Exceptions
> >     somewhere else, eventually. Sometimes when we encounter them in
> >     one context, we need to save them and then re-raise them in a
> >     different execution context. There's one good exception to this:
> >     My pal, EOFError.
> >
> >     If the reader context encounters EOF, it raises EOFError and this
> >     causes a disconnect to be scheduled asynchronously. *Any*
> >     Exception that causes a disconnect to be scheduled asynchronously
> >     is dutifully logged as an ERROR. At this point in the code, we
> >     don't really know if the user of the library considers this an
> >     "error" yet or not. I've waffled a lot on how exactly to treat
> >     this circumstance. ...Hm, I guess that's really the only case
> >     where I have an error that really ought to be suppressed. I
> >     suppose what I will do here is: if the exception happens to be an
> >     EOFError I will drop the severity of the log message down to INFO.
> >     I don't know why it takes being challenged on this stuff to start
> >     thinking clearly about it, but here we are. Thank you for your
> >     feedback :~)
> >
> >     --js
> >
> >
> > Oh, CI testing reminds me of why I am a liar here.
> >
> > the mirror-top-perms test intentionally expects not to be able to
> > connect, but we're treated to these two additional lines of output:
> >
> > +ERROR:qemu.aqmp.qmp_client.qemub-2536319:Negotiation failed: EOFError
> > +ERROR:qemu.aqmp.qmp_client.qemub-2536319:Failed to establish session:
> > EOFError
> >
> > Uh. I guess a temporary suppression in mirror-top-perms, then ...?
>
> Sounds right to me, if that’s simple enough.
>
> (By the way, I understand it right that you want to lower the severity
> of EOFErrors to INFO only on disconnect, right?  Which is why they’re
> still logged as ERRORs here, because they aren’t occurring on disconnects?)
>
>
More or less, yeah.

When an EOFError causes the reader coroutine to halt (because it can't read
the next message), I decided (in v2) to drop that one particular logging
message down to "INFO", because it might -- or might not be -- an expected
occurrence from the point of view of whoever is managing the QMP
connection. Maybe it was expected (The test used qemu-guest-agent or
something else to make the guest shutdown, taking QEMU down with it without
the knowledge of the QMP library layer) or maybe it was unexpected (the QMP
remote really just disappeared from us on a whim). There's no way to know,
so it probably isn't right to consider it an error.

In the connection case, I left it as an ERROR because the caller asked us
to connect to an endpoint and we were unable to, which feels unambiguous.
It will be ultimately reported via Exceptions as qemu.aqmp.ConnectError,
with additional information available in fields of that exception object.
Even though the exception is reported to the caller, I decided to log the
occurrence anyway, because I felt like it should be the job of the library
to make a good log and not the caller's responsibility to catch the
exception and then log it themselves.

That does leave us with this atypical case though: the caller is
intentionally causing problems :)

(Well, atypical for a user of the library who is using it to make a tool
they expect to work. Quite a typical case for tests in the abstract, though
we only seem to have precisely one usage of this pattern in iotests so far.)


> > In most other cases I rather imagine we do want to see this kind of
> > output to help give more information about how things have failed --
> > they ARE errors. We just happen to not care about them right here.
>
> Well, in fact we do expect them here, so we could even log them, but
> first I don’t know whether they’re stable enough for that, and second
> this would break the “choose the AQMP or legacy QMP back-end via an
> environment variable” thing.
>
>
Yeah, that's the other half of it, I came to realize. Just logging the
expected failure feels the most idiomatic, but it requires a new logging
filter (I have to filter out the PID from the logger name to make it work
consistently) and breaks the ability to switch.

So I suppose "for now" just disabling the logger output for a critical
section and leaving a comment that states that once we're feeling confident
about the new library (maybe after the next release when everything has
really gone through the testing wash cycle) we can remove the suppression
and just log the errors the normal way.


> > The only thing I don't exactly like about this is that it requires
> > some knowledge by the caller to know to disable it. It makes writing
> > negative tests a bit more annoying because the library leans so
> > heavily on yelling loudly when it encounters problems.
>
> Yeah.  I’m afraid I don’t have a good idea on how to convey test writers
> how to suppress these errors, even if it were a simple one-liner (like
> `self.vm_b.set_log_threshold(logging.CRITICAL)`)...
>
> We could start an “iotests tips and tricks” document, but do we want to?
>
> Hanna
>
>
Hm, not just yet. More chances for un-checked stuff to bitrot. There's only
this one caller that poses a problem here, so it's probably not going to be
too difficult to just update tests to expect the error logs.

V2 soon. I already respun it, but it's been a week, so I will need to scrub
it down with a good proof-reading pass. Thanks for your patience, and I
hope you enjoyed your PTO :~)

--js

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

Re: [PATCH 12/15] iotests: Disable AQMP logging under non-debug modes

[John Snow]

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

On Mon, Oct 4, 2021 at 2:32 PM John Snow <jsnow@redhat.com> wrote:

>
>
> On Mon, Oct 4, 2021 at 6:12 AM Hanna Reitz <hreitz@redhat.com> wrote:
>
>> On 18.09.21 04:14, John Snow wrote:
>> >
>> >
>> > On Fri, Sep 17, 2021 at 8:58 PM John Snow <jsnow@redhat.com
>> > <mailto:jsnow@redhat.com>> wrote:
>> >
>> >
>> >
>> >     On Fri, Sep 17, 2021 at 10:30 AM Hanna Reitz <hreitz@redhat.com
>> >     <mailto:hreitz@redhat.com>> wrote:
>> >
>> >         On 17.09.21 07:40, John Snow wrote:
>> >         > Disable the aqmp logger, which likes to (at the moment)
>> >         print out
>> >         > intermediate warnings and errors that cause session
>> >         termination; disable
>> >         > them so they don't interfere with the job output.
>> >         >
>> >         > Leave any "CRITICAL" warnings enabled though, those are ones
>> >         that we
>> >         > should never see, no matter what.
>> >
>> >         I mean, looks OK to me, but from what I understand (i.e.
>> little),
>> >         qmp_client doesn’t log CRITICAL messages, at least I can’t see
>> >         any. Only
>> >         ERRORs.
>> >
>> >
>> >     There's *one* critical message in protocol.py, used for a
>> >     circumstance that I *think* should be impossible. I do not think I
>> >     currently use any WARNING level statements.
>> >
>> >         I guess I’m missing some CRITICAL messages in external
>> >         functions called
>> >         from qmp_client.py, but shouldn’t we still keep ERRORs?
>> >
>> >
>> >     ...Mayyyyyybe?
>> >
>> >     The errors logged by AQMP are *almost always* raised as Exceptions
>> >     somewhere else, eventually. Sometimes when we encounter them in
>> >     one context, we need to save them and then re-raise them in a
>> >     different execution context. There's one good exception to this:
>> >     My pal, EOFError.
>> >
>> >     If the reader context encounters EOF, it raises EOFError and this
>> >     causes a disconnect to be scheduled asynchronously. *Any*
>> >     Exception that causes a disconnect to be scheduled asynchronously
>> >     is dutifully logged as an ERROR. At this point in the code, we
>> >     don't really know if the user of the library considers this an
>> >     "error" yet or not. I've waffled a lot on how exactly to treat
>> >     this circumstance. ...Hm, I guess that's really the only case
>> >     where I have an error that really ought to be suppressed. I
>> >     suppose what I will do here is: if the exception happens to be an
>> >     EOFError I will drop the severity of the log message down to INFO.
>> >     I don't know why it takes being challenged on this stuff to start
>> >     thinking clearly about it, but here we are. Thank you for your
>> >     feedback :~)
>> >
>> >     --js
>> >
>> >
>> > Oh, CI testing reminds me of why I am a liar here.
>> >
>> > the mirror-top-perms test intentionally expects not to be able to
>> > connect, but we're treated to these two additional lines of output:
>> >
>> > +ERROR:qemu.aqmp.qmp_client.qemub-2536319:Negotiation failed: EOFError
>> > +ERROR:qemu.aqmp.qmp_client.qemub-2536319:Failed to establish session:
>> > EOFError
>> >
>> > Uh. I guess a temporary suppression in mirror-top-perms, then ...?
>>
>> Sounds right to me, if that’s simple enough.
>>
>> (By the way, I understand it right that you want to lower the severity
>> of EOFErrors to INFO only on disconnect, right?  Which is why they’re
>> still logged as ERRORs here, because they aren’t occurring on
>> disconnects?)
>>
>>
> More or less, yeah.
>
> When an EOFError causes the reader coroutine to halt (because it can't
> read the next message), I decided (in v2) to drop that one particular
> logging message down to "INFO", because it might -- or might not be -- an
> expected occurrence from the point of view of whoever is managing the QMP
> connection. Maybe it was expected (The test used qemu-guest-agent or
> something else to make the guest shutdown, taking QEMU down with it without
> the knowledge of the QMP library layer) or maybe it was unexpected (the QMP
> remote really just disappeared from us on a whim). There's no way to know,
> so it probably isn't right to consider it an error.
>
> In the connection case, I left it as an ERROR because the caller asked us
> to connect to an endpoint and we were unable to, which feels unambiguous.
> It will be ultimately reported via Exceptions as qemu.aqmp.ConnectError,
> with additional information available in fields of that exception object.
> Even though the exception is reported to the caller, I decided to log the
> occurrence anyway, because I felt like it should be the job of the library
> to make a good log and not the caller's responsibility to catch the
> exception and then log it themselves.
>
> That does leave us with this atypical case though: the caller is
> intentionally causing problems :)
>
> (Well, atypical for a user of the library who is using it to make a tool
> they expect to work. Quite a typical case for tests in the abstract, though
> we only seem to have precisely one usage of this pattern in iotests so far.)
>
>
>> > In most other cases I rather imagine we do want to see this kind of
>> > output to help give more information about how things have failed --
>> > they ARE errors. We just happen to not care about them right here.
>>
>> Well, in fact we do expect them here, so we could even log them, but
>> first I don’t know whether they’re stable enough for that, and second
>> this would break the “choose the AQMP or legacy QMP back-end via an
>> environment variable” thing.
>>
>>
> Yeah, that's the other half of it, I came to realize. Just logging the
> expected failure feels the most idiomatic, but it requires a new logging
> filter (I have to filter out the PID from the logger name to make it work
> consistently) and breaks the ability to switch.
>
> So I suppose "for now" just disabling the logger output for a critical
> section and leaving a comment that states that once we're feeling confident
> about the new library (maybe after the next release when everything has
> really gone through the testing wash cycle) we can remove the suppression
> and just log the errors the normal way.
>
>
>> > The only thing I don't exactly like about this is that it requires
>> > some knowledge by the caller to know to disable it. It makes writing
>> > negative tests a bit more annoying because the library leans so
>> > heavily on yelling loudly when it encounters problems.
>>
>> Yeah.  I’m afraid I don’t have a good idea on how to convey test writers
>> how to suppress these errors, even if it were a simple one-liner (like
>> `self.vm_b.set_log_threshold(logging.CRITICAL)`)...
>>
>> We could start an “iotests tips and tricks” document, but do we want to?
>>
>> Hanna
>>
>>
> Hm, not just yet. More chances for un-checked stuff to bitrot. There's
> only this one caller that poses a problem here, so it's probably not going
> to be too difficult to just update tests to expect the error logs.
>
> V2 soon. I already respun it, but it's been a week, so I will need to
> scrub it down with a good proof-reading pass. Thanks for your patience, and
> I hope you enjoyed your PTO :~)
>
>
Oh, uh, I got confused and I actually already sent V2 for this series.
Apologies for the confusion.

--js

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

Re: [PATCH 12/15] iotests: Disable AQMP logging under non-debug modes

[Hanna Reitz]

On 04.10.21 20:32, John Snow wrote:
>
>
> On Mon, Oct 4, 2021 at 6:12 AM Hanna Reitz <hreitz@redhat.com 
> <mailto:hreitz@redhat.com>> wrote:
>
>     On 18.09.21 04:14, John Snow wrote:
>     >
>     >
>     > On Fri, Sep 17, 2021 at 8:58 PM John Snow <jsnow@redhat.com
>     <mailto:jsnow@redhat.com>
>     > <mailto:jsnow@redhat.com <mailto:jsnow@redhat.com>>> wrote:
>     >
>     >
>     >
>     >     On Fri, Sep 17, 2021 at 10:30 AM Hanna Reitz
>     <hreitz@redhat.com <mailto:hreitz@redhat.com>
>     >     <mailto:hreitz@redhat.com <mailto:hreitz@redhat.com>>> wrote:
>     >
>     >         On 17.09.21 07:40, John Snow wrote:
>     >         > Disable the aqmp logger, which likes to (at the moment)
>     >         print out
>     >         > intermediate warnings and errors that cause session
>     >         termination; disable
>     >         > them so they don't interfere with the job output.
>     >         >
>     >         > Leave any "CRITICAL" warnings enabled though, those
>     are ones
>     >         that we
>     >         > should never see, no matter what.
>     >
>     >         I mean, looks OK to me, but from what I understand (i.e.
>     little),
>     >         qmp_client doesn’t log CRITICAL messages, at least I
>     can’t see
>     >         any. Only
>     >         ERRORs.
>     >
>     >
>     >     There's *one* critical message in protocol.py, used for a
>     >     circumstance that I *think* should be impossible. I do not
>     think I
>     >     currently use any WARNING level statements.
>     >
>     >         I guess I’m missing some CRITICAL messages in external
>     >         functions called
>     >         from qmp_client.py, but shouldn’t we still keep ERRORs?
>     >
>     >
>     >     ...Mayyyyyybe?
>     >
>     >     The errors logged by AQMP are *almost always* raised as
>     Exceptions
>     >     somewhere else, eventually. Sometimes when we encounter them in
>     >     one context, we need to save them and then re-raise them in a
>     >     different execution context. There's one good exception to this:
>     >     My pal, EOFError.
>     >
>     >     If the reader context encounters EOF, it raises EOFError and
>     this
>     >     causes a disconnect to be scheduled asynchronously. *Any*
>     >     Exception that causes a disconnect to be scheduled
>     asynchronously
>     >     is dutifully logged as an ERROR. At this point in the code, we
>     >     don't really know if the user of the library considers this an
>     >     "error" yet or not. I've waffled a lot on how exactly to treat
>     >     this circumstance. ...Hm, I guess that's really the only case
>     >     where I have an error that really ought to be suppressed. I
>     >     suppose what I will do here is: if the exception happens to
>     be an
>     >     EOFError I will drop the severity of the log message down to
>     INFO.
>     >     I don't know why it takes being challenged on this stuff to
>     start
>     >     thinking clearly about it, but here we are. Thank you for your
>     >     feedback :~)
>     >
>     >     --js
>     >
>     >
>     > Oh, CI testing reminds me of why I am a liar here.
>     >
>     > the mirror-top-perms test intentionally expects not to be able to
>     > connect, but we're treated to these two additional lines of output:
>     >
>     > +ERROR:qemu.aqmp.qmp_client.qemub-2536319:Negotiation failed:
>     EOFError
>     > +ERROR:qemu.aqmp.qmp_client.qemub-2536319:Failed to establish
>     session:
>     > EOFError
>     >
>     > Uh. I guess a temporary suppression in mirror-top-perms, then ...?
>
>     Sounds right to me, if that’s simple enough.
>
>     (By the way, I understand it right that you want to lower the
>     severity
>     of EOFErrors to INFO only on disconnect, right?  Which is why they’re
>     still logged as ERRORs here, because they aren’t occurring on
>     disconnects?)
>
>
> More or less, yeah.
>
> When an EOFError causes the reader coroutine to halt (because it can't 
> read the next message), I decided (in v2) to drop that one particular 
> logging message down to "INFO", because it might -- or might not be -- 
> an expected occurrence from the point of view of whoever is managing 
> the QMP connection. Maybe it was expected (The test used 
> qemu-guest-agent or something else to make the guest shutdown, taking 
> QEMU down with it without the knowledge of the QMP library layer) or 
> maybe it was unexpected (the QMP remote really just disappeared from 
> us on a whim). There's no way to know, so it probably isn't right to 
> consider it an error.
>
> In the connection case, I left it as an ERROR because the caller asked 
> us to connect to an endpoint and we were unable to, which feels 
> unambiguous. It will be ultimately reported via Exceptions as 
> qemu.aqmp.ConnectError, with additional information available in 
> fields of that exception object. Even though the exception is reported 
> to the caller, I decided to log the occurrence anyway, because I felt 
> like it should be the job of the library to make a good log and not 
> the caller's responsibility to catch the exception and then log it 
> themselves.
>
> That does leave us with this atypical case though: the caller is 
> intentionally causing problems :)
>
> (Well, atypical for a user of the library who is using it to make a 
> tool they expect to work. Quite a typical case for tests in the 
> abstract, though we only seem to have precisely one usage of this 
> pattern in iotests so far.)
>
>     > In most other cases I rather imagine we do want to see this kind of
>     > output to help give more information about how things have
>     failed --
>     > they ARE errors. We just happen to not care about them right here.
>
>     Well, in fact we do expect them here, so we could even log them, but
>     first I don’t know whether they’re stable enough for that, and second
>     this would break the “choose the AQMP or legacy QMP back-end via an
>     environment variable” thing.
>
>
> Yeah, that's the other half of it, I came to realize. Just logging the 
> expected failure feels the most idiomatic, but it requires a new 
> logging filter (I have to filter out the PID from the logger name to 
> make it work consistently) and breaks the ability to switch.
>
> So I suppose "for now" just disabling the logger output for a critical 
> section and leaving a comment that states that once we're feeling 
> confident about the new library (maybe after the next release when 
> everything has really gone through the testing wash cycle) we can 
> remove the suppression and just log the errors the normal way.
>
>     > The only thing I don't exactly like about this is that it requires
>     > some knowledge by the caller to know to disable it. It makes
>     writing
>     > negative tests a bit more annoying because the library leans so
>     > heavily on yelling loudly when it encounters problems.
>
>     Yeah.  I’m afraid I don’t have a good idea on how to convey test
>     writers
>     how to suppress these errors, even if it were a simple one-liner
>     (like
>     `self.vm_b.set_log_threshold(logging.CRITICAL)`)...
>
>     We could start an “iotests tips and tricks” document, but do we
>     want to?
>
>     Hanna
>
>
> Hm, not just yet. More chances for un-checked stuff to bitrot. There's 
> only this one caller that poses a problem here, so it's probably not 
> going to be too difficult to just update tests to expect the error logs.

OK.

> V2 soon. I already respun it, but it's been a week, so I will need to 
> scrub it down with a good proof-reading pass. Thanks for your 
> patience, and I hope you enjoyed your PTO :~)

You know how it is.  Some of it was spent enjoying it, the rest was 
spent lamenting that I’m not enjoying it enough.

Hanna