[Solved] Troubleshooting ZHA light group

Solution


I need help troubleshooting a ZHA light bulb group issue. Perhaps someone more knowledgeable can interpret the logs below better than I.

Some of my light fixtures have multiple Hue bulbs. Ever since I have switched to ZHA those groups often turn themselves back on. This become more clear when moved a 9 Hue bulbs group over to ZHA. I am currently using a Home Assistant group to control the bulbs, but I have tried a Home Assistant light group and a ZHA light group with similar results.

group.dining_room_light turned off (via Lovelace toggle).

2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4544:11:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining9: turned off: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [zigpy.zcl] [0x0367: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=123 command_id=Command.Default_Response>
2020-08-21 08:35:57 DEBUG (MainThread) [zigpy.zcl] [0x84ef: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=121 command_id=Command.Default_Response>
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x84ef:11:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining7: turned off: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0367:11:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining6: turned off: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [zigpy.zcl] [0x0c4f: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=127 command_id=Command.Default_Response>
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0c4f:11:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining5: turned off: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [zigpy.zcl] [0x515f: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=125 command_id=Command.Default_Response>
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x515f:11:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining3: turned off: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [zigpy.zcl] [0x341b: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=129 command_id=Command.Default_Response>
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x341b:11:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining4: turned off: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [zigpy.zcl] [0xd76b: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=119 command_id=Command.Default_Response>
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xd76b:11:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: [0, <Status.SUCCESS: 0>]
2020-08-21 08:35:57 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining1: turned off: [0, <Status.SUCCESS: 0>]
2020-08-21 08:36:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xfebb:11:0x0006]: command failed: off exception: 
2020-08-21 08:36:02 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining8: turned off: 
2020-08-21 08:36:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1c38:11:0x0006]: command failed: off exception: 
2020-08-21 08:36:02 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining2: turned off: 
2020-08-21 08:36:04 DEBUG (MainThread) [zigpy.zcl] [0x9fcf:1:0x0406] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=167 command_id=Command.Report_Attributes>
2020-08-21 08:36:04 DEBUG (MainThread) [zigpy.zcl] [0x9fcf:1:0x0406] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=bitmap8, value=bitmap8.1>>]]
2020-08-21 08:36:04 DEBUG (MainThread) [zigpy.zcl] [0x9fcf:1:0x0406] Attribute report received: occupancy=1
2020-08-21 08:36:05 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9fcf:1:0x0500]: Updated alarm state: 1
2020-08-21 08:36:05 DEBUG (MainThread) [zigpy.zcl] [0x15dd: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=133 command_id=Command.Default_Response>
2020-08-21 08:36:05 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x15dd:11:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-08-21 08:36:05 DEBUG (MainThread) [homeassistant.components.zha.entity] light.kitchen_cabinet: turned on: {'on_off': [1, <Status.SUCCESS: 0>]}
2020-08-21 08:36:22 DEBUG (MainThread) [zigpy.zcl] [0x813f:1:0x0406] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=195 command_id=Command.Report_Attributes>
2020-08-21 08:36:22 DEBUG (MainThread) [zigpy.zcl] [0x813f:1:0x0406] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=bitmap8, value=bitmap8.1>>]]
2020-08-21 08:36:22 DEBUG (MainThread) [zigpy.zcl] [0x813f:1:0x0406] Attribute report received: occupancy=1
2020-08-21 08:36:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x813f:1:0x0500]: Updated alarm state: 1
2020-08-21 08:36:29 DEBUG (MainThread) [zigpy.zdo] [0xf5f4:zdo] ZDO request ZDOCmd.Match_Desc_req: [0xfffd, 49246, [25], []]
2020-08-21 08:36:32 DEBUG (MainThread) [zigpy.zcl] [0xaeb7:1:0x0400] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=179 command_id=Command.Report_Attributes>
2020-08-21 08:36:32 DEBUG (MainThread) [zigpy.zcl] [0xaeb7:1:0x0400] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=uint16_t, value=219>>]]
2020-08-21 08:36:32 DEBUG (MainThread) [zigpy.zcl] [0xaeb7:1:0x0400] Attribute report received: measured_value=219
2020-08-21 08:36:32 DEBUG (MainThread) [zigpy.zcl] [0xaeb7:1:0x0406] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=180 command_id=Command.Report_Attributes>
2020-08-21 08:36:32 DEBUG (MainThread) [zigpy.zcl] [0xaeb7:1:0x0406] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=bitmap8, value=bitmap8.1>>]]
2020-08-21 08:36:32 DEBUG (MainThread) [zigpy.zcl] [0xaeb7:1:0x0406] Attribute report received: occupancy=1
2020-08-21 08:36:32 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xaeb7:1:0x0500]: Updated alarm state: 1
2020-08-21 08:36:50 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining7: polling current state - from cache: False
2020-08-21 08:36:50 DEBUG (MainThread) [zigpy.zcl] [0x84ef: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=136 command_id=Command.Read_Attributes_rsp>
2020-08-21 08:36:50 DEBUG (MainThread) [zigpy.zcl] [0x84ef: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=138 command_id=Command.Read_Attributes_rsp>
2020-08-21 08:36:50 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x84ef:11:0x0008]: received attribute: 0 update with value: 254
2020-08-21 08:36:50 DEBUG (MainThread) [zigpy.zcl] [0x84ef: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=140 command_id=Command.Read_Attributes_rsp>
2020-08-21 08:36:53 DEBUG (MainThread) [homeassistant.components.zha.entity] light.family_room_floor_lamp1: polling current state - from cache: False
2020-08-21 08:36:53 DEBUG (MainThread) [zigpy.zcl] [0xae4b: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=142 command_id=Command.Read_Attributes_rsp>
2020-08-21 08:36:53 DEBUG (MainThread) [zigpy.zcl] [0xae4b: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=144 command_id=Command.Read_Attributes_rsp>

group.dining_room_light turned back on without user intervention starting around here!

2020-08-21 08:36:50 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining7: polling current state - from cache: False
2020-08-21 08:36:50 DEBUG (MainThread) [zigpy.zcl] [0x84ef: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=136 command_id=Command.Read_Attributes_rsp>
2020-08-21 08:36:50 DEBUG (MainThread) [zigpy.zcl] [0x84ef: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=138 command_id=Command.Read_Attributes_rsp>
2020-08-21 08:36:50 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x84ef:11:0x0008]: received attribute: 0 update with value: 254
2020-08-21 08:36:50 DEBUG (MainThread) [zigpy.zcl] [0x84ef: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=140 command_id=Command.Read_Attributes_rsp>
2020-08-21 08:36:53 DEBUG (MainThread) [homeassistant.components.zha.entity] light.family_room_floor_lamp1: polling current state - from cache: False
2020-08-21 08:36:53 DEBUG (MainThread) [zigpy.zcl] [0xae4b: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=142 command_id=Command.Read_Attributes_rsp>
2020-08-21 08:36:53 DEBUG (MainThread) [zigpy.zcl] [0xae4b: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=144 command_id=Command.Read_Attributes_rsp>
2020-08-21 08:36:53 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xae4b:11:0x0008]: received attribute: 0 update with value: 254
2020-08-21 08:37:06 DEBUG (MainThread) [zigpy.zcl] [0x84ef: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=146 command_id=Command.Default_Response>
2020-08-21 08:37:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x84ef:11:0x0008]: executed 'move_to_level_with_on_off' command with args: '(254, 600.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0xd76b: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=154 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xd76b:11:0x0008]: executed 'move_to_level_with_on_off' command with args: '(254, 600.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x341b: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=152 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x341b:11:0x0008]: executed 'move_to_level_with_on_off' command with args: '(254, 600.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x1c38: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=158 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1c38:11:0x0008]: executed 'move_to_level_with_on_off' command with args: '(254, 600.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x4544: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=160 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4544:11:0x0008]: executed 'move_to_level_with_on_off' command with args: '(254, 600.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0xfebb: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=162 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xfebb:11:0x0008]: executed 'move_to_level_with_on_off' command with args: '(254, 600.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x84ef: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.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x0367: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=150 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0367:11:0x0008]: executed 'move_to_level_with_on_off' command with args: '(254, 600.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0xd76b: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=166 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xd76b:11:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x341b: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=168 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x341b:11:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x1c38: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=170 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1c38:11:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x4544: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=172 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4544:11:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0xfebb: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=174 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xfebb:11:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x0c4f: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=156 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0c4f:11:0x0008]: executed 'move_to_level_with_on_off' command with args: '(254, 600.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0xd76b: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.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xd76b:11:0x0300]: executed 'move_to_color_temp' command with args: '(234, 600.0)' kwargs: '{}' result: [10, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining1: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>], 'move_to_color_temp': [10, <Status.SUCCESS: 0>]}
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x341b: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.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x341b:11:0x0300]: executed 'move_to_color_temp' command with args: '(234, 600.0)' kwargs: '{}' result: [10, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining4: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>], 'move_to_color_temp': [10, <Status.SUCCESS: 0>]}
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x1c38: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.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1c38:11:0x0300]: executed 'move_to_color_temp' command with args: '(234, 600.0)' kwargs: '{}' result: [10, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining2: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>], 'move_to_color_temp': [10, <Status.SUCCESS: 0>]}
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x4544: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.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4544:11:0x0300]: executed 'move_to_color_temp' command with args: '(234, 600.0)' kwargs: '{}' result: [10, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining9: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>], 'move_to_color_temp': [10, <Status.SUCCESS: 0>]}
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x84ef:11:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x0c4f: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=188 command_id=Command.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0c4f:11:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x84ef: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.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x84ef:11:0x0300]: executed 'move_to_color_temp' command with args: '(234, 600.0)' kwargs: '{}' result: [10, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining7: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>], 'move_to_color_temp': [10, <Status.SUCCESS: 0>]}
2020-08-21 08:37:07 DEBUG (MainThread) [zigpy.zcl] [0x0c4f: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.Default_Response>
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0c4f:11:0x0300]: executed 'move_to_color_temp' command with args: '(234, 600.0)' kwargs: '{}' result: [10, <Status.SUCCESS: 0>]
2020-08-21 08:37:07 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining5: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>], 'move_to_color_temp': [10, <Status.SUCCESS: 0>]}
2020-08-21 08:37:11 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x515f:11:0x0008]: command failed: move_to_level_with_on_off exception: 
2020-08-21 08:37:11 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining3: turned on: {'move_to_level_with_on_off': TimeoutError()}
2020-08-21 08:37:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0367:11:0x0006]: command failed: on exception: 
2020-08-21 08:37:12 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining6: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': TimeoutError()}
2020-08-21 08:37:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xfebb:11:0x0300]: command failed: move_to_color_temp exception: 
2020-08-21 08:37:12 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining8: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>], 'move_to_color_temp': TimeoutError()}
2020-08-21 08:37:13 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining6: polling current state - from cache: False

