AppTests: Full test cov for app

Signed-off-by: Gabe Goodhart <[email protected]>

Author: gabe-l-hart

scriptit/app.py

@@ -33,6 +33,8 @@
 class TerminalApp:
     __doc__ = __doc__
 
+    CONSOLE_START = "== CONSOLE "
+
     ## Construction ##############################################################
 
     def __init__(
@@ -77,7 +79,6 @@ def __init__(
                 self.log_string_output, self.log_file_handle
             )
         self._wrap_all_logging(preserve_log_handlers)
-        self._log = logging.getLogger("APP")
 
         # Set up a buffer to store non-log lines in
         self.previous_content_entities = []
@@ -115,11 +116,19 @@ def _wrap_all_logging(self, preserve_log_handlers: bool):
         )
 
         # Update all existing handlers
+        # NOTE: The choice here to update _all_ handlers is based on the
+        #   assumption that a user will be unlikely to configure multiple
+        #   handlers when running a terminal app. If they do, log lines will end
+        #   up duplicated for each handler. The alternative is to attempt to
+        #   decide _which_ of the multiple handlers should be wrapped, but this
+        #   gets further complicated by needing to handle future handlers, so
+        #   the simpler choice is to just let this be a user problem.
         for logger in [logging.root] + list(logging.root.manager.loggerDict.values()):
             if isinstance(logger, logging.PlaceHolder):
                 continue
-            for i, handler in enumerate(logger.handlers):
-                logger.handlers[i] = make_wrapped_handler(handler)
+            if logger.handlers:
+                for i, handler in enumerate(logger.handlers):
+                    logger.handlers[i] = make_wrapped_handler(handler)
 
         # When new loggers are set up and have handlers directly configured,
         # intercept them and wrap the handlers
@@ -155,7 +164,7 @@ def _refresh(self, force, use_previous):
         content_height = height - log_height
 
         # Add the log console
