From bdb71c9159621fb17a7cc66a825585d486b5c23d Mon Sep 17 00:00:00 2001 From: Teemu R Date: Sun, 25 Oct 2020 01:53:36 +0200 Subject: [PATCH] Only log xiaomi_miio update exceptions once (#41226) * xiaomi_miio: only log update exceptions once Replaces #37695 * add som more missed exception logger cases + do not change the control flow as pointed out by @cgtobi * Use patch&MagickMock from tests.async_mock * Fix linting for alarm_control_panel * update the test to verify that the warning on update is only logged when the device was previously available --- .../components/xiaomi_miio/air_quality.py | 10 ++- .../xiaomi_miio/alarm_control_panel.py | 12 +-- homeassistant/components/xiaomi_miio/fan.py | 21 +++-- .../components/xiaomi_miio/gateway.py | 7 +- homeassistant/components/xiaomi_miio/light.py | 48 ++++++++---- .../components/xiaomi_miio/sensor.py | 5 +- .../components/xiaomi_miio/switch.py | 26 ++++--- .../components/xiaomi_miio/vacuum.py | 8 +- tests/components/xiaomi_miio/test_vacuum.py | 77 ++++++++++--------- 9 files changed, 127 insertions(+), 87 deletions(-) diff --git a/homeassistant/components/xiaomi_miio/air_quality.py b/homeassistant/components/xiaomi_miio/air_quality.py index baeb0bf39e5..1e1e1b58632 100644 --- a/homeassistant/components/xiaomi_miio/air_quality.py +++ b/homeassistant/components/xiaomi_miio/air_quality.py @@ -195,8 +195,9 @@ class AirMonitorS1(AirMonitorB1): self._humidity = state.humidity self._available = True except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) class AirMonitorV1(AirMonitorB1): @@ -210,8 +211,9 @@ class AirMonitorV1(AirMonitorB1): self._air_quality_index = state.aqi self._available = True except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) @property def unit_of_measurement(self): diff --git a/homeassistant/components/xiaomi_miio/alarm_control_panel.py b/homeassistant/components/xiaomi_miio/alarm_control_panel.py index 89fcb45b864..6880202cbd6 100644 --- a/homeassistant/components/xiaomi_miio/alarm_control_panel.py +++ b/homeassistant/components/xiaomi_miio/alarm_control_panel.py @@ -3,7 +3,7 @@ from functools import partial import logging -from miio.gateway import GatewayException +from miio import DeviceException from homeassistant.components.alarm_control_panel import ( SUPPORT_ALARM_ARM_AWAY, @@ -103,7 +103,7 @@ class XiaomiGatewayAlarm(AlarmControlPanelEntity): partial(func, *args, **kwargs) ) _LOGGER.debug("Response received from miio device: %s", result) - except GatewayException as exc: + except DeviceException as exc: _LOGGER.error(mask_error, exc) async def async_alarm_arm_away(self, code=None): @@ -122,9 +122,11 @@ class XiaomiGatewayAlarm(AlarmControlPanelEntity): """Fetch state from the device.""" try: state = await self.hass.async_add_executor_job(self._gateway.alarm.status) - except GatewayException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + except DeviceException as ex: + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) + return _LOGGER.debug("Got new state: %s", state) diff --git a/homeassistant/components/xiaomi_miio/fan.py b/homeassistant/components/xiaomi_miio/fan.py index b25f69f68c3..8d971446a53 100644 --- a/homeassistant/components/xiaomi_miio/fan.py +++ b/homeassistant/components/xiaomi_miio/fan.py @@ -655,8 +655,10 @@ class XiaomiGenericDevice(FanEntity): return result == SUCCESS except DeviceException as exc: - _LOGGER.error(mask_error, exc) - self._available = False + if self._available: + _LOGGER.error(mask_error, exc) + self._available = False + return False async def async_turn_on(self, speed: str = None, **kwargs) -> None: @@ -785,8 +787,9 @@ class XiaomiAirPurifier(XiaomiGenericDevice): ) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) @property def speed_list(self) -> list: @@ -1029,8 +1032,9 @@ class XiaomiAirHumidifier(XiaomiGenericDevice): ) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) @property def speed_list(self) -> list: @@ -1138,8 +1142,9 @@ class XiaomiAirFresh(XiaomiGenericDevice): ) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) @property def speed_list(self) -> list: diff --git a/homeassistant/components/xiaomi_miio/gateway.py b/homeassistant/components/xiaomi_miio/gateway.py index 8c928cb36e4..eb2f4cdf2eb 100644 --- a/homeassistant/components/xiaomi_miio/gateway.py +++ b/homeassistant/components/xiaomi_miio/gateway.py @@ -65,7 +65,7 @@ class XiaomiGatewayDevice(Entity): self._entry = entry self._unique_id = sub_device.sid self._name = f"{sub_device.name} ({sub_device.sid})" - self._available = None + self._available = False @property def unique_id(self): @@ -100,5 +100,6 @@ class XiaomiGatewayDevice(Entity): await self.hass.async_add_executor_job(self._sub_device.update) self._available = True except gateway.GatewayException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) diff --git a/homeassistant/components/xiaomi_miio/light.py b/homeassistant/components/xiaomi_miio/light.py index 34ebb550adf..d1746fcd889 100644 --- a/homeassistant/components/xiaomi_miio/light.py +++ b/homeassistant/components/xiaomi_miio/light.py @@ -324,8 +324,10 @@ class XiaomiPhilipsAbstractLight(LightEntity): return result == SUCCESS except DeviceException as exc: - _LOGGER.error(mask_error, exc) - self._available = False + if self._available: + _LOGGER.error(mask_error, exc) + self._available = False + return False async def async_turn_on(self, **kwargs): @@ -356,8 +358,10 @@ class XiaomiPhilipsAbstractLight(LightEntity): try: state = await self.hass.async_add_executor_job(self._light.status) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) + return _LOGGER.debug("Got new state: %s", state) @@ -380,8 +384,10 @@ class XiaomiPhilipsGenericLight(XiaomiPhilipsAbstractLight): try: state = await self.hass.async_add_executor_job(self._light.status) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) + return _LOGGER.debug("Got new state: %s", state) @@ -536,8 +542,10 @@ class XiaomiPhilipsBulb(XiaomiPhilipsGenericLight): try: state = await self.hass.async_add_executor_job(self._light.status) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) + return _LOGGER.debug("Got new state: %s", state) @@ -593,8 +601,10 @@ class XiaomiPhilipsCeilingLamp(XiaomiPhilipsBulb): try: state = await self.hass.async_add_executor_job(self._light.status) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) + return _LOGGER.debug("Got new state: %s", state) @@ -637,8 +647,10 @@ class XiaomiPhilipsEyecareLamp(XiaomiPhilipsGenericLight): try: state = await self.hass.async_add_executor_job(self._light.status) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) + return _LOGGER.debug("Got new state: %s", state) @@ -778,8 +790,10 @@ class XiaomiPhilipsEyecareLampAmbientLight(XiaomiPhilipsAbstractLight): try: state = await self.hass.async_add_executor_job(self._light.status) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) + return _LOGGER.debug("Got new state: %s", state) @@ -932,8 +946,10 @@ class XiaomiPhilipsMoonlightLamp(XiaomiPhilipsBulb): try: state = await self.hass.async_add_executor_job(self._light.status) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) + return _LOGGER.debug("Got new state: %s", state) diff --git a/homeassistant/components/xiaomi_miio/sensor.py b/homeassistant/components/xiaomi_miio/sensor.py index 55f6c26c567..d20c2dfac1e 100644 --- a/homeassistant/components/xiaomi_miio/sensor.py +++ b/homeassistant/components/xiaomi_miio/sensor.py @@ -233,8 +233,9 @@ class XiaomiAirQualityMonitor(Entity): ) except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) class XiaomiGatewaySensor(XiaomiGatewayDevice): diff --git a/homeassistant/components/xiaomi_miio/switch.py b/homeassistant/components/xiaomi_miio/switch.py index 781dd10a825..b9e90cc5c23 100644 --- a/homeassistant/components/xiaomi_miio/switch.py +++ b/homeassistant/components/xiaomi_miio/switch.py @@ -280,8 +280,10 @@ class XiaomiPlugGenericSwitch(SwitchEntity): return result == SUCCESS except DeviceException as exc: - _LOGGER.error(mask_error, exc) - self._available = False + if self._available: + _LOGGER.error(mask_error, exc) + self._available = False + return False async def async_turn_on(self, **kwargs): @@ -316,8 +318,9 @@ class XiaomiPlugGenericSwitch(SwitchEntity): self._state_attrs[ATTR_TEMPERATURE] = state.temperature except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) async def async_set_wifi_led_on(self): """Turn the wifi led on.""" @@ -402,8 +405,9 @@ class XiaomiPowerStripSwitch(XiaomiPlugGenericSwitch): self._state_attrs[ATTR_POWER_PRICE] = state.power_price except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) async def async_set_power_mode(self, mode: str): """Set the power mode.""" @@ -492,8 +496,9 @@ class ChuangMiPlugSwitch(XiaomiPlugGenericSwitch): self._state_attrs[ATTR_LOAD_POWER] = state.load_power except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) class XiaomiAirConditioningCompanionSwitch(XiaomiPlugGenericSwitch): @@ -541,5 +546,6 @@ class XiaomiAirConditioningCompanionSwitch(XiaomiPlugGenericSwitch): self._state_attrs[ATTR_LOAD_POWER] = state.load_power except DeviceException as ex: - self._available = False - _LOGGER.error("Got exception while fetching the state: %s", ex) + if self._available: + self._available = False + _LOGGER.error("Got exception while fetching the state: %s", ex) diff --git a/homeassistant/components/xiaomi_miio/vacuum.py b/homeassistant/components/xiaomi_miio/vacuum.py index 53fc458c50d..2a9ae1187b2 100644 --- a/homeassistant/components/xiaomi_miio/vacuum.py +++ b/homeassistant/components/xiaomi_miio/vacuum.py @@ -485,10 +485,10 @@ class MiroboVacuum(StateVacuumEntity): self.dnd_state = self._vacuum.dnd_status() self._available = True - except OSError as exc: - _LOGGER.error("Got OSError while fetching the state: %s", exc) - except DeviceException as exc: - _LOGGER.warning("Got exception while fetching the state: %s", exc) + except (OSError, DeviceException) as exc: + if self._available: + self._available = False + _LOGGER.warning("Got exception while fetching the state: %s", exc) # Fetch timers separately, see #38285 try: diff --git a/tests/components/xiaomi_miio/test_vacuum.py b/tests/components/xiaomi_miio/test_vacuum.py index 3b1234622ad..0fa241fb0b9 100644 --- a/tests/components/xiaomi_miio/test_vacuum.py +++ b/tests/components/xiaomi_miio/test_vacuum.py @@ -2,6 +2,7 @@ from datetime import datetime, time, timedelta from unittest import mock +from miio import DeviceException import pytest from pytz import utc @@ -52,9 +53,12 @@ from homeassistant.const import ( CONF_PLATFORM, STATE_OFF, STATE_ON, + STATE_UNAVAILABLE, ) from homeassistant.setup import async_setup_component +from tests.async_mock import MagicMock, patch + PLATFORM = "xiaomi_miio" # calls made when device status is requested @@ -70,7 +74,7 @@ STATUS_CALLS = [ @pytest.fixture(name="mock_mirobo_is_got_error") def mirobo_is_got_error_fixture(): """Mock mock_mirobo.""" - mock_vacuum = mock.MagicMock() + mock_vacuum = MagicMock() mock_vacuum.status().data = {"test": "raw"} mock_vacuum.status().is_on = False mock_vacuum.status().fanspeed = 38 @@ -98,21 +102,19 @@ def mirobo_is_got_error_fixture(): mock_vacuum.dnd_status().start = time(hour=22, minute=0) mock_vacuum.dnd_status().end = time(hour=6, minute=0) - mock_timer_1 = mock.MagicMock() + mock_timer_1 = MagicMock() mock_timer_1.enabled = True mock_timer_1.cron = "5 5 1 8 1" mock_timer_1.next_schedule = datetime(2020, 5, 23, 13, 21, 10, tzinfo=utc) - mock_timer_2 = mock.MagicMock() + mock_timer_2 = MagicMock() mock_timer_2.enabled = False mock_timer_2.cron = "5 5 1 8 2" mock_timer_2.next_schedule = datetime(2020, 5, 23, 13, 21, 10, tzinfo=utc) mock_vacuum.timer.return_value = [mock_timer_1, mock_timer_2] - with mock.patch( - "homeassistant.components.xiaomi_miio.vacuum.Vacuum" - ) as mock_vaccum_cls: + with patch("homeassistant.components.xiaomi_miio.vacuum.Vacuum") as mock_vaccum_cls: mock_vaccum_cls.return_value = mock_vacuum yield mock_vacuum @@ -135,14 +137,12 @@ new_fanspeeds = { @pytest.fixture(name="mock_mirobo_fanspeeds", params=[old_fanspeeds, new_fanspeeds]) def mirobo_old_speeds_fixture(request): """Fixture for testing both types of fanspeeds.""" - mock_vacuum = mock.MagicMock() + mock_vacuum = MagicMock() mock_vacuum.status().battery = 32 mock_vacuum.fan_speed_presets.return_value = request.param mock_vacuum.status().fanspeed = list(request.param.values())[0] - with mock.patch( - "homeassistant.components.xiaomi_miio.vacuum.Vacuum" - ) as mock_vaccum_cls: + with patch("homeassistant.components.xiaomi_miio.vacuum.Vacuum") as mock_vaccum_cls: mock_vaccum_cls.return_value = mock_vacuum yield mock_vacuum @@ -150,7 +150,7 @@ def mirobo_old_speeds_fixture(request): @pytest.fixture(name="mock_mirobo_is_on") def mirobo_is_on_fixture(): """Mock mock_mirobo.""" - mock_vacuum = mock.MagicMock() + mock_vacuum = MagicMock() mock_vacuum.status().data = {"test": "raw"} mock_vacuum.status().is_on = True mock_vacuum.status().fanspeed = 99 @@ -176,46 +176,53 @@ def mirobo_is_on_fixture(): mock_vacuum.status().state_code = 5 mock_vacuum.dnd_status().enabled = False - mock_timer_1 = mock.MagicMock() + mock_timer_1 = MagicMock() mock_timer_1.enabled = True mock_timer_1.cron = "5 5 1 8 1" mock_timer_1.next_schedule = datetime(2020, 5, 23, 13, 21, 10, tzinfo=utc) - mock_timer_2 = mock.MagicMock() + mock_timer_2 = MagicMock() mock_timer_2.enabled = False mock_timer_2.cron = "5 5 1 8 2" mock_timer_2.next_schedule = datetime(2020, 5, 23, 13, 21, 10, tzinfo=utc) mock_vacuum.timer.return_value = [mock_timer_1, mock_timer_2] - with mock.patch( - "homeassistant.components.xiaomi_miio.vacuum.Vacuum" - ) as mock_vaccum_cls: + with patch("homeassistant.components.xiaomi_miio.vacuum.Vacuum") as mock_vaccum_cls: mock_vaccum_cls.return_value = mock_vacuum yield mock_vacuum -@pytest.fixture(name="mock_mirobo_errors") -def mirobo_errors_fixture(): - """Mock mock_mirobo_errors to simulate a bad vacuum status request.""" - mock_vacuum = mock.MagicMock() - mock_vacuum.status.side_effect = OSError() - with mock.patch( - "homeassistant.components.xiaomi_miio.vacuum.Vacuum" - ) as mock_vaccum_cls: - mock_vaccum_cls.return_value = mock_vacuum - yield mock_vacuum - - -async def test_xiaomi_exceptions(hass, caplog, mock_mirobo_errors): - """Test vacuum supported features.""" +async def test_xiaomi_exceptions(hass, caplog, mock_mirobo_is_on): + """Test error logging on exceptions.""" entity_name = "test_vacuum_cleaner_error" - await setup_component(hass, entity_name) + entity_id = await setup_component(hass, entity_name) + def is_available(): + state = hass.states.get(entity_id) + return state.state != STATE_UNAVAILABLE + + # The initial setup has to be done successfully assert "Initializing with host 192.168.1.100 (token 12345...)" in caplog.text - assert mock_mirobo_errors.status.call_count == 1 - assert "ERROR" in caplog.text - assert "Got OSError while fetching the state" in caplog.text + assert "WARNING" not in caplog.text + assert is_available() + + # Second update causes an exception, which should be logged + mock_mirobo_is_on.status.side_effect = DeviceException("dummy exception") + await hass.helpers.entity_component.async_update_entity(entity_id) + assert "WARNING" in caplog.text + assert "Got exception while fetching the state" in caplog.text + assert not is_available() + + # Third update does not get logged as the device is already unavailable, + # so we clear the log and reset the status to test that + caplog.clear() + mock_mirobo_is_on.status.reset_mock() + + await hass.helpers.entity_component.async_update_entity(entity_id) + assert "Got exception while fetching the state" not in caplog.text + assert not is_available() + assert mock_mirobo_is_on.status.call_count == 1 async def test_xiaomi_vacuum_services(hass, caplog, mock_mirobo_is_got_error): @@ -463,7 +470,7 @@ async def test_xiaomi_vacuum_fanspeeds(hass, caplog, mock_mirobo_fanspeeds): {"entity_id": entity_id, "fan_speed": "invent"}, blocking=True, ) - assert "ERROR" in caplog.text + assert "Fan speed step not recognized" in caplog.text async def test_xiaomi_vacuum_goto_service(hass, caplog, mock_mirobo_is_on):