Cleanup logger function

docs/CHANGELOG.rst

@@ -2,6 +2,7 @@
 Changelog
 =========
 
+* Cleanup logger function
 
 v0.1.31 (2024-07-08)
 ------------------------------------------

src/mdacli/logger.py

@@ -6,18 +6,55 @@
 # Released under the GNU Public Licence, v2 or any higher version
 # SPDX-License-Identifier: GPL-2.0-or-later
 """Logging."""
-
 import contextlib
 import logging
 import sys
+import warnings
+from pathlib import Path
+from typing import List, Optional, Union
 
 from .colors import Emphasise
 
 
-@contextlib.contextmanager
-def setup_logging(logobj, logfile=None, level=logging.WARNING):
+def check_suffix(filename: Union[str, Path], suffix: str) -> Union[str, Path]:
+    """Check the suffix of a file name and adds if it not existing.
+
+    If ``filename`` does not end with ``suffix`` the ``suffix`` is added and a
+    warning will be issued.
+
+    Parameters
+    ----------
+    filename : Name of the file to be checked.
+    suffix : Expected file suffix i.e. ``.txt``.
+
+    Returns
+    -------
+    Checked and probably extended file name.
     """
-    Create a logging environment for a given logobj.
+    path_filename = Path(filename)
+
+    if path_filename.suffix != suffix:
+        warnings.warn(
+            f"The file name should have a '{suffix}' extension. The user "
+            f"requested the file with name '{filename}', but it will be saved "
+            f"as '{filename}{suffix}'.",
+            stacklevel=1,
+        )
+        path_filename = path_filename.parent / (path_filename.name + suffix)
+
+    if type(filename) is str:
+        return str(path_filename)
+    else:
+        return path_filename
+
+
+@contextlib.contextmanager
+def setup_logging(
+    logobj: logging.Logger,
+    logfile: Optional[Union[str, Path]] = None,
+    level: int = logging.WARNING,
+):
+    """Create a logging environment for a given ``log_obj``.
 
     Parameters
     ----------
@@ -28,38 +65,51 @@ def setup_logging(logobj, logfile=None, level=logging.WARNING):
     level : int
         Set the root logger level to the specified level. If for example set
         to :py:obj:`logging.DEBUG` detailed debug logs inludcing filename and
-        function name are displayed. For :py:obj:`logging.INFO only the message
-        logged from errors, warnings and infos will be displayed.
+        function name are displayed. For :py:obj:`logging.INFO` only the
+        message logged from errors, warnings and infos will be displayed.
     """
     try:
+        format = ""
         if level == logging.DEBUG:
-            format = (
-                "[{levelname}] {filename}:{name}:{funcName}:{lineno}: "
-                "{message}"
-            )
-        else:
-            format = "{message}"
+            format += "[{levelname}]:{filename}:{funcName}:{lineno} - "
+        format += "{message}"
+
+        formatter = logging.Formatter(format, style="{")
+        handlers: List[Union[logging.StreamHandler, logging.FileHandler]] = []
 
-        logging.basicConfig(format=format,
-                            handlers=[logging.StreamHandler(sys.stdout)],
-                            level=level,
-                            style='{')
+        stream_handler = logging.StreamHandler(sys.stdout)
+        stream_handler.setFormatter(formatter)
+        handlers.append(stream_handler)
 
         if logfile:
-            logfile += ".log" * (not logfile.endswith("log"))
-            handler = logging.FileHandler(filename=logfile, encoding='utf-8')
-            handler.setFormatter(logging.Formatter(format, style='{'))
-            logobj.addHandler(handler)
+            logfile = check_suffix(filename=logfile, suffix=".log")
+            file_handler = logging.FileHandler(
+                filename=str(logfile), encoding="utf-8")
+            file_handler.setFormatter(formatter)
+            handlers.append(file_handler)
         else:
             logging.addLevelName(logging.INFO, Emphasise.info("INFO"))
             logging.addLevelName(logging.DEBUG, Emphasise.debug("DEBUG"))
             logging.addLevelName(logging.WARNING, Emphasise.warning("WARNING"))
             logging.addLevelName(logging.ERROR, Emphasise.error("ERROR"))
-            logobj.info('Logging to file is disabled.')
+
+        logging.basicConfig(
+            format=format, handlers=handlers, level=level, style="{")
+        logging.captureWarnings(True)
+
+        if logfile:
+            abs_path = str(Path(logfile).absolute().resolve())
+            logobj.info(f"This log is also available at '{abs_path}'.")
+        else:
+            logobj.debug("Logging to file is disabled.")
+
+        for handler in handlers:
+            logobj.addHandler(handler)
 
         yield
+
     finally:
-        handlers = logobj.handlers[:]
         for handler in handlers:
+            handler.flush()
             handler.close()
             logobj.removeHandler(handler)

tests/test_logger.py

@@ -7,52 +7,111 @@
 # SPDX-License-Identifier: GPL-2.0-or-later
 """Test mdacli logger."""
 import logging
+import warnings
+from pathlib import Path
 
