Yoda-x / ha-zha-new

update of the zha component
56 stars 10 forks source link

Slow UI response to bulb brightness change #62

Closed OrangeFractal closed 5 years ago

OrangeFractal commented 5 years ago

Hi Yoda-x, thanks for all the work you've done with zha_new!

I've only got one Phillips Hue bulb I'm testing right now.

Upon adjusting the brightness of the bulb using the slider, the live bulb itself responds immediately, but the brightness slider and bulb icon color in the HA UI lag and behave unpredictably for anywhere from 10 to 30 seconds, before going to the correct spot on the slider. Zha doesn't have this issue, and the UI responds immediately to what the live bulb is doing.

I saw that on your todo list you had mentioned

detect returning endpoints and update state ( mainly for bulbs), needs endpoint 0 (zdo) enabled in zha Ha component

Is that the issue I'm describing? Or is this something else that can be fixed easily on my end? I spoke to a few others and they have had this noticeable "lag" as well.

Additionally, I can replicate the random brightness issue brought up a while back too. Bulbs turn on with random brighness level

I'm not sure if they are related, however, they are both equally frustrating! Thank you!

Yoda-x commented 5 years ago

Hi OrangeF, do you mean that, when you change the brightness or color in the gui, that it jumps back to the original value and then after a few sec to the new value? Let me look inside this and also the issue with the random brighness level. The zdo is about getting notifications when you power on the bulb, almost all zigbee devices announce their self, when they rejoin the network. I have this currently running on my dev installation. to immediate poll the bulb when I put in on via the wall switch.

OrangeFractal commented 5 years ago

Hello! Yes, the brightness seems to jump to a value above or below the desired value for 20 or so seconds, then jumps to the value I want.

Additionally, toggling the on off button seems to halve the brightness each time it is toggled.

I've included some videos below to better describe what's happening.

1

2

3

4

Yoda-x commented 5 years ago

I found some improvements and will prepare a new preview branch, so you can try it out

OrangeFractal commented 5 years ago

Sounds good! I'll test it this weekend! Hopefully my little videos where helpful and didn't cause more confusion!

Yoda-x commented 5 years ago

ok, new preview is now online.

OrangeFractal commented 5 years ago

Just tested it and I think its fixed!!! This is awesome! Thank you! I'm not home right now to actually see the bulb updating to the brightness slider, but the gui is responding great now!! The slider is acting as it should!

Two more things, and I think it will be perfect, pertaining to the popup that shows when adjusting the light's settings:

When moving the slider, every time you do it, a popup at the bottom of the screen comes up that says "Turned on name of light" when that text should only be popping up under two conditions: When you turn the light on for the first time using the on/off switch, and when you move the brightness slider from 0 to a higher value (which automatically turns the light on).

Second, is the other way around. The on/off switch does respond correctly when you turn it off. This texts pops up: "Turned off name of light". However, the "off" text doesn't popup when im adjusting the brightness from some value greater than zero all the way to zero (which automatically turns the light off).

Actually found one more thing too, the slider acts correctly in that it remembers the last brightness setting it was on when you turn it on and off from the on/off switch, even when the brightness is set to 0, but I don't think it should be acting like this at 0 brightness. If the brightness is set to 0 and the switch is turned on, the light turns off because it rembered it was last set to 0. I believe it should act like this: when the brightness value was last set to 0, and the light is turned on from the on/off switch the brightness should automatically go to 100%.

Yoda-x commented 5 years ago

Hi

The popups are out of my scope, as these are controlled in the frontend code.

FYI, there are only two commands send from Hass to zha_new: turn_off and turn_on, where turn_on has a big bunch of optional parameters(brightness, color, color temp...). So, every brightness slider change creates a turn_on command with a brightness parameter.

I will add a check to see if brightness is 0 on turn_on and change it to full if needed

OrangeFractal commented 5 years ago

Thank you for explaining, that's exactly what I was wondering. I appreciate all the time you are putting into this!

Yoda-x commented 5 years ago

Please get the latest preview. I'm unsure if setting it to full brightness or minimal brightness is the best, But now it should set it to full brightness if it was 0. Please give it a try and let me know your thoughts.

OrangeFractal commented 5 years ago

