On Fri, Nov 11, 2022 at 4:39 PM Ani Sinha <a...@anisinha.ca> wrote: > > On Fri, Nov 11, 2022 at 9:52 AM Ani Sinha <a...@anisinha.ca> wrote: > > > > On Thu, Nov 10, 2022 at 11:37 PM John Snow <js...@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.
Just realized that this value is coming from https://gitlab.com/anisinha/qemu/-/blob/master/tests/avocado/avocado_qemu/__init__.py#L232 and can be overiden. So I will override this to 200 seconds. If we still see timeouts, we can raise this further by a bit more. Thanks for bringing this to my attention. 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)
