From c88137f41bcf677355c9fcc72b1c174a71aa9205 Mon Sep 17 00:00:00 2001 From: pederhan Date: Wed, 19 Nov 2025 12:04:15 +0100 Subject: [PATCH 1/4] Add logging tests --- mreg_cli/log.py | 2 ++ tests/test_log.py | 76 +++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 78 insertions(+) create mode 100644 tests/test_log.py diff --git a/mreg_cli/log.py b/mreg_cli/log.py index 9e0cb6b9..ffaa6d08 100644 --- a/mreg_cli/log.py +++ b/mreg_cli/log.py @@ -65,6 +65,7 @@ def start_logging( level=level.as_int(), format=fmt, datefmt="%Y-%m-%d %H:%M:%S", + force=True, ) except Exception as e: print(f"Failed to set up logging: {e}", file=sys.stderr) @@ -77,5 +78,6 @@ def start_logging( def stop_logging(self) -> None: """Stop logging.""" logging.shutdown() + logging.getLogger().handlers.clear() self._is_logging = False self._file = None diff --git a/tests/test_log.py b/tests/test_log.py new file mode 100644 index 00000000..5186c82e --- /dev/null +++ b/tests/test_log.py @@ -0,0 +1,76 @@ +from __future__ import annotations + +import logging +from pathlib import Path + +from inline_snapshot import snapshot + +from mreg_cli.log import MregCliLogger + +# NOTE: we cannot use caplog fixture together with `MregCliLogger`, because +# `start_logging` does nothing if logging already has handlers (which is the case when caplog is used), +# and `stop_logging` removes the caplog handlers. + + +def test_logging_start(tmp_path: Path) -> None: + logfile = tmp_path / "test.log" + mreg_logger = MregCliLogger() + mreg_logger.start_logging(logfile, "DEBUG") + + logger = logging.getLogger("test_logging_start") + logger.debug("This is a debug message.") + logger.info("This is an info message.") + logger.warning("This is a warning message.") + logger.error("This is an error message.") + logger.critical("This is a critical message.") + + # Stop logging to flush buffer to the file + mreg_logger.stop_logging() + + # 5 log messages should be written + assert logfile.read_text().count("\n") == snapshot(5) + + +def test_logging_singleton(tmp_path: Path) -> None: + """Ensure that MregCliLogger behaves as a singleton.""" + logfile = tmp_path / "singleton.log" + + # Do some setup on the first instance + logger = MregCliLogger() + logger.stop_logging() + logger.start_logging(logfile, "INFO") + + logger2 = MregCliLogger() + + assert logger is logger2 + assert logger.status == logger2.status + + +def test_logging_status_as_str_stderr() -> None: + logger = MregCliLogger() + logger.stop_logging() + logger.start_logging(None, "INFO") + status = logger.status + assert status.as_str() == snapshot("INFO > stderr") + + +def test_logging_status_as_str_file(tmp_path: Path) -> None: + logfile = tmp_path / "test.log" + + logger = MregCliLogger() + logger.stop_logging() + + # Actually start logging to the real temp file + logger.start_logging(logfile, "INFO") + # But override the file in the logger object to make it deterministic + logger._file = Path("/path/to/logfile.log") + + status = logger.status + assert status.as_str() == snapshot("INFO > /path/to/logfile.log") + + +def test_logging_status_as_str_disabled() -> None: + logger = MregCliLogger() + logger.stop_logging() + status = logger.status + assert status.as_str() == snapshot("disabled") From 4255847eddcc87bf736cd1f9536f5d9f33679e2d Mon Sep 17 00:00:00 2001 From: pederhan Date: Thu, 20 Nov 2025 10:55:07 +0100 Subject: [PATCH 2/4] Remove unused import --- mreg_cli/commands/logging.py | 1 - 1 file changed, 1 deletion(-) diff --git a/mreg_cli/commands/logging.py b/mreg_cli/commands/logging.py index 783a8fb7..3a748645 100644 --- a/mreg_cli/commands/logging.py +++ b/mreg_cli/commands/logging.py @@ -3,7 +3,6 @@ from __future__ import annotations import argparse -from pathlib import Path from typing import Any from mreg_cli.commands.base import BaseCommand From 8f1af754a92a54f3540617140a4fca8ab448882c Mon Sep 17 00:00:00 2001 From: pederhan Date: Thu, 20 Nov 2025 10:55:31 +0100 Subject: [PATCH 3/4] Rename & improve tests --- tests/test_log.py | 30 ++++++++++++++++++++---------- 1 file changed, 20 insertions(+), 10 deletions(-) diff --git a/tests/test_log.py b/tests/test_log.py index 5186c82e..8040ebec 100644 --- a/tests/test_log.py +++ b/tests/test_log.py @@ -31,22 +31,28 @@ def test_logging_start(tmp_path: Path) -> None: assert logfile.read_text().count("\n") == snapshot(5) -def test_logging_singleton(tmp_path: Path) -> None: +def test_mregclilogger_singleton(tmp_path: Path) -> None: """Ensure that MregCliLogger behaves as a singleton.""" logfile = tmp_path / "singleton.log" - # Do some setup on the first instance + # 2 loggers logger = MregCliLogger() + logger2 = MregCliLogger() + + # Do some setup on the first instance logger.stop_logging() logger.start_logging(logfile, "INFO") - logger2 = MregCliLogger() - + # Ensure both instances + new calls are the same object assert logger is logger2 + assert logger is MregCliLogger() + + # Status should be the same assert logger.status == logger2.status -def test_logging_status_as_str_stderr() -> None: +def test_mregclilogger_status_as_str_stderr() -> None: + """Test logging status when logging to stderr.""" logger = MregCliLogger() logger.stop_logging() logger.start_logging(None, "INFO") @@ -54,7 +60,7 @@ def test_logging_status_as_str_stderr() -> None: assert status.as_str() == snapshot("INFO > stderr") -def test_logging_status_as_str_file(tmp_path: Path) -> None: +def test_mregclilogger_status_as_str_file(tmp_path: Path) -> None: logfile = tmp_path / "test.log" logger = MregCliLogger() @@ -62,14 +68,18 @@ def test_logging_status_as_str_file(tmp_path: Path) -> None: # Actually start logging to the real temp file logger.start_logging(logfile, "INFO") - # But override the file in the logger object to make it deterministic - logger._file = Path("/path/to/logfile.log") + # Test output with actual temp file path (random pytest dir) status = logger.status - assert status.as_str() == snapshot("INFO > /path/to/logfile.log") + assert status.as_str().startswith("INFO > /") + + # Deterministic output with overriden file path + logger._file = Path("/path/to/logfile.log") + assert logger.status.as_str() == snapshot("INFO > /path/to/logfile.log") -def test_logging_status_as_str_disabled() -> None: +def test_mregclilogger_status_as_str_disabled() -> None: + """Test logging status when logging is disabled.""" logger = MregCliLogger() logger.stop_logging() status = logger.status From 71d13045a5057823b9e52f9ef8683a9c338980f9 Mon Sep 17 00:00:00 2001 From: pederhan Date: Mon, 8 Dec 2025 09:47:58 +0100 Subject: [PATCH 4/4] Remove redundant clearing of handlers --- mreg_cli/log.py | 1 - tests/test_log.py | 18 ++++++++++++++++++ 2 files changed, 18 insertions(+), 1 deletion(-) diff --git a/mreg_cli/log.py b/mreg_cli/log.py index ffaa6d08..400e11b1 100644 --- a/mreg_cli/log.py +++ b/mreg_cli/log.py @@ -78,6 +78,5 @@ def start_logging( def stop_logging(self) -> None: """Stop logging.""" logging.shutdown() - logging.getLogger().handlers.clear() self._is_logging = False self._file = None diff --git a/tests/test_log.py b/tests/test_log.py index 8040ebec..f5361f3d 100644 --- a/tests/test_log.py +++ b/tests/test_log.py @@ -84,3 +84,21 @@ def test_mregclilogger_status_as_str_disabled() -> None: logger.stop_logging() status = logger.status assert status.as_str() == snapshot("disabled") + + +def test_log_handlers_multiple_restarts(tmp_path: Path) -> None: + """Test that handlers are flushed when starting logging multiple times.""" + logger = MregCliLogger() + logger.stop_logging() + + # Start logging first time + logger.start_logging(tmp_path / "test.log.1", "INFO") + handlers_after_first_start = logging.getLogger().handlers.copy() + + # Start logging second time + logger.start_logging(tmp_path / "test.log.2", "INFO") + handlers_after_second_start = logging.getLogger().handlers.copy() + + # Should have the same number of handlers, but different instances + assert len(handlers_after_first_start) == len(handlers_after_second_start) + assert handlers_after_first_start != handlers_after_second_start