Bug 13379

Summary: qemuarm64 runtime syslog test failure in testimage
Product: [Build System, Metadata & Runtime] OE-Core Reporter: Armin Kuster <akuster>
Component: coreAssignee: Jon Mason <jon.mason>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: High CC: meta.mr.watcher, meta.watcher, richard.purdie
Version: 2.8   
Target Milestone: 2.8 M2   
Hardware: x86   
OS: Multiple   
URL: https://errors.yoctoproject.org/Errors/Details/248107/
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: Don't know

Description Armin Kuster 2019-06-07 03:35:08 UTC 
SDK testing environment: aarch64-poky-linux
7: 1/1 1/12 (0.02s) (python.Python2Test.test_python2)
No python package in the SDK
6: 1/1 2/12 (0.08s) (perl.PerlTest.test_perl)
8: 1/1 3/12 (0.10s) (python.Python3Test.test_python3)
5: 1/4 4/12 (0.35s) (gcc.GccCompileTest.test_gcc_compile)
Needs cmake
5: 2/4 5/12 (0.24s) (gcc.GccCompileTest.test_gpp2_compile)
5: 3/4 6/12 (0.34s) (gcc.GccCompileTest.test_gpp_compile)
Needs cmake


No perl package in the SDK
No python package in the SDK
No python3 package in the SDK
No perl package in the SDK
No python package in the SDK
No python3 package in the SDK
Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/runtime/cases/oe_syslog.py", line 58, in test_syslog_startup_config
    self.assertEqual(status, 0, msg)
AssertionError: 1 != 0 : Could not restart syslog service. Status and output: 1 and Stopping syslogd/klogd: no syslogd found; none killed
Comment 1 Richard Purdie 2019-06-07 09:44:25 UTC 
These notes in the comment are normal, a core-image-sato-sdk doesn't include perl or python for the SDK system.

The output you've pasted is from the autobuilder where testsdk output was mixed with other test output. 

The error reporting log via the link is clearer, it tried to boot a core-image-sato-sdk image under runqemu and a syslog test failed so the testimage test failed.

NOTE: ======================================================================
NOTE: FAIL: test_syslog_startup_config (oe_syslog.SyslogTestConfig)
NOTE: ----------------------------------------------------------------------
NOTE: Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/runtime/cases/oe_syslog.py", line 58, in test_syslog_startup_config
    self.assertEqual(status, 0, msg)
AssertionError: 1 != 0 : Could not restart syslog service. Status and output: 1 and Stopping syslogd/klogd: no syslogd found; none killed

NOTE: ----------------------------------------------------------------------
NOTE: Ran 59 tests in 242.422s
NOTE: FAILED
NOTE:  (failures=1, skipped=12)

Why, unknown but its probably not arm host specific.
Comment 2 Richard Purdie 2019-06-10 11:31:30 UTC 
pokybuild@ubuntu1804-arm-1:~/yocto-worker/qemuarm64-armhost/build/build/tmp/work/qemuarm64-poky-linux/core-image-sato/1.0-r0/temp$ cat log.do_testimage | grep 5983
DEBUG: Partial data from SSH call: Stopping syslogd/klogd: stopped syslogd (pid 5983)
Output:  Stopping syslogd/klogd: stopped syslogd (pid 5983)
AssertionError: 1 != 0 : Could not restart syslog service. Status and output: 1 and Stopping syslogd/klogd: stopped syslogd (pid 5983)
DEBUG: time: 1560161998.2259839, endtime: 1560162298.1995103
AssertionError: 1 != 0 : Could not restart syslog service. Status and output: 1 and Stopping syslogd/klogd: stopped syslogd (pid 5983)
pokybuild@ubuntu1804-arm-1:~/yocto-worker/qemuarm64-armhost/build/build/tmp/work/qemuarm64-poky-linux/core-image-sato/1.0-r0/temp$ cat log.do_testimage | grep 5983 -C 50
 5966 root      3260 R    ps

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.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; logger foobar
DEBUG: time: 1560161991.9109857, endtime: 1560162291.8819292
DEBUG: [Command returned '0' after 0.15 seconds]
DEBUG: Command: logger foobar
Output:  

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; grep foobar /var/log/messages
DEBUG: time: 1560161992.0634468, endtime: 1560162292.0379906
DEBUG: Partial data from SSH call: Jun 10 10:19:51 qemuarm64 user.notice root: foobar

