| Message ID | 20241112130246.970281-2-clg@redhat.com (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | tests/functional: Finish conversion of Aspeed tests | expand |
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('
> Maybe we could use some funky unicode character instead? For example: > > console_logger.debug('
On 12/11/2024 14.52, Cédric Le Goater wrote: >> Maybe we could use some funky unicode character instead? For example: >> >> console_logger.debug('
On Tue, Nov 12, 2024 at 02:02:43PM +0100, 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") Decoding this as 'latin1' is going to mangle any output that is not represented by a single-byte UTF-8 codepoint. You can't simply switch this to 'utf8' though, as in the socket.recv(1) call you're only reading a single byte, and you can't guarantee that can be decoded if its part of a multi-byte sequence. I think you need to read into a bytearray, instead of reading into a string. Then convert 'expect' into a bytearray too, and compare bytes for a match, thus avoiding problem of partial utf8 sequence decoding errors. > + 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 In the commit message you talk about a problem with non-matched text, and timeouts causing failure. IIUC, the key difference between this code and the use of readline() is that this code is checking for a match in the partial line. ie we don't need to wait for a newline to arrive anymore. That's an interesting difference, but its not obviously correlated with the commit message description. > + > 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) > if success_message is None or success_message in msg: > break > if failure_message and failure_message in msg: > -- > 2.47.0 > > With regards, Daniel
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) if success_message is None or success_message in msg: break if failure_message and failure_message in msg:
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(-)