| Summary: | syslog test failure | ||
|---|---|---|---|
| Product: | [QA/Testing] Runtime Testing | Reporter: | Richard Purdie <richard.purdie> |
| Component: | testimage | Assignee: | Apoorv <apoorv.sangal> |
| Status: | RESOLVED DUPLICATE | QA Contact: | |
| Severity: | normal | ||
| Priority: | Undecided | CC: | jon.mason, randy.macleod |
| Version: | unspecified | ||
| Target Milestone: | --- | ||
| Hardware: | x86 | ||
| OS: | Multiple | ||
| Whiteboard: | |||
| OS type for building Yocto: | --- | Type of Regression: | --- |
| Verified: | Documentation change: | No (bug/feature does not impact docs) | |
May or may not be related to 13379 (process didn't restart fast enough?) |
Detailed logs from the autobuilder: pokybuild@debian9-ty-2:~/yocto-worker/musl-qemux86-64/build/build-renamed/tmp/work/qemux86_64-poky-linux-musl/core-image-sato-sdk/1.0-r0/temp$ cat log.do_testimage | grep var/log/test -C 100 root 80 2 0 06:59 ? 00:00:00 [kworker/0:2-events] root 81 2 0 06:59 ? 00:00:00 [nvme-wq] root 82 2 0 06:59 ? 00:00:00 [nvme-reset-wq] root 83 2 0 06:59 ? 00:00:00 [nvme-delete-wq] root 84 2 0 06:59 ? 00:00:00 [dm_bufio_cache] root 85 2 0 06:59 ? 00:00:00 [kworker/0:3-rcu_gp] root 86 2 0 06:59 ? 00:00:00 [ipv6_addrconf] root 92 2 0 06:59 ? 00:00:00 [jbd2/vda-8] root 93 2 0 06:59 ? 00:00:00 [ext4-rsv-conver] root 117 1 0 06:59 ? 00:00:00 /sbin/udevd -d root 330 2 0 06:59 ? 00:00:00 [kworker/u2:2-events_unbound] root 341 1 0 06:59 ? 00:00:00 /sbin/v86d message+ 502 1 0 06:59 ? 00:00:00 /usr/bin/dbus-daemon --system root 512 1 0 06:59 ? 00:00:00 /usr/sbin/connmand root 518 1 0 06:59 ? 00:00:00 /usr/sbin/wpa_supplicant -u root 548 1 0 06:59 ? 00:00:00 /usr/sbin/sshd root 554 1 0 06:59 ? 00:00:00 xinit /etc/X11/Xsession -- /usr/bin/Xorg :0 -br -pn root 560 554 0 06:59 tty2 00:00:00 /usr/bin/Xorg :0 -br -pn rpc 564 1 0 06:59 ? 00:00:00 /usr/sbin/rpcbind rpcuser 567 1 0 06:59 ? 00:00:00 /usr/sbin/rpc.statd root 573 1 0 06:59 ? 00:00:00 /usr/sbin/atd -f root 577 1 0 06:59 ? 00:00:00 /usr/libexec/bluetooth/bluetoothd root 586 554 0 06:59 ? 00:00:00 matchbox-window-manager -theme Sato -use_cursor no root 591 1 0 06:59 ? 00:00:00 dbus-launch --sh-syntax --exit-with-session root 592 1 0 06:59 ? 00:00:00 /usr/bin/dbus-daemon --syslog --fork --print-pid 5 --print-address 7 --session root 613 586 0 06:59 ? 00:00:00 /usr/libexec/at-spi-bus-launcher --launch-immediately root 617 586 0 06:59 ? 00:00:00 connman-applet root 626 613 0 06:59 ? 00:00:00 /usr/bin/dbus-daemon --config-file=/usr/share/defaults/at-spi2/accessibility.conf --nofork --print-address 3 root 654 586 0 06:59 ? 00:00:00 matchbox-desktop root 655 586 0 06:59 ? 00:00:00 matchbox-panel --start-applets showdesktop,windowselector --end-applets clock,,systray,startup-notify,notify root 656 1 0 06:59 ? 00:00:00 /usr/sbin/console-kit-daemon --no-daemon root 720 1 0 06:59 ? 00:00:00 /usr/libexec/gconfd-2 root 722 1 0 06:59 ? 00:00:00 /usr/bin/settings-daemon root 725 1 0 06:59 ? 00:00:00 /usr/libexec/at-spi2-registryd --use-gnome-session root 733 2 0 06:59 ? 00:00:00 [kworker/u3:1] root 734 2 0 06:59 ? 00:00:00 [lockd] root 736 2 0 06:59 ? 00:00:00 [nfsd] root 737 2 0 06:59 ? 00:00:00 [nfsd] root 738 2 0 06:59 ? 00:00:00 [nfsd] root 739 2 0 06:59 ? 00:00:00 [nfsd] root 740 2 0 06:59 ? 00:00:00 [nfsd] root 741 2 0 06:59 ? 00:00:00 [nfsd] root 742 2 0 06:59 ? 00:00:00 [nfsd] root 743 2 0 06:59 ? 00:00:00 [nfsd] root 747 1 0 06:59 ? 00:00:00 /usr/sbin/rpc.mountd root 755 1 0 06:59 ? 00:00:00 /sbin/syslogd -n -O /var/log/messages root 756 1 0 06:59 ? 00:00:00 /sbin/klogd -n avahi 761 1 0 06:59 ? 00:00:00 avahi-daemon: running [qemux86-64.local] avahi 762 761 0 06:59 ? 00:00:00 avahi-daemon: chroot helper root 775 1 0 06:59 ? 00:00:00 /usr/sbin/ofonod root 779 1 0 06:59 ? 00:00:00 /usr/sbin/crond root 789 1 0 06:59 ? 00:00:00 /usr/sbin/tcf-agent -d -L- -l0 root 794 1 0 06:59 ? 00:00:00 /bin/sh /bin/start_getty 115200 ttyS0 vt102 root 795 1 0 06:59 ? 00:00:00 /bin/sh /bin/start_getty 115200 ttyS1 vt102 root 796 1 0 06:59 tty1 00:00:00 /sbin/getty 38400 tty1 root 827 794 0 06:59 ttyS0 00:00:00 /sbin/getty -L 115200 ttyS0 vt102 root 832 795 0 06:59 ttyS1 00:00:00 -sh root 23372 117 0 07:01 ? 00:00:00 /sbin/udevd -d root 23426 548 0 07:01 ? 00:00:00 sshd: root@notty root 23428 23426 0 07:01 ? 00:00:00 sh -c export PATH=/usr/sbin:/sbin:/usr/bin:/bin; ps -ef root 23429 23428 0 07:01 ? 00:00:00 ps -ef NOTE: ... ok NOTE: test_syslog_logger (oe_syslog.SyslogTestConfig) DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; logger foobar DEBUG: time: 1560582074.2977796, endtime: 1560582374.2899294 DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: Command: logger foobar Output: DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; grep foobar /var/log/messages DEBUG: time: 1560582074.417439, endtime: 1560582374.4114397 DEBUG: Partial data from SSH call: Jun 15 07:01:13 qemux86-64 user.notice root: foobar DEBUG: time: 1560582074.5303643, endtime: 1560582374.5303614 DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: Command: grep foobar /var/log/messages Output: Jun 15 07:01:13 qemux86-64 user.notice root: foobar NOTE: ... ok NOTE: test_syslog_restart (oe_syslog.SyslogTestConfig) DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; /etc/init.d/syslog restart DEBUG: time: 1560582074.5385635, endtime: 1560582374.532718 DEBUG: Partial data from SSH call: Stopping syslogd/klogd: stopped syslogd (pid 755) stopped klogd (pid 756) done Starting syslogd/klogd: done DEBUG: time: 1560582074.666839, endtime: 1560582374.6668367 DEBUG: [Command returned '0' after 0.13 seconds] DEBUG: Command: /etc/init.d/syslog restart Output: Stopping syslogd/klogd: stopped syslogd (pid 755) stopped klogd (pid 756) done Starting syslogd/klogd: done NOTE: ... ok NOTE: test_syslog_startup_config (oe_syslog.SyslogTestConfig) DEBUG: Checking if 'VIRTUAL-RUNTIME_init_manager' value is 'systemd' to skip test DEBUG: Checking if at least one of busybox-syslog is installed DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; echo "LOGFILE=/var/log/test" >> /etc/syslog-startup.conf DEBUG: time: 1560582074.6737978, endtime: 1560582374.669109 DEBUG: [Command returned '0' after 0.13 seconds] DEBUG: Command: echo "LOGFILE=/var/log/test" >> /etc/syslog-startup.conf Output: DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; /etc/init.d/syslog restart DEBUG: time: 1560582074.8038416, endtime: 1560582374.7992222 DEBUG: Partial data from SSH call: Stopping syslogd/klogd: stopped syslogd (pid 23450) stopped klogd (pid 23451) done Starting syslogd/klogd: done DEBUG: time: 1560582074.9312184, endtime: 1560582374.9312165 DEBUG: [Command returned '0' after 0.13 seconds] DEBUG: Command: /etc/init.d/syslog restart Output: Stopping syslogd/klogd: stopped syslogd (pid 23450) stopped klogd (pid 23451) done Starting syslogd/klogd: done DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; logger foobar && grep foobar /var/log/test DEBUG: time: 1560582074.937434, endtime: 1560582374.9320822 DEBUG: Partial data from SSH call: grep: /var/log/test: No such file or directory DEBUG: time: 1560582075.050551, endtime: 1560582375.0505488 DEBUG: [Command returned '2' after 0.12 seconds] DEBUG: Command: logger foobar && grep foobar /var/log/test Output: grep: /var/log/test: No such file or directory NOTE: ... FAIL Traceback (most recent call last): File "/home/pokybuild/yocto-worker/musl-qemux86-64/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/musl-qemux86-64/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/musl-qemux86-64/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/musl-qemux86-64/build/meta/lib/oeqa/runtime/cases/oe_syslog.py", line 63, in test_syslog_startup_config self.assertEqual(status, 0, msg=msg) AssertionError: 2 != 0 : Test log string not found. Output: grep: /var/log/test: No such file or directory NOTE: test_opkg_install_from_repo (opkg.OpkgRepoTest) DEBUG: Checking if at least one of opkg is installed NOTE: ... skipped 'Test requires opkg to be installed' Test requires opkg to be installed NOTE: test_pam (pam.PamBasicTest) DEBUG: Checking if pam is in DISTRO_FEATURES or IMAGE_FEATURES NOTE: ... skipped 'Test requires pam to be in DISTRO_FEATURES' Test requires pam to be in DISTRO_FEATURES DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; which LSB_Test.sh DEBUG: time: 1560582075.0586352, endtime: 1560582375.053858 DEBUG: Partial data from SSH call: which: no LSB_Test.sh in (/usr/sbin:/sbin:/usr/bin:/bin) DEBUG: time: 1560582075.171249, endtime: 1560582375.171247 DEBUG: [Command returned '1' after 0.12 seconds] DEBUG: Command: which LSB_Test.sh Output: which: no LSB_Test.sh in (/usr/sbin:/sbin:/usr/bin:/bin) NOTE: test_parselogs (parselogs.ParseLogsTest) DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; dmesg > /tmp/dmesg_output.log DEBUG: time: 1560582075.1770227, endtime: 1560582375.172533 DEBUG: [Command returned '0' after 0.13 seconds] DEBUG: Command: dmesg > /tmp/dmesg_output.log Output: DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; test -f /var/log/ DEBUG: time: 1560582075.3057215, endtime: 1560582375.3004897 DEBUG: [Command returned '1' after 0.12 seconds] DEBUG: Command: test -f /var/log/ Output: DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; test -d /var/log/ DEBUG: time: 1560582075.4266458, endtime: 1560582375.4192019 DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: Command: test -d /var/log/ Output: DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; find /var/log//*.log -maxdepth 1 -type f DEBUG: time: 1560582075.5433478, endtime: 1560582375.5388057 DEBUG: Partial data from SSH call: /var/log//Xorg.0.log /var/log//dnf.librepo.log /var/log//dnf.log /var/log//dnf.rpm.log /var/log//hawkey.log DEBUG: time: 1560582075.6621203, endtime: 1560582375.6621184 DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: Command: find /var/log//*.log -maxdepth 1 -type f Output: /var/log//Xorg.0.log /var/log//dnf.librepo.log /var/log//dnf.log /var/log//dnf.rpm.log /var/log//hawkey.log DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; test -f /var/log/dmesg DEBUG: time: 1560582075.6673138, endtime: 1560582375.6629565 DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: Command: test -f /var/log/dmesg Output: DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; test -f /tmp/dmesg_output.log DEBUG: time: 1560582075.7936153, endtime: 1560582375.7870095 DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: Command: test -f /tmp/dmesg_output.log Output: DEBUG: [Running]$ scp -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR root@192.168.7.6:/var/log//Xorg.0.log /home/pokybuild/yocto-worker/musl-qemux86-64/build/build/tmp/work/qemux86_64-poky-linux-musl/core-image-sato-sdk/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.28 seconds] DEBUG: [Running]$ scp -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR root@192.168.7.6:/var/log//dnf.librepo.log /home/pokybuild/yocto-worker/musl-qemux86-64/build/build/tmp/work/qemux86_64-poky-linux-musl/core-image-sato-sdk/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.13 seconds] DEBUG: [Running]$ scp -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR root@192.168.7.6:/var/log//dnf.log /home/pokybuild/yocto-worker/musl-qemux86-64/build/build/tmp/work/qemux86_64-poky-linux-musl/core-image-sato-sdk/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: [Running]$ scp -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR root@192.168.7.6:/var/log//dnf.rpm.log /home/pokybuild/yocto-worker/musl-qemux86-64/build/build/tmp/work/qemux86_64-poky-linux-musl/core-image-sato-sdk/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: [Running]$ scp -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR root@192.168.7.6:/var/log//hawkey.log /home/pokybuild/yocto-worker/musl-qemux86-64/build/build/tmp/work/qemux86_64-poky-linux-musl/core-image-sato-sdk/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: [Running]$ scp -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR root@192.168.7.6:/var/log/dmesg /home/pokybuild/yocto-worker/musl-qemux86-64/build/build/tmp/work/qemux86_64-poky-linux-musl/core-image-sato-sdk/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: [Running]$ scp -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR root@192.168.7.6:/tmp/dmesg_output.log /home/pokybuild/yocto-worker/musl-qemux86-64/build/build/tmp/work/qemux86_64-poky-linux-musl/core-image-sato-sdk/1.0-r0/target_logs DEBUG: Data from SSH call: DEBUG: [Command returned '0' after 0.13 seconds] DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; cat /proc/cpuinfo | grep "model name" | head -n1 | awk 'BEGIN{FS=":"}{print $2}' DEBUG: time: 1560582076.986481, endtime: 1560582376.983157 DEBUG: Partial data from SSH call: Intel(R) Core(TM)2 Duo CPU T7700 @ 2.40GHz DEBUG: time: 1560582077.1044374, endtime: 1560582377.104434 DEBUG: [Command returned '0' after 0.12 seconds] DEBUG: Command: cat /proc/cpuinfo | grep "model name" | head -n1 | awk 'BEGIN{FS=":"}{print $2}' Output: Intel(R) Core(TM)2 Duo CPU T7700 @ 2.40GHz DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; cat /proc/cpuinfo | grep "cpu cores" | head -n1 | awk {'print $4'} DEBUG: time: 1560582077.1132822, endtime: 1560582377.1058571 DEBUG: Partial data from SSH call: 1 -- DEBUG: Partial data from SSH call: root 560 554 0 06:59 tty2 00:00:00 /usr/bin/Xorg :0 -br -pn DEBUG: time: 1560582089.733011, endtime: 1560582389.7330089 DEBUG: [Command returned '0' after 0.14 seconds] DEBUG: Command: ps -ef | grep -v xinit | grep [X]org Output: root 560 554 0 06:59 tty2 00:00:00 /usr/bin/Xorg :0 -br -pn DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.6 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; ps -ef DEBUG: time: 1560582089.7391682, endtime: 1560582389.7338417 DEBUG: Partial data from SSH call: UID PID PPID C STIME TTY TIME CMD root 1 0 1 06:59 ? 00:00:02 init [5] root 2 0 0 06:59 ? 00:00:00 [kthreadd] root 3 2 0 06:59 ? 00:00:00 [rcu_gp] root 4 2 0 06:59 ? 00:00:00 [rcu_par_gp] root 5 2 0 06:59 ? 00:00:00 [kworker/0:0-mm_percpu_wq] root 6 2 0 06:59 ? 00:00:00 [kworker/0:0H-kblockd] root 7 2 0 06:59 ? 00:00:00 [kworker/u2:0-flush-253:0] root 8 2 0 06:59 ? 00:00:00 [mm_percpu_wq] root 9 2 0 06:59 ? 00:00:00 [ksoftirqd/0] root 10 2 0 06:59 ? 00:00:00 [rcu_preempt] root 11 2 0 06:59 ? 00:00:00 [migration/0] root 12 2 0 06:59 ? 00:00:00 [cpuhp/0] root 13 2 0 06:59 ? 00:00:00 [kdevtmpfs] root 14 2 0 06:59 ? 00:00:00 [netns] root 15 2 0 06:59 ? 00:00:00 [rcu_tasks_kthre] root 16 2 0 06:59 ? 00:00:00 [kworker/0:1-ipv6_addrconf] root 17 2 0 06:59 ? 00:00:00 [oom_reaper] root 18 2 0 06:59 ? 00:00:00 [writeback] root 19 2 0 06:59 ? 00:00:00 [kcompactd0] root 20 2 0 06:59 ? 00:00:00 [crypto] root 21 2 0 06:59 ? 00:00:00 [kblockd] root 22 2 0 06:59 ? 00:00:00 [ata_sff] root 23 2 0 06:59 ? 00:00:00 [md] root 24 2 0 06:59 ? 00:00:00 [watchdogd] root 25 2 0 06:59 ? 00:00:00 [rpciod] root 26 2 0 06:59 ? 00:00:00 [kworker/u3:0-xprtiod] root 27 2 0 06:59 ? 00:00:00 [xprtiod] root 28 2 0 06:59 ? 00:00:00 [kswapd0] root 29 2 0 06:59 ? 00:00:00 [nfsiod] root 31 2 0 06:59 ? 00:00:00 [kworker/u2:1] root 77 2 0 06:59 ? 00:00:00 [acpi_thermal_pm] root 78 2 0 06:59 ? 00:00:00 [hwrng] root 79 2 0 06:59 ? 00:00:00 [kworker/0:1H-kblockd] root 80 2 0 06:59 ? 00:00:00 [kworker/0:2-events] root 81 2 0 06:59 ? 00:00:00 [nvme-wq] root 82 2 0 06:59 ? 00:00:00 [nvme-reset-wq] root 83 2 0 06:59 ? 00:00:00 [nvme-delete-wq] root 84 2 0 06:59 ? 00:00:00 [dm_bufio_cache] root 85 2 0 06:59 ? 00:00:00 [kworker/0:3-rcu_gp] root 86 2 0 06:59 ? 00:00:00 [ipv6_addrconf] root 92 2 0 06:59 ? 00:00:00 [jbd2/vda-8] root 93 2 0 06:59 ? 00:00:00 [ext4-rsv-conver] root 117 1 0 06:59 ? 00:00:00 /sbin/udevd -d root 330 2 0 06:59 ? 00:00:00 [kworker/u2:2-events_unbound] root 341 1 0 06:59 ? 00:00:00 /sbin/v86d message+ 502 1 0 06:59 ? 00:00:00 /usr/bin/dbus-daemon --system root 512 1 0 06:59 ? 00:00:00 /usr/sbin/connmand root 518 1 0 06:59 ? 00:00:00 /usr/sbin/wpa_supplicant -u root 548 1 0 06:59 ? 00:00:00 /usr/sbin/sshd root 554 1 0 06:59 ? 00:00:00 xinit /etc/X11/Xsession -- /usr/bin/Xorg :0 -br -pn root 560 554 0 06:59 tty2 00:00:00 /usr/bin/Xorg :0 -br -pn rpc 564 1 0 06:59 ? 00:00:00 /usr/sbin/rpcbind rpcuser 567 1 0 06:59 ? 00:00:00 /usr/sbin/rpc.statd root 573 1 0 06:59 ? 00:00:00 /usr/sbin/atd -f root 577 1 0 06:59 ? 00:00:00 /usr/libexec/bluetooth/bluetoothd root 586 554 0 06:59 ? 00:00:00 matchbox-window-manager -theme Sato -use_cursor no root 591 1 0 06:59 ? 00:00:00 dbus-launch --sh-syntax --exit-with-session root 592 1 0 06:59 ? 00:00:00 /usr/bin/dbus-daemon --syslog --fork --print-pid 5 --print-address 7 --session root 613 586 0 06:59 ? 00:00:00 /usr/libexec/at-spi-bus-launcher --launch-immediately root 617 586 0 06:59 ? 00:00:00 connman-appl DEBUG: time: 1560582089.8635972, endtime: 1560582389.863595 DEBUG: Partial data from SSH call: et root 626 613 0 06:59 ? 00:00:00 /usr/bin/dbus-daemon --config-file=/usr/share/defaults/at-spi2/accessibility.conf --nofork --print-address 3 root 654 586 0 06:59 ? 00:00:00 matchbox-desktop root 655 586 0 06:59 ? 00:00:00 matchbox-panel --start-applets showdesktop,windowselector --end-applets clock,,systray,startup-notify,notify root 656 1 0 06:59 ? 00:00:00 /usr/sbin/console-kit-daemon --no-daemon root 720 1 0 06:59 ? 00:00:00 /usr/libexec/gconfd-2 root 722 1 0 06:59 ? 00:00:00 /usr/bin/settings-daemon root 725 1 0 06:59 ? 00:00:00 /usr/libexec/at-spi2-registryd --use-gnome-session root 733 2 0 06:59 ? 00:00:00 [kworker/u3:1] root 734 2 0 06:59 ? 00:00:00 [lockd] root 736 2 0 06:59 ? 00:00:00 [nfsd] root 737 2 0 06:59 ? 00:00:00 [nfsd] root 738 2 0 06:59 ? 00:00:00 [nfsd] root 739 2 0 06:59 ? 00:00:00 [nfsd] root 740 2 0 06:59 ? 00:00:00 [nfsd] root 741 2 0 06:59 ? 00:00:00 [nfsd] root 742 2 0 06:59 ? 00:00:00 [nfsd] root 743 2 0 06:59 ? 00:00:00 [nfsd] root 747 1 0 06:59 ? 00:00:00 /usr/sbin/rpc.mountd avahi 761 1 0 06:59 ? 00:00:00 avahi-daemon: running [qemux86-64.local] avahi 762 761 0 06:59 ? 00:00:00 avahi-daemon: chroot helper root 775 1 0 06:59 ? 00:00:00 /usr/sbin/ofonod root 779 1 0 06:59 ? 00:00:00 /usr/sbin/crond root 789 1 0 06:59 ? 00:00:00 /usr/sbin/tcf-agent -d -L- -l0 root 794 1 0 06:59 ? 00:00:00 /bin/sh /bin/start_getty 115200 ttyS0 vt102 root 795 1 0 06:59 ? 00:00:00 /bin/sh /bin/start_getty 115200 ttyS1 vt102 root 796 1 0 06:59 tty1 00:00:00 /sbin/getty 38400 tty1 root 827 794 0 06:59 ttyS0 00:00:00 /sbin/getty -L 115200 ttyS0 vt102 root 832 795 0 06:59 ttyS1 00:00:00 -sh root 23467 1 0 07:01 ? 00:00:00 /sbin/syslogd -n -O /var/log/test root 23468 1 0 07:01 ? 00:00:00 /sbin/klogd -n root 23727 548 0 07:01 ? 00:00:00 sshd: root@notty root 23729 23727 0 07:01 ? 00:00:00 sh -c export PATH=/usr/sbin:/sbin:/usr/bin:/bin; ps -ef root 23730 23729 0 07:01 ? 00:00:00 ps -ef DEBUG: time: 1560582089.8671882, endtime: 1560582389.8671865 DEBUG: [Command returned '0' after 0.13 seconds] DEBUG: Command: ps -ef Output: UID PID PPID C STIME TTY TIME CMD root 1 0 1 06:59 ? 00:00:02 init [5] root 2 0 0 06:59 ? 00:00:00 [kthreadd] root 3 2 0 06:59 ? 00:00:00 [rcu_gp] root 4 2 0 06:59 ? 00:00:00 [rcu_par_gp] root 5 2 0 06:59 ? 00:00:00 [kworker/0:0-mm_percpu_wq] root 6 2 0 06:59 ? 00:00:00 [kworker/0:0H-kblockd] root 7 2 0 06:59 ? 00:00:00 [kworker/u2:0-flush-253:0] root 8 2 0 06:59 ? 00:00:00 [mm_percpu_wq] root 9 2 0 06:59 ? 00:00:00 [ksoftirqd/0] root 10 2 0 06:59 ? 00:00:00 [rcu_preempt] root 11 2 0 06:59 ? 00:00:00 [migration/0] root 12 2 0 06:59 ? 00:00:00 [cpuhp/0] root 13 2 0 06:59 ? 00:00:00 [kdevtmpfs] root 14 2 0 06:59 ? 00:00:00 [netns] root 15 2 0 06:59 ? 00:00:00 [rcu_tasks_kthre] root 16 2 0 06:59 ? 00:00:00 [kworker/0:1-ipv6_addrconf] root 17 2 0 06:59 ? 00:00:00 [oom_reaper] root 18 2 0 06:59 ? 00:00:00 [writeback] root 19 2 0 06:59 ? 00:00:00 [kcompactd0] root 20 2 0 06:59 ? 00:00:00 [crypto] root 21 2 0 06:59 ? 00:00:00 [kblockd] root 22 2 0 06:59 ? 00:00:00 [ata_sff] root 23 2 0 06:59 ? 00:00:00 [md] root 24 2 0 06:59 ? 00:00:00 [watchdogd] root 25 2 0 06:59 ? 00:00:00 [rpciod] root 26 2 0 06:59 ? 00:00:00 [kworker/u3:0-xprtiod] root 27 2 0 06:59 ? 00:00:00 [xprtiod] root 28 2 0 06:59 ? 00:00:00 [kswapd0] root 29 2 0 06:59 ? 00:00:00 [nfsiod] root 31 2 0 06:59 ? 00:00:00 [kworker/u2:1] root 77 2 0 06:59 ? 00:00:00 [acpi_thermal_pm] root 78 2 0 06:59 ? 00:00:00 [hwrng] root 79 2 0 06:59 ? 00:00:00 [kworker/0:1H-kblockd] root 80 2 0 06:59 ? 00:00:00 [kworker/0:2-events] root 81 2 0 06:59 ? 00:00:00 [nvme-wq] root 82 2 0 06:59 ? 00:00:00 [nvme-reset-wq] root 83 2 0 06:59 ? 00:00:00 [nvme-delete-wq] root 84 2 0 06:59 ? 00:00:00 [dm_bufio_cache] root 85 2 0 06:59 ? 00:00:00 [kworker/0:3-rcu_gp] root 86 2 0 06:59 ? 00:00:00 [ipv6_addrconf] root 92 2 0 06:59 ? 00:00:00 [jbd2/vda-8] root 93 2 0 06:59 ? 00:00:00 [ext4-rsv-conver] root 117 1 0 06:59 ? 00:00:00 /sbin/udevd -d root 330 2 0 06:59 ? 00:00:00 [kworker/u2:2-events_unbound] root 341 1 0 06:59 ? 00:00:00 /sbin/v86d message+ 502 1 0 06:59 ? 00:00:00 /usr/bin/dbus-daemon --system root 512 1 0 06:59 ? 00:00:00 /usr/sbin/connmand root 518 1 0 06:59 ? 00:00:00 /usr/sbin/wpa_supplicant -u root 548 1 0 06:59 ? 00:00:00 /usr/sbin/sshd root 554 1 0 06:59 ? 00:00:00 xinit /etc/X11/Xsession -- /usr/bin/Xorg :0 -br -pn root 560 554 0 06:59 tty2 00:00:00 /usr/bin/Xorg :0 -br -pn rpc 564 1 0 06:59 ? 00:00:00 /usr/sbin/rpcbind rpcuser 567 1 0 06:59 ? 00:00:00 /usr/sbin/rpc.statd root 573 1 0 06:59 ? 00:00:00 /usr/sbin/atd -f root 577 1 0 06:59 ? 00:00:00 /usr/libexec/bluetooth/bluetoothd root 586 554 0 06:59 ? 00:00:00 matchbox-window-manager -theme Sato -use_cursor no root 591 1 0 06:59 ? 00:00:00 dbus-launch --sh-syntax --exit-with-session root 592 1 0 06:59 ? 00:00:00 /usr/bin/dbus-daemon --syslog --fork --print-pid 5 --print-address 7 --session root 613 586 0 06:59 ? 00:00:00 /usr/libexec/at-spi-bus-launcher --launch-immediately root 617 586 0 06:59 ? 00:00:00 connman-applet root 626 613 0 06:59 ? 00:00:00 /usr/bin/dbus-daemon --config-file=/usr/share/defaults/at-spi2/accessibility.conf --nofork --print-address 3 root 654 586 0 06:59 ? 00:00:00 matchbox-desktop root 655 586 0 06:59 ? 00:00:00 matchbox-panel --start-applets showdesktop,windowselector --end-applets clock,,systray,startup-notify,notify root 656 1 0 06:59 ? 00:00:00 /usr/sbin/console-kit-daemon --no-daemon root 720 1 0 06:59 ? 00:00:00 /usr/libexec/gconfd-2 root 722 1 0 06:59 ? 00:00:00 /usr/bin/settings-daemon root 725 1 0 06:59 ? 00:00:00 /usr/libexec/at-spi2-registryd --use-gnome-session root 733 2 0 06:59 ? 00:00:00 [kworker/u3:1] root 734 2 0 06:59 ? 00:00:00 [lockd] root 736 2 0 06:59 ? 00:00:00 [nfsd] root 737 2 0 06:59 ? 00:00:00 [nfsd] root 738 2 0 06:59 ? 00:00:00 [nfsd] root 739 2 0 06:59 ? 00:00:00 [nfsd] root 740 2 0 06:59 ? 00:00:00 [nfsd] root 741 2 0 06:59 ? 00:00:00 [nfsd] root 742 2 0 06:59 ? 00:00:00 [nfsd] root 743 2 0 06:59 ? 00:00:00 [nfsd] root 747 1 0 06:59 ? 00:00:00 /usr/sbin/rpc.mountd avahi 761 1 0 06:59 ? 00:00:00 avahi-daemon: running [qemux86-64.local] avahi 762 761 0 06:59 ? 00:00:00 avahi-daemon: chroot helper root 775 1 0 06:59 ? 00:00:00 /usr/sbin/ofonod root 779 1 0 06:59 ? 00:00:00 /usr/sbin/crond root 789 1 0 06:59 ? 00:00:00 /usr/sbin/tcf-agent -d -L- -l0 root 794 1 0 06:59 ? 00:00:00 /bin/sh /bin/start_getty 115200 ttyS0 vt102 root 795 1 0 06:59 ? 00:00:00 /bin/sh /bin/start_getty 115200 ttyS1 vt102 root 796 1 0 06:59 tty1 00:00:00 /sbin/getty 38400 tty1 root 827 794 0 06:59 ttyS0 00:00:00 /sbin/getty -L 115200 ttyS0 vt102 root 832 795 0 06:59 ttyS1 00:00:00 -sh root 23467 1 0 07:01 ? 00:00:00 /sbin/syslogd -n -O /var/log/test root 23468 1 0 07:01 ? 00:00:00 /sbin/klogd -n root 23727 548 0 07:01 ? 00:00:00 sshd: root@notty root 23729 23727 0 07:01 ? 00:00:00 sh -c export PATH=/usr/sbin:/sbin:/usr/bin:/bin; ps -ef root 23730 23729 0 07:01 ? 00:00:00 ps -ef NOTE: ... ok NOTE: ====================================================================== NOTE: FAIL: test_syslog_startup_config (oe_syslog.SyslogTestConfig) NOTE: ---------------------------------------------------------------------- NOTE: Traceback (most recent call last): File "/home/pokybuild/yocto-worker/musl-qemux86-64/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/musl-qemux86-64/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/musl-qemux86-64/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/musl-qemux86-64/build/meta/lib/oeqa/runtime/cases/oe_syslog.py", line 63, in test_syslog_startup_config self.assertEqual(status, 0, msg=msg) AssertionError: 2 != 0 : Test log string not found. Output: grep: /var/log/test: No such file or directory NOTE: ---------------------------------------------------------------------- NOTE: Ran 59 tests in 124.192s NOTE: FAILED NOTE: (failures=1, skipped=13) DEBUG: Stopping logging thread DEBUG: Stop event received DEBUG: Tearing down logging thread DEBUG: Sending SIGTERM to runqemu RESULTS: RESULTS - buildcpio.BuildCpioTest.test_cpio: PASSED (36.46s) RESULTS - buildgalculator.GalculatorTest.test_galculator: PASSED (14.42s) RESULTS - buildlzip.BuildLzipTest.test_lzip: PASSED (8.26s) RESULTS - connman.ConnmanTest.test_connmand_help: PASSED (0.12s) RESULTS - connman.ConnmanTest.test_connmand_running: PASSED (0.12s) RESULTS - date.DateTest.test_date: PASSED (0.46s) RESULTS - df.DfTest.test_df: PASSED (0.12s) RESULTS - dnf.DnfBasicTest.test_dnf_help: PASSED (0.78s) RESULTS - dnf.DnfBasicTest.test_dnf_history: PASSED (0.54s) RESULTS - dnf.DnfBasicTest.test_dnf_info: PASSED (0.45s) RESULTS - dnf.DnfBasicTest.test_dnf_search: PASSED (0.42s) RESULTS - dnf.DnfBasicTest.test_dnf_version: PASSED (0.40s) RESULTS - dnf.DnfRepoTest.test_dnf_exclude: PASSED (8.70s) RESULTS - dnf.DnfRepoTest.test_dnf_install: PASSED (1.76s) RESULTS - dnf.DnfRepoTest.test_dnf_install_dependency: PASSED (1.79s) RESULTS - dnf.DnfRepoTest.test_dnf_install_from_disk: PASSED (2.34s) RESULTS - dnf.DnfRepoTest.test_dnf_install_from_http: PASSED (1.90s) RESULTS - dnf.DnfRepoTest.test_dnf_installroot: PASSED (4.39s) RESULTS - dnf.DnfRepoTest.test_dnf_makecache: PASSED (0.43s) RESULTS - dnf.DnfRepoTest.test_dnf_reinstall: PASSED (0.57s) RESULTS - dnf.DnfRepoTest.test_dnf_repoinfo: PASSED (0.42s) RESULTS - gcc.GccCompileTest.test_gcc_compile: PASSED (0.83s) RESULTS - gcc.GccCompileTest.test_gpp2_compile: PASSED (0.78s) RESULTS - gcc.GccCompileTest.test_gpp_compile: PASSED (0.77s) RESULTS - gcc.GccCompileTest.test_make: PASSED (0.62s) RESULTS - gi.GObjectIntrospectionTest.test_python: PASSED (0.22s) RESULTS - kernelmodule.KernelModuleTest.test_kernel_module: PASSED (18.68s) RESULTS - logrotate.LogrotateTest.test_1_logrotate_setup: PASSED (0.24s) RESULTS - logrotate.LogrotateTest.test_2_logrotate: PASSED (0.52s) RESULTS - oe_syslog.SyslogTest.test_syslog_running: PASSED (0.13s) RESULTS - oe_syslog.SyslogTestConfig.test_syslog_logger: PASSED (0.24s) RESULTS - oe_syslog.SyslogTestConfig.test_syslog_restart: PASSED (0.14s) RESULTS - parselogs.ParseLogsTest.test_parselogs: PASSED (2.31s) RESULTS - perl.PerlTest.test_perl_works: PASSED (0.12s) RESULTS - ping.PingTest.test_ping: PASSED (0.05s) RESULTS - python.PythonTest.test_python3: PASSED (0.15s) RESULTS - rpm.RpmBasicTest.test_rpm_help: PASSED (0.12s) RESULTS - rpm.RpmBasicTest.test_rpm_query: PASSED (0.26s) RESULTS - rpm.RpmInstallRemoveTest.test_check_rpm_install_removal_log_file_size: PASSED (9.25s) RESULTS - rpm.RpmInstallRemoveTest.test_rpm_install: PASSED (0.54s) RESULTS - rpm.RpmInstallRemoveTest.test_rpm_query_nonroot: PASSED (1.06s) RESULTS - rpm.RpmInstallRemoveTest.test_rpm_remove: PASSED (0.20s) RESULTS - scp.ScpTest.test_scp_file: PASSED (0.40s) RESULTS - ssh.SSHTest.test_ssh: PASSED (0.23s) RESULTS - xorg.XorgTest.test_xorg_running: PASSED (0.27s) RESULTS - apt.AptRepoTest.test_apt_install_from_repo: SKIPPED (0.00s) RESULTS - ldd.LddTest.test_ldd: SKIPPED (0.00s) RESULTS - opkg.OpkgRepoTest.test_opkg_install_from_repo: SKIPPED (0.00s) RESULTS - pam.PamBasicTest.test_pam: SKIPPED (0.00s) RESULTS - ptest.PtestRunnerTest.test_ptestrunner: SKIPPED (0.00s) RESULTS - systemd.SystemdBasicTests.test_systemd_basic: SKIPPED (0.00s) RESULTS - systemd.SystemdBasicTests.test_systemd_failed: SKIPPED (0.00s) RESULTS - systemd.SystemdBasicTests.test_systemd_list: SKIPPED (0.00s) RESULTS - systemd.SystemdJournalTests.test_systemd_boot_time: SKIPPED (0.00s) RESULTS - systemd.SystemdJournalTests.test_systemd_journal: SKIPPED (0.00s) RESULTS - systemd.SystemdServiceTests.test_systemd_disable_enable: SKIPPED (0.00s) RESULTS - systemd.SystemdServiceTests.test_systemd_status: SKIPPED (0.00s) RESULTS - systemd.SystemdServiceTests.test_systemd_stop_start: SKIPPED (0.00s) RESULTS - oe_syslog.SyslogTestConfig.test_syslog_startup_config: FAILED (0.38s) SUMMARY: core-image-sato-sdk () - Ran 59 tests in 124.193s core-image-sato-sdk - FAIL - Required tests failed (successes=45, skipped=13, failures=1, errors=0) ERROR: core-image-sato-sdk - FAILED - check the task log and the ssh log ERROR: DEBUG: Python function do_testimage finished ERROR: Function failed: do_testimage