shelldriver: make kernel silencing more reliable

Current fire and forget approach doesn't work reliably in all corner
cases for various reasons, like for example serial console bitflip or
lost byte issues due to RX fifo overruns. Those issues mostly happen
frequently during early boot process, where there is a lot of output
going on.

So let's make it more reliable by actually checking the kernel log level
setting via /proc/sys/kernel/printk and retry if it's not set to desired
log level.

Following example is from GL.iNet GL-B1300 device:

 root@(none):/# mg-
 /bin/ash: mg-: not found
 root@(none):/# coRC;ct/rcsy/kerne/rnk;eh QZE[    6.365640] kmodloader:
 loading kernel modules from /etc/modules.d/*
 ...
 dmesg -n 1
 /bin/ash: coRC: not found
 /bin/ash: ct/rcsy/kerne/rnk: not found
 /bin/ash: eh: not found
 root@(none):/# echo BZXI; cat /proc/sys/kernel/printk ; echo AUTHSA
 BZXI
 7       4       1       7
 AUTHSA
 root@(none):/# dmesg -n 1
 root@(none):/# echo XYTH; cat /proc/sys/kernel/printk ; echo PNCWGM
 XYTH
 1       4       1       7
 PNCWGM

Signed-off-by: Petr Štetiar <[email protected]>

Author: ynezz

doc/usage.rst

@@ -542,6 +542,7 @@ environment config:
       '_run',
       Mock(return_value=(['OK'], [], 0))
   ).start()
+  patch.object(ShellDriver, "_silence_kernel", Mock()).start()
 
 .. testcode:: pytest-example
   :hide:

labgrid/driver/shelldriver.py

@@ -113,6 +113,35 @@ def _run(self, cmd, *, timeout=30.0, codec="utf-8", decodeerrors="strict"):
     def run(self, cmd, timeout=30.0, codec="utf-8", decodeerrors="strict"):
         return self._run(cmd, timeout=timeout, codec=codec, decodeerrors=decodeerrors)
 
+    def _raw_run(self, cmd, timeout=2, codec="utf-8", decodeerrors="strict"):
+        """Runs command without run() wrapper as it's not yet available"""
+        marker = gen_marker()
+        self.console.sendline(f"echo {marker[:4]}; {cmd} ; echo {marker[4:]}")
+        _, _, match, _ = self.console.expect(
+            rf"{marker[:4]}(.*){marker[4:]}\s+{self.prompt}",
+            timeout=timeout
+        )
+        data = self.re_vt100.sub('', match.group(1).decode(codec, decodeerrors)).split('\r\n')
+        if data and not data[-1]:
+            del data[-1]
+            return data
+
+    def _silence_kernel(self, timeout, kernel_log_level=1, codec="utf-8", decodeerrors="strict"):
+        """Tries to set kernel log level to KERN_ALERT log level to make it less chatty."""
+
+        while True:
+            self.console.sendline(f"dmesg -n {kernel_log_level}")
+            try:
+                data = self._raw_run("cat /proc/sys/kernel/printk")
+                if data[2] and data[2].startswith(f'{kernel_log_level}\t'):
+                    return
+
+            except TIMEOUT:
+                pass
+
+            if timeout.expired:
+                raise TIMEOUT(f"Timeout of {self.login_timeout} seconds exceeded during waiting for kernel silencer")  # pylint: disable=line-too-long
+
     @step()
     def _await_login(self):
         """Awaits the login prompt and logs the user in"""
@@ -141,7 +170,7 @@ def _await_login(self):
             if index == 0:
                 if not did_silence_kernel:
                     # Silence the kernel and wait for another prompt
-                    self.console.sendline("dmesg -n 1")
+                    self._silence_kernel(timeout)
                     did_silence_kernel = True
                 else:
                     # we got a prompt. no need for any further action to