From 7241536df97553de0c5a5a30b7ddf3cda25e1ca2 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Wed, 26 Feb 2025 00:36:25 +0000 Subject: [PATCH 1/5] Adjust remote ESPHome log subscription level on logging change If the logging level changes, notify the ESP device to adjust the level of logging subscription to avoid sending logs that will be filtered by the current log level. --- homeassistant/components/esphome/manager.py | 37 ++++++++++++++++++++- 1 file changed, 36 insertions(+), 1 deletion(-) diff --git a/homeassistant/components/esphome/manager.py b/homeassistant/components/esphome/manager.py index c73268de747d37..7a27bb11a53a78 100644 --- a/homeassistant/components/esphome/manager.py +++ b/homeassistant/components/esphome/manager.py @@ -35,6 +35,7 @@ Platform, ) from homeassistant.core import ( + CALLBACK_TYPE, Event, EventStateChangedData, HomeAssistant, @@ -95,6 +96,14 @@ LogLevel.LOG_LEVEL_VERBOSE: logging.DEBUG, LogLevel.LOG_LEVEL_VERY_VERBOSE: logging.DEBUG, } +LOGGER_TO_LOG_LEVEL = { + logging.NOTSET: LogLevel.LOG_LEVEL_VERY_VERBOSE, + logging.DEBUG: LogLevel.LOG_LEVEL_VERY_VERBOSE, + logging.INFO: LogLevel.LOG_LEVEL_CONFIG, + logging.WARNING: LogLevel.LOG_LEVEL_WARN, + logging.ERROR: LogLevel.LOG_LEVEL_ERROR, + logging.CRITICAL: LogLevel.LOG_LEVEL_ERROR, +} # 7-bit and 8-bit C1 ANSI sequences # https://stackoverflow.com/questions/14693701/how-can-i-remove-the-ansi-escape-sequences-from-a-string-in-python ANSI_ESCAPE_78BIT = re.compile( @@ -161,6 +170,8 @@ class ESPHomeManager: """Class to manage an ESPHome connection.""" __slots__ = ( + "_cancel_subscribe_logs", + "_log_level", "cli", "device_id", "domain_data", @@ -194,6 +205,8 @@ def __init__( self.reconnect_logic: ReconnectLogic | None = None self.zeroconf_instance = zeroconf_instance self.entry_data = entry.runtime_data + self._cancel_subscribe_logs: CALLBACK_TYPE | None = None + self._log_level = LogLevel.LOG_LEVEL_NONE async def on_stop(self, event: Event) -> None: """Cleanup the socket client on HA close.""" @@ -378,6 +391,24 @@ def _async_on_log(self, msg: SubscribeLogsResponse) -> None: ANSI_ESCAPE_78BIT.sub(b"", log).decode("utf-8", "backslashreplace"), ) + @callback + def _async_get_equivalent_log_level(self) -> LogLevel: + """Get the equivalent ESPHome log level for the current logger.""" + return LOGGER_TO_LOG_LEVEL.get( + _LOGGER.getEffectiveLevel(), LogLevel.LOG_LEVEL_VERY_VERBOSE + ) + + @callback + def _async_subscribe_logs(self, log_level: LogLevel) -> None: + """Subscribe to logs.""" + if self._cancel_subscribe_logs is not None: + self._cancel_subscribe_logs() + self._cancel_subscribe_logs = None + self._log_level = log_level + self._cancel_subscribe_logs = self.cli.subscribe_logs( + self._async_on_log, self._log_level + ) + async def _on_connnect(self) -> None: """Subscribe to states and list entities on successful API login.""" entry = self.entry @@ -390,7 +421,7 @@ async def _on_connnect(self) -> None: stored_device_name = entry.data.get(CONF_DEVICE_NAME) unique_id_is_mac_address = unique_id and ":" in unique_id if entry.options.get(CONF_SUBSCRIBE_LOGS): - cli.subscribe_logs(self._async_on_log, LogLevel.LOG_LEVEL_VERY_VERBOSE) + self._async_subscribe_logs(self._async_get_equivalent_log_level()) results = await asyncio.gather( create_eager_task(cli.device_info()), create_eager_task(cli.list_entities_services()), @@ -542,6 +573,10 @@ async def on_connect_error(self, err: Exception) -> None: def _async_handle_logging_changed(self, _event: Event) -> None: """Handle when the logging level changes.""" self.cli.set_debug(_LOGGER.isEnabledFor(logging.DEBUG)) + if self.entry.options.get(CONF_SUBSCRIBE_LOGS) and self._log_level != ( + new_log_level := self._async_get_equivalent_log_level() + ): + self._async_subscribe_logs(new_log_level) async def async_start(self) -> None: """Start the esphome connection manager.""" From ccdba119e92d3bfe87346abe8d7f5a940bc6e06d Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Wed, 26 Feb 2025 00:38:32 +0000 Subject: [PATCH 2/5] Bump aioesphomeapi to 29.2.0 changelog: https://github.com/esphome/aioesphomeapi/compare/v29.1.1...v29.2.0 --- homeassistant/components/esphome/manifest.json | 2 +- requirements_all.txt | 2 +- requirements_test_all.txt | 2 +- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/homeassistant/components/esphome/manifest.json b/homeassistant/components/esphome/manifest.json index 403da9286ab044..b59dd544c490d4 100644 --- a/homeassistant/components/esphome/manifest.json +++ b/homeassistant/components/esphome/manifest.json @@ -16,7 +16,7 @@ "loggers": ["aioesphomeapi", "noiseprotocol", "bleak_esphome"], "mqtt": ["esphome/discover/#"], "requirements": [ - "aioesphomeapi==29.1.1", + "aioesphomeapi==29.2.0", "esphome-dashboard-api==1.2.3", "bleak-esphome==2.7.1" ], diff --git a/requirements_all.txt b/requirements_all.txt index 4949a9fc4a9341..3a7fe746411c0e 100644 --- a/requirements_all.txt +++ b/requirements_all.txt @@ -243,7 +243,7 @@ aioelectricitymaps==0.4.0 aioemonitor==1.0.5 # homeassistant.components.esphome -aioesphomeapi==29.1.1 +aioesphomeapi==29.2.0 # homeassistant.components.flo aioflo==2021.11.0 diff --git a/requirements_test_all.txt b/requirements_test_all.txt index 17a6f6a6f56701..f01c344b3c782e 100644 --- a/requirements_test_all.txt +++ b/requirements_test_all.txt @@ -231,7 +231,7 @@ aioelectricitymaps==0.4.0 aioemonitor==1.0.5 # homeassistant.components.esphome -aioesphomeapi==29.1.1 +aioesphomeapi==29.2.0 # homeassistant.components.flo aioflo==2021.11.0 From 3416877f2852102cf03e79eae76504a19a45b875 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Wed, 26 Feb 2025 00:45:45 +0000 Subject: [PATCH 3/5] cover --- tests/components/esphome/conftest.py | 2 ++ tests/components/esphome/test_manager.py | 18 ++++++++++++++++++ 2 files changed, 20 insertions(+) diff --git a/tests/components/esphome/conftest.py b/tests/components/esphome/conftest.py index 07f6c6ea69714a..ae899e0dc60883 100644 --- a/tests/components/esphome/conftest.py +++ b/tests/components/esphome/conftest.py @@ -230,6 +230,7 @@ def __init__( ) self.on_log_message: Callable[[SubscribeLogsResponse], None] self.device_info = device_info + self.current_log_level = LogLevel.LOG_LEVEL_NONE def set_state_callback(self, state_callback: Callable[[EntityState], None]) -> None: """Set the state callback.""" @@ -435,6 +436,7 @@ def _subscribe_logs( ) -> None: """Subscribe to log messages.""" mock_device.set_on_log_message(on_log_message) + mock_device.current_log_level = log_level def _subscribe_voice_assistant( *, diff --git a/tests/components/esphome/test_manager.py b/tests/components/esphome/test_manager.py index cf9d4a6f2179fd..4df59dca3497b6 100644 --- a/tests/components/esphome/test_manager.py +++ b/tests/components/esphome/test_manager.py @@ -57,6 +57,7 @@ async def test_esphome_device_subscribe_logs( caplog: pytest.LogCaptureFixture, ) -> None: """Test configuring a device to subscribe to logs.""" + assert await async_setup_component(hass, "logger", {"logger": {}}) entry = MockConfigEntry( domain=DOMAIN, data={ @@ -76,6 +77,15 @@ async def test_esphome_device_subscribe_logs( states=[], ) await hass.async_block_till_done() + + await hass.services.async_call( + "logger", + "set_level", + {"homeassistant.components.esphome": "DEBUG"}, + blocking=True, + ) + assert device.current_log_level == LogLevel.LOG_LEVEL_VERY_VERBOSE + caplog.set_level(logging.DEBUG) device.mock_on_log_message( Mock(level=LogLevel.LOG_LEVEL_INFO, message=b"test_log_message") @@ -103,6 +113,14 @@ async def test_esphome_device_subscribe_logs( await hass.async_block_till_done() assert "test_debug_log_message" in caplog.text + await hass.services.async_call( + "logger", + "set_level", + {"homeassistant.components.esphome": "WARNING"}, + blocking=True, + ) + assert device.current_log_level == LogLevel.LOG_LEVEL_WARN + async def test_esphome_device_service_calls_not_allowed( hass: HomeAssistant, From 6b7396b4f61a9b6fb8e66de5d68910ba36bc5d14 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Wed, 26 Feb 2025 03:16:49 +0000 Subject: [PATCH 4/5] remove double logger check since it will not be called if level does not match --- homeassistant/components/esphome/manager.py | 16 +++++++--------- 1 file changed, 7 insertions(+), 9 deletions(-) diff --git a/homeassistant/components/esphome/manager.py b/homeassistant/components/esphome/manager.py index 7a27bb11a53a78..e32bb7d6ded41e 100644 --- a/homeassistant/components/esphome/manager.py +++ b/homeassistant/components/esphome/manager.py @@ -381,15 +381,13 @@ async def on_connect(self) -> None: def _async_on_log(self, msg: SubscribeLogsResponse) -> None: """Handle a log message from the API.""" - logger_level = LOG_LEVEL_TO_LOGGER.get(msg.level, logging.DEBUG) - if _LOGGER.isEnabledFor(logger_level): - log: bytes = msg.message - _LOGGER.log( - logger_level, - "%s: %s", - self.entry.title, - ANSI_ESCAPE_78BIT.sub(b"", log).decode("utf-8", "backslashreplace"), - ) + log: bytes = msg.message + _LOGGER.log( + LOG_LEVEL_TO_LOGGER.get(msg.level, logging.DEBUG), + "%s: %s", + self.entry.title, + ANSI_ESCAPE_78BIT.sub(b"", log).decode("utf-8", "backslashreplace"), + ) @callback def _async_get_equivalent_log_level(self) -> LogLevel: From f15cc7737c2f12606eed0a7c17ab398c0556c280 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Wed, 26 Feb 2025 03:30:04 +0000 Subject: [PATCH 5/5] coverage --- tests/components/esphome/conftest.py | 3 ++- tests/components/esphome/test_manager.py | 14 ++++++++++++++ 2 files changed, 16 insertions(+), 1 deletion(-) diff --git a/tests/components/esphome/conftest.py b/tests/components/esphome/conftest.py index ae899e0dc60883..dc6195bfe1fed3 100644 --- a/tests/components/esphome/conftest.py +++ b/tests/components/esphome/conftest.py @@ -433,10 +433,11 @@ def _subscribe_home_assistant_states( def _subscribe_logs( on_log_message: Callable[[SubscribeLogsResponse], None], log_level: LogLevel - ) -> None: + ) -> Callable[[], None]: """Subscribe to log messages.""" mock_device.set_on_log_message(on_log_message) mock_device.current_log_level = log_level + return lambda: None def _subscribe_voice_assistant( *, diff --git a/tests/components/esphome/test_manager.py b/tests/components/esphome/test_manager.py index 4df59dca3497b6..b805b065d5a7a7 100644 --- a/tests/components/esphome/test_manager.py +++ b/tests/components/esphome/test_manager.py @@ -120,6 +120,20 @@ async def test_esphome_device_subscribe_logs( blocking=True, ) assert device.current_log_level == LogLevel.LOG_LEVEL_WARN + await hass.services.async_call( + "logger", + "set_level", + {"homeassistant.components.esphome": "ERROR"}, + blocking=True, + ) + assert device.current_log_level == LogLevel.LOG_LEVEL_ERROR + await hass.services.async_call( + "logger", + "set_level", + {"homeassistant.components.esphome": "INFO"}, + blocking=True, + ) + assert device.current_log_level == LogLevel.LOG_LEVEL_CONFIG async def test_esphome_device_service_calls_not_allowed(