fix: Apply log level filtering to BufferHandler to suppress debug messages#103
Conversation
Fixes from development branch
Modbus improvements
Add OPC-UA; Improvements on Plugin lifecycle
Python blocks fix; Modbus echo response fix
Fix OPC-UA type mappings
Logging improvements
Development
…sages BufferHandler extends logging.Handler directly, not logging.StreamHandler. The isinstance(h, logging.StreamHandler) check skipped it, leaving its level at NOTSET (0) which passes all messages through. This caused debug messages (e.g. status query responses from SyncUnixClient) to accumulate in the buffer and appear in the REST API /api/runtime-logs endpoint even when --print-debug was not set. https://claude.ai/code/session_01JAxvToztqockUCUQSC7dv7
Three logging fixes: 1. LogParser now maps C runtime's "WARN" to Python's "WARNING" for both the numeric level (used by handler filtering) and the string stored in log entries. Previously WARN messages got level=INFO (wrong numeric mapping) and were stored as "WARN" in the buffer while Python-originated warnings stored "WARNING", breaking level filtering in the REST API. 2. Remove dead webserver/logger/logger.py which defined a shadowed get_logger() that created separate BufferHandlers without level filtering. The __init__.py import that pulled it in was also removed. 3. Update test_log_levels_stored to verify debug messages are filtered by default, and add test_log_levels_stored_with_print_debug to verify they pass through when print_debug is enabled. https://claude.ai/code/session_01JAxvToztqockUCUQSC7dv7
There was a problem hiding this comment.
Pull request overview
Fixes runtime log buffering so debug entries don’t leak into the REST /api/runtime-logs output unless debug printing is enabled, by ensuring handler-level filtering applies to BufferHandler and by normalizing level names.
Changes:
- Apply
effective_levelto all logger handlers (includingBufferHandler) rather than onlyStreamHandler. - Normalize
WARN→WARNINGin the log parser and reflect the normalized value in parsed JSON logs. - Add/extend pytest coverage for debug filtering behavior with and without
print_debug.
Reviewed changes
Copilot reviewed 4 out of 4 changed files in this pull request and generated 3 comments.
| File | Description |
|---|---|
| webserver/logger/parser.py | Adds level normalization so WARN is treated consistently as WARNING. |
| webserver/logger/logger.py | Deletes legacy get_logger implementation (appears superseded by package-level one). |
| webserver/logger/init.py | Ensures handler level is applied to BufferHandler by setting levels on all handlers. |
| tests/pytest/logger/test_logger_buffer.py | Adds assertions verifying debug filtering behavior depends on print_debug. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| LEVEL_MAP = { | ||
| "DEBUG": logging.DEBUG, | ||
| "INFO": logging.INFO, | ||
| "WARN": logging.WARNING, | ||
| "WARNING": logging.WARNING, | ||
| "ERROR": logging.ERROR, | ||
| "CRITICAL": logging.CRITICAL, | ||
| } | ||
|
|
||
| # Normalize non-standard level names to Python conventions | ||
| LEVEL_NORMALIZE = { | ||
| "WARN": "WARNING", | ||
| } |
There was a problem hiding this comment.
LEVEL_NORMALIZE maps "WARN" to "WARNING", so the "WARN" entry in LEVEL_MAP becomes redundant (and can mislead future readers into thinking both forms are expected post-normalization). Consider removing "WARN" from LEVEL_MAP (or, alternatively, removing the normalization and relying solely on LEVEL_MAP if you don’t need to rewrite the emitted "level" field to "WARNING").
| level_name = parsed.get("level", "INFO") | ||
| level_name = LEVEL_NORMALIZE.get(level_name, level_name) | ||
| level = LEVEL_MAP.get(level_name, logging.INFO) | ||
| parsed["level"] = level_name |
There was a problem hiding this comment.
The normalization is currently case-sensitive. If any producers emit "warn" / "info" / etc., they won’t be normalized or mapped as intended. Consider normalizing case (e.g., converting to upper() before applying LEVEL_NORMALIZE/LEVEL_MAP) to make parsing more robust.
| def test_log_levels_stored_with_print_debug(test_logger): | ||
| """Debug messages pass through when print_debug is enabled.""" | ||
| from webserver.logger.config import LoggerConfig | ||
| from webserver.logger import get_logger | ||
|
|
||
| LoggerConfig.print_debug = True | ||
| try: | ||
| # Re-fetch logger to apply new level to handlers | ||
| logger, buffer = get_logger("test_logger", use_buffer=True) | ||
| buffer.clear() | ||
| logger.debug("Debug message") | ||
| logger.info("Info message") | ||
| logger.warning("Warning message") | ||
| logger.error("Error message") | ||
| logs = buffer.get_logs() | ||
| levels = [log["level"] for log in logs] | ||
| assert levels == ["DEBUG", "INFO", "WARNING", "ERROR"] | ||
| finally: | ||
| LoggerConfig.print_debug = False | ||
| # Re-fetch to restore INFO level on handlers | ||
| get_logger("test_logger", use_buffer=True) |
There was a problem hiding this comment.
This test mutates global configuration (LoggerConfig.print_debug) and relies on cleanup in finally. To improve isolation (especially if the suite ever runs tests concurrently), prefer using pytest’s monkeypatch fixture (or an equivalent config fixture) to scope the config change to this test and automatically restore the original value.
BufferHandler extends logging.Handler directly, not logging.StreamHandler.
The isinstance(h, logging.StreamHandler) check skipped it, leaving its
level at NOTSET (0) which passes all messages through. This caused debug
messages (e.g. status query responses from SyncUnixClient) to accumulate
in the buffer and appear in the REST API /api/runtime-logs endpoint even
when --print-debug was not set.
https://claude.ai/code/session_01JAxvToztqockUCUQSC7dv7