From 817c71747fbefa1cd5f90f4d64649530c62ff8b3 Mon Sep 17 00:00:00 2001 From: "David F. Mulcahey" Date: Wed, 27 Dec 2023 10:25:41 -0500 Subject: [PATCH] Delay all ZHA polling until initialization of entities has completed (#105814) * Don't update entities until they are initialized * fix hass reference * only establish polling once * fix log level and small cleanup * start device availability checks after full initialization of network * add logging * clean up sensor polling and class hierarchy * don't attempt restore sensor cleanup in this PR * put check back * fix race condition and remove parallel updates * add sensor polling test * cleanup switch polling and add a test * clean up and actually fix race condition * update light forced refresh * only use flag * unused flag * reduce diff size * collapse --- homeassistant/components/zha/core/device.py | 58 ++++++----- homeassistant/components/zha/core/gateway.py | 5 + homeassistant/components/zha/core/helpers.py | 1 + homeassistant/components/zha/light.py | 29 +++++- homeassistant/components/zha/sensor.py | 100 ++++++++++++++----- homeassistant/components/zha/switch.py | 27 +++-- tests/components/zha/test_sensor.py | 44 +++++++- tests/components/zha/test_switch.py | 11 ++ 8 files changed, 203 insertions(+), 72 deletions(-) diff --git a/homeassistant/components/zha/core/device.py b/homeassistant/components/zha/core/device.py index 0ce6f47b61ed..1a3d3a2da1f8 100644 --- a/homeassistant/components/zha/core/device.py +++ b/homeassistant/components/zha/core/device.py @@ -166,6 +166,9 @@ def __init__( if not self.is_coordinator: keep_alive_interval = random.randint(*_UPDATE_ALIVE_INTERVAL) + self.debug( + "starting availability checks - interval: %s", keep_alive_interval + ) self.unsubs.append( async_track_time_interval( self.hass, @@ -447,35 +450,36 @@ async def _check_available(self, *_: Any) -> None: self._checkins_missed_count = 0 return - if ( - self._checkins_missed_count >= _CHECKIN_GRACE_PERIODS - or self.manufacturer == "LUMI" - or not self._endpoints - ): + if self.hass.data[const.DATA_ZHA].allow_polling: + if ( + self._checkins_missed_count >= _CHECKIN_GRACE_PERIODS + or self.manufacturer == "LUMI" + or not self._endpoints + ): + self.debug( + ( + "last_seen is %s seconds ago and ping attempts have been exhausted," + " marking the device unavailable" + ), + difference, + ) + self.update_available(False) + return + + self._checkins_missed_count += 1 self.debug( - ( - "last_seen is %s seconds ago and ping attempts have been exhausted," - " marking the device unavailable" - ), - difference, + "Attempting to checkin with device - missed checkins: %s", + self._checkins_missed_count, ) - self.update_available(False) - return - - self._checkins_missed_count += 1 - self.debug( - "Attempting to checkin with device - missed checkins: %s", - self._checkins_missed_count, - ) - if not self.basic_ch: - self.debug("does not have a mandatory basic cluster") - self.update_available(False) - return - res = await self.basic_ch.get_attribute_value( - ATTR_MANUFACTURER, from_cache=False - ) - if res is not None: - self._checkins_missed_count = 0 + if not self.basic_ch: + self.debug("does not have a mandatory basic cluster") + self.update_available(False) + return + res = await self.basic_ch.get_attribute_value( + ATTR_MANUFACTURER, from_cache=False + ) + if res is not None: + self._checkins_missed_count = 0 def update_available(self, available: bool) -> None: """Update device availability and signal entities.""" diff --git a/homeassistant/components/zha/core/gateway.py b/homeassistant/components/zha/core/gateway.py index 6c461ac45c3f..1308abb3d371 100644 --- a/homeassistant/components/zha/core/gateway.py +++ b/homeassistant/components/zha/core/gateway.py @@ -47,6 +47,7 @@ ATTR_TYPE, CONF_RADIO_TYPE, CONF_ZIGPY, + DATA_ZHA, DEBUG_COMP_BELLOWS, DEBUG_COMP_ZHA, DEBUG_COMP_ZIGPY, @@ -292,6 +293,10 @@ async def fetch_updated_state() -> None: if dev.is_mains_powered ) ) + _LOGGER.debug( + "completed fetching current state for mains powered devices - allowing polled requests" + ) + self.hass.data[DATA_ZHA].allow_polling = True # background the fetching of state for mains powered devices self.config_entry.async_create_background_task( diff --git a/homeassistant/components/zha/core/helpers.py b/homeassistant/components/zha/core/helpers.py index 0246c1e4b1c5..bb87cb2cf58f 100644 --- a/homeassistant/components/zha/core/helpers.py +++ b/homeassistant/components/zha/core/helpers.py @@ -442,6 +442,7 @@ class ZHAData: device_trigger_cache: dict[str, tuple[str, dict]] = dataclasses.field( default_factory=dict ) + allow_polling: bool = dataclasses.field(default=False) def get_zha_data(hass: HomeAssistant) -> ZHAData: diff --git a/homeassistant/components/zha/light.py b/homeassistant/components/zha/light.py index d545a331a6d0..486b043b4505 100644 --- a/homeassistant/components/zha/light.py +++ b/homeassistant/components/zha/light.py @@ -47,6 +47,7 @@ CONF_ENABLE_ENHANCED_LIGHT_TRANSITION, CONF_ENABLE_LIGHT_TRANSITIONING_FLAG, CONF_GROUP_MEMBERS_ASSUME_STATE, + DATA_ZHA, SIGNAL_ADD_ENTITIES, SIGNAL_ATTR_UPDATED, SIGNAL_SET_LEVEL, @@ -75,7 +76,6 @@ STRICT_MATCH = functools.partial(ZHA_ENTITIES.strict_match, Platform.LIGHT) GROUP_MATCH = functools.partial(ZHA_ENTITIES.group_match, Platform.LIGHT) -PARALLEL_UPDATES = 0 SIGNAL_LIGHT_GROUP_STATE_CHANGED = "zha_light_group_state_changed" SIGNAL_LIGHT_GROUP_TRANSITION_START = "zha_light_group_transition_start" SIGNAL_LIGHT_GROUP_TRANSITION_FINISHED = "zha_light_group_transition_finished" @@ -788,6 +788,7 @@ async def async_added_to_hass(self) -> None: self._cancel_refresh_handle = async_track_time_interval( self.hass, self._refresh, timedelta(seconds=refresh_interval) ) + self.debug("started polling with refresh interval of %s", refresh_interval) self.async_accept_signal( None, SIGNAL_LIGHT_GROUP_STATE_CHANGED, @@ -838,6 +839,8 @@ async def async_will_remove_from_hass(self) -> None: """Disconnect entity object when removed.""" assert self._cancel_refresh_handle self._cancel_refresh_handle() + self._cancel_refresh_handle = None + self.debug("stopped polling during device removal") await super().async_will_remove_from_hass() @callback @@ -980,8 +983,16 @@ async def _refresh(self, time): if self.is_transitioning: self.debug("skipping _refresh while transitioning") return - await self.async_get_state() - self.async_write_ha_state() + if self._zha_device.available and self.hass.data[DATA_ZHA].allow_polling: + self.debug("polling for updated state") + await self.async_get_state() + self.async_write_ha_state() + else: + self.debug( + "skipping polling for updated state, available: %s, allow polled requests: %s", + self._zha_device.available, + self.hass.data[DATA_ZHA].allow_polling, + ) async def _maybe_force_refresh(self, signal): """Force update the state if the signal contains the entity id for this entity.""" @@ -989,8 +1000,16 @@ async def _maybe_force_refresh(self, signal): if self.is_transitioning: self.debug("skipping _maybe_force_refresh while transitioning") return - await self.async_get_state() - self.async_write_ha_state() + if self._zha_device.available and self.hass.data[DATA_ZHA].allow_polling: + self.debug("forcing polling for updated state") + await self.async_get_state() + self.async_write_ha_state() + else: + self.debug( + "skipping _maybe_force_refresh, available: %s, allow polled requests: %s", + self._zha_device.available, + self.hass.data[DATA_ZHA].allow_polling, + ) @callback def _assume_group_state(self, signal, update_params) -> None: diff --git a/homeassistant/components/zha/sensor.py b/homeassistant/components/zha/sensor.py index 4ec4c11ef530..027e710e30c7 100644 --- a/homeassistant/components/zha/sensor.py +++ b/homeassistant/components/zha/sensor.py @@ -1,9 +1,11 @@ """Sensors on Zigbee Home Automation networks.""" from __future__ import annotations +from datetime import timedelta import enum import functools import numbers +import random from typing import TYPE_CHECKING, Any, Self from zigpy import types @@ -37,9 +39,10 @@ UnitOfVolume, UnitOfVolumeFlowRate, ) -from homeassistant.core import HomeAssistant, callback +from homeassistant.core import CALLBACK_TYPE, HomeAssistant, callback from homeassistant.helpers.dispatcher import async_dispatcher_connect from homeassistant.helpers.entity_platform import AddEntitiesCallback +from homeassistant.helpers.event import async_track_time_interval from homeassistant.helpers.typing import StateType from .core import discovery @@ -57,6 +60,7 @@ CLUSTER_HANDLER_SOIL_MOISTURE, CLUSTER_HANDLER_TEMPERATURE, CLUSTER_HANDLER_THERMOSTAT, + DATA_ZHA, SIGNAL_ADD_ENTITIES, SIGNAL_ATTR_UPDATED, ) @@ -68,8 +72,6 @@ from .core.cluster_handlers import ClusterHandler from .core.device import ZHADevice -PARALLEL_UPDATES = 5 - BATTERY_SIZES = { 0: "No battery", 1: "Built in", @@ -185,6 +187,55 @@ def formatter(self, value: int | enum.IntEnum) -> int | float | str | None: return round(float(value * self._multiplier) / self._divisor) +# pylint: disable-next=hass-invalid-inheritance # needs fixing +class PollableSensor(Sensor): + """Base ZHA sensor that polls for state.""" + + _use_custom_polling: bool = True + + def __init__( + self, + unique_id: str, + zha_device: ZHADevice, + cluster_handlers: list[ClusterHandler], + **kwargs: Any, + ) -> None: + """Init this sensor.""" + super().__init__(unique_id, zha_device, cluster_handlers, **kwargs) + self._cancel_refresh_handle: CALLBACK_TYPE | None = None + + async def async_added_to_hass(self) -> None: + """Run when about to be added to hass.""" + await super().async_added_to_hass() + if self._use_custom_polling: + refresh_interval = random.randint(30, 60) + self._cancel_refresh_handle = async_track_time_interval( + self.hass, self._refresh, timedelta(seconds=refresh_interval) + ) + self.debug("started polling with refresh interval of %s", refresh_interval) + + async def async_will_remove_from_hass(self) -> None: + """Disconnect entity object when removed.""" + assert self._cancel_refresh_handle + self._cancel_refresh_handle() + self._cancel_refresh_handle = None + self.debug("stopped polling during device removal") + await super().async_will_remove_from_hass() + + async def _refresh(self, time): + """Call async_update at a constrained random interval.""" + if self._zha_device.available and self.hass.data[DATA_ZHA].allow_polling: + self.debug("polling for updated state") + await self.async_update() + self.async_write_ha_state() + else: + self.debug( + "skipping polling for updated state, available: %s, allow polled requests: %s", + self._zha_device.available, + self.hass.data[DATA_ZHA].allow_polling, + ) + + @MULTI_MATCH( cluster_handler_names=CLUSTER_HANDLER_ANALOG_INPUT, manufacturers="Digi", @@ -258,9 +309,10 @@ def extra_state_attributes(self) -> dict[str, Any]: models={"VZM31-SN", "SP 234", "outletv4"}, ) # pylint: disable-next=hass-invalid-inheritance # needs fixing -class ElectricalMeasurement(Sensor): +class ElectricalMeasurement(PollableSensor): """Active power measurement.""" + _use_custom_polling: bool = False _attribute_name = "active_power" _attr_device_class: SensorDeviceClass = SensorDeviceClass.POWER _attr_state_class: SensorStateClass = SensorStateClass.MEASUREMENT @@ -306,22 +358,17 @@ def formatter(self, value: int) -> int | float: class PolledElectricalMeasurement(ElectricalMeasurement): """Polled active power measurement.""" - _attr_should_poll = True # BaseZhaEntity defaults to False - - async def async_update(self) -> None: - """Retrieve latest state.""" - if not self.available: - return - await super().async_update() + _use_custom_polling: bool = True @MULTI_MATCH(cluster_handler_names=CLUSTER_HANDLER_ELECTRICAL_MEASUREMENT) # pylint: disable-next=hass-invalid-inheritance # needs fixing -class ElectricalMeasurementApparentPower(ElectricalMeasurement): +class ElectricalMeasurementApparentPower(PolledElectricalMeasurement): """Apparent power measurement.""" _attribute_name = "apparent_power" _unique_id_suffix = "apparent_power" + _use_custom_polling = False # Poll indirectly by ElectricalMeasurementSensor _attr_device_class: SensorDeviceClass = SensorDeviceClass.APPARENT_POWER _attr_native_unit_of_measurement = UnitOfApparentPower.VOLT_AMPERE _div_mul_prefix = "ac_power" @@ -329,11 +376,12 @@ class ElectricalMeasurementApparentPower(ElectricalMeasurement): @MULTI_MATCH(cluster_handler_names=CLUSTER_HANDLER_ELECTRICAL_MEASUREMENT) # pylint: disable-next=hass-invalid-inheritance # needs fixing -class ElectricalMeasurementRMSCurrent(ElectricalMeasurement): +class ElectricalMeasurementRMSCurrent(PolledElectricalMeasurement): """RMS current measurement.""" _attribute_name = "rms_current" _unique_id_suffix = "rms_current" + _use_custom_polling = False # Poll indirectly by ElectricalMeasurementSensor _attr_device_class: SensorDeviceClass = SensorDeviceClass.CURRENT _attr_native_unit_of_measurement = UnitOfElectricCurrent.AMPERE _div_mul_prefix = "ac_current" @@ -341,11 +389,12 @@ class ElectricalMeasurementRMSCurrent(ElectricalMeasurement): @MULTI_MATCH(cluster_handler_names=CLUSTER_HANDLER_ELECTRICAL_MEASUREMENT) # pylint: disable-next=hass-invalid-inheritance # needs fixing -class ElectricalMeasurementRMSVoltage(ElectricalMeasurement): +class ElectricalMeasurementRMSVoltage(PolledElectricalMeasurement): """RMS Voltage measurement.""" _attribute_name = "rms_voltage" _unique_id_suffix = "rms_voltage" + _use_custom_polling = False # Poll indirectly by ElectricalMeasurementSensor _attr_device_class: SensorDeviceClass = SensorDeviceClass.VOLTAGE _attr_native_unit_of_measurement = UnitOfElectricPotential.VOLT _div_mul_prefix = "ac_voltage" @@ -353,11 +402,12 @@ class ElectricalMeasurementRMSVoltage(ElectricalMeasurement): @MULTI_MATCH(cluster_handler_names=CLUSTER_HANDLER_ELECTRICAL_MEASUREMENT) # pylint: disable-next=hass-invalid-inheritance # needs fixing -class ElectricalMeasurementFrequency(ElectricalMeasurement): +class ElectricalMeasurementFrequency(PolledElectricalMeasurement): """Frequency measurement.""" _attribute_name = "ac_frequency" _unique_id_suffix = "ac_frequency" + _use_custom_polling = False # Poll indirectly by ElectricalMeasurementSensor _attr_device_class: SensorDeviceClass = SensorDeviceClass.FREQUENCY _attr_translation_key: str = "ac_frequency" _attr_native_unit_of_measurement = UnitOfFrequency.HERTZ @@ -366,11 +416,12 @@ class ElectricalMeasurementFrequency(ElectricalMeasurement): @MULTI_MATCH(cluster_handler_names=CLUSTER_HANDLER_ELECTRICAL_MEASUREMENT) # pylint: disable-next=hass-invalid-inheritance # needs fixing -class ElectricalMeasurementPowerFactor(ElectricalMeasurement): +class ElectricalMeasurementPowerFactor(PolledElectricalMeasurement): """Frequency measurement.""" _attribute_name = "power_factor" _unique_id_suffix = "power_factor" + _use_custom_polling = False # Poll indirectly by ElectricalMeasurementSensor _attr_device_class: SensorDeviceClass = SensorDeviceClass.POWER_FACTOR _attr_native_unit_of_measurement = PERCENTAGE @@ -440,9 +491,10 @@ def formatter(self, value: int) -> int: stop_on_match_group=CLUSTER_HANDLER_SMARTENERGY_METERING, ) # pylint: disable-next=hass-invalid-inheritance # needs fixing -class SmartEnergyMetering(Sensor): +class SmartEnergyMetering(PollableSensor): """Metering sensor.""" + _use_custom_polling: bool = False _attribute_name = "instantaneous_demand" _attr_device_class: SensorDeviceClass = SensorDeviceClass.POWER _attr_state_class: SensorStateClass = SensorStateClass.MEASUREMENT @@ -540,13 +592,7 @@ def formatter(self, value: int) -> int | float: class PolledSmartEnergySummation(SmartEnergySummation): """Polled Smart Energy Metering summation sensor.""" - _attr_should_poll = True # BaseZhaEntity defaults to False - - async def async_update(self) -> None: - """Retrieve latest state.""" - if not self.available: - return - await self._cluster_handler.async_force_update() + _use_custom_polling: bool = True @MULTI_MATCH( @@ -557,6 +603,7 @@ async def async_update(self) -> None: class Tier1SmartEnergySummation(PolledSmartEnergySummation): """Tier 1 Smart Energy Metering summation sensor.""" + _use_custom_polling = False # Poll indirectly by PolledSmartEnergySummation _attribute_name = "current_tier1_summ_delivered" _unique_id_suffix = "tier1_summation_delivered" _attr_translation_key: str = "tier1_summation_delivered" @@ -570,6 +617,7 @@ class Tier1SmartEnergySummation(PolledSmartEnergySummation): class Tier2SmartEnergySummation(PolledSmartEnergySummation): """Tier 2 Smart Energy Metering summation sensor.""" + _use_custom_polling = False # Poll indirectly by PolledSmartEnergySummation _attribute_name = "current_tier2_summ_delivered" _unique_id_suffix = "tier2_summation_delivered" _attr_translation_key: str = "tier2_summation_delivered" @@ -583,6 +631,7 @@ class Tier2SmartEnergySummation(PolledSmartEnergySummation): class Tier3SmartEnergySummation(PolledSmartEnergySummation): """Tier 3 Smart Energy Metering summation sensor.""" + _use_custom_polling = False # Poll indirectly by PolledSmartEnergySummation _attribute_name = "current_tier3_summ_delivered" _unique_id_suffix = "tier3_summation_delivered" _attr_translation_key: str = "tier3_summation_delivered" @@ -596,6 +645,7 @@ class Tier3SmartEnergySummation(PolledSmartEnergySummation): class Tier4SmartEnergySummation(PolledSmartEnergySummation): """Tier 4 Smart Energy Metering summation sensor.""" + _use_custom_polling = False # Poll indirectly by PolledSmartEnergySummation _attribute_name = "current_tier4_summ_delivered" _unique_id_suffix = "tier4_summation_delivered" _attr_translation_key: str = "tier4_summation_delivered" @@ -609,6 +659,7 @@ class Tier4SmartEnergySummation(PolledSmartEnergySummation): class Tier5SmartEnergySummation(PolledSmartEnergySummation): """Tier 5 Smart Energy Metering summation sensor.""" + _use_custom_polling = False # Poll indirectly by PolledSmartEnergySummation _attribute_name = "current_tier5_summ_delivered" _unique_id_suffix = "tier5_summation_delivered" _attr_translation_key: str = "tier5_summation_delivered" @@ -622,6 +673,7 @@ class Tier5SmartEnergySummation(PolledSmartEnergySummation): class Tier6SmartEnergySummation(PolledSmartEnergySummation): """Tier 6 Smart Energy Metering summation sensor.""" + _use_custom_polling = False # Poll indirectly by PolledSmartEnergySummation _attribute_name = "current_tier6_summ_delivered" _unique_id_suffix = "tier6_summation_delivered" _attr_translation_key: str = "tier6_summation_delivered" diff --git a/homeassistant/components/zha/switch.py b/homeassistant/components/zha/switch.py index 71c6e9d90ad0..d4e835751f5b 100644 --- a/homeassistant/components/zha/switch.py +++ b/homeassistant/components/zha/switch.py @@ -108,11 +108,10 @@ async def async_added_to_hass(self) -> None: async def async_update(self) -> None: """Attempt to retrieve on off state from the switch.""" - await super().async_update() - if self._on_off_cluster_handler: - await self._on_off_cluster_handler.get_attribute_value( - "on_off", from_cache=False - ) + self.debug("Polling current state") + await self._on_off_cluster_handler.get_attribute_value( + "on_off", from_cache=False + ) @GROUP_MATCH() @@ -255,16 +254,14 @@ async def async_turn_off(self, **kwargs: Any) -> None: async def async_update(self) -> None: """Attempt to retrieve the state of the entity.""" - await super().async_update() - self.error("Polling current state") - if self._cluster_handler: - value = await self._cluster_handler.get_attribute_value( - self._attribute_name, from_cache=False - ) - await self._cluster_handler.get_attribute_value( - self._inverter_attribute_name, from_cache=False - ) - self.debug("read value=%s, inverted=%s", value, self.inverted) + self.debug("Polling current state") + value = await self._cluster_handler.get_attribute_value( + self._attribute_name, from_cache=False + ) + await self._cluster_handler.get_attribute_value( + self._inverter_attribute_name, from_cache=False + ) + self.debug("read value=%s, inverted=%s", value, self.inverted) @CONFIG_DIAGNOSTIC_MATCH( diff --git a/tests/components/zha/test_sensor.py b/tests/components/zha/test_sensor.py index 59b8bb1293ef..d9a61b12357d 100644 --- a/tests/components/zha/test_sensor.py +++ b/tests/components/zha/test_sensor.py @@ -1,4 +1,5 @@ """Test ZHA sensor.""" +from datetime import timedelta import math from unittest.mock import MagicMock, patch @@ -47,7 +48,10 @@ ) from .conftest import SIG_EP_INPUT, SIG_EP_OUTPUT, SIG_EP_PROFILE, SIG_EP_TYPE -from tests.common import async_mock_load_restore_state_from_storage +from tests.common import ( + async_fire_time_changed, + async_mock_load_restore_state_from_storage, +) ENTITY_ID_PREFIX = "sensor.fakemanufacturer_fakemodel_{}" @@ -921,6 +925,44 @@ async def test_elec_measurement_sensor_type( assert state.attributes["measurement_type"] == expected_type +async def test_elec_measurement_sensor_polling( + hass: HomeAssistant, + elec_measurement_zigpy_dev, + zha_device_joined_restored, +) -> None: + """Test ZHA electrical measurement sensor polling.""" + + entity_id = ENTITY_ID_PREFIX.format("power") + zigpy_dev = elec_measurement_zigpy_dev + zigpy_dev.endpoints[1].electrical_measurement.PLUGGED_ATTR_READS[ + "active_power" + ] = 20 + + await zha_device_joined_restored(zigpy_dev) + + # test that the sensor has an initial state of 2.0 + state = hass.states.get(entity_id) + assert state.state == "2.0" + + # update the value for the power reading + zigpy_dev.endpoints[1].electrical_measurement.PLUGGED_ATTR_READS[ + "active_power" + ] = 60 + + # ensure the state is still 2.0 + state = hass.states.get(entity_id) + assert state.state == "2.0" + + # let the polling happen + future = dt_util.utcnow() + timedelta(seconds=90) + async_fire_time_changed(hass, future) + await hass.async_block_till_done() + + # ensure the state has been updated to 6.0 + state = hass.states.get(entity_id) + assert state.state == "6.0" + + @pytest.mark.parametrize( "supported_attributes", ( diff --git a/tests/components/zha/test_switch.py b/tests/components/zha/test_switch.py index b07b34763d10..0db9b7dd18e0 100644 --- a/tests/components/zha/test_switch.py +++ b/tests/components/zha/test_switch.py @@ -197,6 +197,17 @@ async def test_switch( tsn=None, ) + await async_setup_component(hass, "homeassistant", {}) + + cluster.read_attributes.reset_mock() + await hass.services.async_call( + "homeassistant", "update_entity", {"entity_id": entity_id}, blocking=True + ) + assert len(cluster.read_attributes.mock_calls) == 1 + assert cluster.read_attributes.call_args == call( + ["on_off"], allow_cache=False, only_cache=False, manufacturer=None + ) + # test joining a new switch to the network and HA await async_test_rejoin(hass, zigpy_device, [cluster], (1,))