Re: [PATCH v2 1/4] tests/functional: Introduce _console_read()

[Thomas Huth <thuth@redhat.com>]

On 12/11/2024 14.02, Cédric Le Goater wrote:
> Interaction with the console has been a problem in our avocado
> tests. In some cases, the expected string does not match in the
> output, causing the test to fail with a timeout. These were worked
> around by sleeping before reading the console and even with SSH
> connections in some places.
> 
> To fix, process the console output char by char and not with
> readline. This routine was largely inspired by console_wait() in
> tests/vm/basevm.py.
> 
> Signed-off-by: Cédric Le Goater <clg@redhat.com>
> ---
>   tests/functional/qemu_test/cmd.py | 22 ++++++++++++++++++++--
>   1 file changed, 20 insertions(+), 2 deletions(-)
> 
> diff --git a/tests/functional/qemu_test/cmd.py b/tests/functional/qemu_test/cmd.py
> index cbabb1ceed3c..5bca29d1d721 100644
> --- a/tests/functional/qemu_test/cmd.py
> +++ b/tests/functional/qemu_test/cmd.py
> @@ -12,6 +12,7 @@
>   # later.  See the COPYING file in the top-level directory.
>   
>   import logging
> +import re
>   import os
>   import os.path
>   import subprocess
> @@ -78,6 +79,23 @@ def run_cmd(args):
>   def is_readable_executable_file(path):
>       return os.path.isfile(path) and os.access(path, os.R_OK | os.X_OK)
>   
> +def _console_read(vm, expect):
> +    console_logger = logging.getLogger('console')
> +    output = ""
> +    while True:
> +        data = vm.console_socket.recv(1)
> +        if not data:
> +            break
> +        output += data.decode("latin1")
> +        if expect in output:
> +            break
> +        if "\r" in output or "\n" in output:
> +            lines = re.split("[\r\n]", output)
> +            if lines[0]:
> +                console_logger.debug(lines[0])
> +            output = lines.pop()
> +    return output
> +
>   def _console_interaction(test, success_message, failure_message,
>                            send_string, keep_sending=False, vm=None):
>       assert not keep_sending or send_string
> @@ -98,12 +116,12 @@ def _console_interaction(test, success_message, failure_message,
>               continue
>   
>           try:
> -            msg = console.readline().decode().strip()
> +            msg = _console_read(vm, success_message)
>           except UnicodeDecodeError:
>               msg = None
>           if not msg:
>               continue
> -        console_logger.debug(msg)
> +        console_logger.debug('found "%s"', msg)

Sorry for being picky (yay, bike shed painting!), but it's a little bit hard 
to distinguish these "found" markers in the console.log from the lines that 
just contain the normal output.

Maybe we could use some funky unicode character instead? For example:

         console_logger.debug('🔎 %s', msg)

or:

         console_logger.debug('✅ %s', msg)

?

Or maybe just indent the normal lines, i.e. in the _console_read() function
you could do this instead:

        console_logger.debug('      %s', lines[0])

so that the "found" string is more visually separated?

Or maybe even combine the two approaches?

  Thanks,
   Thomas