Merge pull request #2476 from zyzniewski-reef/fix/logger_stacklevel

fix: increase stacklevel in LoggingMachine log calls

bittensor/utils/btlogging/loggingmachine.py

@@ -47,6 +47,9 @@
 from .helpers import all_loggers
 from bittensor.utils.btlogging.console import BittensorConsole
 
+# https://github.com/python/cpython/issues/97941
+CUSTOM_LOGGER_METHOD_STACK_LEVEL = 2 if sys.version_info >= (3, 11) else 1
+
 
 def _concat_message(msg="", prefix="", suffix=""):
     """Concatenates a message with optional prefix and suffix."""
@@ -447,45 +450,55 @@ def __trace_on__(self) -> bool:
         """
         return self.current_state_value == "Trace"
 
-    def trace(self, msg="", prefix="", suffix="", *args, **kwargs):
+    def trace(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs):
         """Wraps trace message with prefix and suffix."""
         msg = _concat_message(msg, prefix, suffix)
-        self._logger.trace(msg, *args, **kwargs)
+        self._logger.trace(
+            msg,
+            *args,
+            **kwargs,
+            stacklevel=stacklevel + CUSTOM_LOGGER_METHOD_STACK_LEVEL,
+        )
 
-    def debug(self, msg="", prefix="", suffix="", *args, **kwargs):
+    def debug(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs):
         """Wraps debug message with prefix and suffix."""
         msg = _concat_message(msg, prefix, suffix)
-        self._logger.debug(msg, *args, **kwargs)
+        self._logger.debug(msg, *args, **kwargs, stacklevel=stacklevel + 1)
 
-    def info(self, msg="", prefix="", suffix="", *args, **kwargs):
+    def info(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs):
         """Wraps info message with prefix and suffix."""
         msg = _concat_message(msg, prefix, suffix)
-        self._logger.info(msg, *args, **kwargs)
+        self._logger.info(msg, *args, **kwargs, stacklevel=stacklevel + 1)
 
-    def success(self, msg="", prefix="", suffix="", *args, **kwargs):
+    def success(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs):
         """Wraps success message with prefix and suffix."""
         msg = _concat_message(msg, prefix, suffix)
-        self._logger.success(msg, *args, **kwargs)
+        self._logger.success(
+            msg,
+            *args,
+            **kwargs,
+            stacklevel=stacklevel + CUSTOM_LOGGER_METHOD_STACK_LEVEL,
+        )
 
-    def warning(self, msg="", prefix="", suffix="", *args, **kwargs):
+    def warning(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs):
         """Wraps warning message with prefix and suffix."""
         msg = _concat_message(msg, prefix, suffix)
-        self._logger.warning(msg, *args, **kwargs)
+        self._logger.warning(msg, *args, **kwargs, stacklevel=stacklevel + 1)
 
-    def error(self, msg="", prefix="", suffix="", *args, **kwargs):
+    def error(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs):
         """Wraps error message with prefix and suffix."""
         msg = _concat_message(msg, prefix, suffix)
-        self._logger.error(msg, *args, **kwargs)
+        self._logger.error(msg, *args, **kwargs, stacklevel=stacklevel + 1)
 
-    def critical(self, msg="", prefix="", suffix="", *args, **kwargs):
+    def critical(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs):
         """Wraps critical message with prefix and suffix."""
         msg = _concat_message(msg, prefix, suffix)
-        self._logger.critical(msg, *args, **kwargs)
+        self._logger.critical(msg, *args, **kwargs, stacklevel=stacklevel + 1)
 
-    def exception(self, msg="", prefix="", suffix="", *args, **kwargs):
+    def exception(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs):
         """Wraps exception message with prefix and suffix."""
         msg = _concat_message(msg, prefix, suffix)
-        self._logger.exception(msg, *args, **kwargs)
+        self._logger.exception(msg, *args, **kwargs, stacklevel=stacklevel + 1)
 
     def on(self):
         """Enable default state."""

tests/unit_tests/test_logging.py

@@ -176,6 +176,19 @@ def test_all_log_levels_output(logging_machine, caplog):
     assert "Test error" in caplog.text
     assert "Test critical" in caplog.text
 
+    records = [(r.module, r.getMessage()) for r in caplog.records]
+
+    assert records == [
+        ("loggingmachine", "Trace enabled."),
+        ("test_logging", "Test trace"),
+        ("test_logging", "Test debug"),
+        ("test_logging", "Test info"),
+        ("test_logging", "Test success"),
+        ("test_logging", "Test warning"),
+        ("test_logging", "Test error"),
+        ("test_logging", "Test critical"),
+    ]
+
 
 @pytest.mark.parametrize(
     "msg, prefix, suffix, expected_result",