Bug 14611

Summary:	qemuarm64 testimage Target didn't reach login banner
Product:	[QA/Testing] Runtime Testing	Reporter:	Christopher Larson <kergoth>
Component:	testimage	Assignee:	Randy MacLeod <randy.macleod>
Status:	RESOLVED WORKSFORME	QA Contact:
Severity:	normal
Priority:	Medium+	CC:	alexandre.belloni, chee.yang.lee, randy.macleod, sakib.sajal
Version:	unspecified
Target Milestone:	4.1 M1
Hardware:	x86
OS:	Multiple
Whiteboard:	AB-INT
OS type for building Yocto:	---	Type of Regression:	---
Verified:		Documentation change:	No (bug/feature does not impact docs)

Description Christopher Larson 2021-10-22 17:31:44 UTC

Autobuilder failure for build at https://autobuilder.yoctoproject.org/typhoon/#builders/85/builds/1592

Qemuarm64, core-image-minimal:do_testimage failure, master branch, 2d5e0f13e336ab6ff32ee86091a98a6bd84c154d.

WARNING: core-image-minimal-1.0-r0 do_testimage: Target didn't reach login banner in 1500 seconds (10/20/21 03:06:49)
WARNING: core-image-minimal-1.0-r0 do_testimage: Last 25 lines of text:
[   68.261348] NET: Registered PF_VSOCK protocol family
[   69.285488] Key type ._fscrypt registered
[   69.307910] Key type .fscrypt registered
[   69.351008] Key type fscrypt-provisioning registered
[   69.727614] Btrfs loaded, crc32c=crc32c-generic, zoned=no
[   73.658287] Key type encrypted registered
[   74.761128] printk: console [netcon0] enabled
[   74.918164] netconsole: network logging started
[   77.192870] IP-Config: Complete:
[   77.213426]      device=eth0, hwaddr=52:54:00:12:34:12, ipaddr=192.168.7.18, mask=255.255.255.0, gw=192.168.7.17
[   77.372345]      host=192.168.7.18, domain=, nis-domain=(none)
[   77.512269]      bootserver=255.255.255.255, rootserver=255.255.255.255, rootpath=
[   79.406238] md: Waiting for all devices to be available before autodetect
[   79.632952] md: If you don't use raid, use raid=noautodetect
[   79.692464] md: Autodetecting RAID arrays.
[   79.720611] md: autorun ...
[   79.722252] md: ... autorun DONE.
[   87.960570] EXT4-fs (vda): mounted filesystem with ordered data mode. Opts: (null). Quota mode: disabled.
[   87.998557] VFS: Mounted root (ext4 filesystem) on device 253:0.
[   88.468662] devtmpfs: mounted
[   89.182814] Freeing unused kernel memory: 3648K
[   89.660355] Run /sbin/init as init process
[  344.438211] udevd[134]: starting version 3.2.10
[  378.347651] udevd[135]: starting eudev-3.2.10
[  553.683634] EXT4-fs (vda): re-mounted. Opts: (null). Quota mode: disabled.
WARNING: core-image-minimal-1.0-r0 do_testimage: Check full boot log: /home/pokybuild/yocto-worker/qemuarm64/build/build/tmp/work/qemuarm64-poky-linux/core-image-minimal/1.0-r0/testimage/qemu_boot_log.20211020023913
WARNING: core-image-minimal-1.0-r0 do_testimage: Qemu ended unexpectedly, dump data from host is in /home/pokybuild/yocto-worker/qemuarm64/build/build/tmp/log/runtime-hostdump/202110200306_qemu
Output from runqemu:
runqemu - INFO - SIGTERM received
runqemu - INFO - Cleaning up
runqemu - INFO - Removing /home/pokybuild/tmp/core-image-minimal-qemuarm64.ext4.24335
tput: No value for $TERM and no -T specified
tput: No value for $TERM and no -T specified
ERROR: core-image-minimal-1.0-r0 do_testimage: Error executing a python function in exec_func_python() autogenerated:
The stack trace of python calls that resulted in this exception/failure was:
File: 'exec_func_python() autogenerated', lineno: 2, function: <module>
     0001:
 *** 0002:do_testimage(d)
     0003:
File: '/home/pokybuild/yocto-worker/qemuarm64/build/meta/classes/testimage.bbclass', lineno: 135, function: do_testimage
     0131:    dump-guest-memory {"paging":false,"protocol":"file:%s.img"}
     0132:}
     0133:
     0134:python do_testimage() {
 *** 0135:    testimage_main(d)
     0136:}
     0137:
     0138:addtask testimage
     0139:do_testimage[nostamp] = "1"
File: '/home/pokybuild/yocto-worker/qemuarm64/build/meta/classes/testimage.bbclass', lineno: 383, function: testimage_main
     0379:    orig_sigterm_handler = signal.signal(signal.SIGTERM, sigterm_exception)
     0380:    try:
     0381:        # We need to check if runqemu ends unexpectedly
     0382:        # or if the worker send us a SIGTERM
 *** 0383:        tc.target.start(params=d.getVar("TEST_QEMUPARAMS"), runqemuparams=d.getVar("TEST_RUNQEMUPARAMS"))
     0384:        import threading
     0385:        try:
     0386:            threading.Timer(int(d.getVar("TEST_OVERALL_TIMEOUT")), handle_test_timeout, (int(d.getVar("TEST_OVERALL_TIMEOUT")),)).start()
     0387:        except ValueError:
File: '/home/pokybuild/yocto-worker/qemuarm64/build/meta/lib/oeqa/core/target/qemu.py', lineno: 102, function: start
     0098:            except (subprocess.CalledProcessError, subprocess.TimeoutExpired, FileNotFoundError) as err:
     0099:                msg += "Error running command: %s\n%s\n" % (blcmd, err)
     0100:            msg += "\n\n===== end: snippet =====\n"
     0101:
 *** 0102:            raise RuntimeError("FAILED to start qemu - check the task log and the boot log %s" % (msg))
     0103:
     0104:    def stop(self):
     0105:        self.runner.stop()
Exception: RuntimeError: FAILED to start qemu - check the task log and the boot log 
===== start: snippet =====
file: /home/pokybuild/yocto-worker/qemuarm64/build/build/tmp/log/runtime-hostdump/202110200306_qemu/host_00_top
top - 03:06:50 up 4 days,  7:18,  1 user,  load average: 64.46, 80.61, 83.85
Tasks: 915 total,  47 running, 862 sleeping,   0 stopped,   6 zombie
%Cpu(s):  3.0 us,  5.6 sy, 22.8 ni, 67.3 id,  1.3 wa,  0.0 hi,  0.1 si,  0.0 st
KiB Mem : 13192298+total, 10236827+free, 12261804 used, 17292904 buff/cache
KiB Swap: 13410816+total, 13407786+free,    30292 used. 11595868+avail Mem 
  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
25821 pokybui+  15  -5 3978336 1.559g  20388 S 161.8  1.2  33:13.10 qemu-system-aar
25006 pokybui+  15  -5 2491676 451092  20592 R  92.7  0.3  32:25.24 qemu-system-aar
34485 pokybui+  15  -5 3655524 1.497g  20568 S  90.9  1.2  49:22.50 qemu-system-aar
 3017 pokybui+  25   5  187884 154496  17824 R  87.3  0.1   0:20.23 cc1plus
 6469 pokybui+  25   5  113044  81916  17788 R  83.6  0.1   0:04.22 cc1plus
 5592 pokybui+  25   5  247476 215044  17956 R  81.8  0.2   0:08.72 cc1plus
 5672 pokybui+  25   5  162060 127360  17796 R  81.8  0.1   0:08.57 cc1plus
 6967 pokybui+  25   5   20020  14132   3684 R  81.8  0.0   0:01.61 x86_64-poky-lin
 6984 pokybui+  25   5   15716   9976   3808 R  81.8  0.0   0:01.53 x86_64-poky-lin
 3326 pokybui+  25   5  181316 147392  17712 R  80.0  0.1   0:18.92 cc1plus
 4563 pokybui+  25   5  216048 192956  18964 R  80.0  0.1   0:13.19 cc1plus
 6789 pokybui+  25   5  106708  73860  17784 R  80.0  0.1   0:02.40 cc1plus
 6874 pokybui+  25   5   13576   9904   3552 R  80.0  0.0   0:02.05 x86_64-poky-lin
===== end: snippet =====
===== start: snippet =====
file: /home/pokybuild/yocto-worker/qemuarm64/build/build/tmp/work/qemuarm64-poky-linux/core-image-minimal/1.0-r0/testimage/qemu_boot_log.20211020023913
[   77.372345]      host=192.168.7.18, domain=, nis-domain=(none)
[   77.512269]      bootserver=255.255.255.255, rootserver=255.255.255.255, rootpath=
[   79.406238] md: Waiting for all devices to be available before autodetect
[   79.632952] md: If you don't use raid, use raid=noautodetect
[   79.692464] md: Autodetecting RAID arrays.
[   79.720611] md: autorun ...
[   79.722252] md: ... autorun DONE.
[   87.960570] EXT4-fs (vda): mounted filesystem with ordered data mode. Opts: (null). Quota mode: disabled.
[   87.998557] VFS: Mounted root (ext4 filesystem) on device 253:0.
[   88.468662] devtmpfs: mounted
[   89.182814] Freeing unused kernel memory: 3648K
[   89.660355] Run /sbin/init as init process
INIT: version 2.99 booting
Starting udev
[  344.438211] udevd[134]: starting version 3.2.10
[  378.347651] udevd[135]: starting eudev-3.2.10
[  553.683634] EXT4-fs (vda): re-mounted. Opts: (null). Quota mode: disabled.
Configuring packages on first boot....
 (This may take several minutes. Please do not power off the machine.)
Running postinst /etc/rpm-postinsts/100-sysvinit-inittab...
===== end: snippet =====
ERROR: Logfile of failure stored in: /home/pokybuild/yocto-worker/qemuarm64/build/build/tmp/work/qemuarm64-poky-linux/core-image-minimal/1.0-r0/temp/log.do_testimage.19199
NOTE: recipe core-image-minimal-1.0-r0: task do_testimage: Failed

Comment 1 Chee Yang 2021-11-09 09:48:31 UTC

https://autobuilder.yoctoproject.org/typhoon/#/builders/102/builds/2277/steps/12/logs/stdio
centos8-ty-1
qemumips-alt

Comment 2 Chee Yang 2021-11-11 09:52:39 UTC

https://autobuilder.yoctoproject.org/typhoon/#/builders/42/builds/4195/steps/14/logs/stdio
earlier occurrence 
ubuntu1604-ty-1 qemuarm64

Comment 3 Alexandre Belloni 2022-01-13 00:36:28 UTC

https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/4449/steps/14/logs/stdio
qemumips centos7-ty-4

Comment 4 Randy MacLeod 2022-04-14 15:11:37 UTC

Likely due to too much IO load and we have reduced that somewhat.