🔧 DEV: Filter Logger Output to stdout and stderr (#557)

- Filter logger output to `stdout` instead of `stderr`

---------

Co-authored-by: John Pocock <[email protected]>
Co-authored-by: pre-commit-ci[bot] <66853113+pre-commit-ci[bot]@users.noreply.github.com>

tests/test_init.py

@@ -4,6 +4,7 @@
 import logging
 import os
 import shutil
+import subprocess
 
 import pytest
 
@@ -40,14 +41,66 @@ def test_set_logger():
     logger.handlers = []  # reset first to overwrite import
     handler_1 = logging.StreamHandler()
     handler_2 = logging.StreamHandler()
+    handler_3 = logging.StreamHandler()
     logger.addHandler(handler_1)
     logger.addHandler(handler_2)
-    assert len(logger.handlers) == 2
+    logger.addHandler(handler_3)
+    assert len(logger.handlers) == 3
     # skipcq
     importlib.reload(tiatoolbox)
     # should not overwrite, so still have 2 handler
-    assert len(logger.handlers) == 2
+    assert len(logger.handlers) == 3
     logger.handlers = []  # remove all handler
     # skipcq
     importlib.reload(tiatoolbox)
-    assert len(logger.handlers) == 1
+    assert len(logger.handlers) == 2
+
+
+def helper_logger_test(level: str):
+    """Helper for logger tests."""
+    if level.lower() in ["debug", "info"]:
+        output = "out"
+        order = (0, 1)
+    else:
+        output = "err"
+        order = (1, 0)
+    run_statement = (
+        f"from tiatoolbox import logger; "
+        f"import logging; "
+        f"logger.setLevel(logging.{level.upper()}); "
+        f'logger.{level.lower()}("Test if {level.lower()} is written to std{output}.")'
+    )
+
+    proc = subprocess.Popen(
+        [
+            "python",
+            "-c",
+            run_statement,
+        ],
+        stdout=subprocess.PIPE,
+        stderr=subprocess.PIPE,
+    )
+
+    assert (
+        f"[{level.upper()}] Test if {level.lower()} is written to std{output}.".encode()
+        in proc.communicate()[order[0]]
+    )
+    assert proc.communicate()[order[1]] == b""
+
+
+def test_logger_output():
+    """Tests if logger is writing output to correct value."""
+    # Test DEBUG is written to stdout
+    helper_logger_test(level="debug")
+
+    # Test INFO is written to stdout
+    helper_logger_test(level="info")
+
+    # Test WARNING is written to stderr
+    helper_logger_test(level="warning")
+
+    # Test ERROR is written to stderr
+    helper_logger_test(level="error")
+
+    # Test CRITICAL is written to stderr
+    helper_logger_test(level="critical")

tiatoolbox/__init__.py

@@ -25,15 +25,22 @@
 # logging
 logging.captureWarnings(True)
 if not logging.getLogger().hasHandlers():
-    handler = logging.StreamHandler()
     formatter = logging.Formatter(
         "|%(asctime)s.%(msecs)03d| [%(levelname)s] %(message)s",
         datefmt="%Y-%m-%d|%H:%M:%S",
     )
-    handler.setFormatter(formatter)
+    stdout_handler = logging.StreamHandler(sys.stdout)
+    stdout_handler.setFormatter(formatter)
+    stdout_handler.addFilter(lambda record: record.levelno <= logging.INFO)
+
+    stderr_handler = logging.StreamHandler()
+    stderr_handler.setFormatter(formatter)
+    stderr_handler.setLevel(logging.WARNING)
+
     logger = logging.getLogger()  # get root logger
     logger.setLevel(logging.INFO)
-    logger.addHandler(handler)
+    logger.addHandler(stdout_handler)
+    logger.addHandler(stderr_handler)
 else:
     logger = logging.getLogger()