Re: [PATCH v2 02/12] tests/avocado: improve behaviour waiting for login prompts

[Philippe Mathieu-Daudé]

On 14/11/22 17:28, Peter Maydell wrote:
> On Fri, 11 Nov 2022 at 14:58, Alex Bennée <alex.bennee@linaro.org> wrote:
> > This attempts to deal with the problem of login prompts not being
> > guaranteed to be terminated with a newline. The solution to this is to
> > peek at the incoming data looking to see if we see an up-coming match
> > before we fall back to the old readline() logic. The reason to mostly
> > rely on readline is because I am occasionally seeing the peek stalling
> > despite data being there.
> >
> > This seems kinda hacky and gross so I'm open to alternative approaches
> > and cleaner python code.
> >
> > Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
> > Reviewed-by: Philippe Mathieu-Daudé <philmd@linaro.org>
>
> With this patch, the evb_sdk test fails:
>
> Fetching asset from
> ./build/arm-clang/tests/avocado/machine_aspeed.py:AST2x00MachineSDK.test_arm_ast2500_evb_sdk
> JOB ID     : 542e050c4f7e1ddd6d5cdd350e4c26e1bdfcdee4
> JOB LOG    : 
> /home/petmay01/avocado/job-results/job-2022-11-14T16.21-542e050/job.log
>   (1/1) 
> ./build/arm-clang/tests/avocado/machine_aspeed.py:AST2x00MachineSDK.test_arm_ast2500_evb_sdk:
> ERROR: log() missing 1 required positional argument: 'msg' (82.57 s)
> RESULTS    : PASS 0 | ERROR 1 | FAIL 0 | SKIP 0 | WARN 0 | INTERRUPT 0
> | CANCEL 0
> JOB TIME   : 84.09 s
>
> The avocado log reports a traceback where Python has thrown a
> UnicodeDecodeError, and then subsequently an attempted debug
> message in the error-handling path has a syntax error
> ("log() missing 1 required positional argument"):

> _console_interaction(test, success_message, failure_message, None,
> vm=vm)
> 2022-11-14 16:22:48,573 stacktrace       L0045 ERROR|   File
> "/mnt/nvmedisk/linaro/qemu-from-laptop/qemu/build/arm-clang/tests/avocad
> o/avocado_qemu/__init__.py", line 226, in _console_interaction
> 2022-11-14 16:22:48,573 stacktrace       L0045 ERROR|     msg =
> _peek_ahead(console, min_match, success_message)
> 2022-11-14 16:22:48,573 stacktrace       L0045 ERROR|   File
> "/mnt/nvmedisk/linaro/qemu-from-laptop/qemu/build/arm-clang/tests/avocad
> o/avocado_qemu/__init__.py", line 180, in _peek_ahead
> 2022-11-14 16:22:48,573 stacktrace       L0045 ERROR|
> console_logger.log("error in decode of peek")
> 2022-11-14 16:22:48,573 stacktrace       L0045 ERROR| TypeError: log()
> missing 1 required positional argument: 'msg'

Indeed, log() expects a Level as first argument. Here we simply want to
report the exception as a warning and continue:

-- >8 --
         except UnicodeDecodeError:
-            console_logger.log("error in decode of peek")
+            console_logger.warning("error in decode of peek")
             return None
---