From e7d393e29ab25b1c6f1f27172e3b37798cbfb821 Mon Sep 17 00:00:00 2001 From: Claude Date: Tue, 7 Jul 2026 23:58:35 +0000 Subject: [PATCH 1/2] fix(bridge): stop root logger gating INFO out of bot.log MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit setup_logging() did `logging.basicConfig(level=WARNING)` in non-debug mode, which sets the ROOT logger level to WARNING. The root level is a hard gate applied before any handler's own level — records below it are dropped and never dispatched. So every INFO record (boot banners AND operational markers like the "Ignoring persisted session_id" session-resume trace) was discarded before it could reach the INFO-level bot.log file handler. bot.log only ever captured WARNING+, which is why a quiet node's bot.log sits at 0 bytes and INFO-level diagnostics are invisible. Set the root to log_level (INFO) so the file handler receives INFO, and gate the console StreamHandler per-handler at console_level (WARNING in non-debug) so stdout stays quiet. Verified: INFO markers now reach the file while the console still suppresses them. (+ regression test, skips where pydantic isn't installed) Co-Authored-By: Claude Opus 4.8 Claude-Session: https://claude.ai/code/session_017rAPKfsLfaYqNY8iPXWX34 --- bridge/tests/test_logging_levels.py | 65 +++++++++++++++++++++++++++++ bridge/utils/config.py | 15 ++++++- 2 files changed, 78 insertions(+), 2 deletions(-) create mode 100644 bridge/tests/test_logging_levels.py diff --git a/bridge/tests/test_logging_levels.py b/bridge/tests/test_logging_levels.py new file mode 100644 index 0000000..fcead3c --- /dev/null +++ b/bridge/tests/test_logging_levels.py @@ -0,0 +1,65 @@ +"""Regression test for setup_logging() root/handler level gating. + +The bug: setup_logging did `logging.basicConfig(level=WARNING)` in non-debug +mode, which set the ROOT logger level to WARNING. The root level is a hard gate +applied before any handler's own level, so every INFO record (boot banners and +operational markers like "Ignoring persisted session_id") was dropped before it +could reach the INFO-level file handler — bot.log silently lost all INFO output. + +These tests pin the invariant: the root passes INFO+, the file handler captures +INFO, and the console handler stays quiet at WARNING in non-debug mode. +""" + +import logging +import unittest + +pytest = None +try: # pydantic-backed config; skip cleanly where deps aren't installed. + from telegram_bot.utils.config import setup_logging + _HAVE_CONFIG = True +except Exception: # pragma: no cover - import guard + _HAVE_CONFIG = False + + +@unittest.skipUnless(_HAVE_CONFIG, "config (pydantic) not importable in this env") +class SetupLoggingLevelTest(unittest.TestCase): + def setUp(self): + self._root = logging.getLogger() + self._saved_handlers = list(self._root.handlers) + self._saved_level = self._root.level + + def tearDown(self): + for h in list(self._root.handlers): + if h not in self._saved_handlers: + try: + h.close() + except Exception: + pass + self._root.removeHandler(h) + self._root.setLevel(self._saved_level) + + def _console_handlers(self): + return [ + h + for h in self._root.handlers + if isinstance(h, logging.StreamHandler) + and not isinstance(h, logging.FileHandler) + ] + + def test_root_passes_info_and_console_stays_warning(self): + setup_logging() + # Root must pass INFO+ so the INFO file handler actually receives records. + self.assertLessEqual(self._root.level, logging.INFO) + # At least one file handler exists and captures INFO. + file_handlers = [ + h for h in self._root.handlers if isinstance(h, logging.FileHandler) + ] + self.assertTrue(file_handlers) + self.assertTrue(any(h.level <= logging.INFO for h in file_handlers)) + # Console handlers stay quiet (WARNING+) in non-debug mode. + for h in self._console_handlers(): + self.assertGreaterEqual(h.level, logging.WARNING) + + +if __name__ == "__main__": + unittest.main() diff --git a/bridge/utils/config.py b/bridge/utils/config.py index 48f5d5c..b703c2a 100644 --- a/bridge/utils/config.py +++ b/bridge/utils/config.py @@ -689,9 +689,20 @@ def setup_logging() -> None: is_debug = os.environ.get("BOT_DEBUG") - # Console handler - WARNING+ in non-debug, full level in debug + # Console handler - WARNING+ in non-debug, full level in debug. console_level = log_level if is_debug else logging.WARNING - logging.basicConfig(level=console_level, format=config.log_format) + # The ROOT logger level is a hard gate applied BEFORE any handler's own level: + # a record below it is dropped and never reaches the handlers. Setting the root + # to console_level (WARNING in non-debug) therefore silently discarded every + # INFO record — boot banners AND operational markers like "Ignoring persisted + # session_id" — so bot.log only ever captured WARNING+ despite the file handler + # being set to INFO. Set the root to the most-verbose handler's level (log_level) + # and gate the CONSOLE per-handler instead so the file still receives INFO. + logging.basicConfig(level=log_level, format=config.log_format) + for _h in logging.getLogger().handlers: + # basicConfig's console StreamHandler inherits the root level; raise it to + # console_level so stdout stays quiet while the file handlers below get INFO. + _h.setLevel(console_level) # File handler - write to project-root scoped runtime logs. logs_dir = config.logs_dir From f5189b3eaa895386ab0462469cbb4e47731a9db2 Mon Sep 17 00:00:00 2001 From: Hermes Agent Date: Wed, 8 Jul 2026 09:58:38 +0900 Subject: [PATCH 2/2] fix: force root logger level under existing handlers --- bridge/utils/config.py | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/bridge/utils/config.py b/bridge/utils/config.py index b703c2a..2860d96 100644 --- a/bridge/utils/config.py +++ b/bridge/utils/config.py @@ -699,7 +699,11 @@ def setup_logging() -> None: # being set to INFO. Set the root to the most-verbose handler's level (log_level) # and gate the CONSOLE per-handler instead so the file still receives INFO. logging.basicConfig(level=log_level, format=config.log_format) - for _h in logging.getLogger().handlers: + root_logger = logging.getLogger() + # basicConfig is a no-op when a harness (for example pytest) already installed + # handlers, so set the root level explicitly as the durable invariant. + root_logger.setLevel(log_level) + for _h in root_logger.handlers: # basicConfig's console StreamHandler inherits the root level; raise it to # console_level so stdout stays quiet while the file handlers below get INFO. _h.setLevel(console_level)