https://autobuilder.yocto.io/builders/nightly-x86-64/builds/462/steps/Running%20Sanity%20Tests/logs/stdio NOTE: core-image-sato-sdk-1.0-r0 do_testimage: test_cpio (buildcpio.BuildCpioTest) NOTE: core-image-sato-1.0-r0 do_testimage: Qemu pid didn't appeared in 60 seconds WARNING: core-image-sato-1.0-r0 do_testimage: Qemu ended unexpectedly, dump data from host is in /tmp/oe-saved-tests/201708291357_qemu NOTE: core-image-sato-1.0-r0 do_testimage: Sending SIGTERM to runqemu
Another case: https://autobuilder.yocto.io/builders/nightly-qa-extras/builds/456/steps/Running%20Sanity%20Tests/logs/stdio
Created attachment 3971 [details] patch intended to fix/help debug the issue
I have created a patch that refactors the searching for QEMU PID. Also adds additional printouts if things go wrong. Also fixes some unlikely corner cases (self.qemupid = qemu_child could be set but /proc entry does not exist)
OK, so the patch is not 100% working. Back to the drawing board, this time testing a patch that uses QEMU cmd line argument -pidfile. This should greatly simplify/eliminate parsing of "ps" output. BTW, I found out (the hard way) that an uncaught exception in "find_child" will typically result in an immediate error message "Qemu pid didn't appeared in 120 seconds". This probably explains why increasing the timeout value did not improve the testing.
Created attachment 3986 [details] patch using QEMU pidfile
Looking at this: NOTE: core-image-sato-sdk-1.0-r0 do_testimage: Waiting at most 1500 seconds for login banner NOTE: core-image-sato-sdk-1.0-r0 do_testimage: Connection from 127.0.0.1:45934 NOTE: core-image-sato-sdk-1.0-r0 do_testimage: Reached login banner NOTE: core-image-sato-sdk-1.0-r0 do_testimage: Logged as root in serial console NOTE: core-image-sato-sdk-1.0-r0 do_testimage: test_ping (ping.PingTest) NOTE: core-image-sato-sdk-1.0-r0 do_testimage: ... ok NOTE: core-image-sato-sdk-1.0-r0 do_testimage: test_ssh (ssh.SSHTest) NOTE: core-image-sato-sdk-1.0-r0 do_testimage: ... ok NOTE: core-image-sato-sdk-1.0-r0 do_testimage: test_cpio (buildcpio.BuildCpioTest) NOTE: core-image-sato-1.0-r0 do_testimage: Qemu pid didn't appeared in 60 seconds It clearly shows we are logged in QEMU, so QEMU is manifestly running, at this point we must have had found QEMU PID. So the error message "Qemu pid didn't appeared in 60 seconds" is most likely caused by some uncaught exception, resulting in a misleading error message
Refactored/simplified the code that determines PID of the running QEMU, PID is actually provided by QEMU itself via command line argument -pidfile. Hence the code does not need to analyze running processes and various levels of ancestry. This, of course, does not mean we will not see this timeout error again. The replace code, although more complex, did not seem to have any obvious shortcomings. It may, however, provide additional insight as the code code-paths have changed. http://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/?id=ed9d0fa5a92f837b14ff8f4e8d433da92d7dc968 http://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/?id=03aa1ef733032e1acae4d291580968301679117f
closing based on ed9d0fa5a92f837b14ff8f4e8d433da92d7dc968 and 03aa1ef733032e1acae4d291580968301679117f commits. Should the issue recur, the additional logging info that was also added as part of these commits should help.
looks like the closed box didn't stick.... see previous comment for commit and reason.