debugging functional tests that only fail in 'make check-functional'

[Peter Maydell <peter.maydell@linaro.org>]

I'm trying to debug some functional tests that fail for me
with 'make check-functional' on a debug build. Consistently
(well, same set of tests in two runs) when I run
'make -j8 check-functional' these fail:

 7/44 qemu:func-thorough+func-arm-thorough+thorough / func-arm-arm_sx1
                        ERROR           173.31s   exit status 1
10/44 qemu:func-thorough+func-aarch64-thorough+thorough /
func-aarch64-aarch64_virt            TIMEOUT         720.04s   killed
by signal 15 SIGTERM
11/44 qemu:func-thorough+func-arm-thorough+thorough /
func-arm-arm_aspeed_ast2600              TIMEOUT         720.07s
killed by signal 15 SIGTERM
12/44 qemu:func-thorough+func-aarch64-thorough+thorough /
func-aarch64-aarch64_sbsaref_alpine  TIMEOUT         720.07s   killed
by signal 15 SIGTERM
40/44 qemu:func-thorough+func-arm-thorough+thorough /
func-arm-arm_aspeed_ast2500              TIMEOUT         480.01s
killed by signal 15 SIGTERM

The aarch64-virt one is gpu issue, so I know about that one.
The others pass OK on a clang no-debug sanitizer build.

If I try to run just the sx1 tests "by hand":

$ (cd build/x86 && PYTHONPATH=../../python:../../tests/functional
QEMU_TEST_QEMU_BINARY=./qemu-system-arm ./pyvenv/bin/python3
../../tests/functional/test_arm_sx1.py)
TAP version 13
ok 1 test_arm_sx1.SX1Test.test_arm_sx1_flash
ok 2 test_arm_sx1.SX1Test.test_arm_sx1_initrd
ok 3 test_arm_sx1.SX1Test.test_arm_sx1_sd
1..3

they pass; but inside the test framework that third sd test
errors: testlog-thorough.txt says:

===begin===
----------------------------------- stdout -----------------------------------
TAP version 13
ok 1 test_arm_sx1.SX1Test.test_arm_sx1_flash
ok 2 test_arm_sx1.SX1Test.test_arm_sx1_initrd
not ok 3 test_arm_sx1.SX1Test.test_arm_sx1_sd
1..3
----------------------------------- stderr -----------------------------------
Traceback (most recent call last):
  File "/mnt/nvmedisk/linaro/qemu-from-laptop/qemu/python/qemu/machine/machine.py",
line 611, in _do_shutdown
    self._soft_shutdown(timeout)
  File "/mnt/nvmedisk/linaro/qemu-from-laptop/qemu/python/qemu/machine/machine.py",
line 596, in _soft_shutdown
    self._subp.wait(timeout=timeout)
  File "/usr/lib/python3.12/subprocess.py", line 1264, in wait
    return self._wait(timeout=timeout)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/subprocess.py", line 2045, in _wait
    raise TimeoutExpired(self.args, timeout)
subprocess.TimeoutExpired: Command
'('/mnt/nvmedisk/linaro/qemu-from-laptop/qemu/build/x86/qemu-system-arm',
'-display', 'none', '-vga', 'none', '-chardev', 'socket,id=mon,fd=5',
'-mon', 'chardev=mon,mode=control', '-machine', 'sx1', '-chardev',
'socket,id=console,fd=10', '-serial', 'chardev:console', '-append',
'kunit.enable=0 root=/dev/mmcblk0 rootwait console=ttyS0,115200
earlycon=uart8250,mmio32,0xfffb0000,115200n8', '-no-reboot',
'-snapshot', '-drive',
'format=raw,if=sd,file=/home/petmay01/.cache/qemu/download/c1db7f43ef92469ebc8605013728c8950e7608439f01d13678994f0ce101c3a8',
'-kernel', '/home/petmay01/.cache/qemu/download/a0271899a8dc2165f9e0adb2d0a57fc839ae3a469722ffc56c77e108a8887615')'
timed out after 60 seconds

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/mnt/nvmedisk/linaro/qemu-from-laptop/qemu/tests/functional/test_arm_sx1.py",
line 58, in test_arm_sx1_sd
    self.vm.wait(timeout=60)
  File "/mnt/nvmedisk/linaro/qemu-from-laptop/qemu/python/qemu/machine/machine.py",
line 666, in wait
    self.shutdown(timeout=timeout)
  File "/mnt/nvmedisk/linaro/qemu-from-laptop/qemu/python/qemu/machine/machine.py",
line 648, in shutdown
    self._do_shutdown(timeout)
  File "/mnt/nvmedisk/linaro/qemu-from-laptop/qemu/python/qemu/machine/machine.py",
line 618, in _do_shutdown
    raise AbnormalShutdown("Could not perform graceful shutdown") \
qemu.machine.machine.AbnormalShutdown: Could not perform graceful shutdown

More information on test_arm_sx1.SX1Test.test_arm_sx1_sd could be found here:
 /mnt/nvmedisk/linaro/qemu-from-laptop/qemu/build/x86/tests/functional/arm/test_arm_sx1.SX1Test.test_arm_sx1_sd/base.log
 /mnt/nvmedisk/linaro/qemu-from-laptop/qemu/build/x86/tests/functional/arm/test_arm_sx1.SX1Test.test_arm_sx1_sd/console.log

(test program exited with status code 1)
===endit===

which I interpret to mean "we waited the 60 seconds the test says,
but the test didn't exit within that time".

Any suggestions for how to debug?

(Also the console.log is empty regardless of whether the
test passes or fails; this doesn't seem right.)

thanks
-- PMM