Re: [Qemu-devel] [PATCH v2 2/6] tests/acceptance: Test Open Firmware on the PReP/40p

[Philippe Mathieu-Daudé]

On 9/17/19 11:42 AM, Artyom Tarasenko wrote:
> On Tue, Sep 17, 2019 at 11:33 AM Alex Bennée <address@hidden> wrote:
>> Cleber Rosa <address@hidden> writes:
>>> On Mon, Sep 16, 2019 at 01:59:22PM -0400, Cleber Rosa wrote:
>>>> On Sun, Sep 15, 2019 at 11:19:36PM +0200, Philippe Mathieu-Daudé wrote:
>>>>> User case from:
>>>>> https://tyom.blogspot.com/2019/04/aixprep-under-qemu-how-to.html
>>>>>
>>>>> Signed-off-by: Philippe Mathieu-Daudé <address@hidden>
>>>>> ---
>>>>>  tests/acceptance/ppc_prep_40p.py | 21 +++++++++++++++++++++
>>>>>  1 file changed, 21 insertions(+)
>>>>>
>>>>> diff --git a/tests/acceptance/ppc_prep_40p.py 
>>>>> b/tests/acceptance/ppc_prep_40p.py
>>>>> index 53f2d2ecf0..a0eac40d9f 100644
>>>>> --- a/tests/acceptance/ppc_prep_40p.py
>>>>> +++ b/tests/acceptance/ppc_prep_40p.py
>>>>> @@ -61,3 +61,24 @@ class IbmPrep40pMachine(Test):
>>>>>          os_banner = 'NetBSD 4.0 (GENERIC) #0: Sun Dec 16 00:49:40 PST 
>>>>> 2007'
>>>>>          self.wait_for_console_pattern(os_banner)
>>>>>          self.wait_for_console_pattern('Model: IBM PPS Model 6015')
>>>>> +
>>>>> +    def test_openfirmware(self):
>>>>> +        """
>>>>> +        :avocado: tags=arch:ppc
>>>>> +        :avocado: tags=machine:40p
>>>>> +        """
>>>>> +        bios_url = ('https://github.com/artyom-tarasenko/openfirmware/'
>>>>> +                    'releases/download/40p-20190413/q40pofw-serial.rom')
>>>>> +        bios_hash = '880c80172ea5b2247c0ac2a8bf36bbe385192c72'
>>>>> +        bios_path = self.fetch_asset(bios_url, asset_hash=bios_hash)
>>>>> +
>>>>> +        self.vm.set_machine('40p')
>>>>> +        self.vm.set_console()
>>>>> +        self.vm.add_args('-bios', bios_path)
>>>>> +
>>>>> +        self.vm.launch()
>>>>> +        self.wait_for_console_pattern('QEMU PReP/40p')
>>>>> +        fw_banner = 'Open Firmware, built  April 13, 2019 09:29:23'
>>>>> +        self.wait_for_console_pattern(fw_banner)
>>>>> +        prompt_msg = 'Type any key to interrupt automatic startup'
>>>>> +        self.wait_for_console_pattern(prompt_msg)
>>>>> --
>>>>> 2.20.1
>>>>>
>>>>
>>>> Tested-by: Cleber Rosa <address@hidden>
>>>> Reviewed-by: Cleber Rosa <address@hidden>
>>>
>>> Actually, I'm seeing random but consistent failures.  I've tracked
>>> it down to the 'Open Firmware, built  April 13, 2019 09:29:23'.  Out
>>> of 100 executions I got 27 failures, with that line logged as:
>>>
>>>   2019-09-16 14:44:54,540 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:45:00,762 ppc_prep_40p     L0033 DEBUG| n Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:45:06,575 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:45:12,859 ppc_prep_40p     L0033 DEBUG| n Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:45:18,707 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:45:21,876 ppc_prep_40p     L0033 DEBUG| en Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:45:28,054 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:45:31,163 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:45:34,291 ppc_prep_40p     L0033 DEBUG| en Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:45:57,719 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:46:03,610 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:46:06,795 ppc_prep_40p     L0033 DEBUG| n Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:46:17,087 ppc_prep_40p     L0033 DEBUG| n Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:46:21,534 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:46:24,694 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:46:38,076 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:46:49,863 ppc_prep_40p     L0033 DEBUG| n Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:46:54,435 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:47:00,672 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:47:03,834 ppc_prep_40p     L0033 DEBUG| n Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:47:06,852 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:47:14,276 ppc_prep_40p     L0033 DEBUG| n Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:47:17,380 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:47:34,749 ppc_prep_40p     L0033 DEBUG| n Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:47:39,217 ppc_prep_40p     L0033 DEBUG| n Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:47:43,750 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>   2019-09-16 14:48:04,003 ppc_prep_40p     L0033 DEBUG| Firmware, built  
>>> April 13, 2019 09:29:23
>>>
>>> Given that we're not seeing this behavior in other target/marchine
>>> tests, my first impression is that this is what's being produced
>>> by QEMU, and not what's being badly captured by the Avocado and/or
>>> the test code.
>>
>> Is the DEBUG line meant to show everything that avocado saw? I guess we
>> could have a bug in the serial port emulation causing characters to be
>> dropped?
> 
> FWIW back in April I launched QEMU really a lot and never saw a broken banner.
> Either it's Avocado, or a regression. Is it possible to see the
> complete serial log?

I never saw this either.

Around that time (April) we had some problem with VM/Avocado using
chardev devices with Python, Cleber/Alex do you know if this is now fixed?

Meanwhile I'll investigate Cleber's failure (what are your ./configure
options and Avocado version used?)

Thanks,

Phil.