DEBUG: Executing python function extend_recipe_sysroot NOTE: Direct dependencies are ['/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/meta/recipes-devtools/qemu/qemu-helper-native_1.0.bb:do_populate_sysroot', '/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/meta/recipes-devtools/qemu/qemu-native_7.2.0.bb:do_populate_sysroot', '/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/meta/recipes-devtools/qemu/qemu-system-native_7.2.0.bb:do_populate_sysroot', 'virtual:native:/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/meta/recipes-devtools/createrepo-c/createrepo-c_0.20.1.bb:do_populate_sysroot', 'virtual:native:/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/meta/recipes-devtools/dnf/dnf_4.14.0.bb:do_populate_sysroot', 'virtual:native:/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/meta/recipes-devtools/pseudo/pseudo_git.bb:do_populate_sysroot', 'virtual:native:/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/meta/recipes-devtools/unfs3/unfs3_git.bb:do_populate_sysroot', 'virtual:native:/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/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', 'python3-native', 'zlib-native', 'file-native', 'expat-native', 'xz-native', 'sqlite3-native', 'curl-native', 'openssl-native', 'libxml2-native', 'cmake-native', 'glib-2.0-native', 'rpm-native', 'libcomps-native', 'python3-iniparse-native', 'libdnf-native', 'gettext-minimal-native', 'librepo-native', 'libtool-native', 'flex-native', 'libtirpc-native', 'texinfo-dummy-native', 'dtc-native', 'virglrenderer-native', 'alsa-lib-native', 'pixman-native', 'libepoxy-native', 'libsdl2-native', 'libslirp-native', 'libffi-native', 'readline-native', 'gdbm-native', 'ncurses-native', 'bzip2-native', 'util-linux-libuuid-native', 'libnsl2-native', 'perl-native', 'zstd-native', 'gettext-native', 'libpcre2-native', 'util-linux-native', 'lua-native', 'libgcrypt-native', 'elfutils-native', 'popt-native', 'libcheck-native', 'python3-installer-native', 'python3-six-native', 'python3-build-native', 'python3-setuptools-native', 'python3-wheel-native', 'swig-native', 'json-c-native', 'gobject-introspection-native', 'libmodulemd-native', 'libsolv-native', 'attr-native', 'gpgme-native', 'm4-native', 'mesa-native', 'libdrm-native', 'libx11-native', 'libxrender-native', 'libxext-native', 'libxrandr-native', 'make-native', 'libcap-ng-native', 'libgpg-error-native', 'libcap-native', 'libmicrohttpd-native', 'libarchive-native', 'python3-flit-core-native', 'python3-pyproject-hooks-native', 'python3-packaging-native', 'libyaml-native', 'libassuan-native', 'gnu-config-native', 'libxfixes-native', 'python3-mako-native', 'xrandr-native', 'wayland-native', 'libxxf86vm-native', 'xorgproto-native', 'libxshmfence-native', 'llvm-native', 'makedepend-native', 'wayland-protocols-native', 'chrpath-native', 'libxdamage-native', 'libpciaccess-native', 'libpthread-stubs-native', 'xtrans-native', 'util-macros-native', 'libxcb-native', 'gnutls-native', 'unzip-native', 'python3-markupsafe-native', 'python3-pygments-native', 'libedit-native', 'libxdmcp-native', 'xcb-proto-native', 'libxau-native', 'gmp-native', 'libidn2-native', 'libunistring-native', 'nettle-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/qemux86-64-ptest-fast/build/build/tmp/.haivhbqx DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:37575 DEBUG: Created listening socket for qemu serial console on: 127.0.0.1:41231 DEBUG: launchcmd=runqemu snapshot kvm qemux86-64 /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/tmp/deploy/images/qemux86-64/core-image-ptest-libconvert-asn1-perl-qemux86-64.ext4 tcpserial=37575:41231 bootparams=" printk.time=1" qemuparams="-pidfile /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/pidfile_592406 -S -qmp unix:./.qvzqcmyf,server,wait -qmp unix:./.haivhbqx,server,nowait" DEBUG: runqemu started, pid is 592445 DEBUG: waiting at most 300 seconds for qemu pid (04/28/23 02:58:20) DEBUG: QMP Initializing to /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/tmp/.qvzqcmyf DEBUG: QMP Connecting to /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/tmp/.qvzqcmyf QMP connected to QEMU at 04/28/23 02:58:21 and took 1.11 seconds QMP released QEMU at 04/28/23 02:58:22 and took 0.13 seconds from connect DEBUG: qemu started in 1.23 seconds - qemu procces pid is 592482 (04/28/23 02:58:22) DEBUG: qemu cmdline used: /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/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: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 file=/home/pokybuild/tmp/core-image-ptest-libconvert-asn1-perl-qemux86-64.ext4.592447,if=virtio,format=raw -usb -device usb-tablet -usb -device usb-kbd -cpu IvyBridge -machine q35,i8042=off -smp 4 -enable-kvm -m 1024 -serial tcp:127.0.0.1:37575 -serial tcp:127.0.0.1:41231 -pidfile /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/pidfile_592406 -S -qmp unix:./.qvzqcmyf,server,wait -qmp unix:./.haivhbqx,server,nowait -serial mon:vc -device virtio-vga -display sdl,show-cursor=on -kernel /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/tmp/deploy/images/qemux86-64/bzImage -append root=/dev/vda rw ip=192.168.7.24::192.168.7.23:255.255.255.0::eth0:off:8.8.8.8 console=ttyS0 console=ttyS1 oprofile.timer=1 tsc=reliable no_timer_check rcupdate.rcu_expedited=1 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 - Using /home/pokybuild/bin/runqemu-renice to renice runqemu - INFO - Continuing with the following parameters: KERNEL: [/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/tmp/deploy/images/qemux86-64/bzImage] MACHINE: [qemux86-64] FSTYPE: [ext4] ROOTFS: [/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/tmp/deploy/images/qemux86-64/core-image-ptest-libconvert-asn1-perl-qemux86-64.ext4] CONFFILE: [/home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/tmp/deploy/images/qemux86-64/core-image-ptest-libconvert-asn1-perl-qemux86-64.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-libconvert-asn1-perl-qemux86-64.ext4.592447 runqemu - INFO - Copy done in 0.43449854850769043 seconds runqemu - INFO - Running /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/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: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 file=/home/pokybuild/tmp/core-image-ptest-libconvert-asn1-perl-qemux86-64.ext4.592447,if=virtio,format=raw -usb -device usb-tablet -usb -device usb-kbd -cpu IvyBridge -machine q35,i8042=off -smp 4 -enable-kvm -m 1024 -serial tcp:127.0.0.1:37575 -serial tcp:127.0.0.1:41231 -pidfile /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/pidfile_592406 -S -qmp unix:./.qvzqcmyf,server,wait -qmp unix:./.haivhbqx,server,nowait -serial mon:vc -device virtio-vga -display sdl,show-cursor=on -kernel /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/tmp/deploy/images/qemux86-64/bzImage -append 'root=/dev/vda rw ip=192.168.7.24::192.168.7.23:255.255.255.0::eth0:off:8.8.8.8 console=ttyS0 console=ttyS1 oprofile.timer=1 tsc=reliable no_timer_check rcupdate.rcu_expedited=1 printk.time=1' runqemu - INFO - Host uptime: 283110.28 DEBUG: Waiting at most 1500 seconds for login banner (04/28/23 02:58:22) DEBUG: Connection from 127.0.0.1:56284 DEBUG: Reached login banner in 3.33 seconds (04/28/23 02:58:25) 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: 1682650708.5249367, endtime: 1682651008.5210774 DEBUG: Partial data from SSH call: Linux qemux86-64 6.1.25-yocto-standard #1 SMP PREEMPT_DYNAMIC Fri Apr 21 14:37:42 UTC 2023 x86_64 GNU/Linux DEBUG: Waiting for process output: time: 1682650708.8755784, endtime: 1682651008.8755763 DEBUG: Data from SSH call: Linux qemux86-64 6.1.25-yocto-standard #1 SMP PREEMPT_DYNAMIC Fri Apr 21 14:37:42 UTC 2023 x86_64 GNU/Linux DEBUG: [Command returned '0' after 0.56 seconds] DEBUG: Command: uname -a Status: 0 Output: Linux qemux86-64 6.1.25-yocto-standard #1 SMP PREEMPT_DYNAMIC Fri Apr 21 14:37:42 UTC 2023 x86_64 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: 1682650709.0819008, endtime: 1682651009.0775142 DEBUG: Partial data from SSH call: cat: can't open '/etc/controllerimage': No such file or directory DEBUG: Waiting for process output: time: 1682650709.4145043, endtime: 1682651009.414502 DEBUG: Data from SSH call: cat: can't open '/etc/controllerimage': No such file or directory DEBUG: [Command returned '1' after 0.54 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: 1682650709.621562, endtime: 1682651009.6170852 DEBUG: Data from SSH call: DEBUG: [Command returned '1' after 0.34 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: 1682650709.962522, endtime: 1682651009.958004 DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.34 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: 1682650710.3054113, endtime: 1682651010.3012683 DEBUG: Data from SSH call: DEBUG: [Command returned '1' after 0.34 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: 1682650710.6496322, endtime: 1682651010.6450045 DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.35 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: 1682650711.0024412, endtime: 1682651010.9982967 DEBUG: Partial data from SSH call: find: /var/log//*.log: No such file or directory DEBUG: Waiting for process output: time: 1682650711.3376234, endtime: 1682651011.3376212 DEBUG: Data from SSH call: find: /var/log//*.log: No such file or directory DEBUG: [Command returned '1' after 0.54 seconds] DEBUG: Command: find /var/log//*.log -maxdepth 1 -type f Status: 1 Output: find: /var/log//*.log: No such file or directory 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: 1682650711.542798, endtime: 1682651011.5391846 DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.33 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: 1682650711.8756351, endtime: 1682651011.871477 DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.34 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/dmesg /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/build/build/tmp/work/qemux86_64-poky-linux/core-image-ptest-libconvert-asn1-perl/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.15 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/qemux86-64-ptest-fast/build/build/tmp/work/qemux86_64-poky-linux/core-image-ptest-libconvert-asn1-perl/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.14 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: 1682650712.5330544, endtime: 1682651012.5287964 DEBUG: Partial data from SSH call: Intel Xeon E3-12xx v2 (Ivy Bridge) DEBUG: Waiting for process output: time: 1682650712.8594892, endtime: 1682651012.8594866 DEBUG: Data from SSH call: Intel Xeon E3-12xx v2 (Ivy Bridge) DEBUG: [Command returned '0' after 0.53 seconds] DEBUG: Command: cat /proc/cpuinfo | grep "model name" | head -n1 | awk 'BEGIN{FS=":"}{print $2}' Status: 0 Output: Intel Xeon E3-12xx v2 (Ivy Bridge) 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: 1682650713.0655022, endtime: 1682651013.061765 DEBUG: Partial data from SSH call: 4 DEBUG: Waiting for process output: time: 1682650713.3968637, endtime: 1682651013.396861 DEBUG: Data from SSH call: 4 DEBUG: [Command returned '0' after 0.54 seconds] DEBUG: Command: cat /proc/cpuinfo | grep "cpu cores" | head -n1 | awk {'print $4'} 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; cat /proc/cpuinfo | grep "processor" | wc -l DEBUG: Waiting for process output: time: 1682650713.603016, endtime: 1682651013.5988016 DEBUG: Partial data from SSH call: 4 DEBUG: Waiting for process output: time: 1682650713.944067, endtime: 1682651013.9440641 DEBUG: Data from SSH call: 4 DEBUG: [Command returned '0' after 0.55 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: 1682650714.1490626, endtime: 1682651014.145277 DEBUG: Partial data from SSH call: x86_64 DEBUG: Waiting for process output: time: 1682650714.497931, endtime: 1682651014.4979284 DEBUG: Data from SSH call: x86_64 DEBUG: [Command returned '0' after 0.55 seconds] DEBUG: Command: uname -m Status: 0 Output: x86_64 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.14 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-28T02:58 BEGIN: /usr/lib/libconvert-asn1-perl/ptest 1..35 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 ok 26 ok 27 ok 28 ok 29 ok 30 ok 31 ok 32 ok 33 ok 34 ok 35 PASS: t/03seqof 1..24 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 PASS: t/05time 1..18 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 PASS: t/12der 1..27 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 ok 26 ok 27 PASS: t/16extset 1..11 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 PASS: t/07io 1..186 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 # NULL ok 23 ok 24 ok 25 ok 26 # BOOLEAN 0 ok 27 ok 28 ok 29 ok 30 # BOOLEAN 1 ok 31 ok 32 ok 33 ok 34 # BOOLEAN -99 ok 35 ok 36 ok 37 ok 38 # INTEGER -457 ok 39 ok 40 ok 41 ok 42 # INTEGER -1073741824 ok 43 ok 44 ok 45 ok 46 # INTEGER 0 ok 47 ok 48 ok 49 ok 50 # INTEGER 128 ok 51 ok 52 ok 53 ok 54 # INTEGER -128 ok 55 ok 56 ok 57 ok 58 # INTEGER 6715289 ok 59 ok 60 ok 61 ok 62 # INTEGER -255 ok 63 ok 64 ok 65 ok 66 # INTEGER 1073741824 ok 67 ok 68 ok 69 ok 70 ok 71 ok 72 ok 73 ok 74 # STRING 'A string' ok 75 ok 76 ok 77 ok 78 # STRING '' ok 79 ok 80 ok 81 ok 82 # OBJECT_ID 1.2.3.4.5 ok 83 ok 84 ok 85 ok 86 # OBJECT_ID 0.0.17.773.1.1.1 ok 87 ok 88 ok 89 ok 90 # OBJECT_ID 2.99999.99 ok 91 ok 92 ok 93 ok 94 # OBJECT_ID 2.5.457 ok 95 ok 96 ok 97 ok 98 # ENUM -99 ok 99 ok 100 ok 101 ok 102 # ENUM 0 ok 103 ok 104 ok 105 ok 106 # ENUM 6573456 ok 107 ok 108 ok 109 ok 110 # BIT STRING 011011111101110111000000 7 ok 111 ok 112 ok 113 ok 114 ok 115 # BIT STRING 00110011 3 ok 116 ok 117 ok 118 ok 119 ok 120 # BIT STRING 00000000 1 ok 121 ok 122 ok 123 ok 124 ok 125 # BIT STRING 011011100101110111000000 21 ok 126 ok 127 ok 128 ok 129 ok 130 # REAL 1.5 ok 131 ok 132 ok 133 ok 134 # REAL 0 ok 135 ok 136 ok 137 ok 138 # REAL Inf ok 139 ok 140 ok 141 ok 142 # REAL -5.5 ok 143 ok 144 ok 145 ok 146 # REAL -Inf ok 147 ok 148 ok 149 ok 150 # RELATIVE-OID 0.0.17.773.1.1.1 ok 151 ok 152 ok 153 ok 154 # RELATIVE-OID 2.5.457 ok 155 ok 156 ok 157 ok 158 # RELATIVE-OID 1.2.3.4.5 ok 159 ok 160 ok 161 ok 162 # BCDString 0 ok 163 ok 164 ok 165 ok 166 # BCDString 564 ok 167 ok 168 ok 169 ok 170 # BCDString 123456789123456789 ok 171 ok 172 ok 173 ok 174 # BCDString 12345678 ok 175 ok 176 ok 177 ok 178 # BCDString -1 ok 179 ok 180 ok 181 ok 182 # BCDString 2.2 ok 183 ok 184 ok 185 ok 186 PASS: t/00prim 1..26 ok 1 ok 2 ok 3 # t/aj.cer ok 4 ok 5 ok 6 # t/aj2.cer ok 7 ok 8 ok 9 # t/allianz_root.cer ok 10 ok 11 ok 12 # t/dsacert.der ok 13 ok 14 # t/new_root_ca.cer ok 15 ok 16 # t/pgpextension.der ok 17 ok 18 ok 19 # t/subca_2.cer ok 20 ok 21 ok 22 # t/telesec_799972029.crt ok 23 ok 24 # t/verisign.der ok 25 ok 26 PASS: t/x509 1..4 ok 1 ok 2 ok 3 ok 4 PASS: t/11explicit 1..18 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 PASS: t/02seq 1..21 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 PASS: t/01tag 1..7 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 PASS: t/11indef 1..67 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 ok 26 ok 27 ok 28 ok 29 ok 30 ok 31 ok 32 ok 33 ok 34 ok 35 # INTEGER -4294967296 ok 36 ok 37 ok 38 ok 39 # INTEGER 1073741824 ok 40 ok 41 ok 42 ok 43 # INTEGER -2147483648 ok 44 ok 45 ok 46 ok 47 # INTEGER 4294967296 ok 48 ok 49 ok 50 ok 51 # INTEGER 2147483648 ok 52 ok 53 ok 54 ok 55 # INTEGER -1073741824 ok 56 ok 57 ok 58 ok 59 # BCDString -1073741824 ok 60 ok 61 ok 62 ok 63 # BCDString 1073741824 ok 64 ok 65 ok 66 ok 67 PASS: t/06bigint 1..19 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 PASS: t/17extchoice 1..2 ok 1 ok 2 PASS: t/19issue14 1..13 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 PASS: t/08set 1..4 ok 1 ok 2 ok 3 ok 4 PASS: t/09contr 1..12 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 PASS: t/13utf8 1..10 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 PASS: t/10choice 1..25 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 PASS: t/18tagdefault 1..16 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 PASS: t/04opt 1..27 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 ok 26 ok 27 PASS: t/15extseq 1..2 ok 1 ok 2 PASS: t/99misc 1..21 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 PASS: t/14any DURATION: 2 END: /usr/lib/libconvert-asn1-perl/ptest 2023-04-28T02:58 STOP: ptest-runner TOTAL: 1 FAIL: 0 DEBUG: [Command returned '0' after 1.41 seconds] DEBUG: Command: ptest-runner -t 450 -d "/usr/lib" Status: 0 Output: START: ptest-runner 2023-04-28T02:58 BEGIN: /usr/lib/libconvert-asn1-perl/ptest 1..35 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 ok 26 ok 27 ok 28 ok 29 ok 30 ok 31 ok 32 ok 33 ok 34 ok 35 PASS: t/03seqof 1..24 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 PASS: t/05time 1..18 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 PASS: t/12der 1..27 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 ok 26 ok 27 PASS: t/16extset 1..11 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 PASS: t/07io 1..186 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 # NULL ok 23 ok 24 ok 25 ok 26 # BOOLEAN 0 ok 27 ok 28 ok 29 ok 30 # BOOLEAN 1 ok 31 ok 32 ok 33 ok 34 # BOOLEAN -99 ok 35 ok 36 ok 37 ok 38 # INTEGER -457 ok 39 ok 40 ok 41 ok 42 # INTEGER -1073741824 ok 43 ok 44 ok 45 ok 46 # INTEGER 0 ok 47 ok 48 ok 49 ok 50 # INTEGER 128 ok 51 ok 52 ok 53 ok 54 # INTEGER -128 ok 55 ok 56 ok 57 ok 58 # INTEGER 6715289 ok 59 ok 60 ok 61 ok 62 # INTEGER -255 ok 63 ok 64 ok 65 ok 66 # INTEGER 1073741824 ok 67 ok 68 ok 69 ok 70 ok 71 ok 72 ok 73 ok 74 # STRING 'A string' ok 75 ok 76 ok 77 ok 78 # STRING '' ok 79 ok 80 ok 81 ok 82 # OBJECT_ID 1.2.3.4.5 ok 83 ok 84 ok 85 ok 86 # OBJECT_ID 0.0.17.773.1.1.1 ok 87 ok 88 ok 89 ok 90 # OBJECT_ID 2.99999.99 ok 91 ok 92 ok 93 ok 94 # OBJECT_ID 2.5.457 ok 95 ok 96 ok 97 ok 98 # ENUM -99 ok 99 ok 100 ok 101 ok 102 # ENUM 0 ok 103 ok 104 ok 105 ok 106 # ENUM 6573456 ok 107 ok 108 ok 109 ok 110 # BIT STRING 011011111101110111000000 7 ok 111 ok 112 ok 113 ok 114 ok 115 # BIT STRING 00110011 3 ok 116 ok 117 ok 118 ok 119 ok 120 # BIT STRING 00000000 1 ok 121 ok 122 ok 123 ok 124 ok 125 # BIT STRING 011011100101110111000000 21 ok 126 ok 127 ok 128 ok 129 ok 130 # REAL 1.5 ok 131 ok 132 ok 133 ok 134 # REAL 0 ok 135 ok 136 ok 137 ok 138 # REAL Inf ok 139 ok 140 ok 141 ok 142 # REAL -5.5 ok 143 ok 144 ok 145 ok 146 # REAL -Inf ok 147 ok 148 ok 149 ok 150 # RELATIVE-OID 0.0.17.773.1.1.1 ok 151 ok 152 ok 153 ok 154 # RELATIVE-OID 2.5.457 ok 155 ok 156 ok 157 ok 158 # RELATIVE-OID 1.2.3.4.5 ok 159 ok 160 ok 161 ok 162 # BCDString 0 ok 163 ok 164 ok 165 ok 166 # BCDString 564 ok 167 ok 168 ok 169 ok 170 # BCDString 123456789123456789 ok 171 ok 172 ok 173 ok 174 # BCDString 12345678 ok 175 ok 176 ok 177 ok 178 # BCDString -1 ok 179 ok 180 ok 181 ok 182 # BCDString 2.2 ok 183 ok 184 ok 185 ok 186 PASS: t/00prim 1..26 ok 1 ok 2 ok 3 # t/aj.cer ok 4 ok 5 ok 6 # t/aj2.cer ok 7 ok 8 ok 9 # t/allianz_root.cer ok 10 ok 11 ok 12 # t/dsacert.der ok 13 ok 14 # t/new_root_ca.cer ok 15 ok 16 # t/pgpextension.der ok 17 ok 18 ok 19 # t/subca_2.cer ok 20 ok 21 ok 22 # t/telesec_799972029.crt ok 23 ok 24 # t/verisign.der ok 25 ok 26 PASS: t/x509 1..4 ok 1 ok 2 ok 3 ok 4 PASS: t/11explicit 1..18 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 PASS: t/02seq 1..21 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 PASS: t/01tag 1..7 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 PASS: t/11indef 1..67 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 ok 26 ok 27 ok 28 ok 29 ok 30 ok 31 ok 32 ok 33 ok 34 ok 35 # INTEGER -4294967296 ok 36 ok 37 ok 38 ok 39 # INTEGER 1073741824 ok 40 ok 41 ok 42 ok 43 # INTEGER -2147483648 ok 44 ok 45 ok 46 ok 47 # INTEGER 4294967296 ok 48 ok 49 ok 50 ok 51 # INTEGER 2147483648 ok 52 ok 53 ok 54 ok 55 # INTEGER -1073741824 ok 56 ok 57 ok 58 ok 59 # BCDString -1073741824 ok 60 ok 61 ok 62 ok 63 # BCDString 1073741824 ok 64 ok 65 ok 66 ok 67 PASS: t/06bigint 1..19 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 PASS: t/17extchoice 1..2 ok 1 ok 2 PASS: t/19issue14 1..13 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 PASS: t/08set 1..4 ok 1 ok 2 ok 3 ok 4 PASS: t/09contr 1..12 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 PASS: t/13utf8 1..10 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 PASS: t/10choice 1..25 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 PASS: t/18tagdefault 1..16 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 PASS: t/04opt 1..27 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 ok 22 ok 23 ok 24 ok 25 ok 26 ok 27 PASS: t/15extseq 1..2 ok 1 ok 2 PASS: t/99misc 1..21 ok 1 ok 2 ok 3 ok 4 ok 5 ok 6 ok 7 ok 8 ok 9 ok 10 ok 11 ok 12 ok 13 ok 14 ok 15 ok 16 ok 17 ok 18 ok 19 ok 20 ok 21 PASS: t/14any DURATION: 2 END: /usr/lib/libconvert-asn1-perl/ptest 2023-04-28T02:58 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.14 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 7.906s 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: 283130.33 runqemu - INFO - Removing /home/pokybuild/tmp/core-image-ptest-libconvert-asn1-perl-qemux86-64.ext4.592447 tput: No value for $TERM and no -T specified RESULTS: RESULTS - parselogs.ParseLogsTest.test_parselogs: PASSED (4.74s) RESULTS - ping.PingTest.test_ping: PASSED (0.03s) RESULTS - ptest.PtestRunnerTest.test_ptestrunner_expectfail: PASSED (1.69s) RESULTS - ssh.SSHTest.test_ssh: PASSED (1.10s) RESULTS - ptest.PtestRunnerTest.test_ptestrunner_expectsuccess: SKIPPED (0.00s) SUMMARY: core-image-ptest-libconvert-asn1-perl () - Ran 5 tests in 7.906s core-image-ptest-libconvert-asn1-perl - OK - All required tests passed (successes=3, skipped=1, failures=0, errors=0) /home/pokybuild/yocto-worker/qemux86-64-ptest-fast/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