Bug 13681

Summary: testimage does not log qemu errors to main console; only says do_testimage: runqemu exited with code 1
Product: [Build System, Metadata & Runtime] OE-Core Reporter: Tim Orling <tim.orling>
Component: Scripts and ToolsAssignee: Tim Orling <tim.orling>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: Medium+ CC: bluelightning, randy.macleod, richard.purdie, ross.burton
Version: 3.1   
Target Milestone: 3.1 M4   
Hardware: x86   
OS: Multiple   
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: Don't know

Description Tim Orling 2019-12-05 03:32:05 UTC 
Regardless of the actual cause of qemu failing, the testimage task will display something like:

INFO     - WARNING: meta-python2-ptest-image-1.0-r0 do_testimage: runqemu exited with code 1
INFO     - WARNING: meta-python2-ptest-image-1.0-r0 do_testimage: Qemu ended unexpectedly, dump data from host is in /builds/BY-Rqtgf/0/moto-timo/meta-python2/build/tmp/log/runtime-hostdump/201912041721_qemu
ERROR    - ERROR: Task (/builds/BY-Rqtgf/0/moto-timo/meta-python2/recipes-core/images/meta-python2-ptest-image.bb:do_testimage) failed with exit code '1'
INFO     - NOTE: Tasks Summary: Attempted 8429 tasks of which 1 didn't need to be rerun and 1 failed.
INFO     - 
INFO     - Summary: 1 task failed:
INFO     - /builds/BY-Rqtgf/0/moto-timo/meta-python2/recipes-core/images/meta-INFO     - Summary: There were 7 WARNING messages shown.
ERROR    - Command "/builds/BY-Rqtgf/0/moto-timo/meta-python2/build$ /builds/BY-Rqtgf/0/moto-timo/meta-python2/poky/bitbake/bin/bitbake -k -c build meta-python2-ptest-image" failed
 --- Error summary ---
ERROR: Task (/builds/BY-Rqtgf/0/moto-timo/meta-python2/recipes-core/images/meta-python2-ptest-image.bb:do_testimage) failed with exit code '1'
ERROR: Job failed: exit code 1

This happens to be running in a Docker container on gitlab-ci, but that is irrelevant, the same behavior would be seen on baremetal. (And I've seen it many times before I finally got testimage to work).

The actual causes of failure might be /dev/net/tun, /dev/kvm, or /dev/dri not being read/writeable by the user running bitbake.

If you were to run runqemu directly, you would get more information, such as:

runqemu kvm gl
runqemu - INFO - Running bitbake -e...
runqemu - ERROR - TUN control device /dev/net/tun is not writable, please fix (e.g. sudo chmod 666 /dev/net/tun)
runqemu - INFO - Cleaning up

For the testimage task case, if you go to the log.do_testimage, you would see the more useful logging, yet on the console all you would see is:
<snip>
...do_testimage) failed with exit code '1'

When running on a headless system, such as the autobuilder, jenkins or gitlab-ci, this makes it nearly impossible to know which specific thing is causing testimage's ability to run qemu to fail. If you do not have ssh access to the file system, good luck figuring it out.

Let's say you fix the /dev/net/tun access issue, you would get again the same cryptic "runqemu exited with code 1" error where now it would be /dev/kvm that was inaccessible. Fix that... same error code, but now it would be /dev/dri being inaccessible.

Something in the error trapping of testimage is causing the logging to not be sent to the main bitbake console and is EXTREMELY confusing to the user. This has stopped me from getting testimage to work for many months (I persevered and now I at least know what to check for).
Comment 1 Tim Orling 2019-12-05 03:40:52 UTC 
To reproduce this, simply don't run runqemu-gen-tapdevs on a system where sudo still requires a password and then run $ bitbake -c testimage core-image-foo

In other words, on a system where you have not done anything to properly enable testimage, try to run the testimage task. Result: "exit code 1".

On the same system, in the same condition, run $ runqemu core-image-foo and you will get information letting you know that TAP devices have not been setup properly and you have a hint of where to go next.
Comment 2 Paul Eggleton 2019-12-08 22:59:08 UTC 
Confirmed, this is pretty awful. I also notice that a bunch of the "hostdump" logs are "xyz: command not found", presumably because they are invoking commands that are not accessible via HOSTTOOLS.
Comment 4 Tim Orling 2020-04-15 12:12:41 UTC 
The change from print() to logger resolves the initial issue.

There remains the assumption of tools installed on host and target for the respective dump functions. Opening a new bug for that.
Comment 5 Tim Orling 2020-04-15 12:34:59 UTC 
Added testimage_dump_target() bug:
https://bugzilla.yoctoproject.org/show_bug.cgi?id=13871

Added testimage_dump_host() bug:
https://bugzilla.yoctoproject.org/show_bug.cgi?id=13872