I’ve been thinking more about this. I don’t think it is a distance issue as I have four separate light groups that occasionally have this issue. The Dining Room is probably 20 feet from my Deconz II USB stick, while my Family Room lamp (with 3 Hue bulbs) is 10 feet away. I do have my USB stick on an extension cable and raised it up a bit.

I have ordered a Xiaomi Aqara Plug to hopefully act as a repeater, which will arrive tomorrow. I also placed an order with Ikea for a TRÅDFRI Signal repeater. That won’t be here until the end of the month though. I will see if either of these help.

Should I report this as a bug to ZHA?

Is it possible that you had to try a few times to get all the lights together in a single ZHA group? In my case groups were often successfully created, but had a few lights missing from the group, with no way of adding them later. Other times it just worked as it should and all lights got added.

But it looked like the group-ids are reused when you delete an old group, and the old group id seemed to stick with some of the lights in the old group, causing them to turn on when I turned on a newer group.

Oh! I discovered I wasn’t having this problem this morning. Then I realized that I disabled Circadian Lighting mode last night!

So, this is a known issue with light groups. Apparently their status starts at OFF, then switches back to ON when Zigbee realizes that the light is transitioning to OFF (so, effectively its status just went from ON -> OFF -> ON again).

This happens when Circadian Lighting detects a new light turning on, it immediately starts adjusting the brightness/color temperature… which normally is precisely what I want it to do.

I am happy to learn this isn’t a bug with ZHA. I will remove my Zigbee bulb groups from Circadian Lighting until I can outsmart the problem another way. :wink:

I have documented a potential solution to this problem that allows you to keep using the Circadian Lighting component.