From: Peter Maydell <peter.maydell@linaro.org>
To: John Snow <jsnow@redhat.com>
Cc: qemu-devel@nongnu.org, "Cédric Le Goater" <clg@kaod.org>,
"Hanna Reitz" <hreitz@redhat.com>,
"Ani Sinha" <anisinha@redhat.com>,
"Cleber Rosa" <crosa@redhat.com>,
"Wainer dos Santos Moschetta" <wainersm@redhat.com>,
qemu-arm@nongnu.org, qemu-block@nongnu.org,
"Andrew Jeffery" <andrew@aj.id.au>,
"Joel Stanley" <joel@jms.id.au>, "Kevin Wolf" <kwolf@redhat.com>,
"Philippe Mathieu-Daudé" <philmd@linaro.org>,
"Beraldo Leal" <bleal@redhat.com>,
"Daniel Berrange" <berrange@redhat.com>,
"Michael S. Tsirkin" <mst@redhat.com>
Subject: Re: [PATCH v2 0/6] python/machine: use socketpair() for console socket
Date: Thu, 27 Jul 2023 14:05:59 +0100 [thread overview]
Message-ID: <CAFEAcA8hGsXsfLECdRwe7u=DRtK6LE2twT3HaF7w_T2-SNYwgw@mail.gmail.com> (raw)
In-Reply-To: <20230725180337.2937292-1-jsnow@redhat.com>
On Tue, 25 Jul 2023 at 19:04, John Snow <jsnow@redhat.com> wrote:
>
> Like we did for the QMP socket, use socketpair() for the console socket
> so that hopefully there isn't a race condition during early boot where
> data might get dropped on the floor.
>
> May or may not help with various race conditions where early console
> output is not showing up in the logs and/or potentially being missed by
> wait_for_console_pattern.
>
This seems to improve the test I was having trouble with on s390
(machine_aarch64_sbsaref.py:Aarch64SbsarefMachine.test_sbsaref_edk2_firmware)
However it still fails sometimes, apparently we get the first line
of output from the guest but lose a couple of subsequent lines.
Here's a failing log:
2023-07-27 12:55:29,870 protocol L0481 DEBUG| Transitioning
from 'Runstate.CONNECTING' to 'Runstate.RUNNING'.
2023-07-27 12:55:29,930 __init__ L0153 DEBUG| NOTICE: Booting
Trusted Firmware
2023-07-27 12:55:29,955 __init__ L0153 DEBUG| NOTICE: BL1: Booting BL2
2023-07-27 12:55:29,955 __init__ L0153 DEBUG| NOTICE: BL2:
v2.9(release):v2.9.0-51-gc0d8ee386
2023-07-27 12:55:29,955 __init__ L0153 DEBUG| NOTICE: BL2:
Built : 16:44:16, May 30 2023
2023-07-27 12:55:30,092 __init__ L0153 DEBUG| NOTICE: BL1: Booting BL31
2023-07-27 12:55:30,092 __init__ L0153 DEBUG| NOTICE: BL31:
v2.9(release):v2.9.0-51-gc0d8ee386
2023-07-27 12:55:30,092 __init__ L0153 DEBUG| NOTICE: BL31:
Built : 16:44:16, May 30 2023
2023-07-27 12:55:30,092 __init__ L0153 DEBUG| UEFI firmware
(version 1.0 built at 17:14:57 on Mar 21 2023)
2023-07-27 12:55:45,281 __init__ L0153 DEBUG|
ESC[2JESC[04DESC[=3hESC[2JESC[09DESC[2JESC[04DESC[0mESC[30mESC[40m
2023-07-27 12:55:45,538 __init__ L0153 DEBUG|
ESC[01;01HESC[0mESC[34mESC[47m
2023-07-27 12:55:45,642 __init__ L0153 DEBUG|
ESC[01;01HESC[02;02HQEMU SBSA-REF MachineESC[03;02Harm-virtESC[44C2.00
GHzESC[04;02H1.0ESC[49C1024 MB
RAMESC[05;02HESC[52CESC[06;02HESC[52CESC[0mESC[37mESC[40mESC[21;01H
2023-07-27 12:55:45,840 __init__ L0153 DEBUG|
ESC[21;01HESC[0mESC[30mESC[40mESC[25;53H ESC[01D ESC[01D ESC[01D
ESC[01D ESC[01D ESC[01D ESC[01D ESC[01D ESC[01D ESC[01D ESC[01D
ESC[01D ESC[01D ESC[01D ESC[01D ESC[01D ESC[01D ESC[01D
ESC[01D ESC[01D ESC[0mESC[30mESC[47mESC[07;01H
2023-07-27 12:55:45,926 __init__ L0153 DEBUG| ESC[07;01H
2023-07-27 12:55:46,032 __init__ L0153 DEBUG|
ESC[0mESC[37mESC[40mESC[30C<Standard English>ESC[0mESC[30mESC[47m
ESC[57D Select Language ESC[0mESC[34mESC[47mESC[09;01H
ESC[0mESC[30mESC[47mESC[10;01H ESC[02D>ESC[01CDevice Manager
ESC[11;01H ESC[02D>ESC[01CBoot
Manager ESC[12;01H
ESC[02D>ESC[01CBoot Maintenance Manager
ESC[0mESC[34mESC[47mESC[13;01H
ESC[0mESC[30mESC[47mESC[14;01H Continue
ESC[15;01H Reset
ESC[16;01H
ESC[17;01H
ESC[18;01H
ESC[19;01H
ESC[20;01H
2023-07-27 12:55:46,067 __init__ L0153 DEBUG|
ESC[0mESC[37mESC[40mESC[23;02H ESC[22;02H ESC[50C
ESC[51D ESC[23;53H
ESC[77D^v=Move Highlight ESC[22;03H
ESC[23;27H<Enter>=Select Entry ESC[0mESC[34mESC[47mESC[08;58HThis
is the option
2023-07-27 12:55:46,076 __init__ L0153 DEBUG| ESC[57Cone
adjusts to change
2023-07-27 12:55:46,076 __init__ L0153 DEBUG| ESC[57Cthe
language for the
2023-07-27 12:55:46,080 __init__ L0153 DEBUG| ESC[57Ccurrent system
2023-07-27 12:55:46,085 __init__ L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,085 __init__ L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,087 __init__ L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,090 __init__ L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,094 __init__ L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,094 __init__ L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,100 __init__ L0153 DEBUG| ESC[57C
2023-07-27 12:55:46,101 __init__ L0153 DEBUG| ESC[57C
2023-07-27 12:58:25,379 stacktrace L0039 ERROR|
2023-07-27 12:58:25,380 stacktrace L0041 ERROR| Reproduced
traceback from:
/home/linux1/qemu/build/aarch64/tests/venv/lib/python3.8/site-packages/avocado/core/test.py:770
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| Traceback (most
recent call last):
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| File
"/home/linux1/qemu/build/aarch64/tests/venv/lib/python3.8/site-packages/avocado/core/decorators.py",
line 90, in wrapper
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| return
function(obj, *args, **kwargs)
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| File
"/home/linux1/qemu/build/aarch64/tests/avocado/machine_aarch64_sbsaref.py",
line 96, in test_sbsaref_edk2_firmware
2023-07-27 12:58:25,381 stacktrace L0045 ERROR|
wait_for_console_pattern(self, "BL1: v2.9(release):v2.9")
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| File
"/home/linux1/qemu/build/aarch64/tests/avocado/avocado_qemu/__init__.py",
line 199, in wait_for_console_pattern
2023-07-27 12:58:25,381 stacktrace L0045 ERROR|
_console_interaction(test, success_message, failure_message, None,
vm=vm)
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| File
"/home/linux1/qemu/build/aarch64/tests/avocado/avocado_qemu/__init__.py",
line 148, in _console_interaction
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| msg =
console.readline().decode().strip()
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| File
"/usr/lib/python3.8/socket.py", line 669, in readinto
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| return
self._sock.recv_into(b)
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| File
"/home/linux1/qemu/build/aarch64/tests/venv/lib/python3.8/site-packages/avocado/plugins/runner.py",
line 77, in sigterm_handler
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| raise
RuntimeError("Test interrupted by SIGTERM")
2023-07-27 12:58:25,381 stacktrace L0045 ERROR| RuntimeError:
Test interrupted by SIGTERM
Compared to the output logs for a passing run, you can see that
although we captured the first line of output from the guest
("Booting Trusted Firmware") we missed lines 2 and 3 (the
BL1 version line and the BL1 Built: line).
2023-07-27 12:54:07,676 protocol L0481 DEBUG| Transitioning
from 'Runstate.CONNECTING' to 'Runstate.RUNNING'.
2023-07-27 12:54:07,690 __init__ L0153 DEBUG| NOTICE: Booting
Trusted Firmware
2023-07-27 12:54:07,691 __init__ L0153 DEBUG| NOTICE: BL1:
v2.9(release):v2.9.0-51-gc0d8ee386
2023-07-27 12:54:07,691 __init__ L0153 DEBUG| BL1: Built :
16:44:16, May 30 2023
2023-07-27 12:54:07,754 __init__ L0153 DEBUG| NOTICE: BL1: Booting BL2
2023-07-27 12:54:07,828 __init__ L0153 DEBUG| NOTICE: BL2:
v2.9(release):v2.9.0-51-gc0d8ee386
2023-07-27 12:54:07,828 __init__ L0153 DEBUG| NOTICE: BL2:
Built : 16:44:16, May 30 2023
2023-07-27 12:54:07,855 __init__ L0153 DEBUG| NOTICE: BL1: Booting BL31
2023-07-27 12:54:07,877 __init__ L0153 DEBUG| NOTICE: BL31:
v2.9(release):v2.9.0-51-gc0d8ee386
2023-07-27 12:54:07,883 __init__ L0153 DEBUG| NOTICE: BL31:
Built : 16:44:16, May 30 2023
2023-07-27 12:54:07,891 __init__ L0153 DEBUG| UEFI firmware
(version 1.0 built at 17:14:57 on Mar 21 2023)
2023-07-27 12:54:18,354 __init__ L0153 DEBUG|
ESC[2JESC[04DESC[=3hESC[2JESC[09DESC[2JESC[04DESC[0mESC[30mESC[40m
2023-07-27 12:54:18,539 __init__ L0153 DEBUG|
ESC[01;01HESC[0mESC[34mESC[47m
2023-07-27 12:54:18,631 __init__ L0153 DEBUG|
ESC[01;01HESC[02;02HQEMU SBSA-REF MachineESC[03;02Harm-virtESC[44C2.00
GHzESC[04;02H1.0ESC[49C1024 MB
RAMESC[05;02HESC[52CESC[06;02HESC[52CESC[0mESC[37mESC[40mESC[21;01H
2023-07-27 12:54:18,639 machine L0627 DEBUG| Shutting down VM
appliance; timeout=30
2023-07-27 12:54:18,639 machine L0551 DEBUG| Attempting
graceful termination
2023-07-27 12:54:18,639 machine L0518 DEBUG| Closing console socket
2023-07-27 12:54:18,640 machine L0561 DEBUG| Politely asking
QEMU to terminate
thanks
-- PMM
prev parent reply other threads:[~2023-07-27 13:40 UTC|newest]
Thread overview: 24+ messages / expand[flat|nested] mbox.gz Atom feed top
2023-07-25 18:03 [PATCH v2 0/6] python/machine: use socketpair() for console socket John Snow
2023-07-25 18:03 ` [PATCH v2 1/6] python/machine: move socket setup out of _base_args property John Snow
2023-07-25 18:16 ` Daniel P. Berrangé
2023-07-26 7:10 ` Ani Sinha
2023-07-25 18:03 ` [PATCH v2 2/6] python/machine: close sock_pair in cleanup path John Snow
2023-07-25 18:18 ` Daniel P. Berrangé
2023-07-26 7:23 ` Ani Sinha
2023-07-25 18:03 ` [PATCH v2 3/6] python/console_socket: accept existing FD in initializer John Snow
2023-07-25 18:19 ` Daniel P. Berrangé
2023-07-27 5:41 ` Ani Sinha
2023-07-25 18:03 ` [PATCH v2 4/6] python/machine: use socketpair() for console connections John Snow
2023-07-25 18:21 ` Daniel P. Berrangé
2023-07-26 10:50 ` Ani Sinha
2023-07-26 17:21 ` John Snow
2023-07-27 5:52 ` Ani Sinha
2023-07-27 6:49 ` Ani Sinha
2023-07-27 10:41 ` Daniel P. Berrangé
2023-07-25 18:03 ` [PATCH v2 5/6] python/machine: use socketpair() for qtest connection John Snow
2023-07-25 18:24 ` Daniel P. Berrangé
2023-07-25 18:03 ` [PATCH v2 6/6] python/machine: remove unused sock_dir argument John Snow
2023-07-25 18:26 ` Daniel P. Berrangé
2023-07-25 18:33 ` John Snow
2023-07-25 18:36 ` Daniel P. Berrangé
2023-07-27 13:05 ` Peter Maydell [this message]
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to='CAFEAcA8hGsXsfLECdRwe7u=DRtK6LE2twT3HaF7w_T2-SNYwgw@mail.gmail.com' \
--to=peter.maydell@linaro.org \
--cc=andrew@aj.id.au \
--cc=anisinha@redhat.com \
--cc=berrange@redhat.com \
--cc=bleal@redhat.com \
--cc=clg@kaod.org \
--cc=crosa@redhat.com \
--cc=hreitz@redhat.com \
--cc=joel@jms.id.au \
--cc=jsnow@redhat.com \
--cc=kwolf@redhat.com \
--cc=mst@redhat.com \
--cc=philmd@linaro.org \
--cc=qemu-arm@nongnu.org \
--cc=qemu-block@nongnu.org \
--cc=qemu-devel@nongnu.org \
--cc=wainersm@redhat.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).