-import mdacli.logger
-
-
-class Test_setup_logger:
-    """Test the setup_logger."""
-
-    def test_default_log(self, caplog):
-        """Default message in STDOUT."""
-        caplog.set_level(logging.INFO)
-        logger = logging.getLogger("test")
-        with mdacli.logger.setup_logging(logger,
-                                         logfile=None,
-                                         level=logging.INFO):
-            logger.info("foo")
-            assert "foo" in caplog.text
-
-    def test_info_log(self, tmpdir, caplog):
-        """Default message in STDOUT and file."""
-        caplog.set_level(logging.INFO)
-        logger = logging.getLogger("test")
-        with tmpdir.as_cwd():
-            # Explicityly leave out the .dat file ending to check if this
-            # is created by the function.
-            with mdacli.logger.setup_logging(logger,
-                                             logfile="logfile",
-                                             level=logging.INFO):
-                logger.info("foo")
-                assert "foo" in caplog.text
-            with open("logfile.log", "r") as f:
-                log = f.read()
-
-            assert "foo" in log
-
-    def test_debug_log(self, tmpdir, caplog):
-        """Debug message in STDOUT and file."""
-        caplog.set_level(logging.INFO)
-        logger = logging.getLogger("test")
-        with tmpdir.as_cwd():
-            with mdacli.logger.setup_logging(logger,
-                                             logfile="logfile",
-                                             level=logging.DEBUG):
-                logger.info("foo")
-                assert "test:test_logger.py:52 foo\n" in caplog.text
-
-            with open("logfile.log", "r") as f:
-                log = f.read()
-
-            assert "test_logger.py:test:test_debug_log:52: foo\n" in log
+import pytest
+
+from mdacli.logger import check_suffix, setup_logging
+
+
+@pytest.mark.parametrize("filename", ["example.txt", Path("example.txt")])
+def test_check_suffix(filename):
+    """Check suffix tetsing."""
+    result = check_suffix(filename, ".txt")
+
+    assert str(result) == "example.txt"
+    assert isinstance(result, type(filename))
+
+
+@pytest.mark.parametrize("filename", ["example", Path("example")])
+def test_warning_on_missing_suffix(filename):
+    """Check issued warning in missing suffix."""
+    match = r"The file name should have a '\.txt' extension."
+    with pytest.warns(UserWarning, match=match):
+        result = check_suffix(filename, ".txt")
+
+    assert str(result) == "example.txt"
+    assert isinstance(result, type(filename))
+
+
+def test_warnings_in_log(caplog):
+    """Test that warnings are forwarded to the logger.
+
+    Keep this test at the top since it seems otherwise there are some pytest
+    issues...
+    """
+    logger = logging.getLogger()
+
+    with setup_logging(logger):
+        warnings.warn("A warning", stacklevel=1)
+
+    assert "A warning" in caplog.text
+
+
+def test_default_log(caplog, capsys):
+    """Default message only in STDOUT."""
+    caplog.set_level(logging.INFO)
+    logger = logging.getLogger()
+
+    with setup_logging(logger, level=logging.INFO):
+        logger.info("foo")
+        logger.debug("A debug message")
+
+    stdout_log = capsys.readouterr().out
+
+    assert "Logging to file is disabled." not in caplog.text  # DEBUG message
+    assert "INFO" not in stdout_log
+    assert "foo" in stdout_log
+    assert "A debug message" not in stdout_log
+
+
+def test_info_log(caplog, monkeypatch, tmp_path, capsys):
+    """Default message in STDOUT and file."""
+    monkeypatch.chdir(tmp_path)
+    caplog.set_level(logging.INFO)
+    logger = logging.getLogger()
+
+    with setup_logging(logger, logfile="logfile.log", level=logging.INFO):
+        logger.info("foo")
+        logger.debug("A debug message")
+
+    with open("logfile.log", "r") as f:
+        file_log = f.read()
+
+    stdout_log = capsys.readouterr().out
+    log_path = str((tmp_path / "logfile.log").absolute().resolve())
+
+    assert file_log == stdout_log
+    assert f"This log is also available at '{log_path}'" in caplog.text
+
+    for logtext in [stdout_log, file_log]:
+        assert "INFO" not in logtext
+        assert "foo" in logtext
+        assert "A debug message" not in logtext
+
+
+def test_debug_log(caplog, monkeypatch, tmp_path, capsys):
+    """Debug message in STDOUT and file."""
+    monkeypatch.chdir(tmp_path)
+    caplog.set_level(logging.DEBUG)
+    logger = logging.getLogger()
+
+    with setup_logging(logger, logfile="logfile.log", level=logging.DEBUG):
+        logger.info("foo")
+        logger.debug("A debug message")
+
+    with open("logfile.log", "r") as f:
+        file_log = f.read()
+
+    stdout_log = capsys.readouterr().out
+    log_path = str((tmp_path / "logfile.log").absolute())
+
+    assert file_log == stdout_log
+    assert f"This log is also available at '{log_path}'" in caplog.text
+
+    for logtext in [stdout_log, file_log]:
+        assert "foo" in logtext
+        assert "A debug message" in logtext
+        # Test that debug information is in output
+        assert "test_logger.py:test_debug_log:" in logtext

tox.ini

@@ -35,7 +35,12 @@ commands_pre =
     coverage erase
 # execute pytest
 commands =
-    pytest --cov --cov-report=term-missing --cov-append --cov-config=.coveragerc -vv --hypothesis-show-statistics {posargs}
+    pytest \
+        --cov \
+        --cov-report=term-missing \
+        --cov-append --cov-config=.coveragerc \
+        --hypothesis-show-statistics \
+        {posargs}
 # after executing the pytest assembles the coverage reports
 commands_post =
     coverage report
@@ -53,7 +58,7 @@ deps =
 skip_install = true
 commands =
     flake8 {posargs:src/mdacli tests}
-    isort --verbose --check-only --diff src/mdacli tests
+    isort --check-only --diff src/mdacli tests
 
 # asserts package build integrity
 [testenv:build]