From 054d6487da60addcb28ddb2af5a024b04124d753 Mon Sep 17 00:00:00 2001 From: Roman Chkhaidze Date: Tue, 11 Nov 2025 15:13:58 -0800 Subject: [PATCH 1/8] update `LoggingMachine.set_config` - fix for issue `#3128` --- bittensor/utils/btlogging/loggingmachine.py | 72 +++++++++++++--- tests/unit_tests/test_logging.py | 93 +++++++++++++++++++++ 2 files changed, 155 insertions(+), 10 deletions(-) diff --git a/bittensor/utils/btlogging/loggingmachine.py b/bittensor/utils/btlogging/loggingmachine.py index d52003810b..84d200b283 100644 --- a/bittensor/utils/btlogging/loggingmachine.py +++ b/bittensor/utils/btlogging/loggingmachine.py @@ -12,12 +12,12 @@ import sys from logging import Logger from logging.handlers import QueueHandler, QueueListener, RotatingFileHandler -from typing import NamedTuple +from typing import NamedTuple, Union from statemachine import State, StateMachine -from bittensor.core.settings import READ_ONLY from bittensor.core.config import Config +from bittensor.core.settings import READ_ONLY from bittensor.utils.btlogging.console import BittensorConsole from .defines import ( BITTENSOR_LOGGER_NAME, @@ -176,7 +176,7 @@ def _enable_initial_state(self, config): else: self.enable_default() - def _extract_logging_config(self, config: "Config") -> dict: + def _extract_logging_config(self, config: "Config") -> Union[dict, "Config"]: """Extract btlogging's config from bittensor config Parameters: @@ -218,10 +218,16 @@ def set_config(self, config: "Config"): config: Bittensor config instance. """ self._config = self._extract_logging_config(config) - if self._config.logging_dir and self._config.record_log: + + # Handle file logging configuration changes + if self._config.record_log and self._config.logging_dir: expanded_dir = os.path.expanduser(config.logging_dir) logfile = os.path.abspath(os.path.join(expanded_dir, DEFAULT_LOG_FILE_NAME)) self._enable_file_logging(logfile) + else: + # If record_log is False or logging_dir is None, disable file logging + self._disable_file_logging() + if self._config.trace: self.enable_trace() elif self._config.debug: @@ -323,15 +329,61 @@ def disable_third_party_loggers(self): logger.removeHandler(handler) def _enable_file_logging(self, logfile: str): - # preserve idempotency; do not create extra filehandlers - # if one already exists - if any( - [isinstance(handler, RotatingFileHandler) for handler in self._handlers] - ): - return + """Enable file logging to the specified logfile path. + + If a file handler already exists, it will be replaced if the path has changed. This ensures that runtime updates + to logging_dir correctly redirect output. + + Parameters: + logfile: Absolute path to the log file. + """ + # Check if a file handler already exists + existing_file_handler = None + for handler in self._handlers: + if isinstance(handler, RotatingFileHandler): + existing_file_handler = handler + break + + # If file handler exists, check if path has changed + if existing_file_handler is not None: + current_path = os.path.abspath(existing_file_handler.baseFilename) + new_path = os.path.abspath(logfile) + + # If path hasn't changed, no need to update + if current_path == new_path: + return + + # Path has changed, remove old handler and create new one + self._handlers.remove(existing_file_handler) + existing_file_handler.close() + + # Create and add new file handler file_handler = self._create_file_handler(logfile) self._handlers.append(file_handler) + + # Update listener handlers + # Stop listener temporarily to update handlers safely (same pattern as state transitions) + self._listener.stop() self._listener.handlers = tuple(self._handlers) + self._listener.start() + + def _disable_file_logging(self): + """Disable file logging by removing the file handler if it exists.""" + file_handler = None + for handler in self._handlers: + if isinstance(handler, RotatingFileHandler): + file_handler = handler + break + + if file_handler is not None: + self._handlers.remove(file_handler) + file_handler.close() + + # Update listener handlers + # Stop listener temporarily to update handlers safely (same pattern as state transitions) + self._listener.stop() + self._listener.handlers = tuple(self._handlers) + self._listener.start() # state transitions def before_transition(self, event, state): diff --git a/tests/unit_tests/test_logging.py b/tests/unit_tests/test_logging.py index f84bfd9341..25b3857967 100644 --- a/tests/unit_tests/test_logging.py +++ b/tests/unit_tests/test_logging.py @@ -234,3 +234,96 @@ def test_logger_level(logging_machine, caplog): assert "info2" in caplog.text assert "warn2" in caplog.text + + +def test_runtime_logging_dir_update(tmp_path): + """ + Test that updating logging_dir at runtime correctly redirects output to the new path. + This test addresses issue #3128: runtime updates to logging_dir should redirect output. + + The key test is that the file handler's path is updated when logging_dir changes. + """ + import os + from logging.handlers import RotatingFileHandler + + # Create initial logging directory + initial_log_dir = tmp_path / "logs1" + initial_log_dir.mkdir() + initial_log_file = initial_log_dir / DEFAULT_LOG_FILE_NAME + + # Create second logging directory for runtime update + new_log_dir = tmp_path / "logs2" + new_log_dir.mkdir() + new_log_file = new_log_dir / DEFAULT_LOG_FILE_NAME + + # Initialize LoggingMachine with initial directory + initial_config = LoggingConfig( + debug=False, + trace=False, + info=False, + record_log=True, + logging_dir=str(initial_log_dir), + ) + lm = LoggingMachine(initial_config) + + # Verify initial file handler exists and points to initial directory + file_handler = None + for handler in lm._handlers: + if isinstance(handler, RotatingFileHandler): + file_handler = handler + break + + assert file_handler is not None + initial_path = os.path.abspath(file_handler.baseFilename) + assert initial_path == os.path.abspath(str(initial_log_file)) + + # Update logging_dir at runtime + new_config = LoggingConfig( + debug=False, + trace=False, + info=False, + record_log=True, + logging_dir=str(new_log_dir), + ) + lm.set_config(new_config) + + # Verify file handler now points to new directory (not old one) + file_handler = None + for handler in lm._handlers: + if isinstance(handler, RotatingFileHandler): + file_handler = handler + break + + assert file_handler is not None + new_path = os.path.abspath(file_handler.baseFilename) + assert new_path == os.path.abspath(str(new_log_file)) + # Verify it's NOT pointing to the old path + assert new_path != initial_path + + +def test_runtime_disable_file_logging(tmp_path): + """ + Test that disabling file logging at runtime correctly removes the file handler. + """ + from logging.handlers import RotatingFileHandler + + log_dir = tmp_path / "logs" + log_dir.mkdir() + + # Initialize with file logging enabled + config = LoggingConfig( + debug=False, trace=False, info=False, record_log=True, logging_dir=str(log_dir) + ) + lm = LoggingMachine(config) + + # Verify file handler exists + assert any(isinstance(handler, RotatingFileHandler) for handler in lm._handlers) + + # Disable file logging at runtime + new_config = LoggingConfig( + debug=False, trace=False, info=False, record_log=False, logging_dir=str(log_dir) + ) + lm.set_config(new_config) + + # Verify file handler is removed + assert not any(isinstance(handler, RotatingFileHandler) for handler in lm._handlers) From d3603fc218f7b1aeb0885df8e0688b863ad94d80 Mon Sep 17 00:00:00 2001 From: Roman Chkhaidze Date: Tue, 11 Nov 2025 15:23:43 -0800 Subject: [PATCH 2/8] show real file/module in `btlogging.console.*` message --- bittensor/utils/btlogging/console.py | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/bittensor/utils/btlogging/console.py b/bittensor/utils/btlogging/console.py index 20e09bdf60..c3afef1287 100644 --- a/bittensor/utils/btlogging/console.py +++ b/bittensor/utils/btlogging/console.py @@ -16,7 +16,7 @@ """ from functools import wraps -from typing import Callable, TYPE_CHECKING +from typing import TYPE_CHECKING, Callable from .helpers import all_loggers @@ -45,29 +45,29 @@ def __init__(self, logger: "LoggingMachine"): @_print_wrapper def debug(self, message: str): """Logs a DEBUG message to the console.""" - self.logger.debug(message) + self.logger.debug(message, stacklevel=3) @_print_wrapper def info(self, message: str): """Logs a INFO message to the console.""" - self.logger.info(message) + self.logger.info(message, stacklevel=3) @_print_wrapper def success(self, message: str): """Logs a SUCCESS message to the console.""" - self.logger.success(message) + self.logger.success(message, stacklevel=3) @_print_wrapper def warning(self, message: str): """Logs a WARNING message to the console.""" - self.logger.warning(message) + self.logger.warning(message, stacklevel=3) @_print_wrapper def error(self, message: str): """Logs a ERROR message to the console.""" - self.logger.error(message) + self.logger.error(message, stacklevel=3) @_print_wrapper def critical(self, message: str): """Logs a CRITICAL message to the console.""" - self.logger.critical(message) + self.logger.critical(message, stacklevel=3) From 90b80a014c9d237a9965f6549db7c3964129e6a4 Mon Sep 17 00:00:00 2001 From: Roman Chkhaidze Date: Tue, 11 Nov 2025 15:28:46 -0800 Subject: [PATCH 3/8] Reduce log level column width from 16 to 8 --- bittensor/utils/btlogging/format.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bittensor/utils/btlogging/format.py b/bittensor/utils/btlogging/format.py index 6e119a4024..26716845ab 100644 --- a/bittensor/utils/btlogging/format.py +++ b/bittensor/utils/btlogging/format.py @@ -142,7 +142,7 @@ def format(self, record: "logging.LogRecord") -> str: """ format_orig = self._style._fmt - record.levelname = f"{record.levelname:^16}" + record.levelname = f"{record.levelname:^8}" if record.levelno not in LOG_FORMATS: self._style._fmt = ( From aac5f807ac0cf9635c4f8018b83ca309a3fd2968 Mon Sep 17 00:00:00 2001 From: Roman Chkhaidze Date: Fri, 14 Nov 2025 12:33:13 -0800 Subject: [PATCH 4/8] add `BT_LOGGING_ENABLE_THIRD_PARTY_LOGGERS` and `enable_third_party_loggers` attribute in `LoggingConfig` --- bittensor/core/settings.py | 16 ++++--- bittensor/utils/btlogging/loggingmachine.py | 48 ++++++++++++--------- tests/unit_tests/test_logging.py | 37 +++++++++++++--- 3 files changed, 70 insertions(+), 31 deletions(-) diff --git a/bittensor/core/settings.py b/bittensor/core/settings.py index a18d3addc7..2bc0e680e1 100644 --- a/bittensor/core/settings.py +++ b/bittensor/core/settings.py @@ -108,11 +108,17 @@ "max_workers": int(_BT_AXON_MAX_WORKERS) if _BT_AXON_MAX_WORKERS else 10, }, "logging": { - "debug": os.getenv("BT_LOGGING_DEBUG") or False, - "trace": os.getenv("BT_LOGGING_TRACE") or False, - "info": os.getenv("BT_LOGGING_INFO") or False, - "record_log": os.getenv("BT_LOGGING_RECORD_LOG") or False, - "logging_dir": os.getenv("BT_LOGGING_LOGGING_DIR") or str(MINERS_DIR), + "debug": bool(os.getenv("BT_LOGGING_DEBUG")) or False, + "trace": bool(os.getenv("BT_LOGGING_TRACE")) or False, + "info": bool(os.getenv("BT_LOGGING_INFO")) or False, + "record_log": bool(os.getenv("BT_LOGGING_RECORD_LOG")) or False, + "logging_dir": None + if READ_ONLY + else os.getenv("BT_LOGGING_LOGGING_DIR") or str(MINERS_DIR), + "enable_third_party_loggers": os.getenv( + "BT_LOGGING_ENABLE_THIRD_PARTY_LOGGERS" + ) + or False, }, "priority": { "max_workers": int(_BT_PRIORITY_MAX_WORKERS) diff --git a/bittensor/utils/btlogging/loggingmachine.py b/bittensor/utils/btlogging/loggingmachine.py index 84d200b283..38c21e97b2 100644 --- a/bittensor/utils/btlogging/loggingmachine.py +++ b/bittensor/utils/btlogging/loggingmachine.py @@ -17,7 +17,7 @@ from statemachine import State, StateMachine from bittensor.core.config import Config -from bittensor.core.settings import READ_ONLY +from bittensor.core.settings import DEFAULTS from bittensor.utils.btlogging.console import BittensorConsole from .defines import ( BITTENSOR_LOGGER_NAME, @@ -53,6 +53,7 @@ class LoggingConfig(NamedTuple): info: bool record_log: bool logging_dir: str + enable_third_party_loggers: bool class LoggingMachine(StateMachine, Logger): @@ -161,7 +162,12 @@ def __init__(self, config: "Config", name: str = BITTENSOR_LOGGER_NAME): # set up all the loggers self._logger = self._initialize_bt_logger(name) - self.disable_third_party_loggers() + + if self._config.enable_third_party_loggers: + self.enable_third_party_loggers() + else: + self.disable_third_party_loggers() + self._enable_initial_state(self._config) self.console = BittensorConsole(self) @@ -632,45 +638,41 @@ def add_args(cls, parser: argparse.ArgumentParser, prefix: str = None): """Accept specific arguments fro parser""" prefix_str = "" if prefix is None else prefix + "." try: - default_logging_debug = os.getenv("BT_LOGGING_DEBUG") or False - default_logging_info = os.getenv("BT_LOGGING_INFO") or False - default_logging_trace = os.getenv("BT_LOGGING_TRACE") or False - default_logging_record_log = os.getenv("BT_LOGGING_RECORD_LOG") or False - default_logging_logging_dir = ( - None - if READ_ONLY - else os.getenv("BT_LOGGING_LOGGING_DIR") - or os.path.join("~", ".bittensor", "miners") - ) parser.add_argument( "--" + prefix_str + "logging.debug", action="store_true", - help="""Turn on bittensor debugging information""", - default=default_logging_debug, + help="Turn on bittensor debugging information.", + default=DEFAULTS.logging.debug, ) parser.add_argument( "--" + prefix_str + "logging.trace", action="store_true", - help="""Turn on bittensor trace level information""", - default=default_logging_trace, + help="Turn on bittensor trace level information.", + default=DEFAULTS.logging.trace, ) parser.add_argument( "--" + prefix_str + "logging.info", action="store_true", - help="""Turn on bittensor info level information""", - default=default_logging_info, + help="Turn on bittensor info level information.", + default=DEFAULTS.logging.info, ) parser.add_argument( "--" + prefix_str + "logging.record_log", action="store_true", - help="""Turns on logging to file.""", - default=default_logging_record_log, + help="Turns on logging to file.", + default=DEFAULTS.logging.record_log, ) parser.add_argument( "--" + prefix_str + "logging.logging_dir", type=str, help="Logging default root directory.", - default=default_logging_logging_dir, + default=DEFAULTS.logging.logging_dir, + ) + parser.add_argument( + "--" + prefix_str + "logging.enable_third_party_loggers", + action="store_true", + help="Enables logging for third-party loggers.", + default=DEFAULTS.logging.enable_third_party_loggers, ) except argparse.ArgumentError: # re-parsing arguments. @@ -695,6 +697,7 @@ def __call__( info: bool = None, record_log: bool = None, logging_dir: str = None, + enable_third_party_loggers: bool = None, ): if config is not None: cfg = self._extract_logging_config(config) @@ -708,6 +711,8 @@ def __call__( cfg.record_log = record_log if logging_dir is not None: cfg.logging_dir = logging_dir + if enable_third_party_loggers is not None: + cfg.enable_third_party_loggers = enable_third_party_loggers else: cfg = LoggingConfig( debug=debug, @@ -715,5 +720,6 @@ def __call__( info=info, record_log=record_log, logging_dir=logging_dir, + enable_third_party_loggers=enable_third_party_loggers, ) self.set_config(cfg) diff --git a/tests/unit_tests/test_logging.py b/tests/unit_tests/test_logging.py index 25b3857967..535e009eba 100644 --- a/tests/unit_tests/test_logging.py +++ b/tests/unit_tests/test_logging.py @@ -38,7 +38,12 @@ def mock_config(tmp_path): log_file_path = log_dir / DEFAULT_LOG_FILE_NAME mock_config = LoggingConfig( - debug=False, trace=False, info=False, record_log=True, logging_dir=str(log_dir) + debug=False, + trace=False, + info=False, + record_log=True, + logging_dir=str(log_dir), + enable_third_party_loggers=False, ) yield mock_config, log_file_path @@ -141,7 +146,12 @@ def test_enable_file_logging_with_new_config(tmp_path): # check no file handler is created config = LoggingConfig( - debug=False, trace=False, info=False, record_log=True, logging_dir=None + debug=False, + trace=False, + info=False, + record_log=True, + logging_dir=None, + enable_third_party_loggers=False, ) lm = LoggingMachine(config) assert not any( @@ -150,7 +160,12 @@ def test_enable_file_logging_with_new_config(tmp_path): # check file handler now exists new_config = LoggingConfig( - debug=False, trace=False, info=False, record_log=True, logging_dir=str(log_dir) + debug=False, + trace=False, + info=False, + record_log=True, + logging_dir=str(log_dir), + enable_third_party_loggers=False, ) lm.set_config(new_config) assert any(isinstance(handler, stdlogging.FileHandler) for handler in lm._handlers) @@ -263,6 +278,7 @@ def test_runtime_logging_dir_update(tmp_path): info=False, record_log=True, logging_dir=str(initial_log_dir), + enable_third_party_loggers=False, ) lm = LoggingMachine(initial_config) @@ -284,6 +300,7 @@ def test_runtime_logging_dir_update(tmp_path): info=False, record_log=True, logging_dir=str(new_log_dir), + enable_third_party_loggers=False, ) lm.set_config(new_config) @@ -312,7 +329,12 @@ def test_runtime_disable_file_logging(tmp_path): # Initialize with file logging enabled config = LoggingConfig( - debug=False, trace=False, info=False, record_log=True, logging_dir=str(log_dir) + debug=False, + trace=False, + info=False, + record_log=True, + logging_dir=str(log_dir), + enable_third_party_loggers=False, ) lm = LoggingMachine(config) @@ -321,7 +343,12 @@ def test_runtime_disable_file_logging(tmp_path): # Disable file logging at runtime new_config = LoggingConfig( - debug=False, trace=False, info=False, record_log=False, logging_dir=str(log_dir) + debug=False, + trace=False, + info=False, + record_log=False, + logging_dir=str(log_dir), + enable_third_party_loggers=False, ) lm.set_config(new_config) From 779b9fed46fd8eb509eecc9e3f3764f53d8e2f31 Mon Sep 17 00:00:00 2001 From: Roman Chkhaidze Date: Fri, 14 Nov 2025 15:18:28 -0800 Subject: [PATCH 5/8] temporary solution while AsyncSubstrateInterface._get_block_handler is broken --- bittensor/extras/dev_framework/subnet.py | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/bittensor/extras/dev_framework/subnet.py b/bittensor/extras/dev_framework/subnet.py index f0236bea88..d08e3e3ea3 100644 --- a/bittensor/extras/dev_framework/subnet.py +++ b/bittensor/extras/dev_framework/subnet.py @@ -1,3 +1,4 @@ +import time from typing import Optional, Union from collections import namedtuple from async_substrate_interface.async_substrate import AsyncExtrinsicReceipt @@ -310,7 +311,13 @@ async def _async_activate_subnet( ) ).value # added 10 blocks bc 2.5 seconds is not always enough for the chain to update. - await self.s.wait_for_block(current_block + activation_block + 10) + + # === temporary solution while AsyncSubstrateInterface._get_block_handler is broken === + # await self.s.wait_for_block(current_block + activation_block + 10) + block_time = 0.25 if self.s.chain.is_fast_blocks() else 12 + time.sleep(block_time * activation_block) + # === temporary solution while AsyncSubstrateInterface._get_block_handler is broken === + response = await self.s.subnets.start_call( wallet=owner_wallet, netuid=netuid or self._netuid, From 345cfea8026ccc6c13644a3b7ad69a2fef5a3055 Mon Sep 17 00:00:00 2001 From: Roman Chkhaidze Date: Fri, 14 Nov 2025 15:37:25 -0800 Subject: [PATCH 6/8] reverse --- bittensor/extras/dev_framework/subnet.py | 7 +------ 1 file changed, 1 insertion(+), 6 deletions(-) diff --git a/bittensor/extras/dev_framework/subnet.py b/bittensor/extras/dev_framework/subnet.py index d08e3e3ea3..e59283a06c 100644 --- a/bittensor/extras/dev_framework/subnet.py +++ b/bittensor/extras/dev_framework/subnet.py @@ -311,12 +311,7 @@ async def _async_activate_subnet( ) ).value # added 10 blocks bc 2.5 seconds is not always enough for the chain to update. - - # === temporary solution while AsyncSubstrateInterface._get_block_handler is broken === - # await self.s.wait_for_block(current_block + activation_block + 10) - block_time = 0.25 if self.s.chain.is_fast_blocks() else 12 - time.sleep(block_time * activation_block) - # === temporary solution while AsyncSubstrateInterface._get_block_handler is broken === + await self.s.wait_for_block(current_block + activation_block + 10) response = await self.s.subnets.start_call( wallet=owner_wallet, From 385121ebbb0e55fc5e7d3e1c6a09f6cab22fdf97 Mon Sep 17 00:00:00 2001 From: Roman Chkhaidze Date: Fri, 14 Nov 2025 15:38:26 -0800 Subject: [PATCH 7/8] temporary keep ASI 1.5.9 --- pyproject.toml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pyproject.toml b/pyproject.toml index d1285a0361..8354a0234a 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -35,7 +35,7 @@ dependencies = [ "uvicorn", "bittensor-drand>=1.0.0,<2.0.0", "bittensor-wallet>=4.0.0,<5.0", - "async-substrate-interface>=1.5.6" + "async-substrate-interface==1.5.9" ] [project.optional-dependencies] From c0fa19855f8e9f83c011dc88022303f39ef365be Mon Sep 17 00:00:00 2001 From: Roman Chkhaidze Date: Fri, 14 Nov 2025 15:43:20 -0800 Subject: [PATCH 8/8] unused import --- bittensor/extras/dev_framework/subnet.py | 1 - 1 file changed, 1 deletion(-) diff --git a/bittensor/extras/dev_framework/subnet.py b/bittensor/extras/dev_framework/subnet.py index e59283a06c..7cdfbef7ae 100644 --- a/bittensor/extras/dev_framework/subnet.py +++ b/bittensor/extras/dev_framework/subnet.py @@ -1,4 +1,3 @@ -import time from typing import Optional, Union from collections import namedtuple from async_substrate_interface.async_substrate import AsyncExtrinsicReceipt