Reworking logging [Not final].

datashuttle/utils/ds_logger.py

@@ -17,6 +17,22 @@
 from datashuttle.utils import utils
 
 
+def get_logger_name():
+    return "datashuttle"
+
+
+def get_logger():
+    return logging.getLogger(get_logger_name())
+
+
+def logging_is_active():
+    logger_exists = get_logger_name() in logging.root.manager.loggerDict
+    if logger_exists:
+        if get_logger().handlers != []:
+            return True
+    return False
+
+
 def start(
     path_to_log: Path,
     command_name: str,
@@ -38,8 +54,10 @@ def start(
         file_log_level="DEBUG",
         write_git=True,
         log_to_console=False,
+        logger_name=get_logger_name(),
     )
-    logging.info(f"Starting logging for command {command_name}")
+    logger = get_logger()
+    logger.info(f"Starting logging for command {command_name}")
 
 
 def get_logging_filename(command_name: str) -> str:
@@ -94,7 +112,8 @@ def close_log_filehandler() -> None:
     """
     Remove handlers from all loggers.
     """
-    logger = logging.getLogger()
+    logger = get_logger()
+    logger.debug("Finished logging.")
     handlers = logger.handlers[:]
     for handler in handlers:
         logger.removeHandler(handler)

datashuttle/utils/utils.py

@@ -1,6 +1,5 @@
 from __future__ import annotations
 
-import logging
 import re
 import traceback
 import warnings
@@ -24,8 +23,9 @@ def log(message: str) -> None:
     Log the message to the main initialised
     logger.
     """
-    logger = logging.getLogger("datashuttle")
-    logger.debug(message)
+    if ds_logger.logging_is_active():
+        logger = ds_logger.get_logger()
+        logger.debug(message)
 
 
 def log_and_message(message: str, use_rich: bool = False) -> None:
@@ -41,13 +41,21 @@ def log_and_raise_error(message: str, exception: Any) -> None:
     """
     Log the message before raising the same message as an error.
     """
-    if "datashuttle" in logging.root.manager.loggerDict.keys():
-        logger = logging.getLogger("datashuttle")
+    if ds_logger.logging_is_active():
+        logger = ds_logger.get_logger()
         logger.error(f"\n\n{' '.join(traceback.format_stack(limit=5))}")
         logger.error(message)
     raise_error(message, exception)
 
 
+def warn(message: str, log: bool) -> None:
+    """ """
+    if log and ds_logger.logging_is_active():
+        logger = ds_logger.get_logger()
+        logger.warning(message)
+    warnings.warn(message)
+
+
 def raise_error(message: str, exception) -> None:
     """
     Centralized way to raise an error. The logger is closed
@@ -58,14 +66,6 @@ def raise_error(message: str, exception) -> None:
     raise exception(message)
 
 
-def warn(message: str, log: bool) -> None:
-    """ """
-    if log:
-        logger = logging.getLogger("datashuttle")
-        logger.warning(message)
-    warnings.warn(message)
-
-
 def print_message_to_user(
     message: Union[str, list], use_rich: bool = False
 ) -> None:

pyproject.toml

@@ -16,7 +16,7 @@ dependencies = [
     "PyYAML",
     "requests",
     "rich",
-    "fancylog",
+    "fancylog>=0.4.2",
     "simplejson",
     "pyperclip",
     "textual",

tests/test_utils.py

@@ -581,7 +581,7 @@ def set_datashuttle_loggers(disable):
     of test_logging.py and turned back off during
     tear-down.
     """
-    for name in ["datashuttle", "rich"]:
+    for name in [ds_logger.get_logger_name(), "rich"]:
         logger = logging.getLogger(name)
         logger.disabled = disable
 

tests/tests_integration/test_logging.py

@@ -1,4 +1,5 @@
 import glob
+import logging
 import os
 import re
 from pathlib import Path
@@ -8,13 +9,85 @@
 
 from datashuttle import DataShuttle
 from datashuttle.configs.canonical_tags import tags
+from datashuttle.utils import ds_logger
 from datashuttle.utils.custom_exceptions import (
     ConfigError,
     NeuroBlueprintError,
 )
 
 
 class TestLogging:
+
+    @pytest.fixture(scope="function")
+    def teardown_logger(self):
+        """
+        Ensure the logger is deleted at the end of each test.
+        """
+        yield
+        if "datashuttle" in logging.root.manager.loggerDict:
+            logging.root.manager.loggerDict.pop("datashuttle")
+
+    # -------------------------------------------------------------------------
+    # Basic Functionality Tests
+    # -------------------------------------------------------------------------
+
+    def test_logger_name(self):
+        """
+        Check the canonical logger name.
+        """
+        assert ds_logger.get_logger_name() == "datashuttle"
+
+    def test_start_logging(self, tmp_path, teardown_logger):
+        """
+        Test that the central `start` logging function
+        starts the named logger with the expected handlers.
+        """
+        assert ds_logger.logging_is_active() is False
+
+        ds_logger.start(tmp_path, "test-command", variables=[])
+
+        # test logger exists and is as expected
+        assert "datashuttle" in logging.root.manager.loggerDict
+        assert ds_logger.logging_is_active() is True
+
+        logger = logging.getLogger("datashuttle")
+        assert logger.propagate is False
+        assert len(logger.handlers) == 1
+        assert isinstance(logger.handlers[0], logging.FileHandler)
+
+    def test_shutdown_logger(self, tmp_path, teardown_logger):
+        """
+        Check the log handler remover indeed removes the handles.
+        """
+        assert ds_logger.logging_is_active() is False
+
+        ds_logger.start(tmp_path, "test-command", variables=[])
+
+        logger = logging.getLogger("datashuttle")
+
+        ds_logger.close_log_filehandler()
+
+        assert len(logger.handlers) == 0
+        assert ds_logger.logging_is_active() is False
+
+    def test_logging_an_error(self, project, teardown_logger):
+        """
+        Check that errors are caught and logged properly.
+        """
+        try:
+            project.create_folders("rawdata", "sob-001")
+        except:
+            pass
+
+        log = test_utils.read_log_file(project.cfg.logging_path)
+
+        assert "ERROR" in log
+        assert "Problem with name:" in log
+
+    # -------------------------------------------------------------------------
+    # Functional Tests
+    # -------------------------------------------------------------------------
+
     @pytest.fixture(scope="function")
     def clean_project_name(self):
         """