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..2860d96 100644 --- a/bridge/utils/config.py +++ b/bridge/utils/config.py @@ -689,9 +689,24 @@ 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) + 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) # File handler - write to project-root scoped runtime logs. logs_dir = config.logs_dir