Re: biosbits test failing on origin/master

[Ani Sinha]

On Fri, Nov 11, 2022 at 9:52 AM Ani Sinha <ani@anisinha.ca> wrote:
>
> On Thu, Nov 10, 2022 at 11:37 PM John Snow <jsnow@redhat.com> wrote:
> >
> > Hiya, on today's origin/master
> > (2ccad61746ca7de5dd3e25146062264387e43bd4) I'm finding that "make
> > check-avocado" is failing on the new biosbits test on my local
> > development machine:
> >
> >  (001/193) tests/avocado/acpi-bits.py:AcpiBitsTest.test_acpi_smbios_bits:
> > FAIL: True is not false : The VM seems to have failed to shutdown in
> > time (83.65 s)
> >
> > Is this a known issue, or should I begin to investigate it?
>
> In my test environment it does pass.
>
> $ ./tests/venv/bin/avocado run -t acpi tests/avocado
> Fetching asset from
> tests/avocado/acpi-bits.py:AcpiBitsTest.test_acpi_smbios_bits
> JOB ID     : 35726df7d3c2e0f41847822620c78195ba45b9b9
> JOB LOG    : 
> /home/anisinha/avocado/job-results/job-2022-11-11T09.42-35726df/job.log
>  (1/1) tests/avocado/acpi-bits.py:AcpiBitsTest.test_acpi_smbios_bits:
> PASS (57.57 s)
> RESULTS    : PASS 1 | ERROR 0 | FAIL 0 | SKIP 0 | WARN 0 | INTERRUPT 0
> | CANCEL 0
> JOB TIME   : 63.82 s
>
> However, I have seen that on certain slower test machines or when run
> within a virtual machine, the test can take longer to complete and 60
> secs may not always be enough.

Here is an interesting data point. I re-ran on a Centos 8 VM running
on Ubuntu bare metal. Just like the Ubuntu bare metal, it passed fine.
Next, I tried to run it on a Centos 7.9.2009 VM running on the same
Ubuntu bare metal. I was able to reproduce this consistently. So I did
some digging, gdb into qemu and it looked like the VM was just slow
but not stuck. So I timed the QEMU command line that was being used in
the test using the same iso that was being generated by the test. Here
it is:

# time ./qemu-system-x86_64 -display none -vga none -chardev
file,path=/var/tmp/debugcon-log.txt,id=debugcon -device
isa-debugcon,iobase=0x403,chardev=debugcon -cdrom
/var/tmp/acpi-bits-oogd8wp9.tmp/bits-2020.iso

real 2m34.052s
user 2m33.858s
sys 0m0.467s

On bare metal Ubuntu, I see this:

$ time ./qemu-system-x86_64 -display none -vga none -chardev
file,path=/var/tmp/debugcon-log.txt,id=debugcon -device
isa-debugcon,iobase=0x403,chardev=debugcon -cdrom ~/temp/bits-2020.iso

real 1m15.318s
user 1m15.136s
sys 0m0.345s

With "-icount auto" added in the command line,  both bare metal and VM
environments were slower. However, we need this command line for some
latency tests.

avocado framework has a 2 min timeout for any test. This would
definitely time out even without my internal timeout check. I verified
that the test indeed passed by looking into the debug con logs pushed
out by the test framework. If the system is just slow/overloaded I am
not sure what we can do.

In those cases raising the maximum
> completion time to 90 secs helps. Perhaps you can try this and let me
> know if it helps:

Maybe I will make the timeout 90 secs and hope that this will be enough.

>
> diff --git a/tests/avocado/acpi-bits.py b/tests/avocado/acpi-bits.py
> index 8745a58a76..b11fe39350 100644
> --- a/tests/avocado/acpi-bits.py
> +++ b/tests/avocado/acpi-bits.py
> @@ -385,8 +385,9 @@ def test_acpi_smbios_bits(self):
>          self._vm.launch()
>          # biosbits has been configured to run all the specified test suites
>          # in batch mode and then automatically initiate a vm shutdown.
> -        # sleep for maximum of one minute
> -        max_sleep_time = time.monotonic() + 60
> +        # sleep for a maximum of one and half minutes to accommodate
> running this
> +        # even on slower machines.
> +        max_sleep_time = time.monotonic() + 90
>          while self._vm.is_running() and time.monotonic() < max_sleep_time:
>              time.sleep(1)