search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
72.53k stars 30.35k forks source link

FluxLED / MagicHome turns on LED strip twice 0x06 device firmware v1 #63144

Closed chiragd closed 2 years ago

chiragd commented 2 years ago

The problem

Since 2021.12 home assistant turns on my LED strip attached to magichome with a 'blink'. By blink I mean that the light turns on for a moment, immediately turns off and on again, then stays on.

In 2021.10 the light would turn on fine. I would always see an error in the UI, but the light never 'blinked'.

I'm using a magichome controller with an RGBW LED strip.

I do not see anything useful in the logs.

What version of Home Assistant Core has the issue?

core-2021.12.7

What was the last working version of Home Assistant Core?

core-2021.10

What type of installation are you running?

Home Assistant Core

Integration causing the issue

FLUX_LED

Link to integration documentation on our website

https://www.home-assistant.io/integrations/flux_led/

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

probot-home-assistant[bot] commented 2 years ago

flux_led documentation flux_led source (message by IssueLinks)

probot-home-assistant[bot] commented 2 years ago

Hey there @icemanch, mind taking a look at this issue as it has been labeled with an integration (flux_led) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)

bdraco commented 2 years ago

Please turn on debug logging in configuration.yaml, then restart and re-create the condition

logger:
  default: info
  logs:
    homeassistant.components.flux_led: debug
    flux_led: debug

I'm assuming its a 0x33 device which has a firmware bug that incorrectly reports power on state.

bdraco commented 2 years ago

Also please post a screenshot of the device with the complete firmware version

chiragd commented 2 years ago

Where do you want a screenshot from? Magichome? Home assistant? Elsewhere? I'm not sure which screen shows the device firmware.

chiragd commented 2 years ago

MagicHome says:

Firmware version 06.v1.11.7376-A

bdraco commented 2 years ago

From Home Assistant. It should be a url like `/config/devices/device/4b6e9b7fc8768f4df9bd3eae11109522

Example:

Screen Shot 2021-12-31 at 11 53 52
chiragd commented 2 years ago

image

bdraco commented 2 years ago

So its one of the original RGBW controllers with the buggy on state reporting https://github.com/Danielhiversen/flux_led/blob/master/flux_led/models_db.py#L587

Unfortunately there isn't much we can do to fix it since its a problem with the device itself.

The device sometimes reports its off when its really on, and the only way to get it back in sync is to cycle it off, and then on which is why you see if turn on twice. If we don't do this, on the next command it will fail to turn on.

Sometimes these devices do respond to the second turn on and go back in sync so I'll make a tweak to the workaround here https://github.com/home-assistant/core/pull/63154, but ultimately we can't fix the underlying issue since its in the device itself.

If it really bothers you the best option is to get one of the newer 0x06 devices with firmware 3 or later.

You can be sure you are getting one of the newer ones if it has the 2.4ghz remote

Screen Shot 2021-12-31 at 12 02 25
chiragd commented 2 years ago

Understood - thank you. I think I'll swap this unit out for an ESP32 running WLED. I don't use the remote, so I won't miss it :)

bdraco commented 2 years ago

If you are going to junk it, I'd love to add it to my box of testing equipment as none of the devs on the integration have a v1 to test against and they aren't made anymore so we can't find them. I'm also happy to send you out a v3 as I have a lot of them sitting around.

Cheers nick@koston.org

chiragd commented 2 years ago

Here are the logs:

`2022-01-01 19:06:13 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x81 0x8A 0x8B 0x96 (4)

2022-01-01 19:06:13 DEBUG (MainThread) [homeassistant.components.flux_led] Finished fetching 192.168.0.48 data in 0.005 seconds (success: True)

2022-01-01 19:06:13 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0x81 0x06 0x23 0x61 0x26 0x04 0x00 0x00 0x00 0xFF 0x01 0x00 0x0F 0x44 (14)

2022-01-01 19:06:13 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: State: LEDENETRawState(head=129, model_num=6, power_state=35, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=68)

2022-01-01 19:06:13 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Mapped State: LEDENETRawState(head=129, model_num=6, power_state=35, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=68)

2022-01-01 19:06:23 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x81 0x8A 0x8B 0x96 (4)

2022-01-01 19:06:23 DEBUG (MainThread) [homeassistant.components.flux_led] Finished fetching 192.168.0.48 data in 0.004 seconds (success: True)

