DEBUG: Executing python function extend_recipe_sysroot NOTE: Direct dependencies are ['/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/recipes-devtools/qemu/qemu-helper-native_1.0.bb:do_populate_sysroot', '/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/recipes-devtools/qemu/qemu-native_7.2.0.bb:do_populate_sysroot', '/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/recipes-devtools/qemu/qemu-system-native_7.2.0.bb:do_populate_sysroot', 'virtual:native:/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/recipes-devtools/createrepo-c/createrepo-c_0.20.1.bb:do_populate_sysroot', 'virtual:native:/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/recipes-devtools/dnf/dnf_4.14.0.bb:do_populate_sysroot', 'virtual:native:/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/recipes-devtools/pseudo/pseudo_git.bb:do_populate_sysroot', 'virtual:native:/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/recipes-devtools/unfs3/unfs3_git.bb:do_populate_sysroot', 'virtual:native:/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/recipes-extended/cpio/cpio_2.13.bb:do_populate_sysroot'] NOTE: Installed into sysroot: ['cpio-native'] NOTE: Skipping as already exists in sysroot: ['qemu-helper-native', 'qemu-native', 'qemu-system-native', 'createrepo-c-native', 'dnf-native', 'pseudo-native', 'unfs3-native', 'xz-native', 'pixman-native', 'dtc-native', 'glib-2.0-native', 'zlib-native', 'libepoxy-native', 'libsdl2-native', 'alsa-lib-native', 'virglrenderer-native', 'libslirp-native', 'sqlite3-native', 'openssl-native', 'python3-native', 'file-native', 'rpm-native', 'cmake-native', 'expat-native', 'curl-native', 'libxml2-native', 'libtool-native', 'texinfo-dummy-native', 'gettext-minimal-native', 'libdnf-native', 'libcomps-native', 'librepo-native', 'python3-iniparse-native', 'flex-native', 'libtirpc-native', 'libpcre2-native', 'util-linux-native', 'libffi-native', 'gettext-native', 'mesa-native', 'libx11-native', 'libxext-native', 'libxrandr-native', 'libxrender-native', 'libdrm-native', 'perl-native', 'ncurses-native', 'readline-native', 'gdbm-native', 'bzip2-native', 'libnsl2-native', 'util-linux-libuuid-native', 'zstd-native', 'elfutils-native', 'popt-native', 'lua-native', 'libgcrypt-native', 'libcheck-native', 'gobject-introspection-native', 'libsolv-native', 'json-c-native', 'libmodulemd-native', 'swig-native', 'gpgme-native', 'attr-native', 'python3-installer-native', 'python3-wheel-native', 'python3-build-native', 'python3-six-native', 'python3-setuptools-native', 'm4-native', 'libcap-ng-native', 'wayland-protocols-native', 'libxfixes-native', 'python3-mako-native', 'xrandr-native', 'libxshmfence-native', 'makedepend-native', 'xorgproto-native', 'libxxf86vm-native', 'libxdamage-native', 'wayland-native', 'llvm-native', 'chrpath-native', 'libxcb-native', 'util-macros-native', 'xtrans-native', 'libpthread-stubs-native', 'libpciaccess-native', 'make-native', 'libmicrohttpd-native', 'libarchive-native', 'libgpg-error-native', 'libcap-native', 'libyaml-native', 'libassuan-native', 'python3-flit-core-native', 'python3-pyproject-hooks-native', 'python3-packaging-native', 'gnu-config-native', 'python3-markupsafe-native', 'python3-pygments-native', 'libedit-native', 'xcb-proto-native', 'libxau-native', 'libxdmcp-native', 'gnutls-native', 'unzip-native', 'libunistring-native', 'nettle-native', 'libidn2-native', 'gmp-native'] DEBUG: Python function extend_recipe_sysroot finished DEBUG: Executing python function do_testimage DEBUG: test suites: test_ping (ping.PingTest) test_ssh (ssh.SSHTest) test_parselogs (parselogs.ParseLogsTest) test_ptestrunner_expectfail (ptest.PtestRunnerTest) test_ptestrunner_expectsuccess (ptest.PtestRunnerTest) DEBUG: Using kvm for runqemu QMP Available for connection at /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/.qg3937z2 DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:45513 DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:60049 DEBUG: launchcmd=runqemu snapshot kvm qemuarm64 /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/deploy/images/qemuarm64/core-image-ptest-bc-qemuarm64.ext4 tcpserial=45513:60049 bootparams=" printk.time=1" qemuparams="-pidfile /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/pidfile_310143 -S -qmp unix:./.rwfvl5si,server,wait -qmp unix:./.qg3937z2,server,nowait" DEBUG: runqemu started, pid is 310200 DEBUG: waiting at most 300 seconds for qemu pid (04/20/23 13:07:30) DEBUG: QMP Initializing to /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/.rwfvl5si DEBUG: QMP Connecting to /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/.rwfvl5si QMP connected to QEMU at 04/20/23 13:07:31 and took 1.23 seconds QMP released QEMU at 04/20/23 13:07:31 and took 0.36 seconds from connect DEBUG: qemu started in 1.59 seconds - qemu procces pid is 310476 (04/20/23 13:07:31) DEBUG: qemu cmdline used: /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/work/aarch64-linux/qemu-helper-native/1.0-r1/recipe-sysroot-native/usr/bin/qemu-system-aarch64 -device virtio-net-pci,netdev=net0,mac=52:54:00:12:34:18 -netdev tap,id=net0,ifname=tap11,script=no,downscript=no -object rng-random,filename=/dev/urandom,id=rng0 -device virtio-rng-pci,rng=rng0 -drive id=disk0,file=/home/pokybuild/tmp/core-image-ptest-bc-qemuarm64.ext4.310204,if=none,format=raw -device virtio-blk-pci,drive=disk0 -device qemu-xhci -device usb-tablet -device usb-kbd -machine virt -cpu host -machine gic-version=3 -smp 4 -enable-kvm -m 1024 -device virtio-serial-pci -chardev socket,id=virtcon,port=45513,host=127.0.0.1 -device virtconsole,chardev=virtcon -serial tcp:127.0.0.1:60049 -pidfile /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/pidfile_310143 -S -qmp unix:./.rwfvl5si,server,wait -qmp unix:./.qg3937z2,server,nowait -serial mon:vc -display sdl,show-cursor=on -device virtio-gpu-pci -kernel /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/deploy/images/qemuarm64/Image -append root=/dev/vda rw mem=1024M ip=192.168.7.24::192.168.7.23:255.255.255.0::eth0:off:8.8.8.8 console=ttyAMA0 console=hvc0 printk.time=1 DEBUG: Target IP: 192.168.7.24 DEBUG: Server IP: 192.168.7.23 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: KERNEL: [/home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/deploy/images/qemuarm64/Image] MACHINE: [qemuarm64] FSTYPE: [ext4] ROOTFS: [/home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/deploy/images/qemuarm64/core-image-ptest-bc-qemuarm64.ext4] CONFFILE: [/home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/deploy/images/qemuarm64/core-image-ptest-bc-qemuarm64.qemuboot.conf] runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap0.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap1.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap2.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap3.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap4.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap5.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap6.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap7.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap8.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap9.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Acquiring lockfile /tmp/qemu-tap-locks/tap10.lock failed: [Errno 11] Resource temporarily unavailable runqemu - INFO - Using preconfigured tap device tap11 runqemu - INFO - If this is not intended, touch /tmp/qemu-tap-locks/tap11.skip to make runqemu skip tap11. runqemu - INFO - Network configuration: ip=192.168.7.24::192.168.7.23:255.255.255.0::eth0:off:8.8.8.8 runqemu - INFO - Copying rootfs to /home/pokybuild/tmp/core-image-ptest-bc-qemuarm64.ext4.310204 runqemu - INFO - Copy done in 0.48302412033081055 seconds runqemu - INFO - Running /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/work/aarch64-linux/qemu-helper-native/1.0-r1/recipe-sysroot-native/usr/bin/qemu-system-aarch64 -device virtio-net-pci,netdev=net0,mac=52:54:00:12:34:18 -netdev tap,id=net0,ifname=tap11,script=no,downscript=no -object rng-random,filename=/dev/urandom,id=rng0 -device virtio-rng-pci,rng=rng0 -drive id=disk0,file=/home/pokybuild/tmp/core-image-ptest-bc-qemuarm64.ext4.310204,if=none,format=raw -device virtio-blk-pci,drive=disk0 -device qemu-xhci -device usb-tablet -device usb-kbd -machine virt -cpu host -machine gic-version=3 -smp 4 -enable-kvm -m 1024 -device virtio-serial-pci -chardev socket,id=virtcon,port=45513,host=127.0.0.1 -device virtconsole,chardev=virtcon -serial tcp:127.0.0.1:60049 -pidfile /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/pidfile_310143 -S -qmp unix:./.rwfvl5si,server,wait -qmp unix:./.qg3937z2,server,nowait -serial mon:vc -display sdl,show-cursor=on -device virtio-gpu-pci -kernel /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/deploy/images/qemuarm64/Image -append 'root=/dev/vda rw mem=1024M ip=192.168.7.24::192.168.7.23:255.255.255.0::eth0:off:8.8.8.8 console=ttyAMA0 console=hvc0 printk.time=1' runqemu - INFO - Host uptime: 809813.95 DEBUG: Waiting at most 1500 seconds for login banner (04/20/23 13:07:31) DEBUG: Connection from 127.0.0.1:35080 DEBUG: Reached login banner in 3.86 seconds (04/20/23 13:07:35) DEBUG: Logged in as root in serial console NOTE: test_ping (ping.PingTest) DEBUG: Setting up a 30 second(s) timeout DEBUG: Removed SIGALRM handler NOTE: ... ok NOTE: test_ssh (ssh.SSHTest) DEBUG: Checking if at least one of dropbear, openssh-sshd is installed DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; uname -a DEBUG: Waiting for process output: time: 1681996058.816352, endtime: 1681996358.7939982 DEBUG: Partial data from SSH call: Linux qemuarm64 6.1.20-yocto-standard #1 SMP PREEMPT Sat Mar 18 02:48:04 UTC 2023 aarch64 GNU/Linux DEBUG: Waiting for process output: time: 1681996059.1992764, endtime: 1681996359.199273 DEBUG: Data from SSH call: Linux qemuarm64 6.1.20-yocto-standard #1 SMP PREEMPT Sat Mar 18 02:48:04 UTC 2023 aarch64 GNU/Linux DEBUG: [Command returned '0' after 0.61 seconds] DEBUG: Command: uname -a Status: 0 Output: Linux qemuarm64 6.1.20-yocto-standard #1 SMP PREEMPT Sat Mar 18 02:48:04 UTC 2023 aarch64 GNU/Linux DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; cat /etc/controllerimage DEBUG: Waiting for process output: time: 1681996059.4310539, endtime: 1681996359.401807 DEBUG: Partial data from SSH call: cat: can't open '/etc/controllerimage': No such file or directory DEBUG: Waiting for process output: time: 1681996059.7926762, endtime: 1681996359.792673 DEBUG: Data from SSH call: cat: can't open '/etc/controllerimage': No such file or directory DEBUG: [Command returned '1' after 0.59 seconds] DEBUG: Command: cat /etc/controllerimage Status: 1 Output: cat: can't open '/etc/controllerimage': No such file or directory NOTE: ... ok DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; which LSB_Test.sh DEBUG: Waiting for process output: time: 1681996060.0162675, endtime: 1681996359.996444 DEBUG: Data from SSH call: DEBUG: [Command returned '1' after 0.38 seconds] DEBUG: Command: which LSB_Test.sh Status: 1 Output: NOTE: test_parselogs (parselogs.ParseLogsTest) DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; dmesg > /tmp/dmesg_output.log DEBUG: Waiting for process output: time: 1681996060.404667, endtime: 1681996360.3809054 DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.40 seconds] DEBUG: Command: dmesg > /tmp/dmesg_output.log Status: 0 Output: DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; test -f /var/log/ DEBUG: Waiting for process output: time: 1681996060.7961245, endtime: 1681996360.7831988 DEBUG: Data from SSH call: DEBUG: [Command returned '1' after 0.40 seconds] DEBUG: Command: test -f /var/log/ Status: 1 Output: DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; test -d /var/log/ DEBUG: Waiting for process output: time: 1681996061.1935837, endtime: 1681996361.179577 DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.37 seconds] DEBUG: Command: test -d /var/log/ Status: 0 Output: DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; find /var/log//*.log -maxdepth 1 -type f DEBUG: Waiting for process output: time: 1681996061.5695918, endtime: 1681996361.5534332 DEBUG: Partial data from SSH call: /var/log//postinstall.log DEBUG: Waiting for process output: time: 1681996061.9560943, endtime: 1681996361.9560907 DEBUG: Data from SSH call: /var/log//postinstall.log DEBUG: [Command returned '0' after 0.60 seconds] DEBUG: Command: find /var/log//*.log -maxdepth 1 -type f Status: 0 Output: /var/log//postinstall.log DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; test -f /var/log/dmesg DEBUG: Waiting for process output: time: 1681996062.1851377, endtime: 1681996362.1588485 DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.39 seconds] DEBUG: Command: test -f /var/log/dmesg Status: 0 Output: DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; test -f /tmp/dmesg_output.log DEBUG: Waiting for process output: time: 1681996062.5775397, endtime: 1681996362.5530052 DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.40 seconds] DEBUG: Command: test -f /tmp/dmesg_output.log Status: 0 Output: DEBUG: [Running]$ scp -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR root@192.168.7.24:/var/log//postinstall.log /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/work/qemuarm64-poky-linux/core-image-ptest-bc/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.23 seconds] DEBUG: [Running]$ scp -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR root@192.168.7.24:/var/log/dmesg /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/work/qemuarm64-poky-linux/core-image-ptest-bc/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.23 seconds] DEBUG: [Running]$ scp -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR root@192.168.7.24:/tmp/dmesg_output.log /home/pokybuild/yocto-worker/qemuarm64-ptest/build/build/tmp/work/qemuarm64-poky-linux/core-image-ptest-bc/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.24 seconds] DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; cat /proc/cpuinfo | grep "model name" | head -n1 | awk 'BEGIN{FS=":"}{print $2}' DEBUG: Waiting for process output: time: 1681996063.8097456, endtime: 1681996363.7762218 DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.42 seconds] DEBUG: Command: cat /proc/cpuinfo | grep "model name" | head -n1 | awk 'BEGIN{FS=":"}{print $2}' Status: 0 Output: DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; cat /proc/cpuinfo | grep "cpu cores" | head -n1 | awk {'print $4'} DEBUG: Waiting for process output: time: 1681996064.2173328, endtime: 1681996364.1958323 DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.40 seconds] DEBUG: Command: cat /proc/cpuinfo | grep "cpu cores" | head -n1 | awk {'print $4'} Status: 0 Output: DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; cat /proc/cpuinfo | grep "processor" | wc -l DEBUG: Waiting for process output: time: 1681996064.6158926, endtime: 1681996364.594615 DEBUG: Partial data from SSH call: 4 DEBUG: Waiting for process output: time: 1681996064.9982293, endtime: 1681996364.9982255 DEBUG: Data from SSH call: 4 DEBUG: [Command returned '0' after 0.61 seconds] DEBUG: Command: cat /proc/cpuinfo | grep "processor" | wc -l Status: 0 Output: 4 DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; uname -m DEBUG: Waiting for process output: time: 1681996065.2247827, endtime: 1681996365.2008684 DEBUG: Partial data from SSH call: aarch64 DEBUG: Waiting for process output: time: 1681996065.579741, endtime: 1681996365.5797377 DEBUG: Data from SSH call: aarch64 DEBUG: [Command returned '0' after 0.58 seconds] DEBUG: Command: uname -m Status: 0 Output: aarch64 NOTE: ... ok NOTE: test_ptestrunner_expectfail (ptest.PtestRunnerTest) DEBUG: Checking if at least one of ptest-runner is installed DEBUG: Checking if ptest is in DISTRO_FEATURES or IMAGE_FEATURES DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; which ptest-runner DEBUG: Data from SSH call: /usr/bin/ptest-runner DEBUG: [Command returned '0' after 0.21 seconds] DEBUG: Command: which ptest-runner Status: 0 Output: /usr/bin/ptest-runner DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; ptest-runner -t 450 -d "/usr/lib" DEBUG: Data from SSH call: START: ptest-runner 2023-04-20T13:07 BEGIN: /usr/lib/bc/ptest This tests arrays! 0 1 2 3 4 5 6 7 8 9 1000 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029 0 1 2 3 4 5 6 7 8 9 PASS: bc/array.b This tests arrays! 0 1 2 3 4 5 6 7 8 9 0 0 0 0 0 0 0 0 0 0 --- m1 0 1 2 3 4 5 6 7 8 9 PASS: bc/arrayp.b 0 1 1.41421356237309504880 1.73205080756887729352 2.00000000000000000000 2.23606797749978969640 2.44948974278317809819 2.64575131106459059050 2.82842712474619009760 3.00000000000000000000 0 0 0 1 1.41421356237309504880 1.73205080756887729352 2.00000000000000000000 2.23606797749978969640 2.44948974278317809819 2.64575131106459059050 2.82842712474619009760 3.00000000000000000000 0 PASS: bc/aryprm.b 1.56979432312222174523 1.10514068836449430089 PASS: bc/atan.b Checking e(x) scale = 10 Failed: index = 97 val1 = 1338334719204269500461736408706115029076717.4572136445 val2 = 1338334719204269500461736408706115029076717.45721364460012 Total tests: 200 Total failures: 1 Percent failed: .50 scale = 20 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 30 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 40 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 50 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 60 Total tests: 200 Total failures: 0 Percent failed: 0 Checking l(x) scale = 10 Total tests: 400 Total failures: 0 Percent failed: 0 scale = 20 Total tests: 400 Total failures: 0 Percent failed: 0 scale = 30 Total tests: 400 Total failures: 0 Percent failed: 0 scale = 40 Total tests: 400 Total failures: 0 Percent failed: 0 scale = 50 Failed: index = 8651 val1 = 9.06543020018037429960871963849168770641756864298096 val2 = 9.065430200180374299608719638491687706417568642980970004 Total tests: 400 Total failures: 1 Percent failed: .25 scale = 60 Total tests: 400 Total failures: 0 Percent failed: 0 Checking s(x) scale = 10 Failed: index = .80 val1 = .7173560909 val2 = .71735609089952 Total tests: 624 Total failures: 1 Percent failed: .16 scale = 20 Failed: index = 4.47 val1 = -.97076733665828831221 val2 = -.970767336658288312209921 Total tests: 624 Total failures: 1 Percent failed: .16 scale = 30 Failed: index = 2.19 val1 = .814340892425795914434327645905 val2 = .8143408924257959144343276459049990 Failed: index = 4.31 val1 = -.920128053755623783965712426991 val2 = -.9201280537556237839657124269909938 Total tests: 624 Total failures: 2 Percent failed: .32 scale = 40 Failed: index = 2.36 val1 = .7044107657701761194310307129327036851253 val2 = .70441076577017611943103071293270368512529991 Total tests: 624 Total failures: 1 Percent failed: .16 scale = 50 Failed: index = 2.04 val1 = .89192865095337963517152564858420454473014439859865 val2 = .891928650953379635171525648584204544730144398598649944 Total tests: 624 Total failures: 1 Percent failed: .16 scale = 60 Failed: index = .65 val1 = .6051864057360395603725216786059407063184991873698258835123\ 50 val2 = .6051864057360395603725216786059407063184991873698258835123\ 499974 Failed: index = 1.07 val1 = .8772005042746816103070632577768211866500141475064720919109\ 44 val2 = .8772005042746816103070632577768211866500141475064720919109\ 439950 Total tests: 624 Total failures: 2 Percent failed: .32 Checking a(x) scale = 10 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 20 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 30 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 40 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 50 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 60 Total tests: 200 Total failures: 0 Percent failed: 0 Checking j(n,x) n=0, scale = 10 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 10 Total tests: 300 Total failures: 0 Percent failed: 0 n=0, scale = 20 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 20 Total tests: 300 Total failures: 0 Percent failed: 0 n=0, scale = 30 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 30 Total tests: 300 Total failures: 0 Percent failed: 0 n=0, scale = 40 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 40 Total tests: 300 Total failures: 0 Percent failed: 0 n=0, scale = 50 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 50 Total tests: 300 Total failures: 0 Percent failed: 0 n=0, scale = 60 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 60 Total tests: 300 Total failures: 0 Percent failed: 0 PASS: bc/checklib.b .00673400673400673400 PASS: bc/div.b 99836408603283573660347145562829683495827909199408566065153345558783\ 9427595471.89114392327665123852 PASS: bc/exp.b length(b)= 1406 PASS: bc/fact.b -.03329855487630566800748309439984550659781158351287 -.00648115168876276895858580295786734310987910950934 .04431532933245365649911092813736180550142494873120 -.04084340882273173036919689349257616993289838931589 -.02243471758440192810060521803721671199059663161876 -.01449122706478569886133684583938086724345975237695 PASS: bc/jn.b 87.336544750553108986571247303730247577513016929392162019205681 PASS: bc/ln.b 989901 99990000000000000000000000000000000000000000000000000000000000009899\ 01 PASS: bc/mul.b 301 1479 13186 PASS: bc/raise.b -.00318530179313823899 .11677468864383377454 PASS: bc/sine.b 22.33830 22.3383079036 22.3383079036886766608314514 22.3383079036886766608314514388942891544207 PASS: bc/sqrt.b .9999999999999999999999999999999999999999999999999999999999999999999\ 9999999999999999999999994 1.414213562373095048801688724209698078569671875376948073176679737990\ 73247846210703885038753429 1.732050807568877293527446341505872366942805253810380628055806979451\ 93301690880003708114618672 1.999999999999999999999999999999999999999999999999999999999999999999\ 99999999999999999999999997 2.236067977499789696409173668731276235440618359611525724270897245410\ 52092563780489941441440835 2.449489742783178098197284074705891391965947480656670128432692567250\ 96037745731502653985943308 2.645751311064590590501615753639260425710259183082450180368334459201\ 06882323028362776039288645 2.828427124746190097603377448419396157139343750753896146353359475981\ 46495692421407770077506863 2.999999999999999999999999999999999999999999999999999999999999999999\ 99999999999999999999999998 3.162277660168379331998893544432718533719555139325216826857504852792\ 59443863923822134424810836 PASS: bc/sqrt1.b 70.70360669725413661247 223.38531733307809324159 706.40002831257021404187 2233.83101419959697004192 PASS: bc/sqrt2.b PASS: bc/testfn.b DURATION: 20 END: /usr/lib/bc/ptest 2023-04-20T13:08 STOP: ptest-runner TOTAL: 1 FAIL: 0 DEBUG: [Command returned '0' after 20.04 seconds] DEBUG: Command: ptest-runner -t 450 -d "/usr/lib" Status: 0 Output: START: ptest-runner 2023-04-20T13:07 BEGIN: /usr/lib/bc/ptest This tests arrays! 0 1 2 3 4 5 6 7 8 9 1000 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029 0 1 2 3 4 5 6 7 8 9 PASS: bc/array.b This tests arrays! 0 1 2 3 4 5 6 7 8 9 0 0 0 0 0 0 0 0 0 0 --- m1 0 1 2 3 4 5 6 7 8 9 PASS: bc/arrayp.b 0 1 1.41421356237309504880 1.73205080756887729352 2.00000000000000000000 2.23606797749978969640 2.44948974278317809819 2.64575131106459059050 2.82842712474619009760 3.00000000000000000000 0 0 0 1 1.41421356237309504880 1.73205080756887729352 2.00000000000000000000 2.23606797749978969640 2.44948974278317809819 2.64575131106459059050 2.82842712474619009760 3.00000000000000000000 0 PASS: bc/aryprm.b 1.56979432312222174523 1.10514068836449430089 PASS: bc/atan.b Checking e(x) scale = 10 Failed: index = 97 val1 = 1338334719204269500461736408706115029076717.4572136445 val2 = 1338334719204269500461736408706115029076717.45721364460012 Total tests: 200 Total failures: 1 Percent failed: .50 scale = 20 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 30 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 40 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 50 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 60 Total tests: 200 Total failures: 0 Percent failed: 0 Checking l(x) scale = 10 Total tests: 400 Total failures: 0 Percent failed: 0 scale = 20 Total tests: 400 Total failures: 0 Percent failed: 0 scale = 30 Total tests: 400 Total failures: 0 Percent failed: 0 scale = 40 Total tests: 400 Total failures: 0 Percent failed: 0 scale = 50 Failed: index = 8651 val1 = 9.06543020018037429960871963849168770641756864298096 val2 = 9.065430200180374299608719638491687706417568642980970004 Total tests: 400 Total failures: 1 Percent failed: .25 scale = 60 Total tests: 400 Total failures: 0 Percent failed: 0 Checking s(x) scale = 10 Failed: index = .80 val1 = .7173560909 val2 = .71735609089952 Total tests: 624 Total failures: 1 Percent failed: .16 scale = 20 Failed: index = 4.47 val1 = -.97076733665828831221 val2 = -.970767336658288312209921 Total tests: 624 Total failures: 1 Percent failed: .16 scale = 30 Failed: index = 2.19 val1 = .814340892425795914434327645905 val2 = .8143408924257959144343276459049990 Failed: index = 4.31 val1 = -.920128053755623783965712426991 val2 = -.9201280537556237839657124269909938 Total tests: 624 Total failures: 2 Percent failed: .32 scale = 40 Failed: index = 2.36 val1 = .7044107657701761194310307129327036851253 val2 = .70441076577017611943103071293270368512529991 Total tests: 624 Total failures: 1 Percent failed: .16 scale = 50 Failed: index = 2.04 val1 = .89192865095337963517152564858420454473014439859865 val2 = .891928650953379635171525648584204544730144398598649944 Total tests: 624 Total failures: 1 Percent failed: .16 scale = 60 Failed: index = .65 val1 = .6051864057360395603725216786059407063184991873698258835123\ 50 val2 = .6051864057360395603725216786059407063184991873698258835123\ 499974 Failed: index = 1.07 val1 = .8772005042746816103070632577768211866500141475064720919109\ 44 val2 = .8772005042746816103070632577768211866500141475064720919109\ 439950 Total tests: 624 Total failures: 2 Percent failed: .32 Checking a(x) scale = 10 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 20 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 30 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 40 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 50 Total tests: 200 Total failures: 0 Percent failed: 0 scale = 60 Total tests: 200 Total failures: 0 Percent failed: 0 Checking j(n,x) n=0, scale = 10 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 10 Total tests: 300 Total failures: 0 Percent failed: 0 n=0, scale = 20 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 20 Total tests: 300 Total failures: 0 Percent failed: 0 n=0, scale = 30 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 30 Total tests: 300 Total failures: 0 Percent failed: 0 n=0, scale = 40 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 40 Total tests: 300 Total failures: 0 Percent failed: 0 n=0, scale = 50 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 50 Total tests: 300 Total failures: 0 Percent failed: 0 n=0, scale = 60 Total tests: 300 Total failures: 0 Percent failed: 0 n=1, scale = 60 Total tests: 300 Total failures: 0 Percent failed: 0 PASS: bc/checklib.b .00673400673400673400 PASS: bc/div.b 99836408603283573660347145562829683495827909199408566065153345558783\ 9427595471.89114392327665123852 PASS: bc/exp.b length(b)= 1406 PASS: bc/fact.b -.03329855487630566800748309439984550659781158351287 -.00648115168876276895858580295786734310987910950934 .04431532933245365649911092813736180550142494873120 -.04084340882273173036919689349257616993289838931589 -.02243471758440192810060521803721671199059663161876 -.01449122706478569886133684583938086724345975237695 PASS: bc/jn.b 87.336544750553108986571247303730247577513016929392162019205681 PASS: bc/ln.b 989901 99990000000000000000000000000000000000000000000000000000000000009899\ 01 PASS: bc/mul.b 301 1479 13186 PASS: bc/raise.b -.00318530179313823899 .11677468864383377454 PASS: bc/sine.b 22.33830 22.3383079036 22.3383079036886766608314514 22.3383079036886766608314514388942891544207 PASS: bc/sqrt.b .9999999999999999999999999999999999999999999999999999999999999999999\ 9999999999999999999999994 1.414213562373095048801688724209698078569671875376948073176679737990\ 73247846210703885038753429 1.732050807568877293527446341505872366942805253810380628055806979451\ 93301690880003708114618672 1.999999999999999999999999999999999999999999999999999999999999999999\ 99999999999999999999999997 2.236067977499789696409173668731276235440618359611525724270897245410\ 52092563780489941441440835 2.449489742783178098197284074705891391965947480656670128432692567250\ 96037745731502653985943308 2.645751311064590590501615753639260425710259183082450180368334459201\ 06882323028362776039288645 2.828427124746190097603377448419396157139343750753896146353359475981\ 46495692421407770077506863 2.999999999999999999999999999999999999999999999999999999999999999999\ 99999999999999999999999998 3.162277660168379331998893544432718533719555139325216826857504852792\ 59443863923822134424810836 PASS: bc/sqrt1.b 70.70360669725413661247 223.38531733307809324159 706.40002831257021404187 2233.83101419959697004192 PASS: bc/sqrt2.b PASS: bc/testfn.b DURATION: 20 END: /usr/lib/bc/ptest 2023-04-20T13:08 STOP: ptest-runner TOTAL: 1 FAIL: 0 DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.24 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; dmesg | grep "Killed process" DEBUG: Data from SSH call: DEBUG: [Command returned '1' after 0.23 seconds] DEBUG: Command: dmesg | grep "Killed process" Status: 1 Output: NOTE: ... unexpected success NOTE: test_ptestrunner_expectsuccess (ptest.PtestRunnerTest) DEBUG: Checking if at least one of ptest-runner is installed DEBUG: Checking if ptest is in DISTRO_FEATURES or IMAGE_FEATURES NOTE: ... skipped 'Cannot run ptests without @expectedFailure as ptests are expected to fail' Cannot run ptests without @expectedFailure as ptests are expected to fail NOTE: ---------------------------------------------------------------------- NOTE: Ran 5 tests in 27.614s NOTE: OK NOTE: (skipped=1, unexpected successes=1) DEBUG: Stopping logging thread DEBUG: Stop event received DEBUG: Tearing down logging thread DEBUG: Sending SIGTERM to runqemu Output from runqemu: runqemu - INFO - Received signal: 15 runqemu - INFO - Cleaning up runqemu - INFO - Host uptime: 809854.41 runqemu - INFO - Removing /home/pokybuild/tmp/core-image-ptest-bc-qemuarm64.ext4.310204 tput: No value for $TERM and no -T specified RESULTS: RESULTS - parselogs.ParseLogsTest.test_parselogs: PASSED (5.40s) RESULTS - ping.PingTest.test_ping: PASSED (0.14s) RESULTS - ptest.PtestRunnerTest.test_ptestrunner_expectfail: PASSED (20.48s) RESULTS - ssh.SSHTest.test_ssh: PASSED (1.20s) RESULTS - ptest.PtestRunnerTest.test_ptestrunner_expectsuccess: SKIPPED (0.00s) SUMMARY: core-image-ptest-bc () - Ran 5 tests in 27.616s core-image-ptest-bc - OK - All required tests passed (successes=3, skipped=1, failures=0, errors=0) /home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/utils/qemurunner.py:486: ResourceWarning: unclosed self.server_socket = qemusock ResourceWarning: Enable tracemalloc to get the object allocation traceback DEBUG: Python function do_testimage finished