oe-selftest serial timeout

oe-selftest serial timeout

[Richard Purdie]

Hi Robert,

The test we added debug to failed, logs/links below. Looks like the 5s
timeout for non-kvm is too short as was commented elsewhere. Not sure
why the kvm setting isn't being passed in here but it should be set for
these builds, we may need to make sure its inherited as well?

Cheers,

Richard



https://autobuilder.yoctoproject.org/typhoon/#/builders/56/builds/83

2019-01-02 17:48:44,799 - oe-selftest - INFO - ======================================================================
2019-01-02 17:48:44,800 - oe-selftest - INFO - FAIL: runqemu.RunqemuTests.test_boot_rootfs (subunit.RemotedTestCase)
2019-01-02 17:48:44,800 - oe-selftest - INFO - ----------------------------------------------------------------------
2019-01-02 17:48:44,800 - oe-selftest - INFO - testtools.testresult.real._StringException: Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/oe-selftest/build/meta/lib/oeqa/core/decorator/__init__.py", line 32, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/oe-selftest/build/meta/lib/oeqa/selftest/cases/runqemu.py", line 144, in test_boot_rootfs
    self.assertTrue(qemu.runner.logged, "Failed: %s, %s" % (cmd, f.read()))
  File "/usr/lib/python3.6/unittest/case.py", line 682, in assertTrue
    raise self.failureException(msg)
AssertionError: False is not true : Failed: runqemu nographic /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/deploy/images/qemux86-64/core-image-minimal-qemux86-64.ext4, INFO: rootfs file: 
INFO: Qemu log file: /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimage/qemu_boot_log.20190102164633
INFO: SSH log file: /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimage/ssh_target_log.20190102164633
DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:40679
DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:50773
DEBUG: launchcmd=runqemu nographic /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/deploy/images/qemux86-64/core-image-minimal-qemux86-64.ext4 tcpserial=50773 bootparams="console=tty1 console=ttyS0,115200n8 printk.time=1" qemuparams="-serial tcp:127.0.0.1:40679 -pidfile pidfile_8591"
DEBUG: runqemu started, pid is 29140
DEBUG: waiting at most 120 seconds for qemu pid (01/02/19 16:46:39)
DEBUG: qemu started in 0.5013589859008789 seconds - qemu procces pid is 29581 (01/02/19 16:46:40)
DEBUG: Target IP: None
DEBUG: Server IP: None
DEBUG: Starting logging thread
DEBUG: Starting thread event loop
DEBUG: Connection request received
DEBUG: Setting connection established event
DEBUG: Output from runqemu:
runqemu - INFO - Continuing with the following parameters:

runqemu - INFO - Using preconfigured tap device tap0
runqemu - INFO - If this is not intended, touch /tmp/qemu-tap-locks/tap0.skip to make runqemu skip tap0.
runqemu - INFO - Network configuration: 192.168.7.2::192.168.7.1:255.255.255.0
runqemu - INFO - Running /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/work/x86_64-linux/qemu-helper-native/1.0-r1/recipe-sysroot-native/usr/bin/qemu-system-x86_64 -device virtio-net-pci,netdev=net0,mac=52:54:00:12:34:02 -netdev tap,id=net0,ifname=tap0,script=no,downscript=no -drive file=/home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/deploy/images/qemux86-64/core-image-minimal-qemux86-64.ext4,if=virtio,format=raw -vga vmware -show-cursor -usb -device usb-tablet -object rng-random,filename=/dev/urandom,id=rng0 -device virtio-rng-pci,rng=rng0  -nographic -serial tcp:127.0.0.1:40679 -pidfile pidfile_8591  -cpu core2duo -m 256 -serial tcp:127.0.0.1:50773 -kernel /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/deploy/images/qemux86-64/bzImage--4.18.21+git0+8f4a98c938_9eddc793f9-r0.2-qemux86-64-20190102130920.bin -append 'root=/dev/vda rw highres=off  console=ttyS0 mem=256M ip=192.168.7.2::192.168.7.1:255.255.255.0 vga=0 uvesafb.mode_option=640x480-32 oprofile.timer=1 uvesafb.task_timeout=-1 console=tty1 console=ttyS0,115200n8 printk.time=1'