2022-01-01 19:06:23 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0x81 0x06 0x23 0x61 0x26 0x04 0x00 0x00 0x00 0xFF 0x01 0x00 0x0F 0x44 (14)

2022-01-01 19:06:23 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: State: LEDENETRawState(head=129, model_num=6, power_state=35, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=68)

2022-01-01 19:06:23 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Mapped State: LEDENETRawState(head=129, model_num=6, power_state=35, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=68)

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x71 0x24 0x0F 0xA4 (4)

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: Waiting for power state response

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0xF0 0x71 0x23 0x84 (4)

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Setting power state to: 0x23

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: _replace_raw_state: {'power_state': 35}

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Transition time is 1.29, set _transition_complete_time to 1540989.9475885811

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: Did not get expected power state response, sending state query

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x81 0x8A 0x8B 0x96 (4)

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0x81 0x06 0x24 0x61 0x26 0x04 0x00 0x00 0x00 0xFF 0x01 0x00 0x0F 0x45 (14)

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: State: LEDENETRawState(head=129, model_num=6, power_state=36, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=69)

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: unmapped raw state: 129,6,36,97,38,4,0,0,0,255,1,0,15,69,

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: _replace_raw_state: {'head': 129, 'model_num': 6, 'power_state': 36, 'preset_pattern': 97, 'mode': 38, 'speed': 4, 'version_number': 1, 'color_mode': 15, 'check_sum': 69}

2022-01-01 19:06:25 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Mapped State: LEDENETRawState(head=129, model_num=6, power_state=36, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=69)

2022-01-01 19:06:25 DEBUG (MainThread) [homeassistant.components.flux_led] 192.168.0.48: Device state updated: LEDENETRawState(head=129, model_num=6, power_state=36, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=69)

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x81 0x8A 0x8B 0x96 (4)

2022-01-01 19:06:27 DEBUG (MainThread) [homeassistant.components.flux_led] Finished fetching 192.168.0.48 data in 0.005 seconds (success: True)

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0x81 0x06 0x24 0x61 0x26 0x04 0x00 0x00 0x00 0xFF 0x01 0x00 0x0F 0x45 (14)

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: State: LEDENETRawState(head=129, model_num=6, power_state=36, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=69)

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Mapped State: LEDENETRawState(head=129, model_num=6, power_state=36, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=69)

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x71 0x23 0x0F 0xA3 (4)

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: Waiting for power state response

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0xF0 0x71 0x24 0x85 (4)

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Setting power state to: 0x24

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: _replace_raw_state: {'power_state': 36}

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Transition time is 1.29, set _transition_complete_time to 1540992.396592824

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: Did not get expected power state response, sending state query

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x81 0x8A 0x8B 0x96 (4)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0x81 0x06 0x24 0x61 0x26 0x04 0x00 0x00 0x00 0xFF 0x01 0x00 0x0F 0x45 (14)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: State: LEDENETRawState(head=129, model_num=6, power_state=36, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=69)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: _replace_raw_state: {'head': 129, 'model_num': 6, 'power_state': 36, 'preset_pattern': 97, 'mode': 38, 'speed': 4, 'version_number': 1, 'color_mode': 15, 'check_sum': 69}

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Mapped State: LEDENETRawState(head=129, model_num=6, power_state=36, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=69)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: State query did not return expected power state

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: Failed to turn on (1/4)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x71 0x24 0x0F 0xA4 (4)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x71 0x23 0x0F 0xA3 (4)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: Waiting for power state response

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0xF0 0x71 0x23 0x84 (4)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Setting power state to: 0x23

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: _replace_raw_state: {'power_state': 35}

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Transition time is 1.29, set _transition_complete_time to 1540993.616758197

2022-01-01 19:06:28 DEBUG (MainThread) [homeassistant.components.flux_led] 192.168.0.48: Device state updated: LEDENETRawState(head=129, model_num=6, power_state=35, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=69)

2022-01-01 19:06:30 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x81 0x8A 0x8B 0x96 (4)

2022-01-01 19:06:30 DEBUG (MainThread) [homeassistant.components.flux_led] Finished fetching 192.168.0.48 data in 0.004 seconds (success: True)

2022-01-01 19:06:30 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0x81 0x06 0x23 0x61 0x26 0x04 0x00 0x00 0x00 0xFF 0x01 0x00 0x0F 0x44 (14)

