Re: avocado test: log shows initial chunk of terminal output is missing

[Daniel P . Berrangé]

On Mon, Jul 17, 2023 at 04:42:30PM +0100, Peter Maydell wrote:
> I'm looking at an avocado test that's failing intermittently
> on s390 host:
> machine_aarch64_sbsaref.py:Aarch64SbsarefMachine.test_sbsaref_edk2_firmware
> 
> This test looks for various things on the terminal output,
> and it's failing because it hasn't seen the first thing it looks
> for. The avocado log seems to show that the guest has booted
> past that point and has produced a later chunk of the output,
> and avocado appears to have simply lost the earlier output that
> the test case is trying to match on.

Having had a quick look at the test code the test is calling
wait_for_console_pattern() to match console output. This
method calls _console_interaction(), which accesses the property
vm.console_socket. The code in this method does a lazy create
of the socket:

    @property
    def console_socket(self) -> socket.socket:
        """
        Returns a socket connected to the console
        """
        if self._console_socket is None:
            self._console_socket = console_socket.ConsoleSocket(
                self._console_address,
                file=self._console_log_path,
                drain=self._drain_console)
        return self._console_socket

We're configuring the VM with a UNIX socket for the console. Even
if we moved the console_socket.ConsoleSocket() call directly into
the 'launch()' method this would still be inherantly racy.

The solution is the same as we prviously did for the QMP socket.
the QEMUMachine class needs to pre-create the UNIX socket and
pass the pre-opened FD into QEMU, which will guarantee no race
condition.

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 :|