[PATCH 0/4] iotests: add detailed tracebacks to qemu_img() failures

[PATCH 0/4] iotests: add detailed tracebacks to qemu_img() failures

[John Snow]

It came to my attention via th_huth that iotest 065 would crash in a way
that was largely silent, except for the async QMP traces. The real cause
turns out to be that iotest 065 does not support ztsd being compiled out
of the build, so the qemu-img command fails ... silently.
(And then everything after it explodes nastily.)

Almost every user of iotests.qemu_img() does not check the return code,
a few assert it to be zero, and exactly one user asserts it to be
non-zero. qemu_img() is already throwing away process output, too, so no
callers are using that information, either.

Therefore: add an Exception to qemu_img(), with some zazz.

RFC: I didn't attempt to clean up the other dozen function helpers we
have. It's possible we can unify and consolidate cases a bit, but I
wanted to test the waters with a smaller...ish incision first. qemu_io
and qemu_nbd are candidates for this treatment, and using the same
terminal decorations for the VMLaunchError in machine.py is also worth
looking into.

To see this in action, you could configure your QEMU to omit zstd
support and then run ./check -qcow2 065. It'd look something like below:

After:

065   fail       [16:26:17] [16:26:18]   0.3s   (last: 0.4s)  failed, exit status 1
--- /home/jsnow/src/qemu/tests/qemu-iotests/065.out
+++ 065.out.bad
@@ -1,5 +1,64 @@
-........
+....EEE.
+======================================================================
+ERROR: test_qmp (__main__.TestQCow3LazyQMP)
+----------------------------------------------------------------------
+Traceback (most recent call last):
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/065", line 74, in setUp
+    self.TestImageInfoSpecific.setUp(self)
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/065", line 38, in setUp
+    qemu_img('create', '-f', iotests.imgfmt, '-o', self.img_options,
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/iotests.py", line 289, in qemu_img
+    raise VerboseProcessError(
+iotests.VerboseProcessError: Command '['/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/../../qemu-img', 'create', '-f', 'qcow2', '-o', 'compat=1.1,lazy_refcounts=on,compression_type=zstd', '/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img', '128K']' returned non-zero exit status 1.
+  ┏━ output ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
+  ┃ Formatting                                                                 ┃
+  ┃ '/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img',        ┃
+  ┃ fmt=qcow2 cluster_size=65536 extended_l2=off compression_type=zstd         ┃
+  ┃ size=131072 compat=1.1 lazy_refcounts=on refcount_bits=16                  ┃
+  ┃ qemu-img:                                                                  ┃
+  ┃ /home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img:          ┃
+  ┃ Parameter 'compression-type' does not accept value 'zstd'                  ┃
+  ┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛
+
+======================================================================
+ERROR: test_human (__main__.TestQCow3NotLazy)
+----------------------------------------------------------------------
+Traceback (most recent call last):
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/065", line 38, in setUp
+    qemu_img('create', '-f', iotests.imgfmt, '-o', self.img_options,
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/iotests.py", line 289, in qemu_img
+    raise VerboseProcessError(
+iotests.VerboseProcessError: Command '['/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/../../qemu-img', 'create', '-f', 'qcow2', '-o', 'compat=1.1,lazy_refcounts=off,compression_type=zstd', '/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img', '128K']' returned non-zero exit status 1.
+  ┏━ output ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
+  ┃ Formatting                                                                 ┃
+  ┃ '/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img',        ┃
+  ┃ fmt=qcow2 cluster_size=65536 extended_l2=off compression_type=zstd         ┃
+  ┃ size=131072 compat=1.1 lazy_refcounts=off refcount_bits=16                 ┃
+  ┃ qemu-img:                                                                  ┃
+  ┃ /home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img:          ┃
+  ┃ Parameter 'compression-type' does not accept value 'zstd'                  ┃
+  ┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛
+
+======================================================================
+ERROR: test_json (__main__.TestQCow3NotLazy)
+----------------------------------------------------------------------
+Traceback (most recent call last):
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/065", line 38, in setUp
+    qemu_img('create', '-f', iotests.imgfmt, '-o', self.img_options,
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/iotests.py", line 289, in qemu_img
+    raise VerboseProcessError(
+iotests.VerboseProcessError: Command '['/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/../../qemu-img', 'create', '-f', 'qcow2', '-o', 'compat=1.1,lazy_refcounts=off,compression_type=zstd', '/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img', '128K']' returned non-zero exit status 1.
+  ┏━ output ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
+  ┃ Formatting                                                                 ┃
+  ┃ '/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img',        ┃
+  ┃ fmt=qcow2 cluster_size=65536 extended_l2=off compression_type=zstd         ┃
+  ┃ size=131072 compat=1.1 lazy_refcounts=off refcount_bits=16                 ┃
+  ┃ qemu-img:                                                                  ┃
+  ┃ /home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img:          ┃
+  ┃ Parameter 'compression-type' does not accept value 'zstd'                  ┃
+  ┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛
+
 ----------------------------------------------------------------------
 Ran 8 tests

-OK
+FAILED (errors=3)
Failures: 065
Failed 1 of 1 iotests

Before:

065   fail       [16:24:37] [16:24:37]   0.3s   (last: 0.4s)  failed, exit status 1
--- /home/jsnow/src/qemu/tests/qemu-iotests/065.out
+++ 065.out.bad
@@ -1,5 +1,102 @@
-........
+....ERROR:qemu.aqmp.qmp_client.qemu-4002852:Failed to receive Greeting: EOFError
+ERROR:qemu.aqmp.qmp_client.qemu-4002852:Failed to establish session: EOFError
+EEEEE.
+======================================================================
+ERROR: test_qmp (__main__.TestQCow3LazyQMP)
+----------------------------------------------------------------------
+Traceback (most recent call last):
+  File "/home/jsnow/src/qemu/python/qemu/aqmp/protocol.py", line 379, in _new_session
+    await self._establish_session()
+  File "/home/jsnow/src/qemu/python/qemu/aqmp/qmp_client.py", line 250, in _establish_session
+    self._greeting = await self._get_greeting()
+  File "/home/jsnow/src/qemu/python/qemu/aqmp/qmp_client.py", line 270, in _get_greeting
+    msg = await self._recv()
+  File "/home/jsnow/src/qemu/python/qemu/aqmp/protocol.py", line 909, in _recv
+    message = await self._do_recv()
+  File "/home/jsnow/src/qemu/python/qemu/aqmp/qmp_client.py", line 402, in _do_recv
+    msg_bytes = await self._readline()
+  File "/home/jsnow/src/qemu/python/qemu/aqmp/protocol.py", line 877, in _readline
+    raise EOFError
+EOFError
+
+The above exception was the direct cause of the following exception:
+
+Traceback (most recent call last):
+  File "/home/jsnow/src/qemu/python/qemu/machine/machine.py", line 428, in launch
+    self._launch()
+  File "/home/jsnow/src/qemu/python/qemu/machine/machine.py", line 467, in _launch
+    self._post_launch()
+  File "/home/jsnow/src/qemu/python/qemu/machine/qtest.py", line 147, in _post_launch
+    super()._post_launch()
+  File "/home/jsnow/src/qemu/python/qemu/machine/machine.py", line 369, in _post_launch
+    self._qmp.accept(self._qmp_timer)
+  File "/home/jsnow/src/qemu/python/qemu/aqmp/legacy.py", line 93, in accept
+    self._sync(
+  File "/home/jsnow/src/qemu/python/qemu/aqmp/legacy.py", line 67, in _sync
+    return self._aloop.run_until_complete(
+  File "/usr/lib64/python3.9/asyncio/base_events.py", line 642, in run_until_complete
+    return future.result()
+  File "/usr/lib64/python3.9/asyncio/tasks.py", line 479, in wait_for
+    return fut.result()
+  File "/home/jsnow/src/qemu/python/qemu/aqmp/protocol.py", line 282, in accept
+    await self._new_session(address, ssl, accept=True)
+  File "/home/jsnow/src/qemu/python/qemu/aqmp/protocol.py", line 398, in _new_session
+    raise ConnectError(emsg, err) from err
+qemu.aqmp.protocol.ConnectError: Failed to establish session: EOFError
+
+The above exception was the direct cause of the following exception:
+
+Traceback (most recent call last):
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/065", line 76, in setUp
+    self.vm.launch()
+  File "/home/jsnow/src/qemu/python/qemu/machine/machine.py", line 441, in launch
+    raise VMLaunchFailure(
+qemu.machine.machine.VMLaunchFailure: ConnectError: Failed to establish session: EOFError
+	Exit code: 1
+	Command: /home/jsnow/src/qemu/bin/git/tests/qemu-iotests/../../qemu-system-x86_64 -display none -vga none -chardev socket,id=mon,path=/tmp/tmp96jl1ds7/qemu-4002852-monitor.sock -mon chardev=mon,mode=control -qtest unix:path=/tmp/tmp96jl1ds7/qemu-4002852-qtest.sock -accel qtest -nodefaults -display none -accel qtest -drive if=virtio,id=drive0,file=/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img,format=qcow2,cache=writeback,aio=threads,lazy-refcounts=off
+	Output: qemu-system-x86_64: -drive if=virtio,id=drive0,file=/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img,format=qcow2,cache=writeback,aio=threads,lazy-refcounts=off: Could not open '/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img': No such file or directory
+
+
+
+======================================================================
+ERROR: test_human (__main__.TestQCow3NotLazy)
+----------------------------------------------------------------------
+Traceback (most recent call last):
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/065", line 59, in test_human
+    data = data[(data.index('Format specific information:') + 1)
+ValueError: 'Format specific information:' is not in list
+
+======================================================================
+ERROR: test_human (__main__.TestQCow3NotLazy)
+----------------------------------------------------------------------
+Traceback (most recent call last):
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/065", line 42, in tearDown
+    os.remove(test_img)
+FileNotFoundError: [Errno 2] No such file or directory: '/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img'
+
+======================================================================
+ERROR: test_json (__main__.TestQCow3NotLazy)
+----------------------------------------------------------------------
+Traceback (most recent call last):
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/065", line 52, in test_json
+    data = json.loads(qemu_img_pipe('info', '--output=json', test_img))
+  File "/usr/lib64/python3.9/json/__init__.py", line 346, in loads
+    return _default_decoder.decode(s)
+  File "/usr/lib64/python3.9/json/decoder.py", line 337, in decode
+    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
+  File "/usr/lib64/python3.9/json/decoder.py", line 355, in raw_decode
+    raise JSONDecodeError("Expecting value", s, err.value) from None
+json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
+
+======================================================================
+ERROR: test_json (__main__.TestQCow3NotLazy)
+----------------------------------------------------------------------
+Traceback (most recent call last):
+  File "/home/jsnow/src/qemu/tests/qemu-iotests/065", line 42, in tearDown
+    os.remove(test_img)
+FileNotFoundError: [Errno 2] No such file or directory: '/home/jsnow/src/qemu/bin/git/tests/qemu-iotests/scratch/test.img'
+
 ----------------------------------------------------------------------
 Ran 8 tests

-OK
+FAILED (errors=5)
Failures: 065
Failed 1 of 1 iotests

John Snow (4):
  python/utils: add enboxify() text decoration utility
  iotests: add VerboseProcessError
  iotests: Remove explicit checks for qemu_img() == 0
  iotests: make qemu_img raise on non-zero rc by default

 python/qemu/utils/__init__.py                 | 58 +++++++++++++
 tests/qemu-iotests/163                        |  9 +-
 tests/qemu-iotests/216                        |  6 +-
 tests/qemu-iotests/218                        |  2 +-
 tests/qemu-iotests/224                        | 11 ++-
 tests/qemu-iotests/228                        | 12 +--
 tests/qemu-iotests/257                        | 11 +--
 tests/qemu-iotests/258                        |  4 +-
 tests/qemu-iotests/310                        | 14 +--
 tests/qemu-iotests/iotests.py                 | 87 +++++++++++++++++--
 tests/qemu-iotests/tests/block-status-cache   |  3 +-
 tests/qemu-iotests/tests/image-fleecing       |  4 +-
 .../tests/mirror-ready-cancel-error           |  6 +-
 tests/qemu-iotests/tests/mirror-top-perms     |  3 +-
 .../tests/remove-bitmap-from-backing          |  8 +-
 .../qemu-iotests/tests/stream-error-on-reset  |  4 +-
 16 files changed, 185 insertions(+), 57 deletions(-)

-- 
2.34.1

[PATCH 1/4] python/utils: add enboxify() text decoration utility

[John Snow]

>>> print(enboxify(msg, width=72, name="commit message"))
┏━ commit message ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
┃ enboxify() takes a chunk of text and wraps it in a text art box that ┃
┃  adheres to a specified width. An optional title label may be given, ┃
┃  and any of the individual glyphs used to draw the box may be        ┃
┃ replaced or specified as well.                                       ┃
┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛

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

diff --git a/python/qemu/utils/__init__.py b/python/qemu/utils/__init__.py
index 7f1a5138c4b..f785316f230 100644
--- a/python/qemu/utils/__init__.py
+++ b/python/qemu/utils/__init__.py
@@ -15,7 +15,10 @@
 # the COPYING file in the top-level directory.
 #
 
+import os
 import re
+import shutil
+import textwrap
 from typing import Optional
 
 # pylint: disable=import-error
@@ -23,6 +26,7 @@
 
 
 __all__ = (
+    'enboxify',
     'get_info_usernet_hostfwd_port',
     'kvm_available',
     'list_accel',
@@ -43,3 +47,57 @@ def get_info_usernet_hostfwd_port(info_usernet_output: str) -> Optional[int]:
         if match is not None:
             return int(match[1])
     return None
+
+
+# pylint: disable=too-many-arguments
+def enboxify(
+        content: str = '',
+        width: Optional[int] = None,
+        name: Optional[str] = None,
+        padding: int = 1,
+        upper_left: str = '┏',
+        upper_right: str = '┓',
+        lower_left: str = '┗',
+        lower_right: str = '┛',
+        horizontal: str = '━',
+        vertical: str = '┃',
+) -> str:
+    """
+    Wrap some text into a text art box of a given width.
+
+    :param content: The text to wrap into a box.
+    :param width: The number of columns (including the box itself).
+    :param name: A label to apply to the upper-left of the box.
+    :param padding: How many columns of padding to apply inside.
+    """
+    if width is None:
+        width = shutil.get_terminal_size()[0]
+    prefix = vertical + (' ' * padding)
+    suffix = (' ' * padding) + vertical
+    lwidth = width - len(suffix)
+
+    def _bar(name: Optional[str], top: bool = True) -> str:
+        ret = upper_left if top else lower_left
+        right = upper_right if top else lower_right
+        if name is not None:
+            ret += f"{horizontal} {name} "
+
+        assert width is not None
+        filler_len = width - len(ret) - len(right)
+        ret += f"{horizontal * filler_len}{right}"
+        return ret
+
+    def _wrap(line: str) -> str:
+        return os.linesep.join([
+            wrapped_line.ljust(lwidth) + suffix
+            for wrapped_line in textwrap.wrap(
+                    line, width=lwidth, initial_indent=prefix,
+                    subsequent_indent=prefix, replace_whitespace=False,
+                    drop_whitespace=False, break_on_hyphens=False)
+        ])
+
+    return os.linesep.join((
+        _bar(name, top=True),
+        os.linesep.join(_wrap(line) for line in content.splitlines()),
+        _bar(None, top=False),
+    ))
-- 
2.34.1

Re: [PATCH 1/4] python/utils: add enboxify() text decoration utility

[Eric Blake]

On Tue, Feb 15, 2022 at 05:08:50PM -0500, John Snow wrote:
> >>> print(enboxify(msg, width=72, name="commit message"))
> ┏━ commit message ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
> ┃ enboxify() takes a chunk of text and wraps it in a text art box that ┃
> ┃  adheres to a specified width. An optional title label may be given, ┃
> ┃  and any of the individual glyphs used to draw the box may be        ┃

Why do these two lines have a leading space,

> ┃ replaced or specified as well.                                       ┃

but this one doesn't?  It must be an off-by-one corner case when your
choice of space to wrap on is exactly at the wrap column.

> ┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  python/qemu/utils/__init__.py | 58 +++++++++++++++++++++++++++++++++++
>  1 file changed, 58 insertions(+)
> 
> diff --git a/python/qemu/utils/__init__.py b/python/qemu/utils/__init__.py
> index 7f1a5138c4b..f785316f230 100644
> --- a/python/qemu/utils/__init__.py
> +++ b/python/qemu/utils/__init__.py
> @@ -15,7 +15,10 @@
>  # the COPYING file in the top-level directory.
>  #
>  
> +import os
>  import re
> +import shutil
> +import textwrap
>  from typing import Optional
>  
>  # pylint: disable=import-error
> @@ -23,6 +26,7 @@
>  
>  
>  __all__ = (
> +    'enboxify',
>      'get_info_usernet_hostfwd_port',
>      'kvm_available',
>      'list_accel',
> @@ -43,3 +47,57 @@ def get_info_usernet_hostfwd_port(info_usernet_output: str) -> Optional[int]:
>          if match is not None:
>              return int(match[1])
>      return None
> +
> +
> +# pylint: disable=too-many-arguments
> +def enboxify(
> +        content: str = '',
> +        width: Optional[int] = None,
> +        name: Optional[str] = None,
> +        padding: int = 1,
> +        upper_left: str = '┏',
> +        upper_right: str = '┓',
> +        lower_left: str = '┗',
> +        lower_right: str = '┛',
> +        horizontal: str = '━',
> +        vertical: str = '┃',
> +) -> str:
> +    """
> +    Wrap some text into a text art box of a given width.
> +
> +    :param content: The text to wrap into a box.
> +    :param width: The number of columns (including the box itself).
> +    :param name: A label to apply to the upper-left of the box.
> +    :param padding: How many columns of padding to apply inside.
> +    """

Where's theh :param docs for the 6 custom glyphs?

> +    if width is None:
> +        width = shutil.get_terminal_size()[0]
> +    prefix = vertical + (' ' * padding)
> +    suffix = (' ' * padding) + vertical
> +    lwidth = width - len(suffix)
> +
> +    def _bar(name: Optional[str], top: bool = True) -> str:
> +        ret = upper_left if top else lower_left
> +        right = upper_right if top else lower_right
> +        if name is not None:
> +            ret += f"{horizontal} {name} "
> +
> +        assert width is not None
> +        filler_len = width - len(ret) - len(right)
> +        ret += f"{horizontal * filler_len}{right}"
> +        return ret
> +
> +    def _wrap(line: str) -> str:
> +        return os.linesep.join([
> +            wrapped_line.ljust(lwidth) + suffix
> +            for wrapped_line in textwrap.wrap(
> +                    line, width=lwidth, initial_indent=prefix,
> +                    subsequent_indent=prefix, replace_whitespace=False,
> +                    drop_whitespace=False, break_on_hyphens=False)

Always nice when someone else has written the cool library function to
do all the hard work for you ;)  But this is probably where you have the off-by-one I called out above.

> +        ])
> +
> +    return os.linesep.join((
> +        _bar(name, top=True),
> +        os.linesep.join(_wrap(line) for line in content.splitlines()),
> +        _bar(None, top=False),
> +    ))
> -- 
> 2.34.1
> 
> 

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3266
Virtualization:  qemu.org | libvirt.org

Re: [PATCH 1/4] python/utils: add enboxify() text decoration utility

[John Snow]

On Tue, Feb 15, 2022 at 5:55 PM Eric Blake <eblake@redhat.com> wrote:
>
> On Tue, Feb 15, 2022 at 05:08:50PM -0500, John Snow wrote:
> > >>> print(enboxify(msg, width=72, name="commit message"))
> > ┏━ commit message ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
> > ┃ enboxify() takes a chunk of text and wraps it in a text art box that ┃
> > ┃  adheres to a specified width. An optional title label may be given, ┃
> > ┃  and any of the individual glyphs used to draw the box may be        ┃
>
> Why do these two lines have a leading space,
>
> > ┃ replaced or specified as well.                                       ┃
>
> but this one doesn't?  It must be an off-by-one corner case when your
> choice of space to wrap on is exactly at the wrap column.
>

Right, you're probably witnessing the right-pad *and* the actual space.

> > ┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >  python/qemu/utils/__init__.py | 58 +++++++++++++++++++++++++++++++++++
> >  1 file changed, 58 insertions(+)
> >
> > diff --git a/python/qemu/utils/__init__.py b/python/qemu/utils/__init__.py
> > index 7f1a5138c4b..f785316f230 100644
> > --- a/python/qemu/utils/__init__.py
> > +++ b/python/qemu/utils/__init__.py
> > @@ -15,7 +15,10 @@
> >  # the COPYING file in the top-level directory.
> >  #
> >
> > +import os
> >  import re
> > +import shutil
> > +import textwrap
> >  from typing import Optional
> >
> >  # pylint: disable=import-error
> > @@ -23,6 +26,7 @@
> >
> >
> >  __all__ = (
> > +    'enboxify',
> >      'get_info_usernet_hostfwd_port',
> >      'kvm_available',
> >      'list_accel',
> > @@ -43,3 +47,57 @@ def get_info_usernet_hostfwd_port(info_usernet_output: str) -> Optional[int]:
> >          if match is not None:
> >              return int(match[1])
> >      return None
> > +
> > +
> > +# pylint: disable=too-many-arguments
> > +def enboxify(
> > +        content: str = '',
> > +        width: Optional[int] = None,
> > +        name: Optional[str] = None,
> > +        padding: int = 1,
> > +        upper_left: str = '┏',
> > +        upper_right: str = '┓',
> > +        lower_left: str = '┗',
> > +        lower_right: str = '┛',
> > +        horizontal: str = '━',
> > +        vertical: str = '┃',
> > +) -> str:
> > +    """
> > +    Wrap some text into a text art box of a given width.
> > +
> > +    :param content: The text to wrap into a box.
> > +    :param width: The number of columns (including the box itself).
> > +    :param name: A label to apply to the upper-left of the box.
> > +    :param padding: How many columns of padding to apply inside.
> > +    """
>
> Where's theh :param docs for the 6 custom glyphs?
>

Omitted as kinda-sorta-uninteresting. I can add them if we decide we
want this series.
(It's admittedly a bit of a "Hey, what do you think of this?")

> > +    if width is None:
> > +        width = shutil.get_terminal_size()[0]
> > +    prefix = vertical + (' ' * padding)
> > +    suffix = (' ' * padding) + vertical
> > +    lwidth = width - len(suffix)
> > +
> > +    def _bar(name: Optional[str], top: bool = True) -> str:
> > +        ret = upper_left if top else lower_left
> > +        right = upper_right if top else lower_right
> > +        if name is not None:
> > +            ret += f"{horizontal} {name} "
> > +
> > +        assert width is not None
> > +        filler_len = width - len(ret) - len(right)
> > +        ret += f"{horizontal * filler_len}{right}"
> > +        return ret
> > +
> > +    def _wrap(line: str) -> str:
> > +        return os.linesep.join([
> > +            wrapped_line.ljust(lwidth) + suffix
> > +            for wrapped_line in textwrap.wrap(
> > +                    line, width=lwidth, initial_indent=prefix,
> > +                    subsequent_indent=prefix, replace_whitespace=False,
> > +                    drop_whitespace=False, break_on_hyphens=False)
>
> Always nice when someone else has written the cool library function to
> do all the hard work for you ;)  But this is probably where you have the off-by-one I called out above.
>

Yeah, I just didn't want it to eat multiple spaces if they were
present -- I wanted it to reproduce them faithfully. The tradeoff is
some silliness near the margins.

Realistically, if I want something any better than what I've done
here, I should find a library to do it for me instead -- but for the
sake of highlighting some important information, this may be
just-enough-juice.

--js

Re: [PATCH 1/4] python/utils: add enboxify() text decoration utility

[Philippe Mathieu-Daudé via]

On 16/2/22 00:53, John Snow wrote:
> On Tue, Feb 15, 2022 at 5:55 PM Eric Blake <eblake@redhat.com> wrote:
>>
>> On Tue, Feb 15, 2022 at 05:08:50PM -0500, John Snow wrote:
>>>>>> print(enboxify(msg, width=72, name="commit message"))
>>> ┏━ commit message ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
>>> ┃ enboxify() takes a chunk of text and wraps it in a text art box that ┃
>>> ┃  adheres to a specified width. An optional title label may be given, ┃
>>> ┃  and any of the individual glyphs used to draw the box may be        ┃
>>
>> Why do these two lines have a leading space,
>>
>>> ┃ replaced or specified as well.                                       ┃
>>
>> but this one doesn't?  It must be an off-by-one corner case when your
>> choice of space to wrap on is exactly at the wrap column.
>>
> 
> Right, you're probably witnessing the right-pad *and* the actual space.
> 
>>> ┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛
>>>
>>> Signed-off-by: John Snow <jsnow@redhat.com>
>>> ---
>>>   python/qemu/utils/__init__.py | 58 +++++++++++++++++++++++++++++++++++
>>>   1 file changed, 58 insertions(+)

>>> +    def _wrap(line: str) -> str:
>>> +        return os.linesep.join([
>>> +            wrapped_line.ljust(lwidth) + suffix
>>> +            for wrapped_line in textwrap.wrap(
>>> +                    line, width=lwidth, initial_indent=prefix,
>>> +                    subsequent_indent=prefix, replace_whitespace=False,
>>> +                    drop_whitespace=False, break_on_hyphens=False)
>>
>> Always nice when someone else has written the cool library function to
>> do all the hard work for you ;)  But this is probably where you have the off-by-one I called out above.
>>
> 
> Yeah, I just didn't want it to eat multiple spaces if they were
> present -- I wanted it to reproduce them faithfully. The tradeoff is
> some silliness near the margins.
> 
> Realistically, if I want something any better than what I've done
> here, I should find a library to do it for me instead -- but for the
> sake of highlighting some important information, this may be
> just-enough-juice.

's/^┃  /┃ /' on top ;D

Re: [PATCH 1/4] python/utils: add enboxify() text decoration utility

[John Snow]

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

On Tue, Feb 15, 2022, 6:57 PM Philippe Mathieu-Daudé <f4bug@amsat.org>
wrote:

> On 16/2/22 00:53, John Snow wrote:
> > On Tue, Feb 15, 2022 at 5:55 PM Eric Blake <eblake@redhat.com> wrote:
> >>
> >> On Tue, Feb 15, 2022 at 05:08:50PM -0500, John Snow wrote:
> >>>>>> print(enboxify(msg, width=72, name="commit message"))
> >>> ┏━ commit message
> ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
> >>> ┃ enboxify() takes a chunk of text and wraps it in a text art box that
> ┃
> >>> ┃  adheres to a specified width. An optional title label may be given,
> ┃
> >>> ┃  and any of the individual glyphs used to draw the box may be
> ┃
> >>
> >> Why do these two lines have a leading space,
> >>
> >>> ┃ replaced or specified as well.
>  ┃
> >>
> >> but this one doesn't?  It must be an off-by-one corner case when your
> >> choice of space to wrap on is exactly at the wrap column.
> >>
> >
> > Right, you're probably witnessing the right-pad *and* the actual space.
> >
> >>>
> ┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛
> >>>
> >>> Signed-off-by: John Snow <jsnow@redhat.com>
> >>> ---
> >>>   python/qemu/utils/__init__.py | 58
> +++++++++++++++++++++++++++++++++++
> >>>   1 file changed, 58 insertions(+)
>
> >>> +    def _wrap(line: str) -> str:
> >>> +        return os.linesep.join([
> >>> +            wrapped_line.ljust(lwidth) + suffix
> >>> +            for wrapped_line in textwrap.wrap(
> >>> +                    line, width=lwidth, initial_indent=prefix,
> >>> +                    subsequent_indent=prefix,
> replace_whitespace=False,
> >>> +                    drop_whitespace=False, break_on_hyphens=False)
> >>
> >> Always nice when someone else has written the cool library function to
> >> do all the hard work for you ;)  But this is probably where you have
> the off-by-one I called out above.
> >>
> >
> > Yeah, I just didn't want it to eat multiple spaces if they were
> > present -- I wanted it to reproduce them faithfully. The tradeoff is
> > some silliness near the margins.
> >
> > Realistically, if I want something any better than what I've done
> > here, I should find a library to do it for me instead -- but for the
> > sake of highlighting some important information, this may be
> > just-enough-juice.
>
> 's/^┃  /┃ /' on top ;D
>

I have to admit that this function is actually very fragile. Last night, I
did some reading on unicode and emoji encodings and discovered that it's
*basically impossible* to predict the "visual width" of a sequence of
unicode codepoints.

So, this function as written will only really work if we stick to
single-codepoint glyphs that can be rendered 1:1 in a monospace font.

I could probably improve it to work with "some" (but certainly not all)
wide glyphs and emoji, but it's a very complex topic and far outside my
specialty. Support for multi-codepoint narrow/halfwidth glyphs is also an
issue. (This affects some Latin characters outside of ascii if they are
encoded using combining codepoints.)

(See https://hsivonen.fi/string-length/ ... It's nasty.)

So I must admit that this function has some very serious limitations to it.
I want to explain why I wrote it, though.

First: Tracebacks make people's eyes cross over. It's a very long sequence
of mumbo jumbo that most people don't read, because it's program debug
information. I don't blame them. Setting apart the error summary visually
is a helpful tool for drawing one's eyes to the most critical pieces of
information.

Second: In my AQMP library, I use the ascii vertical bar | as a left-hand
border decoration to provide a kind of visual quoting mechanism to
illustrate in the logfile which subsequent confusing lines of jargon belong
to the same log entry. I really like this formatting mechanism, but...

Third: If a line of text becomes so long that it wraps in your terminal,
the visual quote mechanism breaks, making the output messy and hard to
read. Forcibly re-wrapping the text in a virtual box is a necessary
mechanism to preserve readability in this circumstance - the lines from
qemu-img et al may be much wider than your terminal column width.

And so, I drew a box instead of just a left border, because I needed to
re-wrap the text anyway. Visually, I believed it to help explain that the
output was being re-formatted to fit in a certain dimensionality.
Unfortunately, it's inadequate.

So ... what to do.

(1) I can just remove the right margin decoration and call the function
visual_quote or something. If any of the lines get too "long" because of
emoji/日本語, it MAY break the indent line, but occasional uses of one or two
wide characters probably won't cause wrapping that breaks the "visual quote
line" on a terminal with at least 85 columns. Essentially it'd still be
broken, but without a solid right border it'd be harder to notice *small*
breakages.

(2) If there is a genuine interest in using visual highlighting techniques
to make iotest failures easier to diagnose (and making sure it is properly
multilingual), I could use the urwid helper library to estimate visual text
width to make drawing terminal boxes more resilient than what I could do on
my own power. Downside is a new third party dependency. I already use urwid
for the aqmp tui that we're working on, but it's remained an optional
dependency so far.

(3) I can take a swing at improving this text decoration utility and having
it account for the most basic cases. East Asian language support is a low
hanging fruit, though I have only rudimentary familiarity with Hangul. (And
virtually no exposure to Thai or other south-eastern Asian scripts.)

(4) Just leave it alone for now, don't you have IDE/FDC patches to work on?

Sigh. The punishment for trying to do something nice is swift.

--js

>

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

Re: [PATCH 1/4] python/utils: add enboxify() text decoration utility

[Hanna Reitz]

On 16.02.22 17:16, John Snow wrote:
>
> On Tue, Feb 15, 2022, 6:57 PM Philippe Mathieu-Daudé <f4bug@amsat.org> 
> wrote:
>
>     On 16/2/22 00:53, John Snow wrote:
>     > On Tue, Feb 15, 2022 at 5:55 PM Eric Blake <eblake@redhat.com>
>     wrote:
>     >>
>     >> On Tue, Feb 15, 2022 at 05:08:50PM -0500, John Snow wrote:
>     >>>>>> print(enboxify(msg, width=72, name="commit message"))
>     >>> ┏━ commit message
>     ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
>     >>> ┃ enboxify() takes a chunk of text and wraps it in a text art
>     box that ┃
>     >>> ┃  adheres to a specified width. An optional title label may
>     be given, ┃
>     >>> ┃  and any of the individual glyphs used to draw the box may
>     be        ┃
>     >>
>     >> Why do these two lines have a leading space,
>     >>
>     >>> ┃ replaced or specified as well.                          ┃
>     >>
>     >> but this one doesn't?  It must be an off-by-one corner case
>     when your
>     >> choice of space to wrap on is exactly at the wrap column.
>     >>
>     >
>     > Right, you're probably witnessing the right-pad *and* the actual
>     space.
>     >
>     >>>
>     ┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛
>     >>>
>     >>> Signed-off-by: John Snow <jsnow@redhat.com>
>     >>> ---
>     >>>   python/qemu/utils/__init__.py | 58
>     +++++++++++++++++++++++++++++++++++
>     >>>   1 file changed, 58 insertions(+)
>
>     >>> +    def _wrap(line: str) -> str:
>     >>> +        return os.linesep.join([
>     >>> +            wrapped_line.ljust(lwidth) + suffix
>     >>> +            for wrapped_line in textwrap.wrap(
>     >>> +                    line, width=lwidth, initial_indent=prefix,
>     >>> + subsequent_indent=prefix, replace_whitespace=False,
>     >>> +                    drop_whitespace=False,
>     break_on_hyphens=False)
>     >>
>     >> Always nice when someone else has written the cool library
>     function to
>     >> do all the hard work for you ;)  But this is probably where you
>     have the off-by-one I called out above.
>     >>
>     >
>     > Yeah, I just didn't want it to eat multiple spaces if they were
>     > present -- I wanted it to reproduce them faithfully. The tradeoff is
>     > some silliness near the margins.
>     >
>     > Realistically, if I want something any better than what I've done
>     > here, I should find a library to do it for me instead -- but for the
>     > sake of highlighting some important information, this may be
>     > just-enough-juice.
>
>     's/^┃  /┃ /' on top ;D
>
>
> I have to admit that this function is actually very fragile. Last 
> night, I did some reading on unicode and emoji encodings and 
> discovered that it's *basically impossible* to predict the "visual 
> width" of a sequence of unicode codepoints.

Jumping it at random without knowing any of the history (that’s my forte!):

*Clippy face*

It sounds like you want to put a bar to the right of some text in a 
terminal, but you can’t predict the texts horizontal width, and so you 
can’t work out the number of spaces needed to pad the text with before 
the bar.

Two things come to my mind, if we’re talking about TTY output:
(A) printf '%79s┃\r%s\n' '' "$text"
(B) printf '%s\e[80G┃\n' "$text"

I.e. either printing the bar first, then printing the text over the 
line; or using an ANSI escape sequence to have the TTY position the 
bar.  Both seem to work for me in both konsole and xterm.

Or perhaps you’re really trying to find out how long a piece of text is 
visually (so you can break the line when this exceeds some limit), which 
you can also technically do with ANSI escape sequences, because "\e[6n" 
will return the cursor position to stdin (as "\e[{Y};{X}R").  But 
reading from stdin when there’s no newline is always really stupid, so I 
don’t know if you really want that.

(And you also need to print the text first before you can find out how 
long it is, which is kind of not great.)

Now that I wrote this all it feels like I didn’t help at all, but I put 
work into this mail, so I’ll send it anyway!

Hanna

[PATCH 2/4] iotests: add VerboseProcessError

[John Snow]

This adds an Exception that extends the garden variety
subprocess.CalledProcessError. When this exception is raised, it will
still be caught when selecting for the stdlib variant.

The difference is that the str() method of this Exception also adds the
stdout/stderr logs. In effect, if this exception goes unhandled, Python
will print the output in a nice, highlighted box to the terminal so that
it's easy to spot.

This should save some headache from having to re-run test suites with
debugging enabled if we augment the exceptions we print more information
in the default case.

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

diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
index 6ba65eb1ffe..7df393df2c3 100644
--- a/tests/qemu-iotests/iotests.py
+++ b/tests/qemu-iotests/iotests.py
@@ -30,6 +30,7 @@
 import struct
 import subprocess
 import sys
+import textwrap
 import time
 from typing import (Any, Callable, Dict, Iterable, Iterator,
                     List, Optional, Sequence, TextIO, Tuple, Type, TypeVar)
@@ -39,6 +40,7 @@
 
 from qemu.machine import qtest
 from qemu.qmp import QMPMessage
+from qemu.utils import enboxify
 
 # Use this logger for logging messages directly from the iotests module
 logger = logging.getLogger('qemu.iotests')
@@ -117,6 +119,38 @@
 sample_img_dir = os.environ['SAMPLE_IMG_DIR']
 
 
+class VerboseProcessError(subprocess.CalledProcessError):
+    """
+    The same as CalledProcessError, but more verbose.
+
+    This is useful for debugging failed calls during test executions.
+    The return code, signal (if any), and terminal output will be displayed
+    on unhandled exceptions.
+    """
+    def summary(self) -> str:
+        return super().__str__()
+
+    def __str__(self) -> str:
+        lmargin = '  '
+        width = shutil.get_terminal_size()[0] - len(lmargin)
+        sections = []
+
+        if self.stdout:
+            name = 'output' if self.stderr is None else 'stdout'
+            sections.append(enboxify(self.stdout, width, name))
+        else:
+            sections.append(f"{name}: N/A")
+
+        if self.stderr:
+            sections.append(enboxify(self.stderr, width, 'stderr'))
+        elif self.stderr is not None:
+            sections.append("stderr: N/A")
+
+        return os.linesep.join((
+            self.summary(),
+            textwrap.indent(os.linesep.join(sections), prefix=lmargin),
+        ))
+
 @contextmanager
 def change_log_level(
         logger_name: str, level: int = logging.CRITICAL) -> Iterator[None]:
-- 
2.34.1

Re: [PATCH 2/4] iotests: add VerboseProcessError

[Eric Blake]

On Tue, Feb 15, 2022 at 05:08:51PM -0500, John Snow wrote:
> This adds an Exception that extends the garden variety
> subprocess.CalledProcessError. When this exception is raised, it will
> still be caught when selecting for the stdlib variant.
> 
> The difference is that the str() method of this Exception also adds the
> stdout/stderr logs. In effect, if this exception goes unhandled, Python
> will print the output in a nice, highlighted box to the terminal so that
> it's easy to spot.
> 
> This should save some headache from having to re-run test suites with
> debugging enabled if we augment the exceptions we print more information

This didn't parse well for me.  Maybe
s/enabled/enabled,/ s/print more/print with more/

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

Otherwise seems useful.

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3266
Virtualization:  qemu.org | libvirt.org

Re: [PATCH 2/4] iotests: add VerboseProcessError

[John Snow]

On Tue, Feb 15, 2022 at 5:58 PM Eric Blake <eblake@redhat.com> wrote:
>
> On Tue, Feb 15, 2022 at 05:08:51PM -0500, John Snow wrote:
> > This adds an Exception that extends the garden variety
> > subprocess.CalledProcessError. When this exception is raised, it will
> > still be caught when selecting for the stdlib variant.
> >
> > The difference is that the str() method of this Exception also adds the
> > stdout/stderr logs. In effect, if this exception goes unhandled, Python
> > will print the output in a nice, highlighted box to the terminal so that
> > it's easy to spot.
> >
> > This should save some headache from having to re-run test suites with
> > debugging enabled if we augment the exceptions we print more information
>
> This didn't parse well for me.  Maybe
> s/enabled/enabled,/ s/print more/print with more/
>

*cough* copy-paste failure. Two drafts collided here. Oopsie.

[PATCH 3/4] iotests: Remove explicit checks for qemu_img() == 0

[John Snow]

qemu_img() returning zero ought to be the rule, not the
exception. Remove all explicit checks against the condition in
preparation for making non-zero returns an Exception.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 tests/qemu-iotests/163                             |  9 +++------
 tests/qemu-iotests/216                             |  6 +++---
 tests/qemu-iotests/218                             |  2 +-
 tests/qemu-iotests/224                             | 11 +++++------
 tests/qemu-iotests/228                             | 12 ++++++------
 tests/qemu-iotests/257                             |  3 +--
 tests/qemu-iotests/258                             |  4 ++--
 tests/qemu-iotests/310                             | 14 +++++++-------
 tests/qemu-iotests/tests/block-status-cache        |  3 +--
 tests/qemu-iotests/tests/image-fleecing            |  4 ++--
 tests/qemu-iotests/tests/mirror-ready-cancel-error |  6 ++----
 tests/qemu-iotests/tests/mirror-top-perms          |  3 +--
 .../qemu-iotests/tests/remove-bitmap-from-backing  |  8 ++++----
 tests/qemu-iotests/tests/stream-error-on-reset     |  4 ++--
 14 files changed, 40 insertions(+), 49 deletions(-)

diff --git a/tests/qemu-iotests/163 b/tests/qemu-iotests/163
index b8bfc95358e..e4cd4b230f3 100755
--- a/tests/qemu-iotests/163
+++ b/tests/qemu-iotests/163
@@ -107,8 +107,7 @@ class ShrinkBaseClass(iotests.QMPTestCase):
 
         if iotests.imgfmt == 'raw':
             return
-        self.assertEqual(qemu_img('check', test_img), 0,
-                         "Verifying image corruption")
+        qemu_img('check', test_img)
 
     def test_empty_image(self):
         qemu_img('resize',  '-f', iotests.imgfmt, '--shrink', test_img,
@@ -130,8 +129,7 @@ class ShrinkBaseClass(iotests.QMPTestCase):
         qemu_img('resize',  '-f', iotests.imgfmt, '--shrink', test_img,
                  self.shrink_size)
 
-        self.assertEqual(qemu_img("compare", test_img, check_img), 0,
-                         "Verifying image content")
+        qemu_img("compare", test_img, check_img)
 
         self.image_verify()
 
@@ -146,8 +144,7 @@ class ShrinkBaseClass(iotests.QMPTestCase):
         qemu_img('resize',  '-f', iotests.imgfmt, '--shrink', test_img,
                  self.shrink_size)
 
-        self.assertEqual(qemu_img("compare", test_img, check_img), 0,
-                         "Verifying image content")
+        qemu_img("compare", test_img, check_img)
 
         self.image_verify()
 
diff --git a/tests/qemu-iotests/216 b/tests/qemu-iotests/216
index c02f8d2880f..88b385afa30 100755
--- a/tests/qemu-iotests/216
+++ b/tests/qemu-iotests/216
@@ -51,10 +51,10 @@ with iotests.FilePath('base.img') as base_img_path, \
     log('--- Setting up images ---')
     log('')
 
-    assert qemu_img('create', '-f', iotests.imgfmt, base_img_path, '64M') == 0
+    qemu_img('create', '-f', iotests.imgfmt, base_img_path, '64M')
     assert qemu_io_silent(base_img_path, '-c', 'write -P 1 0M 1M') == 0
-    assert qemu_img('create', '-f', iotests.imgfmt, '-b', base_img_path,
-                    '-F', iotests.imgfmt, top_img_path) == 0
+    qemu_img('create', '-f', iotests.imgfmt, '-b', base_img_path,
+             '-F', iotests.imgfmt, top_img_path)
     assert qemu_io_silent(top_img_path,  '-c', 'write -P 2 1M 1M') == 0
 
     log('Done')
diff --git a/tests/qemu-iotests/218 b/tests/qemu-iotests/218
index 4922b4d3b6f..853ed52b349 100755
--- a/tests/qemu-iotests/218
+++ b/tests/qemu-iotests/218
@@ -145,7 +145,7 @@ log('')
 with iotests.VM() as vm, \
      iotests.FilePath('src.img') as src_img_path:
 
-    assert qemu_img('create', '-f', iotests.imgfmt, src_img_path, '64M') == 0
+    qemu_img('create', '-f', iotests.imgfmt, src_img_path, '64M')
     assert qemu_io_silent('-f', iotests.imgfmt, src_img_path,
                           '-c', 'write -P 42 0M 64M') == 0
 
diff --git a/tests/qemu-iotests/224 b/tests/qemu-iotests/224
index 38dd1536254..c31c55b49d2 100755
--- a/tests/qemu-iotests/224
+++ b/tests/qemu-iotests/224
@@ -47,12 +47,11 @@ for filter_node_name in False, True:
          iotests.FilePath('top.img') as top_img_path, \
          iotests.VM() as vm:
 
-        assert qemu_img('create', '-f', iotests.imgfmt,
-                        base_img_path, '64M') == 0
-        assert qemu_img('create', '-f', iotests.imgfmt, '-b', base_img_path,
-                        '-F', iotests.imgfmt, mid_img_path) == 0
-        assert qemu_img('create', '-f', iotests.imgfmt, '-b', mid_img_path,
-                        '-F', iotests.imgfmt, top_img_path) == 0
+        qemu_img('create', '-f', iotests.imgfmt, base_img_path, '64M')
+        qemu_img('create', '-f', iotests.imgfmt, '-b', base_img_path,
+                 '-F', iotests.imgfmt, mid_img_path)
+        qemu_img('create', '-f', iotests.imgfmt, '-b', mid_img_path,
+                 '-F', iotests.imgfmt, top_img_path)
 
         # Something to commit
         assert qemu_io_silent(mid_img_path, '-c', 'write -P 1 0 1M') == 0
diff --git a/tests/qemu-iotests/228 b/tests/qemu-iotests/228
index a5eda2e149b..f79bae02677 100755
--- a/tests/qemu-iotests/228
+++ b/tests/qemu-iotests/228
@@ -54,11 +54,11 @@ with iotests.FilePath('base.img') as base_img_path, \
      iotests.FilePath('top.img') as top_img_path, \
      iotests.VM() as vm:
 
-    assert qemu_img('create', '-f', iotests.imgfmt, base_img_path, '64M') == 0
+    qemu_img('create', '-f', iotests.imgfmt, base_img_path, '64M')
     # Choose a funny way to describe the backing filename
-    assert qemu_img('create', '-f', iotests.imgfmt, '-b',
-                    'file:' + base_img_path, '-F', iotests.imgfmt,
-                    top_img_path) == 0
+    qemu_img('create', '-f', iotests.imgfmt, '-b',
+             'file:' + base_img_path, '-F', iotests.imgfmt,
+             top_img_path)
 
     vm.launch()
 
@@ -172,8 +172,8 @@ with iotests.FilePath('base.img') as base_img_path, \
     # (because qemu cannot "canonicalize"/"resolve" the backing
     # filename unless the backing file is opened implicitly with the
     # overlay)
-    assert qemu_img('create', '-f', iotests.imgfmt, '-b', base_img_path,
-                    '-F', iotests.imgfmt, top_img_path) == 0
+    qemu_img('create', '-f', iotests.imgfmt, '-b', base_img_path,
+             '-F', iotests.imgfmt, top_img_path)
 
     # You can only reliably override backing options by using a node
     # reference (or by specifying file.filename, but, well...)
diff --git a/tests/qemu-iotests/257 b/tests/qemu-iotests/257
index c72c82a171b..fb5359c581e 100755
--- a/tests/qemu-iotests/257
+++ b/tests/qemu-iotests/257
@@ -240,8 +240,7 @@ def compare_images(image, reference, baseimg=None, expected_match=True):
     """
     expected_ret = 0 if expected_match else 1
     if baseimg:
-        assert qemu_img("rebase", "-u", "-b", baseimg, '-F', iotests.imgfmt,
-                        image) == 0
+        qemu_img("rebase", "-u", "-b", baseimg, '-F', iotests.imgfmt, image)
     ret = qemu_img("compare", image, reference)
     log('qemu_img compare "{:s}" "{:s}" ==> {:s}, {:s}'.format(
         image, reference,
diff --git a/tests/qemu-iotests/258 b/tests/qemu-iotests/258
index a6618208a89..7798a04d7d3 100755
--- a/tests/qemu-iotests/258
+++ b/tests/qemu-iotests/258
@@ -75,13 +75,13 @@ def test_concurrent_finish(write_to_stream_node):
 
         # It is important to use raw for the base layer (so that
         # permissions are just handed through to the protocol layer)
-        assert qemu_img('create', '-f', 'raw', node0_path, '64M') == 0
+        qemu_img('create', '-f', 'raw', node0_path, '64M')
 
         stream_throttle=None
         commit_throttle=None
 
         for path in [node1_path, node2_path, node3_path, node4_path]:
-            assert qemu_img('create', '-f', iotests.imgfmt, path, '64M') == 0
+            qemu_img('create', '-f', iotests.imgfmt, path, '64M')
 
         if write_to_stream_node:
             # This is what (most of the time) makes commit finish
diff --git a/tests/qemu-iotests/310 b/tests/qemu-iotests/310
index 33c34118694..4e6d70e5ac6 100755
--- a/tests/qemu-iotests/310
+++ b/tests/qemu-iotests/310
@@ -43,15 +43,15 @@ with iotests.FilePath('base.img') as base_img_path, \
     log('--- Setting up images ---')
     log('')
 
-    assert qemu_img('create', '-f', iotests.imgfmt, base_img_path, '64M') == 0
+    qemu_img('create', '-f', iotests.imgfmt, base_img_path, '64M')
     assert qemu_io_silent(base_img_path, '-c', 'write -P 1 0M 1M') == 0
     assert qemu_io_silent(base_img_path, '-c', 'write -P 1 3M 1M') == 0
-    assert qemu_img('create', '-f', iotests.imgfmt, '-b', base_img_path,
-                    '-F', iotests.imgfmt, mid_img_path) == 0
+    qemu_img('create', '-f', iotests.imgfmt, '-b', base_img_path,
+             '-F', iotests.imgfmt, mid_img_path)
     assert qemu_io_silent(mid_img_path, '-c', 'write -P 3 2M 1M') == 0
     assert qemu_io_silent(mid_img_path, '-c', 'write -P 3 4M 1M') == 0
-    assert qemu_img('create', '-f', iotests.imgfmt, '-b', mid_img_path,
-                    '-F', iotests.imgfmt, top_img_path) == 0
+    qemu_img('create', '-f', iotests.imgfmt, '-b', mid_img_path,
+             '-F', iotests.imgfmt, top_img_path)
     assert qemu_io_silent(top_img_path, '-c', 'write -P 2 1M 1M') == 0
 
 #      0 1 2 3 4
@@ -105,8 +105,8 @@ with iotests.FilePath('base.img') as base_img_path, \
     log('')
 
     # Detach backing to check that we can read the data from the top level now
-    assert qemu_img('rebase', '-u', '-b', '', '-f', iotests.imgfmt,
-                    top_img_path) == 0
+    qemu_img('rebase', '-u', '-b', '', '-f', iotests.imgfmt,
+             top_img_path)
 
     assert qemu_io_silent(top_img_path, '-c', 'read -P 0 0 1M') == 0
     assert qemu_io_silent(top_img_path, '-c', 'read -P 2 1M 1M') == 0
diff --git a/tests/qemu-iotests/tests/block-status-cache b/tests/qemu-iotests/tests/block-status-cache
index 6fa10bb8f8a..40e648e251a 100755
--- a/tests/qemu-iotests/tests/block-status-cache
+++ b/tests/qemu-iotests/tests/block-status-cache
@@ -35,8 +35,7 @@ nbd_sock = os.path.join(iotests.sock_dir, 'nbd.sock')
 class TestBscWithNbd(iotests.QMPTestCase):
     def setUp(self) -> None:
         """Just create an empty image with a read-only NBD server on it"""
-        assert qemu_img_create('-f', iotests.imgfmt, test_img,
-                               str(image_size)) == 0
+        qemu_img_create('-f', iotests.imgfmt, test_img, str(image_size))
 
         # Pass --allocation-depth to enable the qemu:allocation-depth context,
         # which we are going to query to provoke a block-status inquiry with
diff --git a/tests/qemu-iotests/tests/image-fleecing b/tests/qemu-iotests/tests/image-fleecing
index a58b5a17816..ac8f19e5062 100755
--- a/tests/qemu-iotests/tests/image-fleecing
+++ b/tests/qemu-iotests/tests/image-fleecing
@@ -53,8 +53,8 @@ def do_test(use_cbw, base_img_path, fleece_img_path, nbd_sock_path, vm):
     log('--- Setting up images ---')
     log('')
 
-    assert qemu_img('create', '-f', iotests.imgfmt, base_img_path, '64M') == 0
-    assert qemu_img('create', '-f', 'qcow2', fleece_img_path, '64M') == 0
+    qemu_img('create', '-f', iotests.imgfmt, base_img_path, '64M')
+    qemu_img('create', '-f', 'qcow2', fleece_img_path, '64M')
 
     for p in patterns:
         qemu_io('-f', iotests.imgfmt,
diff --git a/tests/qemu-iotests/tests/mirror-ready-cancel-error b/tests/qemu-iotests/tests/mirror-ready-cancel-error
index 770ffca3793..1d0e333b5ef 100755
--- a/tests/qemu-iotests/tests/mirror-ready-cancel-error
+++ b/tests/qemu-iotests/tests/mirror-ready-cancel-error
@@ -31,10 +31,8 @@ target = os.path.join(iotests.test_dir, 'target.img')
 
 class TestMirrorReadyCancelError(iotests.QMPTestCase):
     def setUp(self) -> None:
-        assert iotests.qemu_img_create('-f', iotests.imgfmt, source,
-                                       str(image_size)) == 0
-        assert iotests.qemu_img_create('-f', iotests.imgfmt, target,
-                                       str(image_size)) == 0
+        iotests.qemu_img_create('-f', iotests.imgfmt, source, str(image_size))
+        iotests.qemu_img_create('-f', iotests.imgfmt, target, str(image_size))
 
         # Ensure that mirror will copy something before READY so the
         # target format layer will forward the pre-READY flush to its
diff --git a/tests/qemu-iotests/tests/mirror-top-perms b/tests/qemu-iotests/tests/mirror-top-perms
index b5849978c41..6ac8d5efccb 100755
--- a/tests/qemu-iotests/tests/mirror-top-perms
+++ b/tests/qemu-iotests/tests/mirror-top-perms
@@ -34,8 +34,7 @@ source = os.path.join(iotests.test_dir, 'source.img')
 
 class TestMirrorTopPerms(iotests.QMPTestCase):
     def setUp(self):
-        assert qemu_img('create', '-f', iotests.imgfmt, source,
-                        str(image_size)) == 0
+        qemu_img('create', '-f', iotests.imgfmt, source, str(image_size))
         self.vm = iotests.VM()
         self.vm.add_drive(source)
         self.vm.add_blockdev(f'null-co,node-name=null,size={image_size}')
diff --git a/tests/qemu-iotests/tests/remove-bitmap-from-backing b/tests/qemu-iotests/tests/remove-bitmap-from-backing
index 3c397b08ea4..fee31413400 100755
--- a/tests/qemu-iotests/tests/remove-bitmap-from-backing
+++ b/tests/qemu-iotests/tests/remove-bitmap-from-backing
@@ -27,11 +27,11 @@ iotests.script_initialize(supported_fmts=['qcow2'],
 top, base = iotests.file_path('top', 'base')
 size = '1M'
 
-assert qemu_img_create('-f', iotests.imgfmt, base, size) == 0
-assert qemu_img_create('-f', iotests.imgfmt, '-b', base,
-                       '-F', iotests.imgfmt, top, size) == 0
+qemu_img_create('-f', iotests.imgfmt, base, size)
+qemu_img_create('-f', iotests.imgfmt, '-b', base,
+                '-F', iotests.imgfmt, top, size)
 
-assert qemu_img('bitmap', '--add', base, 'bitmap0') == 0
+qemu_img('bitmap', '--add', base, 'bitmap0')
 # Just assert that our method of checking bitmaps in the image works.
 assert 'bitmaps' in qemu_img_pipe('info', base)
 
diff --git a/tests/qemu-iotests/tests/stream-error-on-reset b/tests/qemu-iotests/tests/stream-error-on-reset
index 7eaedb24d7b..389ae822b8b 100755
--- a/tests/qemu-iotests/tests/stream-error-on-reset
+++ b/tests/qemu-iotests/tests/stream-error-on-reset
@@ -54,9 +54,9 @@ class TestStreamErrorOnReset(QMPTestCase):
           to it will result in an error
         - top image is attached to a virtio-scsi device
         """
-        assert qemu_img_create('-f', imgfmt, base, str(image_size)) == 0
+        qemu_img_create('-f', imgfmt, base, str(image_size))
         assert qemu_io_silent('-c', f'write 0 {data_size}', base) == 0
-        assert qemu_img_create('-f', imgfmt, top, str(image_size)) == 0
+        qemu_img_create('-f', imgfmt, top, str(image_size))
 
         self.vm = iotests.VM()
         self.vm.add_args('-accel', 'tcg') # Make throttling work properly
-- 
2.34.1

Re: [PATCH 3/4] iotests: Remove explicit checks for qemu_img() == 0

[Eric Blake]

On Tue, Feb 15, 2022 at 05:08:52PM -0500, John Snow wrote:
> qemu_img() returning zero ought to be the rule, not the
> exception. Remove all explicit checks against the condition in
> preparation for making non-zero returns an Exception.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---

Reviewed-by: Eric Blake <eblake@redhat.com>

This one seems clean whether or not there are questions about using
enboxify earlier in the series.

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3266
Virtualization:  qemu.org | libvirt.org

Re: [PATCH 3/4] iotests: Remove explicit checks for qemu_img() == 0

[John Snow]

On Tue, Feb 15, 2022 at 6:05 PM Eric Blake <eblake@redhat.com> wrote:
>
> On Tue, Feb 15, 2022 at 05:08:52PM -0500, John Snow wrote:
> > qemu_img() returning zero ought to be the rule, not the
> > exception. Remove all explicit checks against the condition in
> > preparation for making non-zero returns an Exception.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
>
> Reviewed-by: Eric Blake <eblake@redhat.com>
>
> This one seems clean whether or not there are questions about using
> enboxify earlier in the series.
>

Yeah, if we don't want ~fancy~ text decoration, the rest of this
should still be broadly helpful, I think. There are simpler text
decorations we can use to keep the output from looking like traceback
soup.

--js

[PATCH 4/4] iotests: make qemu_img raise on non-zero rc by default

[John Snow]

re-configure qemu_img() into a function that will by default raise a
VerboseProcessException (extended from CalledProcessException) on
non-zero return codes. This will produce a stack trace that will show
the command line arguments and return code from the failed process run.

Users that want something more flexible (There appears to be only one)
can use check=False and manage the return themselves.

Signed-off-by: John Snow <jsnow@redhat.com>
---
 tests/qemu-iotests/257        |  8 ++++--
 tests/qemu-iotests/iotests.py | 53 +++++++++++++++++++++++++++++++----
 2 files changed, 53 insertions(+), 8 deletions(-)

diff --git a/tests/qemu-iotests/257 b/tests/qemu-iotests/257
index fb5359c581e..e7e7a2317e3 100755
--- a/tests/qemu-iotests/257
+++ b/tests/qemu-iotests/257
@@ -241,11 +241,13 @@ def compare_images(image, reference, baseimg=None, expected_match=True):
     expected_ret = 0 if expected_match else 1
     if baseimg:
         qemu_img("rebase", "-u", "-b", baseimg, '-F', iotests.imgfmt, image)
-    ret = qemu_img("compare", image, reference)
+
+    sub = qemu_img("compare", image, reference, check=False)
+
     log('qemu_img compare "{:s}" "{:s}" ==> {:s}, {:s}'.format(
         image, reference,
-        "Identical" if ret == 0 else "Mismatch",
-        "OK!" if ret == expected_ret else "ERROR!"),
+        "Identical" if sub.returncode == 0 else "Mismatch",
+        "OK!" if sub.returncode == expected_ret else "ERROR!"),
         filters=[iotests.filter_testfiles])
 
 def test_bitmap_sync(bsync_mode, msync_mode='bitmap', failure=None):
diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
index 7df393df2c3..8a244fafece 100644
--- a/tests/qemu-iotests/iotests.py
+++ b/tests/qemu-iotests/iotests.py
@@ -249,9 +249,51 @@ def qemu_img_pipe_and_status(*args: str) -> Tuple[str, int]:
     return qemu_tool_pipe_and_status('qemu-img', full_args,
                                      drop_successful_output=is_create)
 
-def qemu_img(*args: str) -> int:
-    '''Run qemu-img and return the exit code'''
-    return qemu_img_pipe_and_status(*args)[1]
+def qemu_img(*args: str, check: bool = True, combine_stdio: bool = True
+             ) -> subprocess.CompletedProcess[str]:
+    """
+    Run qemu_img, returning a CompletedProcess instance.
+
+    The CompletedProcess object has args, returncode, and output properties.
+    If streams are not combined, It will also have stdout/stderr properties.
+
+    :param args: command-line arguments to qemu_img.
+    :param check: set to False to suppress VerboseProcessError.
+    :param combine_stdio: set to False to keep stdout/stderr separated.
+
+    :raise VerboseProcessError:
+        On non-zero exit code, when 'check=True' was provided. This
+        exception has 'stderr', 'stdout' and 'returncode' properties
+        that may be inspected to show greater detail. If this exception
+        is not handled, The command-line, return code, and all console
+        output will be included at the bottom of the stack trace.
+    """
+    full_args = qemu_img_args + qemu_img_create_prepare_args(list(args))
+
+    subp = subprocess.run(
+        full_args,
+        stdout=subprocess.PIPE,
+        stderr=subprocess.STDOUT if combine_stdio else subprocess.PIPE,
+        universal_newlines=True,
+        check=False
+    )
+
+    # For behavioral consistency with qemu_tool_pipe_and_status():
+    # Print out an immediate error when the return code is negative.
+    if subp.returncode < 0:
+        cmd = ' '.join(full_args)
+        sys.stderr.write(
+            f'qemu-img received signal {-subp.returncode}: {cmd}\n')
+
+    if check and subp.returncode:
+        raise VerboseProcessError(
+            subp.returncode, full_args,
+            output=subp.stdout,
+            stderr=subp.stderr,
+        )
+
+    return subp
+
 
 def ordered_qmp(qmsg, conv_keys=True):
     # Dictionaries are not ordered prior to 3.6, therefore:
@@ -469,8 +511,9 @@ def qemu_nbd_popen(*args):
 
 def compare_images(img1, img2, fmt1=imgfmt, fmt2=imgfmt):
     '''Return True if two image files are identical'''
-    return qemu_img('compare', '-f', fmt1,
-                    '-F', fmt2, img1, img2) == 0
+    res = qemu_img('compare', '-f', fmt1,
+                   '-F', fmt2, img1, img2, check=False)
+    return res.returncode == 0
 
 def create_image(name, size):
     '''Create a fully-allocated raw image with sector markers'''
-- 
2.34.1

Re: [PATCH 4/4] iotests: make qemu_img raise on non-zero rc by default

[Eric Blake]

On Tue, Feb 15, 2022 at 05:08:53PM -0500, John Snow wrote:
> re-configure qemu_img() into a function that will by default raise a
> VerboseProcessException (extended from CalledProcessException) on
> non-zero return codes. This will produce a stack trace that will show
> the command line arguments and return code from the failed process run.
> 
> Users that want something more flexible (There appears to be only one)

s/There/there/

> can use check=False and manage the return themselves.
> 
> Signed-off-by: John Snow <jsnow@redhat.com>
> ---
>  tests/qemu-iotests/257        |  8 ++++--
>  tests/qemu-iotests/iotests.py | 53 +++++++++++++++++++++++++++++++----
>  2 files changed, 53 insertions(+), 8 deletions(-)
> 

> +def qemu_img(*args: str, check: bool = True, combine_stdio: bool = True
> +             ) -> subprocess.CompletedProcess[str]:
> +    """
> +    Run qemu_img, returning a CompletedProcess instance.
> +
> +    The CompletedProcess object has args, returncode, and output properties.
> +    If streams are not combined, It will also have stdout/stderr properties.

s/It/it/

> +
> +    :param args: command-line arguments to qemu_img.
> +    :param check: set to False to suppress VerboseProcessError.
> +    :param combine_stdio: set to False to keep stdout/stderr separated.
> +
> +    :raise VerboseProcessError:
> +        On non-zero exit code, when 'check=True' was provided. This
> +        exception has 'stderr', 'stdout' and 'returncode' properties
> +        that may be inspected to show greater detail. If this exception
> +        is not handled, The command-line, return code, and all console

s/The/the/

> +        output will be included at the bottom of the stack trace.
> +    """

> @@ -469,8 +511,9 @@ def qemu_nbd_popen(*args):
>  
>  def compare_images(img1, img2, fmt1=imgfmt, fmt2=imgfmt):
>      '''Return True if two image files are identical'''
> -    return qemu_img('compare', '-f', fmt1,
> -                    '-F', fmt2, img1, img2) == 0
> +    res = qemu_img('compare', '-f', fmt1,
> +                   '-F', fmt2, img1, img2, check=False)
> +    return res.returncode == 0

Not sure why there was so much Mid-sentence capitalization ;)

Seems useful, although it is at the limits of my python review skills,
so this is a weak:

Reviewed-by: Eric Blake <eblake@redhat.com>

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3266
Virtualization:  qemu.org | libvirt.org

Re: [PATCH 4/4] iotests: make qemu_img raise on non-zero rc by default

[John Snow]

On Tue, Feb 15, 2022 at 6:09 PM Eric Blake <eblake@redhat.com> wrote:
>
> On Tue, Feb 15, 2022 at 05:08:53PM -0500, John Snow wrote:
> > re-configure qemu_img() into a function that will by default raise a
> > VerboseProcessException (extended from CalledProcessException) on
> > non-zero return codes. This will produce a stack trace that will show
> > the command line arguments and return code from the failed process run.
> >
> > Users that want something more flexible (There appears to be only one)
>
> s/There/there/
>
> > can use check=False and manage the return themselves.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > ---
> >  tests/qemu-iotests/257        |  8 ++++--
> >  tests/qemu-iotests/iotests.py | 53 +++++++++++++++++++++++++++++++----
> >  2 files changed, 53 insertions(+), 8 deletions(-)
> >
>
> > +def qemu_img(*args: str, check: bool = True, combine_stdio: bool = True
> > +             ) -> subprocess.CompletedProcess[str]:
> > +    """
> > +    Run qemu_img, returning a CompletedProcess instance.
> > +
> > +    The CompletedProcess object has args, returncode, and output properties.
> > +    If streams are not combined, It will also have stdout/stderr properties.
>
> s/It/it/
>
> > +
> > +    :param args: command-line arguments to qemu_img.
> > +    :param check: set to False to suppress VerboseProcessError.
> > +    :param combine_stdio: set to False to keep stdout/stderr separated.
> > +
> > +    :raise VerboseProcessError:
> > +        On non-zero exit code, when 'check=True' was provided. This
> > +        exception has 'stderr', 'stdout' and 'returncode' properties
> > +        that may be inspected to show greater detail. If this exception
> > +        is not handled, The command-line, return code, and all console
>
> s/The/the/
>
> > +        output will be included at the bottom of the stack trace.
> > +    """
>
> > @@ -469,8 +511,9 @@ def qemu_nbd_popen(*args):
> >
> >  def compare_images(img1, img2, fmt1=imgfmt, fmt2=imgfmt):
> >      '''Return True if two image files are identical'''
> > -    return qemu_img('compare', '-f', fmt1,
> > -                    '-F', fmt2, img1, img2) == 0
> > +    res = qemu_img('compare', '-f', fmt1,
> > +                   '-F', fmt2, img1, img2, check=False)
> > +    return res.returncode == 0
>
> Not sure why there was so much Mid-sentence capitalization ;)

Mostly the result of editing a few different drafts together and
failing to fix the casing. Oopsie.

>
> Seems useful, although it is at the limits of my python review skills,
> so this is a weak:
>
> Reviewed-by: Eric Blake <eblake@redhat.com>
>

Understood, thanks!

--js