Hello! Coincidentally I just got home and received new lights from sengled that I'm testing as well and their default behavior is setting it to minimal brightness. I think setting it to minimal brightness might be the route to go.

Yoda-x commented 5 years ago

Yepp,I will make this default. Can you verify the change works as expected with the full brightness, I will then change it to minimal and add it to the master branch....

OrangeFractal commented 5 years ago

Just tested it, and I don't think it worked. It might be a lightbulb specific thing though. I've been doing these tests on hue bulbs, but on the sengled bulbs i mentioned previously, the lowest brightness setting on the gui doesn't turn the bulb off, and that was before you made the updates.

Yoda-x commented 5 years ago

right, I have also some bulbs I can't turn off via brightness and some that do. but you say, the bulb stays off if you turn it on via the toggle switch in the gui?

OrangeFractal commented 5 years ago

Yeah if I turn the brightness slider all the way down, the light turns off, if i then toggle with the on/off switch, the ligh stays off.

OrangeFractal commented 5 years ago

Hi Yoda-x

Also, noticed this in the logs, probably not related to this issue, but:

2018-11-28 00:33:38 WARNING (MainThread) [homeassistant.loader] You are using a custom component for device_tracker.life360 which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2018-11-28 00:33:39 WARNING (MainThread) [homeassistant.loader] You are using a custom component for zha_new which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2018-11-28 00:33:47 WARNING (MainThread) [bellows.uart] Reset success
2018-11-28 00:33:47 WARNING (MainThread) [homeassistant.loader] You are using a custom component for light.zha_new which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2018-11-28 00:33:50 WARNING (MainThread) [bellows.zigbee.application] 0xbf4a:1:0x0006 Unexpected response TSN=18 command=7 args=[[<ConfigureReportingResponseRecord status=0 direction=0 attrid=0>]] 
2018-11-28 00:33:52 WARNING (MainThread) [bellows.zigbee.application] 0xbf4a:1:0x0006 Unexpected response TSN=18 command=7 args=[[<ConfigureReportingResponseRecord status=0 direction=0 attrid=0>]] 
2018-11-28 00:33:58 WARNING (MainThread) [homeassistant.components.light] Setup of platform zha_new is taking over 10 seconds.
2018-11-28 00:33:58 WARNING (MainThread) [homeassistant.components.light] Setup of platform zha_new is taking over 10 seconds.
2018-11-28 00:34:05 ERROR (MainThread) [custom_components.light.zha_new] [0xe187:11:0x0006] set config report exeptional failed: sendunicast reply timeout error
2018-11-28 00:34:19 WARNING (MainThread) [bellows.zigbee.application] 0x96a1:1:0x0004 Unexpected response TSN=91 command=258 args=[255, []] 
2018-11-28 00:34:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_1 is taking over 10 seconds
2018-11-28 00:34:59 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_6 is taking over 10 seconds
2018-11-28 00:35:29 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_3 is taking over 10 seconds
2018-11-28 00:36:24 WARNING (MainThread) [bellows.zigbee.application] 0x77f6:1:0x0004 Unexpected response TSN=55 command=258 args=[255, []] 
2018-11-28 00:36:54 WARNING (MainThread) [bellows.zigbee.application] 0xbf4a:1:0x0004 Unexpected response TSN=90 command=258 args=[255, []] 
2018-11-28 00:36:54 WARNING (MainThread) [bellows.zigbee.application] 0x77f6:1:0x0008 Unexpected response TSN=98 command=1 args=[[<ReadAttributeRecord attrid=0 status=0 value=255>]] 
2018-11-28 00:37:26 WARNING (MainThread) [bellows.zigbee.application] 0xbff8:1:0x0008 Unexpected response TSN=174 command=1 args=[[<ReadAttributeRecord attrid=0 status=0 value=255>]] 
2018-11-28 00:37:33 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_6 is taking over 10 seconds
2018-11-28 00:37:33 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_3 is taking over 10 seconds
2018-11-28 00:38:35 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.clock_light is taking over 10 seconds
2018-11-28 00:39:06 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_6 is taking over 10 seconds
2018-11-28 00:39:37 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.front_porch_1 is taking over 10 seconds
2018-11-28 00:39:37 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.front_porch_4 is taking over 10 seconds
2018-11-28 00:39:37 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_2 is taking over 10 seconds
2018-11-28 00:39:52 ERROR (MainThread) [custom_components.light.zha_new] [0x4eb0:11:0x0008] set config report exeptional failed: sendunicast reply timeout error
2018-11-28 00:39:58 WARNING (MainThread) [homeassistant.components.light] Updating zha_new light took longer than the scheduled update interval 0:00:30
2018-11-28 00:40:29 WARNING (MainThread) [homeassistant.components.light] Updating zha_new light took longer than the scheduled update interval 0:00:30
2018-11-28 00:41:10 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_7 is taking over 10 seconds
2018-11-28 00:41:10 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.front_porch_1 is taking over 10 seconds
2018-11-28 00:41:14 ERROR (MainThread) [homeassistant.core] Error doing job: SSL handshake failed
Traceback (most recent call last):
  File "uvloop/handles/stream.pyx", line 609, in uvloop.loop.UVStream._on_eof
  File "uvloop/sslproto.pyx", line 171, in uvloop.loop._SSLPipe.feed_ssldata
  File "/usr/local/lib/python3.6/ssl.py", line 689, in do_handshake
    self._sslobj.do_handshake()
