Simplify sut_stdout and test_stdout events

Simplifed stdout events showing data coming from SUT during execution.
With this patch we are also much faster to read from Qemu process
stdout.

Signed-off-by: Andrea Cervesato <andrea.cervesato@suse.com>

Author: acerv

ltp/dispatcher.py

@@ -164,42 +164,21 @@ def exec_suites(self, suites: list, skip_tests: list = None) -> list:
         raise NotImplementedError()
 
 
-class StdoutChecker(IOBuffer):
+class RedirectTestStdout(IOBuffer):
     """
     Check for test's stdout and raise an exception if Kernel panic occured.
     """
 
     def __init__(self, test: Test) -> None:
-        self.stdout = ""
         self._test = test
-        self._line = ""
+        self.stdout = ""
 
     def write(self, data: str) -> None:
-        if len(data) == 1:
-            self._line += data
-            if data == "\n":
-                ltp.events.fire(
-                    "test_stdout_line",
-                    self._test,
-                    self._line[:-1])
-                self._line = ""
-        else:
-            lines = data.split('\n')
-            for line in lines[:-1]:
-                self._line += line
-                ltp.events.fire("test_stdout_line", self._test, self._line)
-                self._line = ""
-
-            self._line = lines[-1]
-
-            if data.endswith('\n') and self._line:
-                ltp.events.fire("test_stdout_line", self._test, self._line)
-                self._line = ""
-
+        ltp.events.fire("test_stdout", self._test, data)
         self.stdout += data
 
 
-class RedirectStdout(IOBuffer):
+class RedirectSUTStdout(IOBuffer):
     """
     Redirect data from stdout to events.
     """
@@ -211,7 +190,7 @@ def write(self, data: str) -> None:
         if not self._sut:
             return
 
-        ltp.events.fire("sut_stdout_line", self._sut.name, data)
+        ltp.events.fire("sut_stdout", self._sut.name, data)
 
 
 class SerialDispatcher(Dispatcher):
@@ -313,7 +292,7 @@ def _reboot_sut(self, force: bool = False) -> None:
 
         self._sut.ensure_communicate(
             timeout=3600,
-            iobuffer=RedirectStdout(self._sut),
+            iobuffer=RedirectSUTStdout(self._sut),
             force=force)
 
         self._logger.info("SUT rebooted")
@@ -365,12 +344,12 @@ def _run_test(self, test: Test) -> TestResults:
         timed_out = False
         reboot = False
 
-        checker = StdoutChecker(test)
+        buffer = RedirectTestStdout(test)
         try:
             test_data = self._sut.run_command(
                 cmd,
                 timeout=self._test_timeout,
-                iobuffer=checker)
+                iobuffer=buffer)
         except SUTTimeoutError:
             timed_out = True
             try:
@@ -405,7 +384,7 @@ def _run_test(self, test: Test) -> TestResults:
             test_data = {
                 "name": test.name,
                 "command": test.command,
-                "stdout": checker.stdout,
+                "stdout": buffer.stdout,
                 "returncode": -1,
                 "exec_time": self._test_timeout,
             }

ltp/qemu.py

@@ -56,6 +56,7 @@ def __init__(self) -> None:
         self._serial_type = None
         self._qemu_cmd = None
         self._opts = None
+        self._last_read = ""
 
     @staticmethod
     def _generate_string(length: int = 10) -> str:
@@ -263,28 +264,41 @@ def _wait_for(
         if not self.is_running:
             return None
 
-        stdout = ""
+        stdout = self._last_read
         panic = False
+        found = False
 
         with Timeout(timeout) as timer:
-            while not stdout.endswith(message):
+            while not found:
                 events = self._poller.poll(0.1)
 
-                if not events and self._stop:
-                    break
+                # stop or panic when no events are available,
+                # so we collect all stdout before exit
+                if not events:
+                    if self._stop:
+                        break
 
-                if not events and panic:
-                    raise KernelPanicError()
+                    if panic:
+                        raise KernelPanicError()
 
                 for fdesc, _ in events:
                     if fdesc != self._proc.stdout.fileno():
                         continue
 
-                    data = self._read_stdout(1, iobuffer)
+                    data = self._read_stdout(1024, iobuffer)
                     if data:
                         stdout += data
 
-                    if stdout.endswith("Kernel panic"):
+                    # search for message inside stdout
+                    message_pos = stdout.find(message)
+                    if message_pos != -1:
+                        self._last_read = stdout[message_pos + len(message):]
+                        found = True
+                        break
+
+                    # turn on panic flag, so we rise it when all the
+                    # stdout has been collected
+                    if "Kernel panic" in stdout:
                         panic = True
 
                 timer.check(

ltp/session.py

@@ -25,7 +25,7 @@ class SessionError(LTPException):
     """
 
 
-class Printer(IOBuffer):
+class RedirectStdout(IOBuffer):
     """
     Redirect data from stdout to events.
     """
@@ -38,7 +38,7 @@ def write(self, data: str) -> None:
         if self._is_cmd:
             ltp.events.fire("run_cmd_stdout", data)
         else:
-            ltp.events.fire("sut_stdout_line", self._sut.name, data)
+            ltp.events.fire("sut_stdout", self._sut.name, data)
 
 
 class Session:
@@ -150,7 +150,7 @@ def _start_sut(self) -> None:
 
         self._sut.ensure_communicate(
             timeout=3600,
-            iobuffer=Printer(self._sut, False))
+            iobuffer=RedirectStdout(self._sut, False))
 
     def _stop_sut(self, timeout: float = 30) -> None:
         """
@@ -164,11 +164,11 @@ def _stop_sut(self, timeout: float = 30) -> None:
         if self._sut.is_running:
             self._sut.stop(
                 timeout=timeout,
-                iobuffer=Printer(self._sut, False))
+                iobuffer=RedirectStdout(self._sut, False))
         else:
             self._sut.force_stop(
                 timeout=timeout,
-                iobuffer=Printer(self._sut, False))
+                iobuffer=RedirectStdout(self._sut, False))
 
     def _stop_all(self, timeout: float = 30) -> None:
         """
@@ -227,7 +227,7 @@ def run_single(
                     ret = self._sut.run_command(
                         command,
                         timeout=self._exec_timeout,
-                        iobuffer=Printer(self._sut, True))
+                        iobuffer=RedirectStdout(self._sut, True))
 
                     ltp.events.fire(
                         "run_cmd_stop",

ltp/ui.py

@@ -13,11 +13,10 @@
 from ltp.results import TestResults
 from ltp.results import SuiteResults
 
+
 # pylint: disable=too-many-public-methods
 # pylint: disable=missing-function-docstring
 # pylint: disable=unused-argument
-
-
 class ConsoleUserInterface:
     """
     Console based user interface.
@@ -32,7 +31,6 @@ class ConsoleUserInterface:
 
     def __init__(self, no_colors: bool = False) -> None:
         self._no_colors = no_colors
-        self._line = ""
         self._tmpdir = ""
 
         ltp.events.register("session_started", self.session_started)
@@ -81,30 +79,6 @@ def _user_friendly_duration(duration: float) -> str:
 
         return uf_time
 
-    def _print_stdout(self, data: str) -> None:
-        """
-        Print stdout coming from command run or test.
-        """
-        if len(data) == 1:
-            self._line += data
-            if data == "\n":
-                self._print(self._line, end='')
-                self._line = ""
-        else:
-            lines = data.splitlines(True)
-            if len(lines) > 0:
-                for line in lines[:-1]:
-                    self._line += line
-
-                    self._print(self._line, end='')
-                    self._line = ""
-
-                self._line = lines[-1]
-
-            if data.endswith('\n') and self._line:
-                self._print(self._line, end='')
-                self._line = ""
-
     def session_started(self, tmpdir: str) -> None:
         uname = platform.uname()
         message = "Host information\n\n"
@@ -135,7 +109,7 @@ def run_cmd_start(self, cmd: str) -> None:
         self._print(f"{cmd}", color=self.CYAN)
 
     def run_cmd_stdout(self, data: str) -> None:
-        self._print_stdout(data)
+        self._print(data, end='')
 
     def run_cmd_stop(self, command: str, stdout: str, returncode: int) -> None:
         self._print(f"\nExit code: {returncode}\n")
@@ -273,15 +247,15 @@ def __init__(self, no_colors: bool = False) -> None:
 
         self._timed_out = False
 
-        ltp.events.register("sut_stdout_line", self.sut_stdout_line)
+        ltp.events.register("sut_stdout", self.sut_stdout)
         ltp.events.register("kernel_tainted", self.kernel_tainted)
         ltp.events.register("test_timed_out", self.test_timed_out)
         ltp.events.register("test_started", self.test_started)
         ltp.events.register("test_completed", self.test_completed)
-        ltp.events.register("test_stdout_line", self.test_stdout_line)
+        ltp.events.register("test_stdout", self.test_stdout)
 
-    def sut_stdout_line(self, _: str, data: str) -> None:
-        self._print_stdout(data)
+    def sut_stdout(self, _: str, data: str) -> None:
+        self._print(data, end='')
 
     def kernel_tainted(self, message: str) -> None:
         self._print(f"Tained kernel: {message}", color=self.YELLOW)
@@ -313,10 +287,10 @@ def test_completed(self, results: TestResults) -> None:
         uf_time = self._user_friendly_duration(results.exec_time)
         self._print(f"\nDuration: {uf_time}\n")
 
-    def test_stdout_line(self, _: Test, line: str) -> None:
+    def test_stdout(self, _: Test, line: str) -> None:
         col = ""
 
         if "Kernel panic" in line:
             col = self.RED
 
-        self._print(line, color=col)
+        self._print(line, color=col, end='')