[OE-core] [PATCH v3] oe_syslog.py: Handle syslogd/klogd restart race

[Jon Mason]

syslogd and klogd can occasionally take too long to restart, which
causes tests to fail by starting before the log daemons are ready.  To
work around this problem, poll for up to 30 seconds on the processes to
verify the old ones are killed and the new ones are up and running.
Similarly, add checks for rsyslogd and systemd-journald to possibly
catch issues with those daemons.

[YOCTO #13379]

Signed-off-by: Jon Mason <jdmason at kudzu.us>
---
 meta/lib/oeqa/runtime/cases/oe_syslog.py | 125 +++++++++++++++++++++--
 1 file changed, 117 insertions(+), 8 deletions(-)

diff --git a/meta/lib/oeqa/runtime/cases/oe_syslog.py b/meta/lib/oeqa/runtime/cases/oe_syslog.py
index 0f5f9f43ca..40a52eb078 100644
--- a/meta/lib/oeqa/runtime/cases/oe_syslog.py
+++ b/meta/lib/oeqa/runtime/cases/oe_syslog.py
@@ -6,6 +6,7 @@ from oeqa.runtime.case import OERuntimeTestCase
 from oeqa.core.decorator.depends import OETestDepends
 from oeqa.core.decorator.data import skipIfDataVar
 from oeqa.runtime.decorator.package import OEHasPackage
+import time
 
 class SyslogTest(OERuntimeTestCase):
 
@@ -21,6 +22,110 @@ class SyslogTest(OERuntimeTestCase):
 
 class SyslogTestConfig(OERuntimeTestCase):
 
+    @OETestDepends(['oe_syslog.SyslogTest.test_syslog_running'])
+    def rsyslog_restart_sanity(self, rsyslog_pid):
+        status, output = self.target.run('/etc/init.d/rsyslog restart')
+
+        # Always check for an error, most likely a race between shutting down and starting up
+        timeout = time.time() + 30
+
+        while time.time() < timeout:
+            # Verify the previous ones are no longer running
+            status, err_output = self.target.run('kill -0 %s' %rsyslog_pid)
+            if not status:
+                self.logger.debug("previous rsyslogd is still running")
+                status = 1
+                continue
+
+            # Verify the new ones are running
+            status, new_rsyslog_pid = self.target.run('pidof rsyslogd')
+            if status:
+                self.logger.debug("new rsyslogd is not running")
+                continue
+
+            # Everything is fine now, so keep running
+            status = 0
+            break
+
+        msg = ('Could not restart rsyslog service. Status and output:'
+               ' %s and %s' % (status,output))
+        self.assertEqual(status, 0, msg)
+
+
+    @OETestDepends(['oe_syslog.SyslogTest.test_syslog_running'])
+    def systemd_journal_restart_sanity(self, journald_pid):
+        status, output = self.target.run('systemctl restart syslog.service')
+
+        # Always check for an error, most likely a race between shutting down and starting up
+        timeout = time.time() + 30
+
+        while time.time() < timeout:
+            # Verify the previous ones are no longer running
+            status, err_output = self.target.run('kill -0 %s' %journald_pid)
+            if not status:
+                self.logger.debug("previous systemd-journald is still running")
+                status = 1
+                continue
+
+            # Verify the new ones are running
+            status, new_journald_pid = self.target.run('pidof systemd-journald')
+            if status:
+                self.logger.debug("new systemd-journald is not running")
+                continue
+
+            # Everything is fine now, so keep running
+            status = 0
+            break
+
+        msg = ('Could not restart systemd-journald service. Status and output:'
+               ' %s and %s' % (status,output))
+        self.assertEqual(status, 0, msg)
+
+
+    @OETestDepends(['oe_syslog.SyslogTest.test_syslog_running'])
+    def syslog_restart_sanity(self):
+        status, syslogd_pid = self.target.run('pidof syslogd')
+        status, klogd_pid = self.target.run('pidof klogd')
+
+        status, output = self.target.run('/etc/init.d/syslog restart')
+
+        # Always check for an error, most likely a race between shutting down and starting up
+        timeout = time.time() + 30
+
+        while time.time() < timeout:
+            # Verify the previous ones are no longer running
+            status, err_output = self.target.run('kill -0 %s' %syslogd_pid)
+            if not status:
+                self.logger.debug("previous syslogd is still running")
+                status = 1
+                continue
+
+            status, err_output = self.target.run('kill -0 %s' %klogd_pid)
+            if not status:
+                self.logger.debug("previous klogd is still running")
+                status = 1
+                continue
+
+            # Verify the new ones are running
+            status, new_syslogd_pid = self.target.run('pidof syslogd')
+            if status:
+                self.logger.debug("new syslogd is not running")
+                continue
+
+            status, new_klogd_pid = self.target.run('pidof klogd')
+            if status:
+                self.logger.debug("new syslogd is not running")
+                continue
+
+            # Everything is fine now, so keep running
+            status = 0
+            break
+
+        msg = ('Could not restart syslog service. Status and output:'
+               ' %s and %s' % (status,output))
+        self.assertEqual(status, 0, msg)
+
+
     @OETestDepends(['oe_syslog.SyslogTest.test_syslog_running'])
     def test_syslog_logger(self):
         status, output = self.target.run('logger foobar')
@@ -37,12 +142,18 @@ class SyslogTestConfig(OERuntimeTestCase):
                ' Output: %s ' % output)
         self.assertEqual(status, 0, msg=msg)
 
+
     @OETestDepends(['oe_syslog.SyslogTest.test_syslog_running'])
     def test_syslog_restart(self):
-        if "systemd" != self.tc.td.get("VIRTUAL-RUNTIME_init_manager", ""):
-            (_, _) = self.target.run('/etc/init.d/syslog restart')
+        status, journal_pid = self.target.run('pidof systemd-journald')
+        if not status:
+            self.systemd_journal_restart_sanity(journal_pid)
         else:
-            (_, _) = self.target.run('systemctl restart syslog.service')
+            status, rsyslog_pid = self.target.run('pidof rsyslogd')
+            if not status:
+                self.rsyslog_restart_sanity(rsyslog_pid)
+            else:
+                self.syslog_restart_sanity()
 
 
     @OETestDepends(['oe_syslog.SyslogTestConfig.test_syslog_logger'])
@@ -52,10 +163,8 @@ class SyslogTestConfig(OERuntimeTestCase):
     def test_syslog_startup_config(self):
         cmd = 'echo "LOGFILE=/var/log/test" >> /etc/syslog-startup.conf'
         self.target.run(cmd)
-        status, output = self.target.run('/etc/init.d/syslog restart')
-        msg = ('Could not restart syslog service. Status and output:'
-               ' %s and %s' % (status,output))
-        self.assertEqual(status, 0, msg)
+
+        self.syslog_restart_sanity()
 
         cmd = 'logger foobar && grep foobar /var/log/test'
         status,output = self.target.run(cmd)
@@ -64,4 +173,4 @@ class SyslogTestConfig(OERuntimeTestCase):
 
         cmd = "sed -i 's#LOGFILE=/var/log/test##' /etc/syslog-startup.conf"
         self.target.run(cmd)
-        self.target.run('/etc/init.d/syslog restart')
+        self.syslog_restart_sanity()
-- 
2.21.0