From ed5d7a8eec11768781bf5c66adfdf4c4dd4d186a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Tomasz=20=C5=BBy=C5=BAniewski?= Date: Mon, 25 Nov 2024 20:55:08 +0100 Subject: [PATCH 1/8] fix: increase stacklevel in LoggingMachine log calls --- bittensor/utils/btlogging/loggingmachine.py | 32 ++++++++++----------- 1 file changed, 16 insertions(+), 16 deletions(-) diff --git a/bittensor/utils/btlogging/loggingmachine.py b/bittensor/utils/btlogging/loggingmachine.py index 8b5c3faa5b..28255fed50 100644 --- a/bittensor/utils/btlogging/loggingmachine.py +++ b/bittensor/utils/btlogging/loggingmachine.py @@ -443,45 +443,45 @@ 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 + 2) - 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 + 2) - 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.""" From 756eef7d04d96831753721fdac8673d61141b141 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Tomasz=20=C5=BBy=C5=BAniewski?= Date: Mon, 25 Nov 2024 21:29:22 +0100 Subject: [PATCH 2/8] tests: check LogRecord's calling module --- tests/unit_tests/test_logging.py | 13 +++++++++++++ 1 file changed, 13 insertions(+) diff --git a/tests/unit_tests/test_logging.py b/tests/unit_tests/test_logging.py index 2aa43d1e70..437084553a 100644 --- a/tests/unit_tests/test_logging.py +++ b/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", From 391dec727687a6d6570b2101f9f7c5bbd69ea871 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Tomasz=20=C5=BBy=C5=BAniewski?= Date: Mon, 25 Nov 2024 22:20:24 +0100 Subject: [PATCH 3/8] fix: adjust LoggingMachine stacklevel on Python < 3.11 --- bittensor/utils/btlogging/loggingmachine.py | 24 +++++++++++++++++---- 1 file changed, 20 insertions(+), 4 deletions(-) diff --git a/bittensor/utils/btlogging/loggingmachine.py b/bittensor/utils/btlogging/loggingmachine.py index 28255fed50..1af48be6ca 100644 --- a/bittensor/utils/btlogging/loggingmachine.py +++ b/bittensor/utils/btlogging/loggingmachine.py @@ -443,10 +443,18 @@ def __trace_on__(self) -> bool: """ return self.current_state_value == "Trace" - def trace(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): + def trace( + self, + msg="", + prefix="", + suffix="", + *args, + stacklevel=2 if sys.version_info >= (3, 11) else 1, # logger.trace is not an internal method + **kwargs, + ): """Wraps trace message with prefix and suffix.""" msg = _concat_message(msg, prefix, suffix) - self._logger.trace(msg, *args, **kwargs, stacklevel=stacklevel + 2) + self._logger.trace(msg, *args, **kwargs, stacklevel=stacklevel + 1) def debug(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): """Wraps debug message with prefix and suffix.""" @@ -458,10 +466,18 @@ def info(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): msg = _concat_message(msg, prefix, suffix) self._logger.info(msg, *args, **kwargs, stacklevel=stacklevel + 1) - def success(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): + def success( + self, + msg="", + prefix="", + suffix="", + *args, + stacklevel=2 if sys.version_info >= (3, 11) else 1, # logger.success is not an internal method + **kwargs, + ): """Wraps success message with prefix and suffix.""" msg = _concat_message(msg, prefix, suffix) - self._logger.success(msg, *args, **kwargs, stacklevel=stacklevel + 2) + self._logger.success(msg, *args, **kwargs, stacklevel=stacklevel + 1) def warning(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): """Wraps warning message with prefix and suffix.""" From edceaf2b1979fafbb7c8101a7162819f9e61637d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Tomasz=20=C5=BBy=C5=BAniewski?= Date: Mon, 25 Nov 2024 22:27:33 +0100 Subject: [PATCH 4/8] style: reformat code --- bittensor/utils/btlogging/loggingmachine.py | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/bittensor/utils/btlogging/loggingmachine.py b/bittensor/utils/btlogging/loggingmachine.py index 1af48be6ca..78c987c582 100644 --- a/bittensor/utils/btlogging/loggingmachine.py +++ b/bittensor/utils/btlogging/loggingmachine.py @@ -449,7 +449,9 @@ def trace( prefix="", suffix="", *args, - stacklevel=2 if sys.version_info >= (3, 11) else 1, # logger.trace is not an internal method + stacklevel=2 # logger.trace is not an internal method + if sys.version_info >= (3, 11) + else 1, **kwargs, ): """Wraps trace message with prefix and suffix.""" @@ -472,7 +474,9 @@ def success( prefix="", suffix="", *args, - stacklevel=2 if sys.version_info >= (3, 11) else 1, # logger.success is not an internal method + stacklevel=2 # logger.success is not an internal method + if sys.version_info >= (3, 11) + else 1, **kwargs, ): """Wraps success message with prefix and suffix.""" From ce58209d756d8544817099df54817390a1df309f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Tomasz=20=C5=BBy=C5=BAniewski?= Date: Tue, 26 Nov 2024 09:05:47 +0100 Subject: [PATCH 5/8] refactor: define CUSTOM_LOGGER_METHOD_STACKLEVEL --- bittensor/utils/btlogging/loggingmachine.py | 44 ++++++++++----------- 1 file changed, 20 insertions(+), 24 deletions(-) diff --git a/bittensor/utils/btlogging/loggingmachine.py b/bittensor/utils/btlogging/loggingmachine.py index 5e69c5e718..24e0586cb5 100644 --- a/bittensor/utils/btlogging/loggingmachine.py +++ b/bittensor/utils/btlogging/loggingmachine.py @@ -47,6 +47,12 @@ from .helpers import all_loggers from bittensor.utils.btlogging.console import BittensorConsole +# https://github.com/python/cpython/issues/97941 +if sys.version_info >= (3, 11): + CUSTOM_LOGGER_METHOD_STACKLEVEL = 2 +else: + CUSTOM_LOGGER_METHOD_STACKLEVEL = 1 + def _concat_message(msg="", prefix="", suffix=""): """Concatenates a message with optional prefix and suffix.""" @@ -447,20 +453,15 @@ def __trace_on__(self) -> bool: """ return self.current_state_value == "Trace" - def trace( - self, - msg="", - prefix="", - suffix="", - *args, - stacklevel=2 # logger.trace is not an internal method - if sys.version_info >= (3, 11) - else 1, - **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, stacklevel=stacklevel + 1) + self._logger.trace( + msg, + *args, + **kwargs, + stacklevel=stacklevel + CUSTOM_LOGGER_METHOD_STACKLEVEL, + ) def debug(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): """Wraps debug message with prefix and suffix.""" @@ -472,20 +473,15 @@ def info(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): msg = _concat_message(msg, prefix, suffix) self._logger.info(msg, *args, **kwargs, stacklevel=stacklevel + 1) - def success( - self, - msg="", - prefix="", - suffix="", - *args, - stacklevel=2 # logger.success is not an internal method - if sys.version_info >= (3, 11) - else 1, - **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, stacklevel=stacklevel + 1) + self._logger.success( + msg, + *args, + **kwargs, + stacklevel=stacklevel + CUSTOM_LOGGER_METHOD_STACKLEVEL, + ) def warning(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): """Wraps warning message with prefix and suffix.""" From e96954f8bef9d233e9c7bbe5572147e8077d5c37 Mon Sep 17 00:00:00 2001 From: zyzniewski-reef Date: Tue, 26 Nov 2024 18:29:10 +0100 Subject: [PATCH 6/8] Update bittensor/utils/btlogging/loggingmachine.py Co-authored-by: Roman <167799377+roman-opentensor@users.noreply.github.com> --- bittensor/utils/btlogging/loggingmachine.py | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/bittensor/utils/btlogging/loggingmachine.py b/bittensor/utils/btlogging/loggingmachine.py index 24e0586cb5..7514699fef 100644 --- a/bittensor/utils/btlogging/loggingmachine.py +++ b/bittensor/utils/btlogging/loggingmachine.py @@ -48,10 +48,7 @@ from bittensor.utils.btlogging.console import BittensorConsole # https://github.com/python/cpython/issues/97941 -if sys.version_info >= (3, 11): - CUSTOM_LOGGER_METHOD_STACKLEVEL = 2 -else: - CUSTOM_LOGGER_METHOD_STACKLEVEL = 1 +CUSTOM_LOGGER_METHOD_STACK_LEVEL = 2 if sys.version_info >= (3, 11) else 1 def _concat_message(msg="", prefix="", suffix=""): From c01fd88d69591f01e4254619b4e0dc46a669f6d0 Mon Sep 17 00:00:00 2001 From: zyzniewski-reef Date: Tue, 26 Nov 2024 18:29:18 +0100 Subject: [PATCH 7/8] Update bittensor/utils/btlogging/loggingmachine.py Co-authored-by: Roman <167799377+roman-opentensor@users.noreply.github.com> --- bittensor/utils/btlogging/loggingmachine.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bittensor/utils/btlogging/loggingmachine.py b/bittensor/utils/btlogging/loggingmachine.py index 7514699fef..23577d2e00 100644 --- a/bittensor/utils/btlogging/loggingmachine.py +++ b/bittensor/utils/btlogging/loggingmachine.py @@ -457,7 +457,7 @@ def trace(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): msg, *args, **kwargs, - stacklevel=stacklevel + CUSTOM_LOGGER_METHOD_STACKLEVEL, + stacklevel=stacklevel + CUSTOM_LOGGER_METHOD_STACK_LEVEL, ) def debug(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): From 085c70d593aba13f29f1947d3a1f0db6979e6f4c Mon Sep 17 00:00:00 2001 From: Roman <167799377+roman-opentensor@users.noreply.github.com> Date: Tue, 26 Nov 2024 09:36:32 -0800 Subject: [PATCH 8/8] Update bittensor/utils/btlogging/loggingmachine.py --- bittensor/utils/btlogging/loggingmachine.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bittensor/utils/btlogging/loggingmachine.py b/bittensor/utils/btlogging/loggingmachine.py index 23577d2e00..d4441054de 100644 --- a/bittensor/utils/btlogging/loggingmachine.py +++ b/bittensor/utils/btlogging/loggingmachine.py @@ -477,7 +477,7 @@ def success(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs): msg, *args, **kwargs, - stacklevel=stacklevel + CUSTOM_LOGGER_METHOD_STACKLEVEL, + stacklevel=stacklevel + CUSTOM_LOGGER_METHOD_STACK_LEVEL, ) def warning(self, msg="", prefix="", suffix="", *args, stacklevel=1, **kwargs):