Bug 13364

Summary: oe-selftest runqemu test case error
Product: [QA/Testing] Functional (self) Testing Reporter: Chen Qi <Qi.Chen>
Component: oe-selftestAssignee: Changqing Li <changqing.li>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: Medium+ CC: liezhi.yang, randy.macleod, richard.purdie
Version: 2.8   
Target Milestone: 2.8 M3   
Hardware: x86   
OS: Multiple   
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: No (bug/feature does not impact docs)

Description Chen Qi 2019-05-29 01:44:28 UTC
The comment is:
oe-selftest -r runqemu meta_ide -j 15

The error link is:
https://autobuilder.yoctoproject.org/typhoon/#/builders/73/builds/635/steps/7/logs/step3d

Key error message is as below:

2019-2019-05-27 13:08:38,987 - oe-selftest - INFO - ERROR: runqemu.RunqemuTests.test_boot_machine_slirp (subunit.RemotedTestCase)
2019-05-27 13:08:38,987 - oe-selftest - INFO - ----------------------------------------------------------------------
2019-05-27 13:08:38,987 - oe-selftest - INFO - testtools.testresult.real._StringException: Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemux86-64/build/meta/lib/oeqa/utils/commands.py", line 339, in runqemu
    qemu.start(params=qemuparams, ssh=ssh, runqemuparams=runqemuparams, launch_cmd=launch_cmd, discard_writes=discard_writes)
  File "/home/pokybuild/yocto-worker/qemux86-64/build/meta/lib/oeqa/targetcontrol.py", line 178, in start
    raise bb.build.FuncFailed("%s - FAILED to start qemu - check the task log and the boot log" % self.pn)
bb.build.FuncFailed: Function failed: core-image-minimal - FAILED to start qemu - check the task log and the boot log
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemux86-64/build/meta/lib/oeqa/selftest/cases/runqemu.py", line 107, in test_boot_machine_slirp
    with runqemu(self.recipe, ssh=False, launch_cmd=cmd) as qemu:
  File "/usr/lib64/python3.6/contextlib.py", line 81, in __enter__
    return next(self.gen)
  File "/home/pokybuild/yocto-worker/qemux86-64/build/meta/lib/oeqa/utils/commands.py", line 345, in runqemu
    raise Exception(msg)
Exception: Failed to start QEMU - see the logs in /home/pokybuild/yocto-worker/qemux86-64/build/build-st-43557/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimageQemurunner log output from /home/pokybuild/yocto-worker/qemux86-64/build/build-st-43557/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimage/qemurunner_log.20190527130524:
INFO: rootfs file: 
INFO: Qemu log file: /home/pokybuild/yocto-worker/qemux86-64/build/build-st-43557/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimage/qemu_boot_log.20190527130524
INFO: SSH log file: /home/pokybuild/yocto-worker/qemux86-64/build/build-st-43557/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimage/ssh_target_log.20190527130524
DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:58811
DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:39721
DEBUG: launchcmd=runqemu nographic kvm slirp qemux86-64 tcpserial=39721 bootparams="console=tty1 console=ttyS0,115200n8 printk.time=1" qemuparams="-serial tcp:127.0.0.1:58811 -pidfile pidfile_43557"
DEBUG: runqemu started, pid is 50135
DEBUG: waiting at most 120 seconds for qemu pid (05/27/19 13:05:26)
ERROR: Qemu pid didn't appear in 120 seconds (05/27/19 13:07:26)
[snip]
05-27 13:08:38,987 - oe-selftest - INFO - ERROR: runqemu.RunqemuTests.test_boot_machine_slirp (subunit.RemotedTestCase)
2019-05-27 13:08:38,987 - oe-selftest - INFO - ----------------------------------------------------------------------
2019-05-27 13:08:38,987 - oe-selftest - INFO - testtools.testresult.real._StringException: Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemux86-64/build/meta/lib/oeqa/utils/commands.py", line 339, in runqemu
    qemu.start(params=qemuparams, ssh=ssh, runqemuparams=runqemuparams, launch_cmd=launch_cmd, discard_writes=discard_writes)
  File "/home/pokybuild/yocto-worker/qemux86-64/build/meta/lib/oeqa/targetcontrol.py", line 178, in start
    raise bb.build.FuncFailed("%s - FAILED to start qemu - check the task log and the boot log" % self.pn)
bb.build.FuncFailed: Function failed: core-image-minimal - FAILED to start qemu - check the task log and the boot log
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemux86-64/build/meta/lib/oeqa/selftest/cases/runqemu.py", line 107, in test_boot_machine_slirp
    with runqemu(self.recipe, ssh=False, launch_cmd=cmd) as qemu:
  File "/usr/lib64/python3.6/contextlib.py", line 81, in __enter__
    return next(self.gen)
  File "/home/pokybuild/yocto-worker/qemux86-64/build/meta/lib/oeqa/utils/commands.py", line 345, in runqemu
    raise Exception(msg)
Exception: Failed to start QEMU - see the logs in /home/pokybuild/yocto-worker/qemux86-64/build/build-st-43557/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimageQemurunner log output from /home/pokybuild/yocto-worker/qemux86-64/build/build-st-43557/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimage/qemurunner_log.20190527130524:
INFO: rootfs file: 
INFO: Qemu log file: /home/pokybuild/yocto-worker/qemux86-64/build/build-st-43557/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimage/qemu_boot_log.20190527130524
INFO: SSH log file: /home/pokybuild/yocto-worker/qemux86-64/build/build-st-43557/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimage/ssh_target_log.20190527130524
DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:58811
DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:39721
DEBUG: launchcmd=runqemu nographic kvm slirp qemux86-64 tcpserial=39721 bootparams="console=tty1 console=ttyS0,115200n8 printk.time=1" qemuparams="-serial tcp:127.0.0.1:58811 -pidfile pidfile_43557"
DEBUG: runqemu started, pid is 50135
DEBUG: waiting at most 120 seconds for qemu pid (05/27/19 13:05:26)
ERROR: Qemu pid didn't appear in 120 seconds (05/27/19 13:07:26)
runqemu - ERROR - Failed to run qemu: qemu-system-x86_64: Could not set up host forwarding rule 'tcp::2323-:23'
[snip]
2019-05-27 13:08:43,229 - oe-selftest - INFO - RESULTS - runqemu.RunqemuTests.test_boot_machine_slirp: ERROR (123.77s)
Comment 1 Richard Purdie 2019-05-30 14:41:51 UTC
I suspect this is race where if two slirp tests are run at the same time, they clash over resources. We should use variable port ranges or a lock file or something else if that is the problem.