Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
65 changes: 65 additions & 0 deletions bridge/tests/test_logging_levels.py
Original file line number Diff line number Diff line change
@@ -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()
19 changes: 17 additions & 2 deletions bridge/utils/config.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down