Re: [PATCH] tests/functional: fix race in virtio balloon test

[Thomas Huth <thuth@redhat.com>]

On 06/03/2025 18.42, Thomas Huth wrote:
> On 05/03/2025 13.25, Philippe Mathieu-Daudé wrote:
>> Hi Daniel,
>>
>> On 4/3/25 19:33, Daniel P. Berrangé wrote:
>>> There are two race conditions in the recently added virtio balloon
>>> test
>>>
>>>   * The /dev/vda device node is not ready
>>>   * The virtio-balloon driver has not issued the first stats refresh
>>>
>>> To fix the former, monitor dmesg for a line about 'vda'.
>>>
>>> To fix the latter, retry the stats query until seeing fresh data.
>>>
>>> Adding 'quiet' to the kernel command line reduces serial output
>>> which otherwise slows boot, making it less likely to hit the former
>>> race too.
>>>
>>> Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
>>> ---
>>>   tests/functional/test_virtio_balloon.py | 24 +++++++++++++++++++-----
>>>   1 file changed, 19 insertions(+), 5 deletions(-)
>>>
>>> diff --git a/tests/functional/test_virtio_balloon.py b/tests/functional/ 
>>> test_virtio_balloon.py
>>> index 67b48e1b4e..308d197eb3 100755
>>> --- a/tests/functional/test_virtio_balloon.py
>>> +++ b/tests/functional/test_virtio_balloon.py
>>> @@ -32,7 +32,7 @@ class VirtioBalloonx86(QemuSystemTest):
>>>           
>>> 'e3c1b309d9203604922d6e255c2c5d098a309c2d46215d8fc026954f3c5c27a0')
>>>       DEFAULT_KERNEL_PARAMS = ('root=/dev/vda1 console=ttyS0 net.ifnames=0 '
>>> -                             'rd.rescue')
>>> +                             'rd.rescue quiet')
>>>       def wait_for_console_pattern(self, success_message, vm=None):
>>>           wait_for_console_pattern(
>>> @@ -47,6 +47,9 @@ def mount_root(self):
>>>           prompt = '# '
>>>           self.wait_for_console_pattern(prompt)
>>> +        # Synchronize on virtio-block driver creating the root device
>>> +        exec_command_and_wait_for_pattern(self, "while ! (dmesg -c | 
>>> grep vda:) ; do sleep 1 ; done", "vda1")
>>> +
>>>           exec_command_and_wait_for_pattern(self, 'mount /dev/vda1 / 
>>> sysroot',
>>>                                             prompt)
>>>           exec_command_and_wait_for_pattern(self, 'chroot /sysroot',
>>> @@ -65,10 +68,21 @@ def assert_initial_stats(self):
>>>               assert val == UNSET_STATS_VALUE
>>>       def assert_running_stats(self, then):
>>> -        ret = self.vm.qmp('qom-get',
>>> -                          {'path': '/machine/peripheral/balloon',
>>> -                           'property': 'guest-stats'})['return']
>>> -        when = ret.get('last-update')
>>> +        # We told the QEMU to refresh stats every 100ms, but
>>> +        # there can be a delay between virtio-ballon driver
>>> +        # being modprobed and seeing the first stats refresh
>>> +        # Retry a few times for robustness under heavy load
>>> +        retries = 10
>>> +        when = 0
>>> +        while when == 0 and retries:
>>> +            ret = self.vm.qmp('qom-get',
>>> +                              {'path': '/machine/peripheral/balloon',
>>> +                               'property': 'guest-stats'})['return']
>>> +            when = ret.get('last-update')
>>> +            if when == 0:
>>> +                retries = retries - 1
>>> +                time.sleep(0.5)
>>> +
>>>           now = time.time()
>>>           assert when > then and when < now
>>
>> Unfortunately I'm still getting a timeout:
>> https://gitlab.com/philmd/qemu/-/jobs/9318095233
>>
>> 2025-03-05 12:09:55,360 - DEBUG: Console interaction: 
>> success_msg='Entering emergency mode.' failure_msg='Kernel panic - not 
>> syncing' send_string='None'
>> 2025-03-05 12:09:55,360 - DEBUG: Opening console socket
>> 2025-03-05 12:10:32,722 - DEBUG: Console interaction: success_msg='# ' 
>> failure_msg='Kernel panic - not syncing' send_string='None'
>> 2025-03-05 12:10:32,823 - DEBUG: Console interaction: success_msg='vda1' 
>> failure_msg='None' send_string='while ! (dmesg -c | grep vda:) ; do sleep 
>> 1 ; done
>>
>> 2025-03-05 12:10:30,534: Warning: /dev/vda1 does not exist
>> 2025-03-05 12:10:30,535:
>> 2025-03-05 12:10:30,598: Generating "/run/initramfs/rdsosreport.txt"
>> 2025-03-05 12:10:32,720:
>> 2025-03-05 12:10:32,721:
>> 2025-03-05 12:10:32,722: Entering emergency mode.
>> 2025-03-05 12:10:32,724: Exit the shell to continue.
>> 2025-03-05 12:10:32,726: Type "journalctl" to view system logs.
>> 2025-03-05 12:10:32,727: You might want to save "/run/initramfs/ 
>> rdsosreport.txt" to a USB stick or /boot
>> 2025-03-05 12:10:32,728: after mounting them and attach it to a bug report.
>> 2025-03-05 12:10:32,729:
>> 2025-03-05 12:10:32,731:
>> 2025-03-05 12:10:32,823: :/#
> 
> Same for me, it always seems to hang when being run with the gitlab shared 
> runners:
> 
>   https://gitlab.com/thuth/qemu/-/jobs/9333926038#L612
>   https://gitlab.com/thuth/qemu/-/jobs/9333926046#L625
> 
> ... no clue what's still going wrong, though ...

... but I just noticed that all other functional tests that use the same 
assets are using:

         self.require_accelerator('kvm')
         self.vm.add_args('-accel', 'kvm')

so they are skipped on the gitlab shared runners (but still executed in the 
custom runners of the qemu-project), while your test also is enabled for TCG 
and thus runs in the shared runners, too.
So unless you've got a clue what's going wrong here (I fail to see the 
reason for the problem unfortunately), I'd suggest that we mark the 
virtio_balloon test with require_accelerator('kvm'), too, to get the CI 
working with the shared runners again. WDYT?

  Thomas