Re: [PATCH v3 2/5] python/utils: add VerboseProcessError

[John Snow]

On Thu, Mar 17, 2022 at 5:23 AM Hanna Reitz <hreitz@redhat.com> wrote:
>
> On 08.03.22 02:57, John Snow wrote:
> > This adds an Exception that extends the Python stdlib
> > subprocess.CalledProcessError.
> >
> > 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 visually distinct wrapper to the terminal so
> > that it's easy to spot in a sea of traceback information.
> >
> > Signed-off-by: John Snow <jsnow@redhat.com>
> > Reviewed-by: Eric Blake <eblake@redhat.com>
> > ---
> >   python/qemu/utils/__init__.py | 36 +++++++++++++++++++++++++++++++++++
> >   1 file changed, 36 insertions(+)
> >
> > diff --git a/python/qemu/utils/__init__.py b/python/qemu/utils/__init__.py
> > index 5babf40df2..355ac550bc 100644
> > --- a/python/qemu/utils/__init__.py
> > +++ b/python/qemu/utils/__init__.py
> > @@ -18,6 +18,7 @@
> >   import os
> >   import re
> >   import shutil
> > +from subprocess import CalledProcessError
> >   import textwrap
> >   from typing import Optional
> >
> > @@ -26,6 +27,7 @@
> >
> >
> >   __all__ = (
> > +    'VerboseProcessError',
> >       'add_visual_margin',
> >       'get_info_usernet_hostfwd_port',
> >       'kvm_available',
> > @@ -121,3 +123,37 @@ def _wrap(line: str) -> str:
> >           os.linesep.join(_wrap(line) for line in content.splitlines()),
> >           _bar(None, top=False),
> >       ))
> > +
> > +
> > +class VerboseProcessError(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 the normal CalledProcessError str() output."""
> > +        return super().__str__()
> > +
> > +    def __str__(self) -> str:
> > +        lmargin = '  '
> > +        width = -len(lmargin)
> > +        sections = []
> > +
> > +        name = 'output' if self.stderr is None else 'stdout'
> > +        if self.stdout:
> > +            sections.append(add_visual_margin(self.stdout, width, name))
> > +        else:
> > +            sections.append(f"{name}: N/A")
> > +
> > +        if self.stderr:
> > +            sections.append(add_visual_margin(self.stderr, width, 
> > 'stderr'))
> > +        elif self.stderr is not None:
>
> What exactly is this condition for?  I would’ve understood if it was
> `self.stdout` (because the stdout section then is called just “output”,
> so it would make sense to omit the stderr block), but this way it looks
> like we’ll only go here if `self.stderr` is an empty string (which
> doesn’t make much sense to me, and I don’t understand why we wouldn’t
> have the same in the `self.stdout` part above).
>
> (tl;dr: should this be `self.stdout`?)
>
> Hanna
>

if self.stderr is None, it means that the IO streams were combined. If
it is merely empty, it means there wasn't any stderr output.

so:

if self.stderr: There's content here, so put it in a lil' box
else: could be either None or the empty string. If it's None, we
didn't *have* a stderr, so don't print anything at all, let the
"output" section above handle it. If we did have stderr and it just
happened to be empty, write N/A.

I wanted that "N/A" to provide active feedback to show the human
operator that we're not just failing to show them what the stderr
output was: there genuinely wasn't any.

> > +            sections.append("stderr: N/A")
> > +
> > +        return os.linesep.join((
> > +            self.summary(),
> > +            textwrap.indent(os.linesep.join(sections), prefix=lmargin),
> > +        ))
>