From d865901686dc6355d328f25df0da6bba0ef784fa Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Mon, 14 Feb 2022 13:00:11 -0600 Subject: [PATCH] Speed up turn on when the power state response takes more than 0.3s (#362) --- flux_led/aiodevice.py | 46 +++++++++++++++++++---------- flux_led/protocol.py | 42 ++++++++++++++++++++++++++ tests.py | 6 ++-- tests_aio.py | 68 ++++++++++++++++++++++++++++++++++++++----- 4 files changed, 135 insertions(+), 27 deletions(-) diff --git a/flux_led/aiodevice.py b/flux_led/aiodevice.py index 11b203fa..281f1366 100644 --- a/flux_led/aiodevice.py +++ b/flux_led/aiodevice.py @@ -54,8 +54,8 @@ DEVICE_CONFIG_WAIT_SECONDS = ( 3.5 # time it takes for the device to respond after a config change ) -POWER_STATE_TIMEOUT = 0.6 -POWER_CHANGE_ATTEMPTS = 3 +POWER_STATE_TIMEOUT = 1.2 +POWER_CHANGE_ATTEMPTS = 6 class AIOWifiLedBulb(LEDENETDevice): @@ -183,9 +183,9 @@ async def _async_send_state_query(self) -> None: await self._async_send_msg(self._protocol.construct_state_query()) async def _async_wait_state_change( - self, futures: List["asyncio.Future[Any]"], state: bool + self, futures: List["asyncio.Future[Any]"], state: bool, timeout: float ) -> bool: - done, _ = await asyncio.wait(futures, timeout=POWER_STATE_TIMEOUT) + done, _ = await asyncio.wait(futures, timeout=timeout) if done and self.is_on == state: return True return False @@ -203,7 +203,7 @@ async def _async_set_power_state( await self._async_send_msg(self._protocol.construct_state_change(state)) _LOGGER.debug("%s: Waiting for power state response", self.ipaddr) if await self._async_wait_state_change( - [state_future, power_state_future], state + [state_future, power_state_future], state, POWER_STATE_TIMEOUT * (3 / 8) ): return True if power_state_future.done() and accept_any_power_state_response: @@ -223,8 +223,15 @@ async def _async_set_power_state( if state_future.done(): state_future = asyncio.Future() self._state_futures.append(state_future) + pending: "List[asyncio.Future[Any]]" = [state_future] + if not power_state_future.done(): + # If the power state still hasn't responded + # we want to stop waiting as soon as it does + pending.append(power_state_future) await self._async_send_state_query() - if await self._async_wait_state_change([state_future], state): + if await self._async_wait_state_change( + pending, state, POWER_STATE_TIMEOUT * (5 / 8) + ): return True _LOGGER.debug( "%s: State query did not return expected power state of %s", @@ -248,7 +255,10 @@ async def _async_set_power_locked(self, state: bool) -> bool: async def _async_set_power_state_with_retry(self, state: bool) -> bool: for idx in range(POWER_CHANGE_ATTEMPTS): - if await self._async_set_power_state(state, False): + accept_any_power_state_response = idx > 2 + if await self._async_set_power_state( + state, accept_any_power_state_response + ): _LOGGER.debug( "%s: Completed power state change to %s (%s/%s)", self.ipaddr, @@ -256,6 +266,13 @@ async def _async_set_power_state_with_retry(self, state: bool) -> bool: 1 + idx, POWER_CHANGE_ATTEMPTS, ) + if accept_any_power_state_response and self.is_on != state: + # Sometimes these devices respond with "I turned off" and + # they actually turn on when we are requesting to turn on. + assert self._protocol is not None + byte = self._protocol.on_byte if state else self._protocol.off_byte + self._set_power_state(byte) + self._set_power_transition_complete_time() return True _LOGGER.debug( "%s: Failed to set power state to %s (%s/%s)", @@ -264,15 +281,12 @@ async def _async_set_power_state_with_retry(self, state: bool) -> bool: 1 + idx, POWER_CHANGE_ATTEMPTS, ) - if await self._async_set_power_state(state, True): - _LOGGER.debug("%s: Assuming power state change of %s", self.ipaddr, state) - # Sometimes these devices respond with "I turned off" and - # they actually even when we are requesting to turn on. - assert self._protocol is not None - byte = self._protocol.on_byte if state else self._protocol.off_byte - self._set_power_state(byte) - self._set_power_transition_complete_time() - return True + _LOGGER.error( + "%s: Failed to change power state to %s after %s attempts; Try rebooting the device", + self.ipaddr, + state, + POWER_CHANGE_ATTEMPTS, + ) return False async def async_set_white_temp( diff --git a/flux_led/protocol.py b/flux_led/protocol.py index f9246c4d..c472e297 100755 --- a/flux_led/protocol.py +++ b/flux_led/protocol.py @@ -1774,6 +1774,20 @@ def construct_request_strip_setting(self) -> bytearray: inner_pre_constructed=True, ) + def construct_state_query(self) -> bytearray: + """The bytes to send for a query request.""" + return self.construct_wrapped_message( + super().construct_state_query(), + inner_pre_constructed=True, + ) + + def construct_state_change(self, turn_on: int) -> bytearray: + """The bytes to send for a state change request.""" + return self.construct_wrapped_message( + super().construct_state_change(turn_on), + inner_pre_constructed=True, + ) + # ic response # 0x00 0x63 0x00 0x32 0x00 0x01 0x04 0x03 0x32 0x01 0xD0 (11) # b0 b1 b2 b3 00 01 01 37 00 0b 00 63 00 32 00 01 04 03 32 01 d0 aa @@ -2083,6 +2097,20 @@ class ProtocolLEDENETCCT(ProtocolLEDENET9Byte): MIN_BRIGHTNESS = 2 + def construct_state_query(self) -> bytearray: + """The bytes to send for a query request.""" + return self.construct_wrapped_message( + super().construct_state_query(), + inner_pre_constructed=True, + ) + + def construct_state_change(self, turn_on: int) -> bytearray: + """The bytes to send for a state change request.""" + return self.construct_wrapped_message( + super().construct_state_change(turn_on), + inner_pre_constructed=True, + ) + @property def timer_response_len(self) -> int: """Return the time response len.""" @@ -2160,6 +2188,20 @@ def construct_levels_change( class ProtocolLEDENETAddressableChristmas(ProtocolLEDENETAddressableBase): + def construct_state_query(self) -> bytearray: + """The bytes to send for a query request.""" + return self.construct_wrapped_message( + super().construct_state_query(), + inner_pre_constructed=True, + ) + + def construct_state_change(self, turn_on: int) -> bytearray: + """The bytes to send for a state change request.""" + return self.construct_wrapped_message( + super().construct_state_change(turn_on), + inner_pre_constructed=True, + ) + @property def name(self) -> str: """The name of the protocol.""" diff --git a/tests.py b/tests.py index 0ff12d5c..aa11a79f 100644 --- a/tests.py +++ b/tests.py @@ -2392,15 +2392,13 @@ def read_data(expected): 2, [(255, 255, 255), (0, 255, 0)], 100, MultiColorEffects.STATIC ) assert data == ( - b"\xb0\xb1\xb2\xb3\x00\x01\x01\x02\x00\x0fY\x00\x0f\xff\xff\xff" - b"\x00\xff\x00\x00\x1e\x01d\x00\xe7\xa7" + b"\xb0\xb1\xb2\xb3\x00\x01\x01\x03\x00\x0fY\x00\x0f\xff\xff\xff\x00\xff\x00\x00\x1e\x01d\x00\xe7\xa8" ) data = light._protocol.construct_zone_change( 4, [(255, 255, 255), (0, 255, 0)], 100, MultiColorEffects.STATIC ) assert data == ( - b"\xb0\xb1\xb2\xb3\x00\x01\x01\x03\x00\x15Y\x00\x15\xff\xff\xff" - b"\xff\xff\xff\x00\xff\x00\x00\xff\x00\x00\x1e\x01d\x00\xe9\xb2" + b"\xb0\xb1\xb2\xb3\x00\x01\x01\x04\x00\x15Y\x00\x15\xff\xff\xff\xff\xff\xff\x00\xff\x00\x00\xff\x00\x00\x1e\x01d\x00\xe9\xb3" ) @patch("flux_led.WifiLedBulb._send_msg") diff --git a/tests_aio.py b/tests_aio.py index f25c8d13..eefafad4 100644 --- a/tests_aio.py +++ b/tests_aio.py @@ -441,7 +441,7 @@ def _send_data(*args, **kwargs): light.is_on is True ) # transition time should now be in effect since we forced state - data = [*(b"\x81\x25\x23\x61\x05\x10\xb6\x00\x98\x19\x04\x25\x0f\xde",) * 10] + data = [*(b"\x81\x25\x23\x61\x05\x10\xb6\x00\x98\x19\x04\x25\x0f\xde",) * 14] await light.async_turn_off() await asyncio.sleep(0) # If all we get is on 0x81 responses, the bulb failed to turn off @@ -455,9 +455,12 @@ def _send_data(*args, **kwargs): with patch.object(aiodevice, "POWER_STATE_TIMEOUT", 0.010): await asyncio.create_task(light.async_turn_off()) assert light.is_on is True - assert "Failed to set power state to False (1/3)" in caplog.text - assert "Failed to set power state to False (2/3)" in caplog.text - assert "Failed to set power state to False (3/3)" in caplog.text + assert "Failed to set power state to False (1/6)" in caplog.text + assert "Failed to set power state to False (2/6)" in caplog.text + assert "Failed to set power state to False (3/6)" in caplog.text + assert "Failed to set power state to False (4/6)" in caplog.text + assert "Failed to set power state to False (5/6)" in caplog.text + assert "Failed to set power state to False (6/6)" in caplog.text with patch.object(light._aio_protocol, "write", _send_data), patch.object( aiodevice, "POWER_STATE_TIMEOUT", 0.010 @@ -502,9 +505,12 @@ def _send_data(*args, **kwargs): with patch.object(aiodevice, "POWER_STATE_TIMEOUT", 0.010): await asyncio.create_task(light.async_turn_on()) assert light.is_on is False - assert "Failed to set power state to True (1/3)" in caplog.text - assert "Failed to set power state to True (2/3)" in caplog.text - assert "Failed to set power state to True (3/3)" in caplog.text + assert "Failed to set power state to True (1/6)" in caplog.text + assert "Failed to set power state to True (2/6)" in caplog.text + assert "Failed to set power state to True (3/6)" in caplog.text + assert "Failed to set power state to True (4/6)" in caplog.text + assert "Failed to set power state to True (5/6)" in caplog.text + assert "Failed to set power state to True (6/6)" in caplog.text @pytest.mark.asyncio @@ -2194,6 +2200,54 @@ def _updated_callback(*args, **kwargs): await light.async_update() +@pytest.mark.asyncio +async def test_christmas_protocol_device_turn_on(mock_aio_protocol): + """Test a christmas protocol device.""" + light = AIOWifiLedBulb("192.168.1.166") + + def _updated_callback(*args, **kwargs): + pass + + task = asyncio.create_task(light.async_setup(_updated_callback)) + transport, protocol = await mock_aio_protocol() + light._aio_protocol.data_received( + b"\x81\x1a\x23\x61\x00\x00\x00\xff\x00\x00\x01\x00\x06\x25" + ) + await task + assert light.rgb == (0, 255, 0) + assert light.brightness == 255 + assert len(light.effect_list) == 101 + assert light.protocol == PROTOCOL_LEDENET_ADDRESSABLE_CHRISTMAS + assert light.dimmable_effects is False + assert light.requires_turn_on is False + assert light._protocol.power_push_updates is True + assert light._protocol.state_push_updates is False + + data = [] + written = [] + + def _send_data(*args, **kwargs): + written.append(args[0]) + light._aio_protocol.data_received(data.pop(0)) + + with patch.object(aiodevice, "POWER_STATE_TIMEOUT", 0.010), patch.object( + light._aio_protocol, "write", _send_data + ): + data = [ + b"\x81\x1a\x23\x61\x00\x00\x00\xff\x00\x00\x01\x00\x06\x25", + b"\x81\x25\x24\x61\x05\x10\xb6\x00\x98\x19\x04\x25\x0f\xdf", + ] + await light.async_turn_off() + await asyncio.sleep(0) + assert light.is_on is False + assert len(data) == 0 + + assert written == [ + b"\xb0\xb1\xb2\xb3\x00\x01\x01\x00\x00\x04q$\x0f\xa4\x14", + b"\xb0\xb1\xb2\xb3\x00\x01\x01\x01\x00\x04\x81\x8a\x8b\x96\xf9", + ] + + @pytest.mark.asyncio async def test_christmas_protocol_device(mock_aio_protocol): """Test a christmas protocol device."""