2022-01-01 19:06:30 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: State: LEDENETRawState(head=129, model_num=6, power_state=35, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=68)

2022-01-01 19:06:30 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: unmapped raw state: 129,6,35,97,38,4,0,0,0,255,1,0,15,68,

2022-01-01 19:06:30 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Mapped State: LEDENETRawState(head=129, model_num=6, power_state=35, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=68)

2022-01-01 19:06:30 DEBUG (MainThread) [homeassistant.components.flux_led] 192.168.0.48: Device state updated: LEDENETRawState(head=129, model_num=6, power_state=35, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=68)`

bdraco commented 2 years ago

This is the turn on request (byte 0x23)

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x71 0x23 0x0F 0xA3 (4)

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: Waiting for power state response

The device tells us it successfully turned off (byte 0x24) 🤦 2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0xF0 0x71 0x24 0x85 (4)

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Setting power state to: 0x24

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: _replace_raw_state: {'power_state': 36}

2022-01-01 19:06:27 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Transition time is 1.29, set _transition_complete_time to 1540992.396592824

We realize it send us back powered off instead of powered on 2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: Did not get expected power state response, sending state query

We send a query to check the state

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x81 0x8A 0x8B 0x96 (4)

The device tells us its off

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0x81 0x06 0x24 0x61 0x26 0x04 0x00 0x00 0x00 0xFF 0x01 0x00 0x0F 0x45 (14)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: State: LEDENETRawState(head=129, model_num=6, power_state=36, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=69)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: _replace_raw_state: {'head': 129, 'model_num': 6, 'power_state': 36, 'preset_pattern': 97, 'mode': 38, 'speed': 4, 'version_number': 1, 'color_mode': 15, 'check_sum': 69}

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Mapped State: LEDENETRawState(head=129, model_num=6, power_state=36, preset_pattern=97, mode=38, speed=4, red=0, green=0, blue=0, warm_white=255, version_number=1, cool_white=0, color_mode=15, check_sum=69)

We announce it in the wrong state still

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: State query did not return expected power state

... and we consider it failed

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: Failed to turn on (1/4)

We now send off/on to get the device back in sync

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x71 0x24 0x0F 0xA4 (4)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) => 0x71 0x23 0x0F 0xA3 (4)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aiodevice] 192.168.0.48: Waiting for power state response

The device is now back in sync and its reported it powered on

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.aioprotocol] ('192.168.0.48', 5577) <= 0xF0 0x71 0x23 0x84 (4)

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Setting power state to: 0x23

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: _replace_raw_state: {'power_state': 35}

2022-01-01 19:06:28 DEBUG (MainThread) [flux_led.base_device] 192.168.0.48: Transition time is 1.29, set _transition_complete_time to 1540993.616758197

The change I made in https://github.com/home-assistant/core/pull/63154 will try to turn it on 2x before doing the off/on to resync the internal state.

chiragd commented 2 years ago

Thanks for the explanation. Very helpful.

I made a video for you comparing home assistant and magic home. Magic home performs flawlessly.

bdraco commented 2 years ago

Magic Home doesn't check the state after it sends the command, it just assumes success and hopes it worked (we check because sometimes it doesn't).

Thats why you'll see it out of sync sometimes for a moment since it hasn't queried the state again.

chiragd commented 2 years ago

Makes sense. I noticed in the home assistant log we send an off then on the second time. Maybe we should do this the first time instead of 2x on?

bdraco commented 2 years ago

I noticed in the home assistant log we send an off then on the second time. Maybe we should do this the first time instead of 2x on?

Ideally we don't make users with the non-buggy firmware (which is the bulk of the devices) have the additional delay so I'd like the try the 2x on first

bdraco commented 2 years ago

@chiragd If you want to try the new change before its released

mkdir /config/custom_components
cd /config/custom_components
git clone https://github.com/bdraco/flux_led_custom flux_led

Restart

If its using the custom one you'll see something like this in the log 2022-01-01 22:33:00 WARNING (SyncWorker_6) [homeassistant.loader] We found a custom integration flux_led which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant

chiragd commented 2 years ago

That seems to work perfectly - thank you so much!

chiragd commented 2 years ago

How long do changes take to make their way into home assistant?

bdraco commented 2 years ago

The bugfix should go in .8 in a few days. The other new functionality should be Feb