Re: [PATCH] tests/functional: add --debug CLI arg

["Daniel P. Berrangé" <berrange@redhat.com>]

On Wed, Jul 16, 2025 at 09:08:00AM +0300, Manos Pitsidianakis wrote:
> Add argument parsing to functional tests to improve developer experience
> when running individual tests. All logs are printed to stdout
> interspersed with TAP output.
> 
>   ./pyvenv/bin/python3 ../tests/functional/test_aarch64_virt.py --help
>   usage: test_aarch64_virt [-h] [-d]
> 
>   QEMU Functional test
> 
>   options:
>     -h, --help   show this help message and exit
>     -d, --debug  Also print test and console logs on stdout. This will
>                  make the TAP output invalid and is meant for debugging
>                  only.
> 
> Signed-off-by: Manos Pitsidianakis <manos.pitsidianakis@linaro.org>
> ---
>  docs/devel/testing/functional.rst      |  2 ++
>  tests/functional/qemu_test/testcase.py | 51 ++++++++++++++++++++++++++++++++--
>  2 files changed, 50 insertions(+), 3 deletions(-)
> 
> diff --git a/docs/devel/testing/functional.rst b/docs/devel/testing/functional.rst
> index 9e56dd1b1189216b9b4aede00174c15203f38b41..9d08abe2848277d635befb0296f578cfaa4bd66d 100644
> --- a/docs/devel/testing/functional.rst
> +++ b/docs/devel/testing/functional.rst
> @@ -63,6 +63,8 @@ directory should be your build folder. For example::
>    $ export QEMU_TEST_QEMU_BINARY=$PWD/qemu-system-x86_64
>    $ pyvenv/bin/python3 ../tests/functional/test_file.py
>  
> +By default, functional tests redirect informational logs and console output to
> +log files. Specify the ``--debug`` flag to also print those to standard output.
>  The test framework will automatically purge any scratch files created during
>  the tests. If needing to debug a failed test, it is possible to keep these
>  files around on disk by setting ```QEMU_TEST_KEEP_SCRATCH=1``` as an env
> diff --git a/tests/functional/qemu_test/testcase.py b/tests/functional/qemu_test/testcase.py
> index 2082c6fce43b0544d4e4258cd4155f555ed30cd4..fad7a946c6677e9ef5c42b8f77187ba836c11aeb 100644
> --- a/tests/functional/qemu_test/testcase.py
> +++ b/tests/functional/qemu_test/testcase.py
> @@ -11,6 +11,7 @@
>  # This work is licensed under the terms of the GNU GPL, version 2 or
>  # later.  See the COPYING file in the top-level directory.
>  
> +import argparse
>  import logging
>  import os
>  from pathlib import Path
> @@ -31,6 +32,20 @@
>  from .uncompress import uncompress
>  
>  
> +def parse_args(test_name: str) -> argparse.Namespace:
> +    parser = argparse.ArgumentParser(
> +        prog=test_name, description="QEMU Functional test"
> +    )
> +    parser.add_argument(
> +        "-d",
> +        "--debug",
> +        action="store_true",
> +        help="Also print test and console logs on stdout. This will make the"
> +        " TAP output invalid and is meant for debugging only.",
> +    )
> +    return parser.parse_args()
> +
> +
>  class QemuBaseTest(unittest.TestCase):
>  
>      '''
> @@ -196,6 +211,9 @@ def assets_available(self):
>          return True
>  
>      def setUp(self):
> +        path = os.path.basename(sys.argv[0])[:-3]
> +        args = parse_args(path)

IMHO this is not code that belongs in setUp. Indeed, I don't think
it belongs in this file at all, better have a helper for parsing
args in 'utils', and expose a global 'debug_enabled' flag from utils
that we can reference elsewhere.

> +        self.debug_output = args.debug
>          self.qemu_bin = os.getenv('QEMU_TEST_QEMU_BINARY')
>          self.assertIsNotNone(self.qemu_bin, 'QEMU_TEST_QEMU_BINARY must be set')
>          self.arch = self.qemu_bin.split('-')[-1]
> @@ -221,6 +239,16 @@ def setUp(self):
>          self.machinelog.setLevel(logging.DEBUG)
>          self.machinelog.addHandler(self._log_fh)
>  
> +        if self.debug_output:
> +            handler = logging.StreamHandler(sys.stdout)
> +            handler.setLevel(logging.DEBUG)
> +            formatter = logging.Formatter(
> +                "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
> +            )
> +            handler.setFormatter(formatter)
> +            self.log.addHandler(handler)
> +            self.machinelog.addHandler(handler)

There was already a lot of effectively duplicated code between
this and the console_log stuff below. This new addition makes
that duplication even more substantial, such that I think it
all needs to be spun out into a helper method.

> +
>          if not self.assets_available():
>              self.skipTest('One or more assets is not available')
>  
> @@ -230,11 +258,16 @@ def tearDown(self):
>          if self.socketdir is not None:
>              shutil.rmtree(self.socketdir.name)
>              self.socketdir = None
> -        self.machinelog.removeHandler(self._log_fh)
> -        self.log.removeHandler(self._log_fh)
> +        for handler in [self._log_fh, logging.StreamHandler(sys.stdout)]:

We should have stashed the original handler when created,
rather than re-creating StreamHandler at time of removal.
I'm kinda of surprised it even works to re-create it.

> +            self.machinelog.removeHandler(handler)
> +            self.log.removeHandler(handler)
>  
>      def main():
>          path = os.path.basename(sys.argv[0])[:-3]
> +        # If argparse receives --help or an unknown argument, it will raise a
> +        # SystemExit which will get caught by the test runner. Parse the
> +        # arguments here too to handle that case.
> +        _ = parse_args(path)
>  
>          cache = os.environ.get("QEMU_TEST_PRECACHE", None)
>          if cache is not None:
> @@ -292,6 +325,14 @@ def setUp(self):
>          fileFormatter = logging.Formatter('%(asctime)s: %(message)s')
>          self._console_log_fh.setFormatter(fileFormatter)
>          console_log.addHandler(self._console_log_fh)
> +        if self.debug_output:
> +            handler = logging.StreamHandler(sys.stdout)
> +            handler.setLevel(logging.DEBUG)
> +            formatter = logging.Formatter(
> +                "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
> +            )
> +            handler.setFormatter(formatter)
> +            console_log.addHandler(handler)
>  
>      def set_machine(self, machinename):
>          # TODO: We should use QMP to get the list of available machines
> @@ -398,5 +439,9 @@ def set_vm_arg(self, arg, value):
>      def tearDown(self):
>          for vm in self._vms.values():
>              vm.shutdown()
> -        logging.getLogger('console').removeHandler(self._console_log_fh)
> +        for handler in [
> +            self._console_log_fh,
> +            logging.StreamHandler(sys.stdout),
> +        ]:
> +            logging.getLogger("console").removeHandler(handler)
>          super().tearDown()
> 
> ---
> base-commit: c079d3a31e45093286c65f8ca5350beb3a4404a9
> change-id: 20250716-functional_tests_debug_arg-aa0a5f6b9375
> 
> --
> γαῖα πυρί μιχθήτω
> 

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