Merge branch 'SAR-55-expose-formatter' into 'master'

SAR-55 Provide access to default formatter

See merge request ska-telescope/ska-logging!2

README.md

@@ -89,6 +89,25 @@ def main():
     configure_logging(overrides=ADDITIONAL_LOGGING_CONFIG)
 ```
 
+Custom handlers that use the standard logging format may be useful.  In this case, the function
+`get_default_formatter` is available.  The example below is contrived, but shows the approach.
+A more practical use case is adding and removing handlers at runtime.
+
+```python
+import logging
+import logging.handlers
+from ska_logging import configure_logging, get_default_formatter
+
+
+def main():
+    configure_logging()
+    logger = logging.getLogger("ska.example")
+    handler = logging.handlers.MemoryHandler(capacity=10)
+    handler.setFormatter(get_default_formatter())
+    logger.addHandler(handler)
+    logger.info("Logging started for Example application")
+```
+
 By default, calls to `configure_logging` do not disable existing non-root loggers.  This allows
 multiple calls to the function, although that will generally not be required.  This behaviour can be
 overridden using the `"disable_existing_loggers"` key.

ska_logging/__init__.py

@@ -2,12 +2,22 @@
 
 """Module init code."""
 
-__all__ = ("configure_logging",)
+__all__ = (
+    "configure_logging",
+    "get_default_formatter",
+    "SkaLoggingError",
+    "SkaLoggingTagsFormatError",
+)
 __author__ = "Anton Joubert"
 __email__ = "ajoubert+ska@ska.ac.za"
 
 
-from .configuration import configure_logging
+from .configuration import (
+    configure_logging,
+    get_default_formatter,
+    SkaLoggingError,
+    SkaLoggingTagsFormatError,
+)
 
 
 # BEGIN VERSION CHECK

ska_logging/configuration.py

@@ -7,6 +7,14 @@ import logging.config
 import time
 
 
+class SkaLoggingError(Exception):
+    """Base class for all SKA Logger exceptions."""
+
+
+class SkaLoggingTagsFormatError(SkaLoggingError):
+    """Invalid format for the 'tags' field string."""
+
+
 class _UTCFormatter(logging.Formatter):
     converter = time.gmtime
 
@@ -38,6 +46,8 @@ _FORMAT_STR_WITH_TAGS = (
     "%(message)s"
 )
 
+_INVALID_TAG_CHARS = ("|", "%")
+
 _LOGGING_CONFIG = {
     "version": 1,
     "disable_existing_loggers": False,
@@ -107,6 +117,45 @@ def configure_logging(level=None, tags_filter=None, overrides=None):
     logging.config.dictConfig(config)
 
 
+def get_default_formatter(tags=False):
+    """Return a formatter configured with the standard logging format.
+
+    Parameters
+    ----------
+
+    tags : bool or str, optional
+        If boolean, then treated as a toggle:
+          - True:  include the "tags" field in the format string.  This requires
+                   a tags filter to be linked to the corresponding handler.
+          - False:  exclude the "tags" field from the format string.
+        If string, then it is a static tag.  Instead of using a logging filter, the
+        formatter will just use this static string for the "tags" field directly.
+
+    Returns
+    -------
+    logging.Formatter
+        A new default formatter.
+
+    Raises
+    ------
+    SkaLoggingTagsFormatError:
+        If the static tags string has an invalid format.
+
+    """
+    if isinstance(tags, str):
+        invalid_chars = [c for c in _INVALID_TAG_CHARS if c in tags]
+        if invalid_chars:
+            raise SkaLoggingTagsFormatError(
+                "Invalid char(s) {} in tags: {!r}".format(invalid_chars, tags)
+            )
+        format_str = _FORMAT_STR_WITH_TAGS.replace("%(tags)s", tags)
+    elif tags:
+        format_str = _FORMAT_STR_WITH_TAGS
+    else:
+        format_str = _FORMAT_STR_NO_TAGS
+    return _UTCFormatter(fmt=format_str)
+
+
 def _override(config, overrides):
     """Update a config dictionary with overrides, merging dictionaries.
 

tests/test_configuration.py

@@ -9,7 +9,7 @@ import pytest
 
 import ska_logging.configuration
 
-from ska_logging import configure_logging
+from ska_logging import configure_logging, get_default_formatter, SkaLoggingTagsFormatError
 
 
 @pytest.fixture
@@ -103,31 +103,31 @@ class TestConfigureLogging:
         configure_logging(tags_filter=MyFilter, overrides=RECORDER_OVERRIDES)
         yield logging.getLogger("ska.logger")
 
-    def test_configure_logging_includes_console_handler(self, default_logger):
+    def test_includes_console_handler(self, default_logger):
         assert get_named_handler(default_logger, "console")
 
-    def test_configure_logging_multiple_calls_non_root_logger_still_enabled(self, default_logger):
+    def test_multiple_calls_non_root_logger_still_enabled(self, default_logger):
         logger = logging.getLogger("ska.logger.test")
         assert not logger.disabled
         configure_logging()
         assert not logger.disabled
 
-    def test_configure_logging_default_log_level_info(self, default_logger):
+    def test_default_log_level_info(self, default_logger):
         logger = logging.getLogger("ska.logger.test")
         assert logger.getEffectiveLevel() == logging.INFO
         assert default_logger.getEffectiveLevel() == logging.INFO
 
-    def test_configure_logging_set_log_level_int(self):
+    def test_set_log_level_int(self):
         configure_logging(level=logging.DEBUG)
         logger = logging.getLogger("ska.logger.test")
         assert logger.getEffectiveLevel() == logging.DEBUG
 
-    def test_configure_logging_set_log_level_string(self):
+    def test_set_log_level_string(self):
         configure_logging(level="WARNING")
         logger = logging.getLogger("ska.logger.test")
         assert logger.getEffectiveLevel() == logging.WARNING
 
-    def test_configure_logging_default_uses_utc_time(self, recording_logger):
+    def test_default_uses_utc_time(self, recording_logger):
         recording_logger.info("UTC message")
         recorder = get_named_handler(recording_logger, "recorder")
         record = recorder.records[0]
@@ -136,17 +136,17 @@ class TestConfigureLogging:
         assert "UTC message" in log_message
         assert expected_time in log_message  # just testing UTC, so ignore the milliseconds part
 
-    def test_configure_logging_default_no_tags(self, default_logger):
+    def test_default_no_tags(self, default_logger):
         handler = get_named_handler(default_logger, "console")
         formatter = handler.formatter
         assert "%(tag)s" not in formatter._fmt
 
-    def test_configure_logging_tags_filter_adds_tags_field(self, recording_tags_logger):
+    def test_tags_filter_adds_tags_field(self, recording_tags_logger):
         handler = get_named_handler(recording_tags_logger, "console")
         formatter = handler.formatter
         assert "%(tags)s" in formatter._fmt
 
-    def test_configure_logging_tags_filter_emits_tags_value(self, recording_tags_logger):
+    def test_tags_filter_emits_tags_value(self, recording_tags_logger):
         recording_tags_logger.info("Tags message")
         recorder = get_named_handler(recording_tags_logger, "recorder")
         record = recorder.records[0]
@@ -154,7 +154,7 @@ class TestConfigureLogging:
         assert record.tags == "key1:value1,key2:value2"
         assert log_message.endswith("|key1:value1,key2:value2|Tags message")
 
-    def test_configure_logging_override(self):
+    def test_override(self):
         overrides = {
             "handlers": {"test": {"class": "logging.StreamHandler", "formatter": "default"}},
             "root": {"handlers": ["console", "test"]},
@@ -165,6 +165,38 @@ class TestConfigureLogging:
         assert get_named_handler(logger, "test")
 
 
+class TestGetDefaultFormatter:
+    """Tests for :func:`~ska_logging.configuration.get_default_formatter`."""
+
+    def test_default_no_tags(self):
+        formatter = get_default_formatter()
+        assert isinstance(formatter, ska_logging.configuration._UTCFormatter)
+        assert formatter._fmt == ska_logging.configuration._FORMAT_STR_NO_TAGS
+
+    def test_get_tags_disabled(self):
+        formatter = get_default_formatter(tags=False)
+        assert isinstance(formatter, ska_logging.configuration._UTCFormatter)
+        assert formatter._fmt == ska_logging.configuration._FORMAT_STR_NO_TAGS
+
+    def test_get_tags_enabled(self):
+        formatter = get_default_formatter(tags=True)
+        assert isinstance(formatter, ska_logging.configuration._UTCFormatter)
+        assert formatter._fmt == ska_logging.configuration._FORMAT_STR_WITH_TAGS
+
+    def test_get_tags_static_string(self):
+        formatter = get_default_formatter(tags="test-key:test-value")
+        assert isinstance(formatter, ska_logging.configuration._UTCFormatter)
+        tags_format = ska_logging.configuration._FORMAT_STR_WITH_TAGS
+        expected_format = tags_format.replace("%(tags)s", "test-key:test-value")
+        assert formatter._fmt == expected_format
+
+    def test_get_tags_invalid_static_string(self):
+        with pytest.raises(SkaLoggingTagsFormatError):
+            get_default_formatter(tags="no|pipes|allowed")
+        with pytest.raises(SkaLoggingTagsFormatError):
+            get_default_formatter(tags="no%percentage%symbols%allowed")
+
+
 class TestOverride:
     """Tests for :func:`~ska_logging.configuration._override`.