ssl.SSLError: [SSL: WRONG_VERSION_NUMBER] wrong version number (_ssl.c:841)
2018-11-28 00:41:14 ERROR (MainThread) [homeassistant.core] Error doing job: SSL error errno:1 reason: WRONG_VERSION_NUMBER
Traceback (most recent call last):
  File "uvloop/sslproto.pyx", line 504, in uvloop.loop.SSLProtocol.data_received
  File "uvloop/sslproto.pyx", line 204, in uvloop.loop._SSLPipe.feed_ssldata
  File "uvloop/sslproto.pyx", line 171, in uvloop.loop._SSLPipe.feed_ssldata
  File "/usr/local/lib/python3.6/ssl.py", line 689, in do_handshake
    self._sslobj.do_handshake()
ssl.SSLError: [SSL: WRONG_VERSION_NUMBER] wrong version number (_ssl.c:841)
2018-11-28 00:41:16 WARNING (MainThread) [bellows.zigbee.application] 0x4eb0:0:0x8031 Unexpected response TSN=38 command=32817 args=[0, <Neighbors Entries=8 StartIndex=0 NeighborTableList=[<Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:0d:6f:00:0b:44:8f:51 NWKAddr=0 NeighborType=4 PermitJoining=1 Depth=0 LQI=180>, <Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:0b:a6:02 NWKAddr=54542 NeighborType=53 PermitJoining=1 Depth=1 LQI=247>]>] 
2018-11-28 00:41:18 WARNING (MainThread) [bellows.zigbee.application] 0x4eb0:0:0x8031 Unexpected response TSN=38 command=32817 args=[0, <Neighbors Entries=8 StartIndex=0 NeighborTableList=[<Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:0d:6f:00:0b:44:8f:51 NWKAddr=0 NeighborType=4 PermitJoining=1 Depth=0 LQI=180>, <Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:0b:a6:02 NWKAddr=54542 NeighborType=53 PermitJoining=1 Depth=1 LQI=247>]>] 
2018-11-28 00:41:18 WARNING (MainThread) [bellows.zigbee.application] 0x4eb0:0:0x8031 Unexpected response TSN=40 command=32817 args=[0, <Neighbors Entries=8 StartIndex=2 NeighborTableList=[<Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:14:e4:06 NWKAddr=43187 NeighborType=53 PermitJoining=1 Depth=1 LQI=231>, <Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:5e:fd:90 NWKAddr=61744 NeighborType=53 PermitJoining=1 Depth=1 LQI=252>]>] 
2018-11-28 00:41:20 WARNING (MainThread) [bellows.zigbee.application] 0x4eb0:0:0x8031 Unexpected response TSN=40 command=32817 args=[0, <Neighbors Entries=8 StartIndex=2 NeighborTableList=[<Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:14:e4:06 NWKAddr=43187 NeighborType=53 PermitJoining=1 Depth=1 LQI=231>, <Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:5e:fd:90 NWKAddr=61744 NeighborType=53 PermitJoining=1 Depth=1 LQI=252>]>] 
2018-11-28 00:41:20 WARNING (MainThread) [bellows.zigbee.application] 0x4eb0:0:0x8031 Unexpected response TSN=42 command=32817 args=[0, <Neighbors Entries=8 StartIndex=4 NeighborTableList=[<Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:26:ad:01 NWKAddr=57735 NeighborType=53 PermitJoining=1 Depth=1 LQI=252>, <Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:16:4b:55 NWKAddr=65071 NeighborType=53 PermitJoining=1 Depth=1 LQI=252>]>] 
2018-11-28 00:41:20 WARNING (MainThread) [bellows.zigbee.application] 0x4eb0:0:0x8031 Unexpected response TSN=38 command=32817 args=[0, <Neighbors Entries=8 StartIndex=0 NeighborTableList=[<Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:0d:6f:00:0b:44:8f:51 NWKAddr=0 NeighborType=4 PermitJoining=1 Depth=0 LQI=180>, <Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:0b:a6:02 NWKAddr=54542 NeighborType=53 PermitJoining=1 Depth=1 LQI=247>]>] 
2018-11-28 00:41:21 WARNING (MainThread) [bellows.zigbee.application] 0x4eb0:0:0x8031 Unexpected response TSN=42 command=32817 args=[0, <Neighbors Entries=8 StartIndex=4 NeighborTableList=[<Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:26:ad:01 NWKAddr=57735 NeighborType=53 PermitJoining=1 Depth=1 LQI=252>, <Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:16:4b:55 NWKAddr=65071 NeighborType=53 PermitJoining=1 Depth=1 LQI=252>]>] 
2018-11-28 00:41:22 WARNING (MainThread) [bellows.zigbee.application] 0x4eb0:0:0x8031 Unexpected response TSN=40 command=32817 args=[0, <Neighbors Entries=8 StartIndex=2 NeighborTableList=[<Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:14:e4:06 NWKAddr=43187 NeighborType=53 PermitJoining=1 Depth=1 LQI=231>, <Neighbor PanId=75:31:d3:34:93:2b:1c:86 IEEEAddr=00:17:88:01:03:5e:fd:90 NWKAddr=61744 NeighborType=53 PermitJoining=1 Depth=1 LQI=252>]>] 
2018-11-28 00:42:12 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_6 is taking over 10 seconds
2018-11-28 00:42:12 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_5 is taking over 10 seconds