DEBUG: time: 1560161992.1876037, endtime: 1560162292.1875982
DEBUG: [Command returned '0' after 0.15 seconds]
DEBUG: Command: grep foobar /var/log/messages
Output:  Jun 10 10:19:51 qemuarm64 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.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; /etc/init.d/syslog restart
DEBUG: time: 1560161992.2168841, endtime: 1560162292.1926873
DEBUG: Partial data from SSH call: Stopping syslogd/klogd: stopped syslogd (pid 491)
stopped klogd (pid 492)
done
Starting syslogd/klogd: /sbin/klogd is already running
492

DEBUG: time: 1560161992.3694496, endtime: 1560162292.3694448
DEBUG: [Command returned '1' after 0.18 seconds]
DEBUG: Command: /etc/init.d/syslog restart
Output:  Stopping syslogd/klogd: stopped syslogd (pid 491)
stopped klogd (pid 492)
done
Starting syslogd/klogd: /sbin/klogd is already running
492

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.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; echo "LOGFILE=/var/log/test" >> /etc/syslog-startup.conf
DEBUG: time: 1560161992.398775, endtime: 1560162292.3758519
DEBUG: [Command returned '0' after 0.15 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.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; /etc/init.d/syslog restart
DEBUG: time: 1560161992.546063, endtime: 1560162292.5228472
DEBUG: Partial data from SSH call: Stopping syslogd/klogd: stopped syslogd (pid 5983)
no klogd found; none killed

DEBUG: time: 1560161992.675645, endtime: 1560162292.6756399
DEBUG: [Command returned '1' after 0.15 seconds]
DEBUG: Command: /etc/init.d/syslog restart
Output:  Stopping syslogd/klogd: stopped syslogd (pid 5983)
no klogd found; none killed

NOTE:  ... FAIL
Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/runtime/cases/oe_syslog.py", line 58, in test_syslog_startup_config
    self.assertEqual(status, 0, msg)
AssertionError: 1 != 0 : Could not restart syslog service. Status and output: 1 and Stopping syslogd/klogd: stopped syslogd (pid 5983)
no klogd found; none killed

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.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; which LSB_Test.sh
DEBUG: time: 1560161992.7077365, endtime: 1560162292.684823
DEBUG: [Command returned '1' after 0.15 seconds]
DEBUG: Command: which LSB_Test.sh
Output:  

NOTE: test_parselogs (parselogs.ParseLogsTest)
DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; dmesg > /tmp/dmesg_output.log
DEBUG: time: 1560161992.8540227, endtime: 1560162292.8330717
DEBUG: [Command returned '0' after 0.14 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.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; test -f /var/log/
DEBUG: time: 1560161992.9947643, endtime: 1560162292.9750624
DEBUG: [Command returned '1' after 0.14 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.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; test -d /var/log/
DEBUG: time: 1560161993.1378112, endtime: 1560162293.1139073
DEBUG: [Command returned '0' after 0.14 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.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; find /var/log//*.log -maxdepth 1 -type f
DEBUG: time: 1560161993.2800267, endtime: 1560162293.2579641
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: 1560161993.4009938, endtime: 1560162293.4009898
DEBUG: [Command returned '0' after 0.14 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
--
DEBUG: Partial data from SSH call: error: package base-passwd-doc is not installed

DEBUG: time: 1560161997.3737924, endtime: 1560162297.3737886
DEBUG: [Command returned '1' after 0.16 seconds]
DEBUG: Command: rpm -e base-passwd-doc
Output:  error: package base-passwd-doc is not installed

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; rpm -ivh /tmp/base-passwd-doc.rpm
DEBUG: time: 1560161997.3995771, endtime: 1560162297.3755364
DEBUG: Partial data from SSH call: Verifying...                          ########################################
Preparing...                          ########################################
Updating / installing...
base-passwd-doc-3.5.29-r0.0           ########################################

DEBUG: time: 1560161997.5884736, endtime: 1560162297.58847
DEBUG: [Command returned '0' after 0.21 seconds]
DEBUG: Command: rpm -ivh /tmp/base-passwd-doc.rpm
Output:  Verifying...                          ########################################
Preparing...                          ########################################
Updating / installing...
base-passwd-doc-3.5.29-r0.0           ########################################

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; rpm -e base-passwd-doc
DEBUG: time: 1560161997.6080253, endtime: 1560162297.5902102
DEBUG: [Command returned '0' after 0.19 seconds]
DEBUG: Command: rpm -e base-passwd-doc
Output:  

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; rpm -ivh /tmp/base-passwd-doc.rpm
DEBUG: time: 1560161997.7979486, endtime: 1560162297.7808943
DEBUG: Partial data from SSH call: Verifying...                          ########################################
Preparing...                          ########################################
Updating / installing...
base-passwd-doc-3.5.29-r0.0           ########################################

DEBUG: time: 1560161997.9938881, endtime: 1560162297.9938843
DEBUG: [Command returned '0' after 0.21 seconds]
DEBUG: Command: rpm -ivh /tmp/base-passwd-doc.rpm
Output:  Verifying...                          ########################################
Preparing...                          ########################################
Updating / installing...
base-passwd-doc-3.5.29-r0.0           ########################################

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; rpm -e base-passwd-doc
DEBUG: time: 1560161998.0212069, endtime: 1560162297.996756
DEBUG: [Command returned '0' after 0.20 seconds]
DEBUG: Command: rpm -e base-passwd-doc
Output:  

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; rpm -ivh /tmp/base-passwd-doc.rpm
DEBUG: time: 1560161998.2259839, endtime: 1560162298.1995103
DEBUG: Partial data from SSH call: Verifying...                          ########################################
Preparing...                          ########################################
Updating / installing...
base-passwd-doc-3.5.29-r0.0           ########################################

DEBUG: time: 1560161998.4130461, endtime: 1560162298.4130425
DEBUG: [Command returned '0' after 0.22 seconds]
DEBUG: Command: rpm -ivh /tmp/base-passwd-doc.rpm
Output:  Verifying...                          ########################################
Preparing...                          ########################################
Updating / installing...
base-passwd-doc-3.5.29-r0.0           ########################################

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; rpm -e base-passwd-doc
DEBUG: time: 1560161998.433548, endtime: 1560162298.4148393
DEBUG: [Command returned '0' after 0.18 seconds]
DEBUG: Command: rpm -e base-passwd-doc
Output:  

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; rpm -ivh /tmp/base-passwd-doc.rpm
DEBUG: time: 1560161998.6178071, endtime: 1560162298.6003454
DEBUG: Partial data from SSH call: Verifying...                          ########################################
Preparing...                          ########################################
Updating / installing...
base-passwd-doc-3.5.29-r0.0           ########################################

DEBUG: time: 1560161998.8037794, endtime: 1560162298.803775
DEBUG: [Command returned '0' after 0.20 seconds]
DEBUG: Command: rpm -ivh /tmp/base-passwd-doc.rpm
Output:  Verifying...                          ########################################
Preparing...                          ########################################
Updating / installing...
base-passwd-doc-3.5.29-r0.0           ########################################

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; rpm -e base-passwd-doc
DEBUG: time: 1560161998.828446, endtime: 1560162298.8057628
DEBUG: [Command returned '0' after 0.19 seconds]
DEBUG: Command: rpm -e base-passwd-doc
Output:  

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; rpm -ivh /tmp/base-passwd-doc.rpm
DEBUG: time: 1560161999.0202553, endtime: 1560162298.9970593
DEBUG: Partial data from SSH call: Verifying...                          ########################################
Preparing...                          ########################################
Updating / installing...
base-passwd-doc-3.5.29-r0.0           ########################################

DEBUG: time: 1560161999.2100928, endtime: 1560162299.2100885
DEBUG: [Command returned '0' after 0.21 seconds]
DEBUG: Command: rpm -ivh /tmp/base-passwd-doc.rpm
--
Output:  -rw-------    1 root     root       4194304 Jun 10 10:20 /tmp/test_scp_file

DEBUG: [Running]$ ssh -l root -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.8 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; rm /tmp/test_scp_file
DEBUG: time: 1560162006.2613993, endtime: 1560162306.2352417
DEBUG: [Command returned '0' after 0.15 seconds]
DEBUG: Command: rm /tmp/test_scp_file
Output:  

NOTE:  ... ok
NOTE: test_stap (stap.StapTest)
DEBUG: Checking if at least one of systemtap is installed
NOTE:  ... skipped 'Test requires systemtap to be installed'
Test requires systemtap to be installed
NOTE: test_systemd_basic (systemd.SystemdBasicTests)
DEBUG: Checking if 'VIRTUAL-RUNTIME_init_manager' value is not 'systemd' to skip test
NOTE:  ... skipped 'systemd is not the init manager for this image'
systemd is not the init manager for this image
NOTE: test_systemd_failed (systemd.SystemdBasicTests)
NOTE:  ... skipped "Test case systemd.SystemdBasicTests.test_systemd_failed depends on systemd.SystemdBasicTests.test_systemd_basic but it didn't pass/run."
Test case systemd.SystemdBasicTests.test_systemd_failed depends on systemd.SystemdBasicTests.test_systemd_basic but it didn't pass/run.
NOTE: test_systemd_list (systemd.SystemdBasicTests)
NOTE:  ... skipped "Test case systemd.SystemdBasicTests.test_systemd_list depends on systemd.SystemdBasicTests.test_systemd_basic but it didn't pass/run."
Test case systemd.SystemdBasicTests.test_systemd_list depends on systemd.SystemdBasicTests.test_systemd_basic but it didn't pass/run.
NOTE: test_systemd_boot_time (systemd.SystemdJournalTests)
NOTE:  ... skipped "Test case systemd.SystemdJournalTests.test_systemd_boot_time depends on systemd.SystemdBasicTests.test_systemd_basic but it didn't pass/run."
Test case systemd.SystemdJournalTests.test_systemd_boot_time depends on systemd.SystemdBasicTests.test_systemd_basic but it didn't pass/run.
NOTE: test_systemd_journal (systemd.SystemdJournalTests)
NOTE:  ... skipped "Test case systemd.SystemdJournalTests.test_systemd_journal depends on systemd.SystemdBasicTests.test_systemd_basic but it didn't pass/run."
Test case systemd.SystemdJournalTests.test_systemd_journal depends on systemd.SystemdBasicTests.test_systemd_basic but it didn't pass/run.
NOTE: test_systemd_status (systemd.SystemdServiceTests)
NOTE:  ... skipped "Test case systemd.SystemdServiceTests.test_systemd_status depends on systemd.SystemdBasicTests.test_systemd_basic but it didn't pass/run."
Test case systemd.SystemdServiceTests.test_systemd_status depends on systemd.SystemdBasicTests.test_systemd_basic but it didn't pass/run.
NOTE: test_systemd_disable_enable (systemd.SystemdServiceTests)
NOTE:  ... skipped "Test case systemd.SystemdServiceTests.test_systemd_disable_enable depends on systemd.SystemdServiceTests.test_systemd_status but it didn't pass/run."
Test case systemd.SystemdServiceTests.test_systemd_disable_enable depends on systemd.SystemdServiceTests.test_systemd_status but it didn't pass/run.
NOTE: test_systemd_stop_start (systemd.SystemdServiceTests)
NOTE:  ... skipped "Test case systemd.SystemdServiceTests.test_systemd_stop_start depends on systemd.SystemdServiceTests.test_systemd_status but it didn't pass/run."
Test case systemd.SystemdServiceTests.test_systemd_stop_start depends on systemd.SystemdServiceTests.test_systemd_status but it didn't pass/run.
NOTE: ======================================================================
NOTE: FAIL: test_syslog_startup_config (oe_syslog.SyslogTestConfig)
NOTE: ----------------------------------------------------------------------
NOTE: Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/runtime/cases/oe_syslog.py", line 58, in test_syslog_startup_config
    self.assertEqual(status, 0, msg)
AssertionError: 1 != 0 : Could not restart syslog service. Status and output: 1 and Stopping syslogd/klogd: stopped syslogd (pid 5983)
no klogd found; none killed

NOTE: ======================================================================
NOTE: FAIL: test_check_rpm_install_removal_log_file_size (rpm.RpmInstallRemoveTest)
NOTE: ----------------------------------------------------------------------
NOTE: Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuarm64-armhost/build/meta/lib/oeqa/runtime/cases/rpm.py", line 137, in test_check_rpm_install_removal_log_file_size
    'Cound not find sufficient amount of rpm entries in /var/log/messages, found {} entries'.format(output))
AssertionError: 76 not greater than or equal to 80 : Cound not find sufficient amount of rpm entries in /var/log/messages, found 76 entries

NOTE: ----------------------------------------------------------------------
NOTE: Ran 59 tests in 56.777s
NOTE: FAILED
NOTE:  (failures=2, skipped=25)
DEBUG: Stopping logging thread
DEBUG: Stop event received
DEBUG: Tearing down logging thread
DEBUG: Sending SIGTERM to runqemu
RESULTS:
RESULTS - connman.ConnmanTest.test_connmand_help: PASSED (0.18s)
RESULTS - connman.ConnmanTest.test_connmand_running: PASSED (0.15s)
RESULTS - date.DateTest.test_date: PASSED (0.57s)
RESULTS - df.DfTest.test_df: PASSED (0.15s)
RESULTS - dnf.DnfBasicTest.test_dnf_help: PASSED (1.78s)
RESULTS - dnf.DnfBasicTest.test_dnf_history: PASSED (1.22s)
RESULTS - dnf.DnfBasicTest.test_dnf_info: PASSED (0.47s)
RESULTS - dnf.DnfBasicTest.test_dnf_search: PASSED (0.44s)
RESULTS - dnf.DnfBasicTest.test_dnf_version: PASSED (0.42s)
RESULTS - dnf.DnfRepoTest.test_dnf_exclude: PASSED (7.91s)
RESULTS - dnf.DnfRepoTest.test_dnf_install: PASSED (1.55s)
RESULTS - dnf.DnfRepoTest.test_dnf_install_dependency: PASSED (2.80s)
RESULTS - dnf.DnfRepoTest.test_dnf_install_from_disk: PASSED (4.81s)
RESULTS - dnf.DnfRepoTest.test_dnf_install_from_http: PASSED (2.62s)
RESULTS - dnf.DnfRepoTest.test_dnf_installroot: PASSED (14.40s)
RESULTS - dnf.DnfRepoTest.test_dnf_makecache: PASSED (0.47s)
RESULTS - dnf.DnfRepoTest.test_dnf_reinstall: PASSED (0.75s)
RESULTS - dnf.DnfRepoTest.test_dnf_repoinfo: PASSED (0.63s)
RESULTS - oe_syslog.SyslogTest.test_syslog_running: PASSED (0.17s)
RESULTS - oe_syslog.SyslogTestConfig.test_syslog_logger: PASSED (0.31s)
RESULTS - oe_syslog.SyslogTestConfig.test_syslog_restart: PASSED (0.18s)
RESULTS - parselogs.ParseLogsTest.test_parselogs: PASSED (2.60s)
RESULTS - perl.PerlTest.test_perl_works: PASSED (0.17s)
RESULTS - ping.PingTest.test_ping: PASSED (0.10s)
RESULTS - python.PythonTest.test_python3: PASSED (0.17s)
RESULTS - rpm.RpmBasicTest.test_rpm_help: PASSED (0.15s)
RESULTS - rpm.RpmBasicTest.test_rpm_query: PASSED (0.28s)
RESULTS - rpm.RpmInstallRemoveTest.test_rpm_install: PASSED (0.50s)
RESULTS - rpm.RpmInstallRemoveTest.test_rpm_query_nonroot: PASSED (1.03s)
Comment 3 Richard Purdie 2019-06-10 11:32:54 UTC 
From https://autobuilder.yoctoproject.org/typhoon/#/builders/97/builds/30

looks like its taking time for the syslog/klogd processes to restart and the test is getting out of sequence with where the system is at. I suspect we don't see this on x86 as things work slightly faster than with arm. We have seen the issue very occasionally.

The fix might be to improve the syslogd/klogd init script to function better (wait for the dameons to exit?).
Comment 4 Richard Purdie 2019-06-15 12:42:17 UTC 
Maybe be related to #13401?
Comment 5 Richard Purdie 2019-06-17 15:43:19 UTC 
start-stop-daemon comes from busybox and its basic, doesn't support a --retry option to ensure the process in question really does exit.

starts-stop-daemon from dpkg does but we probably need to be able to work with the busybox version.

Perhaps we need to add something to the syslog init script which waits for the pid to exit and then restart and wait for it to start to avoid the race issues we're seeing?
Comment 6 Randy MacLeod 2019-06-20 14:42:44 UTC 
*** Bug 13401 has been marked as a duplicate of this bug. ***