feat: Add trace-level logger (#5414)

This is useful for logs we want hidden by default but can be turned
on via configuration.

cloudinit/log.py

@@ -23,6 +23,23 @@
 
 DEFAULT_LOG_FORMAT = "%(asctime)s - %(filename)s[%(levelname)s]: %(message)s"
 DEPRECATED = 35
+TRACE = logging.DEBUG - 5
+
+
+class CustomLoggerType(logging.Logger):
+    """A hack to get mypy to stop complaining about custom logging methods.
+
+    When using deprecated or trace logging, rather than:
+        LOG = logging.getLogger(__name__)
+    Instead do:
+        LOG = cast(CustomLoggerType, logging.getLogger(__name__))
+    """
+
+    def trace(self, *args, **kwargs):
+        pass
+
+    def deprecated(self, *args, **kwargs):
+        pass
 
 
 def setup_basic_logging(level=logging.DEBUG, formatter=None):
@@ -45,14 +62,20 @@ def flush_loggers(root):
     flush_loggers(root.parent)
 
 
-def define_deprecation_logger(lvl=DEPRECATED):
-    logging.addLevelName(lvl, "DEPRECATED")
+def define_extra_loggers() -> None:
+    """Add DEPRECATED and TRACE log levels to the logging module."""
+
+    def new_logger(level):
+        def log_at_level(self, message, *args, **kwargs):
+            if self.isEnabledFor(level):
+                self._log(level, message, args, **kwargs)
 
-    def deprecated(self, message, *args, **kwargs):
-        if self.isEnabledFor(lvl):
-            self._log(lvl, message, args, **kwargs)
+        return log_at_level
 
-    logging.Logger.deprecated = deprecated
+    logging.addLevelName(DEPRECATED, "DEPRECATED")
+    logging.addLevelName(TRACE, "TRACE")
+    setattr(logging.Logger, "deprecated", new_logger(DEPRECATED))
+    setattr(logging.Logger, "trace", new_logger(TRACE))
 
 
 def setup_logging(cfg=None):
@@ -183,7 +206,7 @@ def configure_root_logger():
 
     # Always format logging timestamps as UTC time
     logging.Formatter.converter = time.gmtime
-    define_deprecation_logger()
+    define_extra_loggers()
     setup_backup_logging()
     reset_logging()
 

tests/unittests/test_log.py

@@ -6,6 +6,7 @@
 import io
 import logging
 import time
+from typing import cast
 
 import pytest
 
@@ -63,10 +64,18 @@ def test_logger_uses_gmtime(self):
 
 class TestDeprecatedLogs:
     def test_deprecated_log_level(self, caplog):
-        logging.getLogger().deprecated("deprecated message")
+        logger = cast(log.CustomLoggerType, logging.getLogger())
+        logger.deprecated("deprecated message")
         assert "DEPRECATED" == caplog.records[0].levelname
         assert "deprecated message" in caplog.text
 
+    def test_trace_log_level(self, caplog):
+        logger = cast(log.CustomLoggerType, logging.getLogger())
+        logger.setLevel(logging.NOTSET)
+        logger.trace("trace message")
+        assert "TRACE" == caplog.records[0].levelname
+        assert "trace message" in caplog.text
+
     @pytest.mark.parametrize(
         "expected_log_level, deprecation_info_boundary",
         (
@@ -115,6 +124,7 @@ def test_deprecate_log_level_based_on_features(
         )
 
     def test_log_deduplication(self, caplog):
+        log.define_extra_loggers()
         util.deprecate(
             deprecated="stuff",
             deprecated_version="19.1",