It says that the light component is taking over 10 seconds, and then soon after each light bulb does that same, and takes a while to update. Is this a normal warning log?

Yoda-x commented 5 years ago

the update warning for lights is normal if the bulbs are powered off. zha.tries to pull the state and times out, Also unexpected responses happen sometimes. I will look in the issue you mentioned above. A debug of the switch-on with brightness=0 would be helpful..

The traceback is not related to zha, as it not uses ssl.

OrangeFractal commented 5 years ago

Thanks for explaining Yoda-x,

I have to check, but I believe the bulbs are powered on when I get the time-out warnings.

Heres the log when the switch is turned on with the brightness=0

2018-11-28 14:40:04 DEBUG (MainThread) [custom_components.light.zha_new] light.clock_light async_update
2018-11-28 14:40:04 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 14:40:04 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 14:40:04 DEBUG (MainThread) [custom_components.light.zha_new] light.clock_light get membership: [25, []]
OrangeFractal commented 5 years ago

Could be something related too, but my colored bulbs says they turn off for 1 minute every 10 minutes. The bulbs stay on, I believe, but my history shows them turning on and off at regular intervals.

2018-11-28 15:58:56 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_6 get membership: None
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_5 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_7 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_3 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_1 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_1 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_4 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_2 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_6 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_2 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.clock_light async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_3 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_4 async_update
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_1 get membership: [25, []]
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_4 get membership: [25, []]
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_2 get membership: [255, []]
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_6 get membership: [25, []]
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.clock_light get membership: [25, []]
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_2 get membership: [25, []]
2018-11-28 15:59:10 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_3 get membership: [25, []]
2018-11-28 15:59:11 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_1 get membership: [255, []]
2018-11-28 15:59:11 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_4 get membership: [255, []]
2018-11-28 15:59:11 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 15:59:11 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 15:59:11 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 15:59:11 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 15:59:11 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:11 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 15:59:11 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 15:59:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 15:59:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=45940
2018-11-28 15:59:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=19594
2018-11-28 15:59:12 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_3 get membership: [255, []]
2018-11-28 15:59:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=11272
2018-11-28 15:59:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=48954
2018-11-28 15:59:13 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=45940
2018-11-28 15:59:13 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=19594
2018-11-28 15:59:13 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 15:59:13 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 15:59:13 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=11272
2018-11-28 15:59:13 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=48954
2018-11-28 15:59:25 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:26 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:27 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:27 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_1 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_7 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_1 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.clock_light async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_6 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_4 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_5 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_4 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_2 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_3 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_2 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_3 async_update
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:41 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_1 get membership: [25, []]
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_7 get membership: [25, []]
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] light.clock_light get membership: [25, []]
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_1 get membership: [255, []]
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_4 get membership: [25, []]
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_2 get membership: [25, []]
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_3 get membership: [25, []]
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_4 get membership: [255, []]
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_3 get membership: [255, []]
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_2 get membership: [255, []]
2018-11-28 15:59:42 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 15:59:43 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 15:59:43 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 15:59:43 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 15:59:43 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 15:59:43 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 15:59:43 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 15:59:43 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 15:59:43 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=11272
2018-11-28 15:59:43 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=48954
2018-11-28 15:59:43 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=45940
2018-11-28 15:59:44 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=19594
2018-11-28 15:59:44 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=11272
2018-11-28 15:59:44 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=48954
2018-11-28 15:59:44 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=45940
2018-11-28 15:59:44 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=19594
2018-11-28 15:59:57 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_6 get membership: None
2018-11-28 15:59:57 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_5 get membership: None
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_5 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_3 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.clock_light async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_1 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_3 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_7 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_2 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_4 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_1 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_4 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_2 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_6 async_update
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 16:00:12 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 16:00:13 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.true
2018-11-28 16:00:13 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.true: 1>}
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] cluster:6 attribute=value received: 0=Bool.false
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] received: {'on_off': <Bool.false: 0>}
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] light.clock_light get membership: [25, []]
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_3 get membership: [25, []]
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_7 get membership: [25, []]
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_1 get membership: [25, []]
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_1 get membership: [255, []]
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_2 get membership: [25, []]
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_4 get membership: [25, []]
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] light.living_room_6 get membership: [25, []]
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_4 get membership: [255, []]
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_2 get membership: [255, []]
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=11272
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=48954
2018-11-28 16:00:14 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 16:00:15 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=45940
2018-11-28 16:00:15 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=19594
2018-11-28 16:00:15 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=45940
2018-11-28 16:00:15 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=19594
2018-11-28 16:00:17 DEBUG (MainThread) [custom_components.light.zha_new] light.front_porch_3 get membership: [255, []]
2018-11-28 16:00:17 DEBUG (MainThread) [custom_components.light.zha_new] cluster:8 attribute=value received: 0=255
2018-11-28 16:00:17 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 7=250
2018-11-28 16:00:17 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 3=11272
2018-11-28 16:00:17 DEBUG (MainThread) [custom_components.light.zha_new] cluster:768 attribute=value received: 4=48954

example

Yoda-x commented 5 years ago

please update the preview branch. I learned that the minimal brightness, where a bulbs turn off is 1 and not 0. Thus I needed to to adjust the code to reflect it. I have a innr bulb which works fine now. about the other issue: that bulbs go unavailable is somehow normal ->#49. you may check the topology how they connect to the controller. this every 10 min outage may related, I will check the code if I see a cause

PS: I forgot, this 10 min issue should be also fixed. You got code from my dev branch. Bulbs now report their status every 10 min or if something changes. so, if you have a remote control paired with a bulb and change color/brighness/on_off with the remote. The bulb sends an update to hass, same if you power it on with the wall switch. there was an error detecting on/off.

OrangeFractal commented 5 years ago

I think that worked! but, is this the behavior we want? Maybe by the brightness slider, should not be able to turn the light completely off, only to the lowest brightness, do you know what I mean?

Yoda-x commented 5 years ago

yes, I know. I can change it to limit the minimum value to 2. This would disable the turn-off via the slider which makes sense as you have the toggle button to turn it off. It's a simple change. Not sure how other platforms handle this. But it would make the behavior consistent, as I have bulbs that I can't slide to off.

PS: added this change, pls update the preview branch

Yoda-x commented 5 years ago

now on master, closing ticket