-        heading = "== CONSOLE "
+        heading = self.CONSOLE_START
         raw_log_lines = filter(
             lambda line: bool(line.strip()),
             self.log_string_output.getvalue().split("\n"),
@@ -166,6 +175,8 @@ def _refresh(self, force, use_previous):
                 log_lines.append(line[:width])
                 line = line[width:]
             log_lines.append(line)
+        # DEBUG
+        print(log_lines)
         self.printer.add(heading + "=" * max(0, width - len(heading)))
         for line in log_lines[-max_log_lines:]:
             self.printer.add(line)

tests/test_app.py

@@ -0,0 +1,177 @@
+"""
+Tests for TerminalApp
+"""
+
+# Standard
+from contextlib import contextmanager
+from unittest import mock
+import logging
+import os
+import tempfile
+
+from tests.conftest import ResettableStringIO
+
+# Local
+from scriptit import RefreshPrinter, TerminalApp
+
+
+@contextmanager
+def reset_logging():
+    """Fixture to reset global changes to the logging module
+
+    NOTE: This uses a contextmanager instead of a fixture because the pytest log
+        capture system takes place _after_ a fixture runs and therefore the
+        tests end up with multiple handlers.
+    """
+    new_root = logging.RootLogger(logging.root.level)
+    new_manager = logging.Manager(new_root)
+    new_root.manager = new_manager
+    with mock.patch("logging.root", new_root):
+        with mock.patch.object(logging.Logger, "manager", new_manager):
+            with mock.patch.object(logging.Logger, "root", new_root):
+                logging.basicConfig()
+                log = new_root.getChild("TEST")
+                yield log
+
+
+def test_app_basic():
+    """Test that the basic execution of the app works as expected"""
+    with reset_logging() as log:
+        # Set up the app that will capture the logging
+        stream = ResettableStringIO()
+        app = TerminalApp(write_stream=stream)
+
+        # Log and make sure the content went to the stream
+        log.warning("hello")
+        lines = stream.getvalue().split("\n")
+        assert len(lines) == 4
+        assert lines[0].startswith(TerminalApp.CONSOLE_START)
+        assert "hello" in lines[1]
+        assert set([ch for ch in lines[2].strip()]) == {"="}
+        assert not lines[3].strip()
+        stream.reset()
+
+        # Add some content and refresh. This will include the logs and the added
+        # content lines
+        app.add("Line one")
+        app.add("Line two")
+        app.refresh()
+        lines = stream.getvalue().split("\n")
+        assert len(lines) == 7
+        assert lines[0].count(RefreshPrinter.UP_LINE) == 4
+        assert lines[1].startswith(TerminalApp.CONSOLE_START)
+        assert "hello" in lines[2]
+        assert set([ch for ch in lines[3].strip()]) == {"="}
+        assert lines[4].strip() == "Line one"
+        assert lines[5].strip() == "Line two"
+        assert not lines[6].strip()
+
+
+def test_app_log_file():
+    """Test that logging to a file works alongside the app"""
+    with tempfile.TemporaryDirectory() as workdir, reset_logging() as log:
+        log_file = os.path.join(workdir, "test.log")
+        stream = ResettableStringIO()
+        TerminalApp(write_stream=stream, log_file=log_file)
+
+        # Log and make sure the content went to the stream and the file
+        log.warning("hello")
+        lines = stream.getvalue().split("\n")
+        assert len(lines) == 4
+        with open(log_file, "r") as handle:
+            log_file_lines = list(handle.readlines())
+        assert len(log_file_lines) == 1
+        stream.reset()
+
+        # Log again and make sure there are now two log lines in the file
+        log.warning("world")
+        lines = stream.getvalue().split("\n")
+        assert len(lines) == 6  # Clear + extra log line
+        with open(log_file, "r") as handle:
+            log_file_lines = list(handle.readlines())
+        assert len(log_file_lines) == 2
+
+
+def test_app_preserve_logs():
+    """Test that preserving existing loggers works as expected"""
+    with reset_logging() as log:
+        stream = ResettableStringIO()
+        logger_stream = ResettableStringIO()
+        logging.root.addHandler(logging.StreamHandler(logger_stream))
+        TerminalApp(write_stream=stream, preserve_log_handlers=True)
+        log.warning("hello")
+        logged_lines = logger_stream.getvalue().split("\n")
+        assert len(logged_lines) == 2
+        assert "hello" in logged_lines[0]
+        assert not logged_lines[1].strip()
+
+
+def test_app_pad_log_console():
+    """Test that the log console can be padded to a fixed size"""
+    with reset_logging():
+        stream = ResettableStringIO()
+        TerminalApp(
+            write_stream=stream,
+            pad_log_console=True,
+            log_console_size=5,
+        )
+        log = logging.getLogger("NEW")
+        log.warning("watch out")
+        lines = stream.getvalue().split("\n")
+        assert len(lines) == 6  # Padded to 5 plus last newline
+
+
+def test_app_logging_post_config():
+    """Test that logging can be configured after the app initializes and log
+    placeholders don't cause any problems
+    """
+    with reset_logging():
+        stream = ResettableStringIO()
+        TerminalApp(write_stream=stream)
+        logging.basicConfig(level=logging.INFO, force=True)
+        log = logging.getLogger("foo.bar.baz")
+        log.info("hello there")
+        lines = stream.getvalue().split("\n")
+        assert len(lines) == 4  # Header, line, footer, newline
+
+
+def test_app_logging_direct_add_handler():
+    """Make sure that addHandler called on a logger will get wrapped"""
+    with reset_logging():
+        stream = ResettableStringIO()
+        TerminalApp(write_stream=stream)
+        log = logging.getLogger("test")
+        log.addHandler(logging.StreamHandler())
+        log.setLevel(logging.DEBUG)
+        log.propagate = False
+        log.debug("watch out")
+        lines = stream.getvalue().split("\n")
+        assert len(lines) == 4  # Header, line, footer, newline
+
+
+def test_app_logging_placeholder():
+    """Make sure that logging placeholders can be safely reconfigured"""
+    with reset_logging():
+        log = logging.getLogger("foo.bar.baz")
+        stream = ResettableStringIO()
+        TerminalApp(write_stream=stream)
+        log.warning("test")
+        lines = stream.getvalue().split("\n")
+        assert len(lines) == 4  # Header, line, footer, newline
+
+
+def test_app_wrap_long_log_lines():
+    """Make sure long lines get wrapped if they exceed the term width"""
+    term_size_mock = mock.MagicMock()
+    term_width = 20
+    term_size_mock.columns = term_width
+    term_size_mock.lines = 150
+    with reset_logging() as log, mock.patch(
+        "shutil.get_terminal_size", return_value=term_size_mock
+    ):
+        stream = ResettableStringIO()
+        TerminalApp(write_stream=stream)
+        msg = "*" * int(term_width * 2.1)
+        log.warning(msg)
+        lines = stream.getvalue().split("\n")
+        assert len(lines) == 6