QEMU 3.1.0 monitor - type 'help' for more information
(qemu) 
DEBUG: Waiting at most 1000 seconds for login banner (01/02/19 16:46:40)
DEBUG: Connection from 127.0.0.1:53454
DEBUG: Reached login banner in 83.91195774078369 seconds (01/02/19 16:48:04)
DEBUG: Couldn't login into serial console as root using blank password
DEBUG: The output:
 root
^[7^[[r
^[[6n<<< run_serial(): command timed out after 5 seconds without output >>>

Re: oe-selftest serial timeout

[Robert Yang]

Hi RP,

On 1/3/19 5:13 AM, Richard Purdie wrote:
> Hi Robert,
> 
> The test we added debug to failed, logs/links below. Looks like the 5s
> timeout for non-kvm is too short as was commented elsewhere. Not sure

I've sent a patch to set default timeout to 60s:

oeqa/utils/qemurunner: set timeout to 60s for run_serial

> why the kvm setting isn't being passed in here but it should be set for
> these builds, we may need to make sure its inherited as well?

And another 2 patches to make sure oeqa/selftest/runqemu use kvm when
QEMU_USE_KVM is set:

oeqa: Fix for QEMU_USE_KVM
oeqa/selftest/runqemu: enable kvm when QEMU_USE_KVM is set

// Robert

> 
> Cheers,
> 
> Richard
> 
> 
> 
> https://autobuilder.yoctoproject.org/typhoon/#/builders/56/builds/83
> 
> 2019-01-02 17:48:44,799 - oe-selftest - INFO - ======================================================================
> 2019-01-02 17:48:44,800 - oe-selftest - INFO - FAIL: runqemu.RunqemuTests.test_boot_rootfs (subunit.RemotedTestCase)
> 2019-01-02 17:48:44,800 - oe-selftest - INFO - ----------------------------------------------------------------------
> 2019-01-02 17:48:44,800 - oe-selftest - INFO - testtools.testresult.real._StringException: Traceback (most recent call last):
>    File "/home/pokybuild/yocto-worker/oe-selftest/build/meta/lib/oeqa/core/decorator/__init__.py", line 32, in wrapped_f
>      return func(*args, **kwargs)
>    File "/home/pokybuild/yocto-worker/oe-selftest/build/meta/lib/oeqa/selftest/cases/runqemu.py", line 144, in test_boot_rootfs
>      self.assertTrue(qemu.runner.logged, "Failed: %s, %s" % (cmd, f.read()))
>    File "/usr/lib/python3.6/unittest/case.py", line 682, in assertTrue
>      raise self.failureException(msg)
> AssertionError: False is not true : Failed: runqemu nographic /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/deploy/images/qemux86-64/core-image-minimal-qemux86-64.ext4, INFO: rootfs file:
> INFO: Qemu log file: /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimage/qemu_boot_log.20190102164633
> INFO: SSH log file: /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/work/qemux86_64-poky-linux/core-image-minimal/1.0-r0/testimage/ssh_target_log.20190102164633
> DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:40679
> DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:50773
> DEBUG: launchcmd=runqemu nographic /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/deploy/images/qemux86-64/core-image-minimal-qemux86-64.ext4 tcpserial=50773 bootparams="console=tty1 console=ttyS0,115200n8 printk.time=1" qemuparams="-serial tcp:127.0.0.1:40679 -pidfile pidfile_8591"
> DEBUG: runqemu started, pid is 29140
> DEBUG: waiting at most 120 seconds for qemu pid (01/02/19 16:46:39)
> DEBUG: qemu started in 0.5013589859008789 seconds - qemu procces pid is 29581 (01/02/19 16:46:40)
> DEBUG: Target IP: None
> DEBUG: Server IP: None
> DEBUG: Starting logging thread
> DEBUG: Starting thread event loop
> DEBUG: Connection request received
> DEBUG: Setting connection established event
> DEBUG: Output from runqemu:
> runqemu - INFO - Continuing with the following parameters:
> 
> runqemu - INFO - Using preconfigured tap device tap0
> runqemu - INFO - If this is not intended, touch /tmp/qemu-tap-locks/tap0.skip to make runqemu skip tap0.
> runqemu - INFO - Network configuration: 192.168.7.2::192.168.7.1:255.255.255.0
> runqemu - INFO - Running /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/work/x86_64-linux/qemu-helper-native/1.0-r1/recipe-sysroot-native/usr/bin/qemu-system-x86_64 -device virtio-net-pci,netdev=net0,mac=52:54:00:12:34:02 -netdev tap,id=net0,ifname=tap0,script=no,downscript=no -drive file=/home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/deploy/images/qemux86-64/core-image-minimal-qemux86-64.ext4,if=virtio,format=raw -vga vmware -show-cursor -usb -device usb-tablet -object rng-random,filename=/dev/urandom,id=rng0 -device virtio-rng-pci,rng=rng0  -nographic -serial tcp:127.0.0.1:40679 -pidfile pidfile_8591  -cpu core2duo -m 256 -serial tcp:127.0.0.1:50773 -kernel /home/pokybuild/yocto-worker/oe-selftest/build/build-st-8591/tmp/deploy/images/qemux86-64/bzImage--4.18.21+git0+8f4a98c938_9eddc793f9-r0.2-qemux86-64-20190102130920.bin -append 'root=/dev/vda rw highres=off  console=ttyS0 mem=256M ip=192.168.7.2::192.168.7.1:255.255.255.0 vga=0 uvesafb.mode_option=640x480-32 oprofile.timer=1 uvesafb.task_timeout=-1 console=tty1 console=ttyS0,115200n8 printk.time=1'
> 
> QEMU 3.1.0 monitor - type 'help' for more information
> (qemu)
> DEBUG: Waiting at most 1000 seconds for login banner (01/02/19 16:46:40)
> DEBUG: Connection from 127.0.0.1:53454
> DEBUG: Reached login banner in 83.91195774078369 seconds (01/02/19 16:48:04)
> DEBUG: Couldn't login into serial console as root using blank password
> DEBUG: The output:
>   root
> ^[7^[[r
> ^[[6n<<< run_serial(): command timed out after 5 seconds without output >>>
> 
> 
> 

Re: oe-selftest serial timeout

[richard.purdie]

On Thu, 2019-01-03 at 16:03 +0800, Robert Yang wrote:
> Hi RP,
> 
> On 1/3/19 5:13 AM, Richard Purdie wrote:
> > Hi Robert,
> > 
> > The test we added debug to failed, logs/links below. Looks like the
> > 5s
> > timeout for non-kvm is too short as was commented elsewhere. Not
> > sure
> 
> I've sent a patch to set default timeout to 60s:
> 
> oeqa/utils/qemurunner: set timeout to 60s for run_serial

Thanks, that should help a lot!

Its queued in -next.

> > why the kvm setting isn't being passed in here but it should be set
> > for
> > these builds, we may need to make sure its inherited as well?
> 
> And another 2 patches to make sure oeqa/selftest/runqemu use kvm when
> QEMU_USE_KVM is set:
> 
> oeqa: Fix for QEMU_USE_KVM
> oeqa/selftest/runqemu: enable kvm when QEMU_USE_KVM is set

I've replied on this one, I think we need to tweak the patch a little
more and solve a few issues once and for all whilst we're changing that
code!

Cheers,

Richard