core: ZHA Group State Changes does not Update entity state
The problem
Using ZHA on Conbee II on an IntelNUC i7. I migrated all of my Philips Hue devices from Hue to ZHA. Can’t say how it was prior to 0.117, as I’ve only recently moved it all over…
In my experience, I turn off (or on) a group of lights and in real life the lights are turned on or off correctly, but in HA the state for the individual lights sometimes hang in the old state.
I’ve tried with both a normal group of lights as well as an actual ZigBee group, results seem to be the same.
As an example, I made some screenshots, these lights are less than 1m away from the controller:
The below is the initial state:
I then turn on the top entity, which in this case is a Zigbee group, notice how not all of the lights turned on (although in real-life, they are turned on):
I then proceed to turn off the group. However, the group state jumps back to on, the state of one light does not change, while the rest all turn off (in real-life, all the lights do turn off).
I then turn off the group again, and finally it goes back to the initial state. Which lights do / don’t reflect is totally random. It’s not specific devices.
Environment
| Option | Value |
|---|---|
| arch | x86_64 |
| chassis | embedded |
| dev | false |
| docker | true |
| docker_version | 19.03.11 |
| hassio | true |
| host_os | HassOS 4.15 |
| installation_type | Home Assistant OS |
| os_name | Linux |
| os_version | 5.4.72 |
| python_version | 3.8.6 |
| supervisor | 2020.11.0 |
| timezone | Europe/Amsterdam |
| version | 0.117.3 |
| virtualenv | false |
- Home Assistant Core release with the issue: 0.117.0 -> 0.117.3
- Last working Home Assistant Core release (if known): N/A
- Operating environment (OS/Container/Supervised/Core): HomeAssistantOS
- Integration causing this issue: ZHA
- Link to integration documentation on our website: https://www.home-assistant.io/integrations/zha/
Problem-relevant configuration.yaml
zha:
zigpy_config:
network:
channel: 25 # What channel the radio should try to use.
channels: [15, 20, 25] # Channel mask
ota:
ikea_provider: true # Auto update Trådfri devices
ledvance_provider: true # Auto update LEDVANCE devices
otau_directory: /config/zha/ota # Utilize .ota files to update everything else
Traceback/Error logs
2020-11-04 16:16:13 DEBUG (MainThread) [zigpy.device] Ignoring message (b'016401') on cluster 6: unknown endpoint or cluster id: 'No cluster ID 0x0006 on (00:21:2e:ff:ff:05:3a:17, 1)'
2020-11-04 16:16:13 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=202 command_id=Command.Report_Attributes>
2020-11-04 16:16:13 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=1>)]]
2020-11-04 16:16:13 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] Attribute report received: current_level=1
2020-11-04 16:16:13 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=203 command_id=Command.Report_Attributes>
2020-11-04 16:16:13 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.true>)]]
2020-11-04 16:16:13 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0006] Attribute report received: on_off=1
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0x99e7:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=102 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=104 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=106 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0x3b2f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=114 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0x99e7:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=116 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=118 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0x40f4:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=110 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0x99e7:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=124 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=120 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0x40f4:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=128 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0x40f4:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=132 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=126 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=130 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=204 command_id=Command.Report_Attributes>
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=254>)]]
2020-11-04 16:16:14 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] Attribute report received: current_level=254
2020-11-04 16:16:19 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=134 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:19 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=136 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:19 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=140 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:19 DEBUG (MainThread) [zigpy.zcl] [0x3b2f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=138 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:19 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=142 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:16:24 DEBUG (MainThread) [zigpy.zcl] [0xf2fb:1:0x0b04] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=144 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.device] Ignoring message (b'019800') on cluster 6: unknown endpoint or cluster id: 'No cluster ID 0x0006 on (00:21:2e:ff:ff:05:3a:17, 1)'
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0x99e7:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=154 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=160 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=156 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=205 command_id=Command.Report_Attributes>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=253>)]]
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] Attribute report received: current_level=253
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=164 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=158 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=170 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=174 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=172 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=178 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=180 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:10 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=176 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:11 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=182 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:11 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=184 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:11 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=207 command_id=Command.Report_Attributes>
2020-11-04 16:17:11 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=254>)]]
2020-11-04 16:17:11 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] Attribute report received: current_level=254
2020-11-04 16:17:15 DEBUG (MainThread) [zigpy.zcl] [0x3b2f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=188 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:15 DEBUG (MainThread) [zigpy.zcl] [0x99e7:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=190 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:15 DEBUG (MainThread) [zigpy.zcl] [0x40f4:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=186 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:15 DEBUG (MainThread) [zigpy.zcl] [0x3b2f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=192 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:15 DEBUG (MainThread) [zigpy.zcl] [0x40f4:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=194 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:24 DEBUG (MainThread) [zigpy.zcl] [0xf2fb:1:0x0b04] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=196 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:25 DEBUG (MainThread) [zigpy.device] Ignoring message (b'01c600') on cluster 6: unknown endpoint or cluster id: 'No cluster ID 0x0006 on (00:21:2e:ff:ff:05:3a:17, 1)'
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0x99e7:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=200 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=202 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=206 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=210 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0x40f4:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=208 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=204 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=216 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=218 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=222 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=228 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=226 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0x40f4:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=220 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=224 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=230 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0x40f4:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=232 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:26 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=234 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:31 DEBUG (MainThread) [zigpy.zcl] [0x99e7:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=236 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:31 DEBUG (MainThread) [zigpy.zcl] [0x3b2f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=238 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:31 DEBUG (MainThread) [zigpy.zcl] [0x3b2f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=240 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:17:42 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=208 command_id=Command.Report_Attributes>
2020-11-04 16:17:42 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0300] ZCL request 0x000a: [[Attribute(attrid=3, value=<TypeValue type=uint16_t, value=13449>), Attribute(attrid=1, value=<TypeValue type=uint8_t, value=222>), Attribute(attrid=0, value=<TypeValue type=uint8_t, value=187>)]]
2020-11-04 16:17:42 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0300] Attribute report received: current_x=13449, current_saturation=222, current_hue=187
2020-11-04 16:17:54 DEBUG (MainThread) [zigpy.zcl] [0xf2fb:1:0x0b04] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=242 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:06 DEBUG (MainThread) [zigpy.zcl] [0x92e7:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=147 command_id=Command.Report_Attributes>
2020-11-04 16:18:06 DEBUG (MainThread) [zigpy.zcl] [0x92e7:11:0x0300] ZCL request 0x000a: [[Attribute(attrid=3, value=<TypeValue type=uint16_t, value=22636>), Attribute(attrid=1, value=<TypeValue type=uint8_t, value=40>), Attribute(attrid=0, value=<TypeValue type=uint8_t, value=158>)]]
2020-11-04 16:18:06 DEBUG (MainThread) [zigpy.zcl] [0x92e7:11:0x0300] Attribute report received: current_x=22636, current_saturation=40, current_hue=158
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x15c7:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=75 command_id=Command.Report_Attributes>
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x15c7:11:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=1>)]]
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x15c7:11:0x0008] Attribute report received: current_level=1
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x15c7:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=76 command_id=Command.Report_Attributes>
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x15c7:11:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.false>)]]
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x15c7:11:0x0006] Attribute report received: on_off=0
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x3a09:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=123 command_id=Command.Report_Attributes>
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x3a09:11:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=1>)]]
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x3a09:11:0x0008] Attribute report received: current_level=1
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x3a09:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=124 command_id=Command.Report_Attributes>
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x3a09:11:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.false>)]]
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x3a09:11:0x0006] Attribute report received: on_off=0
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x67ef:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=111 command_id=Command.Report_Attributes>
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x67ef:11:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=1>)]]
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x67ef:11:0x0008] Attribute report received: current_level=1
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x67ef:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=112 command_id=Command.Report_Attributes>
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x67ef:11:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.false>)]]
2020-11-04 16:18:14 DEBUG (MainThread) [zigpy.zcl] [0x67ef:11:0x0006] Attribute report received: on_off=0
2020-11-04 16:18:15 DEBUG (MainThread) [zigpy.zcl] [0x33ef:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=244 command_id=Command.Default_Response>
2020-11-04 16:18:24 DEBUG (MainThread) [zigpy.zcl] [0xf2fb:1:0x0b04] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=246 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:37 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=248 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:37 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=250 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:37 DEBUG (MainThread) [zigpy.zcl] [0xc69f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=252 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:43 DEBUG (MainThread) [zigpy.zcl] [0x99e7:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=254 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:43 DEBUG (MainThread) [zigpy.zcl] [0x99e7:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=0 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:43 DEBUG (MainThread) [zigpy.zcl] [0x99e7:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=2 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:49 DEBUG (MainThread) [zigpy.zcl] [0x67ef:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=4 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:49 DEBUG (MainThread) [zigpy.zcl] [0x67ef:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=6 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:49 DEBUG (MainThread) [zigpy.zcl] [0x67ef:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=8 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:52 DEBUG (MainThread) [zigpy.zcl] [0xaa9c:2:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=8 command_id=Command.Report_Attributes>
2020-11-04 16:18:52 DEBUG (MainThread) [zigpy.zcl] [0xaa9c:2:0x0001] ZCL request 0x000a: [[Attribute(attrid=33, value=<TypeValue type=uint8_t, value=157>)]]
2020-11-04 16:18:52 DEBUG (MainThread) [zigpy.zcl] [0xaa9c:2:0x0001] Attribute report received: battery_percentage_remaining=157
2020-11-04 16:18:52 DEBUG (MainThread) [zigpy.zcl] [0x932f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=10 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:52 DEBUG (MainThread) [zigpy.zcl] [0x932f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=13 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:52 DEBUG (MainThread) [zigpy.zcl] [0x932f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=15 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:54 DEBUG (MainThread) [zigpy.zcl] [0xf2fb:1:0x0b04] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=17 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:54 DEBUG (MainThread) [zigpy.zcl] [0x92e7:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=19 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:54 DEBUG (MainThread) [zigpy.zcl] [0x92e7:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=21 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:54 DEBUG (MainThread) [zigpy.zcl] [0xf44b:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=25 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:54 DEBUG (MainThread) [zigpy.zcl] [0x92e7:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=23 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:54 DEBUG (MainThread) [zigpy.zcl] [0xf44b:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=27 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:18:54 DEBUG (MainThread) [zigpy.zcl] [0xf44b:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=29 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:03 DEBUG (MainThread) [zigpy.zcl] [0x4edb:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=31 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:03 DEBUG (MainThread) [zigpy.zcl] [0x4edb:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=33 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:03 DEBUG (MainThread) [zigpy.zcl] [0x4edb:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=35 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:04 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=37 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:04 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=39 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:04 DEBUG (MainThread) [zigpy.zcl] [0xc78f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=41 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:05 DEBUG (MainThread) [zigpy.zdo] [0x1677:zdo] ZDO request ZDOCmd.Match_Desc_req: [0xFFFD, 49246, [25], []]
2020-11-04 16:19:07 DEBUG (MainThread) [zigpy.zcl] [0xafa8:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=44 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:07 DEBUG (MainThread) [zigpy.device] [0xafa8] Delivery error for seq # 0x2e, on endpoint id 11 cluster 0x0008: message send failure
2020-11-04 16:19:07 DEBUG (MainThread) [zigpy.zcl] [0xafa8:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=48 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:10 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=50 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:10 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=52 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:10 DEBUG (MainThread) [zigpy.zcl] [0x9217:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=54 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:10 DEBUG (MainThread) [zigpy.zcl] [0x1677:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=56 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:10 DEBUG (MainThread) [zigpy.zcl] [0x1677:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=58 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:10 DEBUG (MainThread) [zigpy.zcl] [0x1677:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=60 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:13 DEBUG (MainThread) [zigpy.zcl] [0x3b2f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=62 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:13 DEBUG (MainThread) [zigpy.zcl] [0x3b2f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=64 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:13 DEBUG (MainThread) [zigpy.zcl] [0x3b2f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=66 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:22 DEBUG (MainThread) [zigpy.zcl] [0x0297:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=68 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:22 DEBUG (MainThread) [zigpy.zcl] [0x0297:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=70 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:22 DEBUG (MainThread) [zigpy.device] [0x0297] Delivery error for seq # 0x48, on endpoint id 11 cluster 0x0300: message send failure
2020-11-04 16:19:22 DEBUG (MainThread) [zigpy.zcl] [0x0297:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=72 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:22 DEBUG (MainThread) [zigpy.zcl] [0x0297:11:0x0300] ZCL request 0x0001: [[ReadAttributeRecord(attrid=7, status=<Status.SUCCESS: 0>, value=<TypeValue type=uint16_t, value=340>)]]
2020-11-04 16:19:24 DEBUG (MainThread) [zigpy.zcl] [0x15c7:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=74 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:24 DEBUG (MainThread) [zigpy.zcl] [0xf2fb:1:0x0b04] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=78 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:24 DEBUG (MainThread) [zigpy.zcl] [0x15c7:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=76 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:24 DEBUG (MainThread) [zigpy.zcl] [0x15c7:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=80 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:31 DEBUG (MainThread) [zigpy.zcl] [0x2393:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=82 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:31 DEBUG (MainThread) [zigpy.zcl] [0x2393:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=84 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:31 DEBUG (MainThread) [zigpy.zcl] [0x2393:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=86 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:42 DEBUG (MainThread) [zigpy.zcl] [0x3a09:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=88 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:42 DEBUG (MainThread) [zigpy.zcl] [0x3a09:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=90 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:42 DEBUG (MainThread) [zigpy.zcl] [0x3a09:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=92 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:49 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=94 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:49 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=96 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:49 DEBUG (MainThread) [zigpy.zcl] [0xfb9f:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=98 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:51 DEBUG (MainThread) [zigpy.zcl] [0x7c13:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=100 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:51 DEBUG (MainThread) [zigpy.zcl] [0xd5bf:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=102 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:51 DEBUG (MainThread) [zigpy.zcl] [0x7c13:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=104 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:51 DEBUG (MainThread) [zigpy.zcl] [0xd5bf:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=106 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:51 DEBUG (MainThread) [zigpy.zcl] [0x7c13:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=108 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:51 DEBUG (MainThread) [zigpy.zcl] [0xd5bf:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=110 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:19:54 DEBUG (MainThread) [zigpy.zcl] [0xf2fb:1:0x0b04] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=112 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:20:00 DEBUG (MainThread) [zigpy.zcl] [0x8022:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=114 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:20:00 DEBUG (MainThread) [zigpy.zcl] [0x8022:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=116 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:20:00 DEBUG (MainThread) [zigpy.zcl] [0x8022:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=118 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:20:02 DEBUG (MainThread) [zigpy.device] [0x4c51] Delivery error for seq # 0x78, on endpoint id 11 cluster 0x0006: message send failure
2020-11-04 16:20:02 DEBUG (MainThread) [zigpy.zcl] [0x4c51:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=120 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:20:02 DEBUG (MainThread) [zigpy.zcl] [0x4c51:11:0x0006] ZCL request 0x0001: [[ReadAttributeRecord(attrid=0, status=<Status.SUCCESS: 0>, value=<TypeValue type=Bool, value=Bool.false>)]]
2020-11-04 16:20:02 DEBUG (MainThread) [zigpy.zcl] [0x4c51:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=122 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:20:02 DEBUG (MainThread) [zigpy.zcl] [0x1d83:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=124 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:20:02 DEBUG (MainThread) [zigpy.zcl] [0x4c51:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=126 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:20:02 DEBUG (MainThread) [zigpy.zcl] [0x1d83:11:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=128 command_id=Command.Read_Attributes_rsp>
2020-11-04 16:20:02 DEBUG (MainThread) [zigpy.zcl] [0x1d83:11:0x0300] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=130 command_id=Command.Read_Attributes_rsp>
Additional information
There is a thread in the HomeAssistant Community forum as well.
About this issue
- Original URL
- State: closed
- Created 4 years ago
- Comments: 36 (16 by maintainers)
Thoughts on the behavior - if I’m understanding this correctly - since Hue bulbs don’t report back status automatically, HA is individually polling for the state of each bulb each time after sending a zigbee group command. Based on what we’re seeing in the UI, it appears that if the polling is not successful, HA reverts the state in the UI back to the previously known state. My question is - if we have just done something in the UI - turn the group/entity off - we should assume that is the correct state unless we receive a SUCCESSFUL poll response that indicates otherwise. For example - we click a button in the UI to turn the group off, the state in HA gets updated to OFF based on that action, the zigbee command goes out and the lights actually turn off. Great - we’re in the right state. Polling starts, but not all lights return a response successfully - let’s leave the state in the UI where we set it based on the assumption that it worked. Now, if on the other hand, we get a poll response back that was successful and shows the bulb as still being ON - then yes, update the state in HA.
Something else - I know in my zigbee network on ZHA, if I try to send too many commands too quickly, they will randomly fail. I see this in something like a Scene that contains more than 4 bulbs. When I try to activate the scene, random bulbs will not change, and after activating the scene multiple times, they will all get to the intended state. Yet commands sent in a broadcast to a group, or even each single bulb will receive the command successfully every time, just not when send out a bunch of unicast commands all at once. I’ve seen mention of Hue not having enough buffer space as an explanation for this. So, what if that’s true of the polling as well. Are we maybe blasting out too many polling requests all at once, and this might be the cause for the polling fail?
BTW - I had neither the inaccurate state issue, nor the too many commands issue with deconz - all bulb placement and coordinator stick placement are the same, just switched over to ZHA. I mention this because it seems like there is room for improvement in ZHA. Maybe deconz spaces the commands out just a bit or does something else to work around things.
@hpio The newer Hue Bluetooth lights have proper attribute reporting, so they may work better. Recently, some changes regarding the state of a ZHA group have already landed in the latest Home Assistant Dev build. I’m not sure if this also affects the state of individual lights (which are in the ZHA group that’s turned on/off).
The older (ZLL profile) Hue bulbs (probably yours) do not report their state (attribute reporting) at all. They need to be polled. The Hue Bridge does this every couple of seconds (not sure if it changes depending on how many lights are in the network though) and ZHA polls the light shortly after the turning on/off command was sent AND every 3 to 5 minutes. So, if you turn on/off a ZHA group and the state of the individual lights is not instantly changing, it should appear in a couple of minutes. (Although this isn’t ideal obviously)
(Please also upload the signature of your Hue bulbs that have this issue to: https://paste.ubuntu.com/ and send the link here)
Edit: You could try updating (after doing a backup of course) to the latest Home Assistant dev build:
ha core update --version 2021.4.0.dev20210326I had this problem with my ConBee II. I finally switched to ZZH and that works fine. You could also try using ZHA groups, so you’re only sending one command to turn all the lights off. Just go to Integrations -> Configure ZHA -> (at the top) Groups.
I’ve also switched everything over from deCONZ to ZHA and also experience the problem with bulbs sometimes not doing the action when there are too many commands at the same time. In the bedroom for example we have 5 color bulbs. When turning them on/off or changing color then occasionally one will not follow.
No, most bulbs are LTW013, then some LCT003 and LTG002. Firmware wise they’re all on the firmware that was available last time I had them paired to hue bridge around 5 months ago
@dmulcahey that is correct, bulbs change state correctly and immediately after a command is issued
@hpio is the issue just on the HA UI? Do the bulbs reflect the change immediately?