fix: Update logging to be more conservative #624
Conversation
We currently log warning logs on local disconnects. This is moved to log info and instead we should let the caller log warnings when RPCs fail etc. This will log at the info level only after failures to reconnect, but then logs again when reconnect happens.
There was a problem hiding this comment.
Pull request overview
This PR makes logging more conservative for local connection events by reducing log verbosity. The changes prevent log spam from transient connection issues while still providing visibility into persistent connection problems.
Key Changes:
- Connection loss events now log at
debuglevel instead ofwarningto reduce noise - Connection retry failures only log after the first retry attempt (not immediately on first failure)
- Successful reconnections are logged at
infolevel when following multiple failures
Reviewed changes
Copilot reviewed 2 out of 2 changed files in this pull request and generated 2 comments.
| File | Description |
|---|---|
| roborock/devices/local_channel.py | Changes connection loss logging from warning to debug level to reduce noise for expected disconnections |
| roborock/devices/v1_channel.py | Adds conditional logging that only emits info messages after the second connection failure and upon successful reconnection, preventing log spam from the initial connection attempt |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| def _connection_lost(self, exc: Exception | None) -> None: | ||
| """Handle connection loss.""" | ||
| _LOGGER.warning("Connection lost to %s", self._host, exc_info=exc) | ||
| _LOGGER.debug("Local connection lost to %s", self._host, exc_info=exc) |
There was a problem hiding this comment.
The log level change from warning to debug will break existing tests. Tests test_connection_lost_callback and test_connection_lost_without_exception in tests/devices/test_local_channel.py (lines 231 and 245) check for "Connection lost" in caplog.text, but caplog by default only captures WARNING level and above. These tests will need to be updated to either:
- Set
caplog.set_level(logging.DEBUG)to capture debug logs, or - Update the assertions to reflect the new intentional behavior where connection loss is logged at debug level
| if local_connect_failures == 2: | ||
| _LOGGER.info( | ||
| "Local connection to device %s failed, retrying in %s seconds", | ||
| self._device_uid, | ||
| reconnect_backoff.total_seconds(), | ||
| ) | ||
| await asyncio.sleep(reconnect_backoff.total_seconds()) | ||
| reconnect_backoff = min(reconnect_backoff * RECONNECT_MULTIPLIER, MAX_RECONNECT_INTERVAL) | ||
|
|
||
| use_cache = self._should_use_cache(local_connect_failures) | ||
| await self._local_connect(prefer_cache=use_cache) | ||
| # Reset backoff and failures on success | ||
| reconnect_backoff = MIN_RECONNECT_INTERVAL | ||
| if local_connect_failures >= 2: | ||
| _LOGGER.info("Local connection to device %s re-established", self._device_uid) |
There was a problem hiding this comment.
The new reconnection logging behavior lacks test coverage. Consider adding tests for the _background_reconnect method to verify:
- No log is emitted on the first connection failure (when
local_connect_failures == 1) - An info log is emitted on the second failure (when
local_connect_failures == 2) before the retry - An info log is emitted when reconnection succeeds after 2+ failures
- No reconnection success log is emitted if the first attempt succeeds (when
local_connect_failures < 2)
| local_connect_failures += 1 | ||
| if local_connect_failures > 1: | ||
| if local_connect_failures == 2: | ||
| _LOGGER.info( |
There was a problem hiding this comment.
I worry someone may get confused by their logs if it stops showing it retrying. What if we did this every n reconnect failures?
There was a problem hiding this comment.
Or maybe just "will continue retrying" rather than giving a timeframe
|
Will let this get replaced by #637 |
2 participants
We currently log warning logs on local disconnects. This is moved to log info and instead we should let the caller log warnings when RPCs fail etc. This will log at the info level only after failures to reconnect, but then logs again when reconnect happens.