Mlcube download log

cli/medperf/tests/ui/test_cli.py

@@ -21,7 +21,18 @@ def test_print_displays_message_through_typer(self, mocker, cli, msg):
         cli.print(msg)
 
         # Assert
-        spy.assert_called_once_with(msg)
+        spy.assert_called_once_with(msg, nl=True)
+
+    @pytest.mark.parametrize("nl", [True, False])
+    def test_print_typer_new_line(self, mocker, cli, msg, nl):
+        # Arrange
+        spy = mocker.patch("typer.echo")
+
+        # Act
+        cli.print(msg, nl=nl)
+
+        # Assert
+        spy.assert_called_once_with(msg, nl=nl)
 
     def test_print_displays_message_through_yaspin_when_interactive(
         self, mocker, cli, msg

cli/medperf/ui/cli.py

@@ -11,13 +11,14 @@ def __init__(self):
         self.spinner = yaspin(color="green")
         self.is_interactive = False
 
-    def print(self, msg: str = ""):
+    def print(self, msg: str = "", nl: bool = True):
         """Display a message on the command line
 
         Args:
             msg (str): message to print
+            nl: if print a new line after message
         """
-        self.__print(msg)
+        self.__print(msg, nl=nl)
 
     def print_error(self, msg: str):
         """Display an error message on the command line
@@ -38,11 +39,14 @@ def print_warning(self, msg: str):
         msg = typer.style(msg, fg=typer.colors.YELLOW, bold=True)
         self.__print(msg)
 
-    def __print(self, msg: str = ""):
+    def __print(self, msg: str = "", nl: bool = True):
         if self.is_interactive:
+            # TODO: nl does not work for yaspin as new-line character
+            #  is explicitly hardcoded in spinner.write()
             self.spinner.write(msg)
         else:
-            typer.echo(msg)
+            # pass
+            typer.echo(msg, nl=nl)
 
     def start_interactive(self):
         """Start an interactive session where messages can be overwritten

cli/medperf/ui/interface.py

@@ -3,8 +3,10 @@
 
 
 class UI(ABC):
+    is_interactive: bool = False
+
     @abstractmethod
-    def print(self, msg: str = ""):
+    def print(self, msg: str = "", nl: bool = True):
         """Display a message to the interface. If on interactive session overrides
         previous message
         """
@@ -33,19 +35,17 @@ def stop_interactive(self):
     def interactive(self):
         """Context managed interactive session. Expected to yield the same instance"""
 
+    @property
     @abstractmethod
-    def text(self, msg: str):
+    def text(self):
         """Displays a messages that overwrites previous messages if they were created
         during an interactive session.
         If not supported or not on an interactive session, it is expected to fallback
         to the UI print function.
-
-        Args:
-            msg (str): message to display
         """
 
     @abstractmethod
-    def prompt(msg: str) -> str:
+    def prompt(self, msg: str) -> str:
         """Displays a prompt to the user and waits for an answer"""
 
     @abstractmethod

cli/medperf/ui/stdin.py

@@ -11,8 +11,8 @@ class StdIn(UI):
     hidden prompts and interactive prints will not work as expected.
     """
 
-    def print(self, msg: str = ""):
-        return print(msg)
+    def print(self, msg: str = "", nl: bool = True):
+        return print(msg, end='\n' if nl else '')
 
     def print_error(self, msg: str):
         return self.print(msg)
@@ -40,3 +40,6 @@ def prompt(self, msg: str) -> str:
 
     def hidden_prompt(self, msg: str) -> str:
         return self.prompt(msg)
+
+    def print_highlight(self, msg: str = ""):
+        self.print(msg)

cli/medperf/utils.py

@@ -16,12 +16,13 @@
 from pexpect import spawn
 from datetime import datetime
 from pydantic.datetime_parse import parse_datetime
-from typing import List
+from typing import List, Generator
 from colorama import Fore, Style
-from pexpect.exceptions import TIMEOUT
+from pexpect.exceptions import TIMEOUT, EOF
 from git import Repo, GitCommandError
 import medperf.config as config
 from medperf.exceptions import ExecutionError, MedperfException, InvalidEntityError
+from medperf.ui.interface import UI
 
 
 def get_file_hash(path: str) -> str:
@@ -217,7 +218,7 @@ def dict_pretty_print(in_dict: dict, skip_none_values: bool = True):
 class _MLCubeOutputFilter:
     def __init__(self, proc_pid: int):
         self.log_pattern = re.compile(
-            r"^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2} \S+ \S+\[(\d+)\] (\S+) (.*)$"
+            r"^\s*\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2} \S+ \S+\[(\d+)\] (\S+) (.*)$"
         )
         # Clear log lines from color / style symbols before matching with regexp
         self.ansi_escape_pattern = re.compile(r'\x1b\[[0-9;]*[mGK]')
@@ -231,18 +232,35 @@ def check_line(self, line: str) -> bool:
             true if line should be filtered out (==saved to debug file only),
             false if line should be printed to user also
         """
-        match = self.log_pattern.match(self.ansi_escape_pattern.sub('', line))
+        clean_line = self.ansi_escape_pattern.sub('', line)
+        match = self.log_pattern.match(clean_line)
         if match:
             line_pid, matched_log_level_str, content = match.groups()
             matched_log_level = logging.getLevelName(matched_log_level_str)
 
             # if line matches conditions, it is just logged to debug; else, shown to user
-            return (line_pid == self.proc_pid  # hide only `mlcube` framework logs
-                    and isinstance(matched_log_level, int)
-                    and matched_log_level < logging.INFO)  # hide only debug logs
+            result = (line_pid == self.proc_pid  # hide only `mlcube` framework logs
+                      and isinstance(matched_log_level, int)
+                      and matched_log_level < logging.INFO)  # hide only debug logs
+            return result
         return False
 
 
+def _read_new_line_from_proc(proc: spawn) -> Generator[str]:
+    buffer: list[bytes] = []
+    new_lines = {'\r', '\n'}
+    try:
+        while ch := proc.read(1):
+
+            if ch.decode('utf-8', 'ignore') in new_lines:
+                res = b''.join(buffer).decode('utf-8')
+                buffer = []
+                yield res
+            buffer.append(ch)
+    except EOF:
+        yield b''.join(buffer).decode('utf-8')
+
+
 def combine_proc_sp_text(proc: spawn) -> str:
     """Combines the output of a process and the spinner.
     Joins any string captured from the process with the
@@ -256,34 +274,33 @@ def combine_proc_sp_text(proc: spawn) -> str:
         str: all non-carriage-return-ending string captured from proc
     """
 
-    ui = config.ui
+    ui: UI = config.ui
+    ui_was_interactive = ui.is_interactive
+    ui.stop_interactive()
     proc_out = ""
-    break_ = False
     log_filter = _MLCubeOutputFilter(proc.pid)
 
-    while not break_:
-        if not proc.isalive():
-            break_ = True
-        try:
-            line = proc.readline()
-        except TIMEOUT:
-            logging.error("Process timed out")
-            logging.debug(proc_out)
-            raise ExecutionError("Process timed out")
-        line = line.decode("utf-8", "ignore")
-
-        if not line:
-            continue
-
-        # Always log each line just in case the final proc_out
-        # wasn't logged for some reason
-        logging.debug(line)
-        proc_out += line
-        if not log_filter.check_line(line):
-            ui.print(f"{Fore.WHITE}{Style.DIM}{line.strip()}{Style.RESET_ALL}")
-
-    logging.debug("MLCube process finished")
-    logging.debug(proc_out)
+    try:
+        for line in _read_new_line_from_proc(proc):
+            if not line:
+                break
+
+            # Always log each line just in case the final proc_out
+            # wasn't logged for some reason
+            logging.debug(line)
+            proc_out += line
+            if not log_filter.check_line(line):
+                ui.print(f"{Fore.WHITE}{Style.DIM}{line}{Style.RESET_ALL}", nl=False)
+
+        logging.debug("MLCube process finished")
+    except TIMEOUT:
+        logging.error("Process timed out")
+        raise ExecutionError("Process timed out")
+    finally:
+        logging.debug(proc_out)
+        if ui_was_interactive:
+            ui.start_interactive()
+
     return proc_out