core: Aqara Opple 4 & 6 button remotes do not generate ZHA events

The problem

I took delivery of 2 Aqara Opple remotes today and tried paring them onto my Zigbee network. Both devices paired successfully and reported no errors in the logs. Neither device generates any ZHA events. The device info page shows them as configured and each time I press a button on the device the Last Seen: text shows the current time in the device view. I have seen various reports other other users also loosing ZHA events from these devices when upgrading to Home Assistant 2021.08 or later.

Happy to help debug this problem. Just tell me what I need to do.

What is version of Home Assistant Core has the issue?

core-2021.10.3

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Container

Integration causing the issue

ZHA

Link to integration documentation on our website

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

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2021-10-11 22:21:32 INFO (MainThread) [zigpy.application] New device 0x2657 (04:cf:8c:df:3c:7c:80:f3) joined the network
2021-10-11 22:21:32 DEBUG (MainThread) [zigpy.device] [0x2657] Scheduling initialization
2021-10-11 22:21:32 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 0 to ep 0, cluster 19: b'\xd3W&\xf3\x80|<\xdf\x8c\xcf\x04\x84'
2021-10-11 22:21:32 INFO (MainThread) [zigpy.device] [0x2657] Requesting 'Node Descriptor'
2021-10-11 22:21:32 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0x90 request
2021-10-11 22:21:32 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 0, profile: 0x0000, cluster_id: 0x0013, data: b'd35726f3807c3cdf8ccf0484'
2021-10-11 22:21:32 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (18, 145, 0, <DeconzAddressEndpoint address_mode=2 address=0x2657 endpoint=0>, 0, <ZDOCmd.Node_Desc_req: 0x0002>, 0, b'\x90W&', 2, 0)
2021-10-11 22:21:32 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 145]

2021-10-11 22:21:33 INFO (MainThread) [zigpy.device] [0x2657] Got Node Descriptor: NodeDescriptor(logical_type=<LogicalType.EndDevice: 2>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.AllocateAddress|MainsPowered: 132>, manufacturer_code=4447, maximum_buffer_size=127, maximum_incoming_transfer_size=100, server_mask=11264, maximum_outgoing_transfer_size=100, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=False, *is_coordinator=False, *is_end_device=True, *is_full_function_device=False, *is_mains_powered=True, *is_receiver_on_when_idle=False, *is_router=False, *is_security_capable=False)
2021-10-11 22:21:33 INFO (MainThread) [zigpy.device] [0x2657] Discovering endpoints
2021-10-11 22:21:33 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0x98 request
2021-10-11 22:21:33 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (18, 153, 0, <DeconzAddressEndpoint address_mode=2 address=0x2657 endpoint=0>, 0, <ZDOCmd.Active_EP_req: 0x0005>, 0, b'\x98W&', 2, 0)
2021-10-11 22:21:33 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 153]
2021-10-11 22:21:34 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0]
2021-10-11 22:21:34 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:34 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [56, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 1, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 1, 260, 0, b'\x18\x00\n\x05\x00B\x16lumi.remote.b486opcn01\x01\x00 \x11', 0, 175, 255, 231, 138, 86, 0, -45]
2021-10-11 22:21:34 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 1 to ep 1, cluster 0: b'\x18\x00\n\x05\x00B\x16lumi.remote.b486opcn01\x01\x00 \x11'
2021-10-11 22:21:34 DEBUG (MainThread) [zigpy.device] [0x2657] Received ZCL while uninitialized on endpoint id 1, cluster 0x0000 id, hdr: <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.Report_Attributes>, payload: b'\x05\x00B\x16lumi.remote.b486opcn01\x01\x00 \x11'
2021-10-11 22:21:34 DEBUG (MainThread) [zigpy.device] [0x2657] Uninitialized device command 'Command.Report_Attributes' args: [[Attribute(attrid=5, value=<TypeValue type=CharacterString, value=lumi.remote.b486opcn01>), Attribute(attrid=1, value=<TypeValue type=uint8_t, value=17>)]]
2021-10-11 22:21:34 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 1, profile: 0x0104, cluster_id: 0x0000, data: b'18000a050042166c756d692e72656d6f74652e623438366f70636e303101002011'
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0]
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,)
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 153: 00
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x99 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0x2657 endpoint=0>, status: 0x00
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0]
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [34, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 0, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 0, 0, 32773, b'\x98\x00W&\x06\x01\x02\x03\x04\x05\x06', 0, 175, 255, 231, 138, 86, 0, -46]
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 0 to ep 0, cluster 32773: b'\x98\x00W&\x06\x01\x02\x03\x04\x05\x06'
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 0, profile: 0x0000, cluster_id: 0x8005, data: b'9800572606010203040506'
2021-10-11 22:21:35 INFO (MainThread) [zigpy.device] [0x2657] Discovered endpoints: [1, 2, 3, 4, 5, 6]
2021-10-11 22:21:35 INFO (MainThread) [zigpy.device] [0x2657] Initializing endpoints [<Endpoint id=1 in=[] out=[] status=<Status.NEW: 0>>, <Endpoint id=2 in=[] out=[] status=<Status.NEW: 0>>, <Endpoint id=3 in=[] out=[] status=<Status.NEW: 0>>, <Endpoint id=4 in=[] out=[] status=<Status.NEW: 0>>, <Endpoint id=5 in=[] out=[] status=<Status.NEW: 0>>, <Endpoint id=6 in=[] out=[] status=<Status.NEW: 0>>]
2021-10-11 22:21:35 INFO (MainThread) [zigpy.endpoint] [0x2657:1] Discovering endpoint information
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0x9a request
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (19, 155, 0, <DeconzAddressEndpoint address_mode=2 address=0x2657 endpoint=0>, 0, <ZDOCmd.Simple_Desc_req: 0x0004>, 0, b'\x9aW&\x01', 2, 0)
2021-10-11 22:21:35 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 155]
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0]
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,)
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 155: 00
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x9b 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0x2657 endpoint=0>, status: 0x00
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0]
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [50, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 0, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 0, 0, 32772, b'\x9a\x00W&\x16\x01\x04\x01\x05\x01\x01\x03\x00\x00\x03\x00\x01\x00\x04\x03\x00\x06\x00\x08\x00\x00\x03', 0, 175, 252, 231, 138, 86, 0, -46]
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 0 to ep 0, cluster 32772: b'\x9a\x00W&\x16\x01\x04\x01\x05\x01\x01\x03\x00\x00\x03\x00\x01\x00\x04\x03\x00\x06\x00\x08\x00\x00\x03'
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 0, profile: 0x0000, cluster_id: 0x8004, data: b'9a0057261601040105010103000003000100040300060008000003'
2021-10-11 22:21:36 INFO (MainThread) [zigpy.endpoint] [0x2657:1] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=1, profile=260, device_type=261, device_version=1, input_clusters=[0, 3, 1], output_clusters=[3, 6, 8, 768])
2021-10-11 22:21:36 INFO (MainThread) [zigpy.endpoint] [0x2657:2] Discovering endpoint information
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0x9c request
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (19, 157, 0, <DeconzAddressEndpoint address_mode=2 address=0x2657 endpoint=0>, 0, <ZDOCmd.Simple_Desc_req: 0x0004>, 0, b'\x9cW&\x02', 2, 0)
2021-10-11 22:21:36 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 157]
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0]
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,)
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0]
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 157: 00
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x9d 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0x2657 endpoint=0>, status: 0x00
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [68, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 1, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 1, 260, 64704, b'\x1c_\x11\x01\n\xf7\x00A$\x01!\xdc\x0b\x03(\x19\x04!\xa8\x01\x05!G\x00\x06$\x04\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01d\x10\x00', 0, 175, 255, 231, 138, 86, 0, -47]
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 1 to ep 1, cluster 64704: b'\x1c_\x11\x01\n\xf7\x00A$\x01!\xdc\x0b\x03(\x19\x04!\xa8\x01\x05!G\x00\x06$\x04\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01d\x10\x00'
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy.device] [0x2657] Received ZCL while uninitialized on endpoint id 1, cluster 0xfcc0 id, hdr: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=True is_reply=True disable_default_response=True> manufacturer=4447 tsn=1 command_id=Command.Report_Attributes>, payload: b'\xf7\x00A$\x01!\xdc\x0b\x03(\x19\x04!\xa8\x01\x05!G\x00\x06$\x04\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01d\x10\x00'
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy.device] [0x2657] Uninitialized device command 'Command.Report_Attributes' args: [[Attribute(attrid=247, value=<TypeValue type=LVBytes, value=b'\x01!\xdc\x0b\x03(\x19\x04!\xa8\x01\x05!G\x00\x06$\x04\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01d\x10\x00'>)]]
2021-10-11 22:21:37 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 1, profile: 0x0104, cluster_id: 0xfcc0, data: b'1c5f11010af70041240121dc0b0328190421a8010521470006240400000000082111010a2100000c2001641000'
2021-10-11 22:21:38 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0]
2021-10-11 22:21:38 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:38 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [42, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 0, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 0, 0, 32772, b'\x9c\x00W&\x0e\x02\x04\x01\x03\x01\x01\x01\x03\x00\x02\x06\x00\x03\x00', 0, 175, 255, 238, 138, 86, 0, -46]
2021-10-11 22:21:38 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 0 to ep 0, cluster 32772: b'\x9c\x00W&\x0e\x02\x04\x01\x03\x01\x01\x01\x03\x00\x02\x06\x00\x03\x00'
2021-10-11 22:21:38 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 0, profile: 0x0000, cluster_id: 0x8004, data: b'9c0057260e0204010301010103000206000300'
2021-10-11 22:21:38 INFO (MainThread) [zigpy.endpoint] [0x2657:2] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=2, profile=260, device_type=259, device_version=1, input_clusters=[3], output_clusters=[6, 3])
2021-10-11 22:21:38 INFO (MainThread) [zigpy.endpoint] [0x2657:3] Discovering endpoint information
2021-10-11 22:21:38 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0x9e request
2021-10-11 22:21:38 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (19, 159, 0, <DeconzAddressEndpoint address_mode=2 address=0x2657 endpoint=0>, 0, <ZDOCmd.Simple_Desc_req: 0x0004>, 0, b'\x9eW&\x03', 2, 0)
2021-10-11 22:21:38 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 159]
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0]
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,)
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 159: 00
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x9f 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0x2657 endpoint=0>, status: 0x00
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0]
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [42, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 0, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 0, 0, 32772, b'\x9e\x00W&\x0e\x03\x04\x01\x03\x01\x01\x02\x12\x00\x03\x00\x01\x06\x00', 0, 175, 255, 231, 138, 86, 0, -47]
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 0 to ep 0, cluster 32772: b'\x9e\x00W&\x0e\x03\x04\x01\x03\x01\x01\x02\x12\x00\x03\x00\x01\x06\x00'
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 0, profile: 0x0000, cluster_id: 0x8004, data: b'9e0057260e0304010301010212000300010600'
2021-10-11 22:21:39 INFO (MainThread) [zigpy.endpoint] [0x2657:3] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=3, profile=260, device_type=259, device_version=1, input_clusters=[18, 3], output_clusters=[6])
2021-10-11 22:21:39 INFO (MainThread) [zigpy.endpoint] [0x2657:4] Discovering endpoint information
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0xa0 request
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (19, 161, 0, <DeconzAddressEndpoint address_mode=2 address=0x2657 endpoint=0>, 0, <ZDOCmd.Simple_Desc_req: 0x0004>, 0, b'\xa0W&\x04', 2, 0)
2021-10-11 22:21:39 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 161]
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0]
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,)
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 161: 00
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0xa1 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0x2657 endpoint=0>, status: 0x00
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0]
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [42, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 0, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 0, 0, 32772, b'\xa0\x00W&\x0e\x04\x04\x01\x03\x01\x01\x02\x12\x00\x03\x00\x01\x06\x00', 0, 175, 255, 231, 138, 86, 0, -45]
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 0 to ep 0, cluster 32772: b'\xa0\x00W&\x0e\x04\x04\x01\x03\x01\x01\x02\x12\x00\x03\x00\x01\x06\x00'
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 0, profile: 0x0000, cluster_id: 0x8004, data: b'a00057260e0404010301010212000300010600'
2021-10-11 22:21:40 INFO (MainThread) [zigpy.endpoint] [0x2657:4] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=4, profile=260, device_type=259, device_version=1, input_clusters=[18, 3], output_clusters=[6])
2021-10-11 22:21:40 INFO (MainThread) [zigpy.endpoint] [0x2657:5] Discovering endpoint information
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0xa2 request
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (19, 163, 0, <DeconzAddressEndpoint address_mode=2 address=0x2657 endpoint=0>, 0, <ZDOCmd.Simple_Desc_req: 0x0004>, 0, b'\xa2W&\x05', 2, 0)
2021-10-11 22:21:40 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 163]
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0]
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,)
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0]
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 163: 00
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0xa3 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0x2657 endpoint=0>, status: 0x00
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [68, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 1, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 1, 260, 64704, b'\x1c_\x11\x02\n\xf7\x00A$\x01!\xdf\x0b\x03(\x19\x04!\xa8\x01\x05!G\x00\x06$\x04\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01d\x10\x00', 0, 175, 255, 231, 138, 86, 0, -48]
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 1 to ep 1, cluster 64704: b'\x1c_\x11\x02\n\xf7\x00A$\x01!\xdf\x0b\x03(\x19\x04!\xa8\x01\x05!G\x00\x06$\x04\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01d\x10\x00'
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy.device] [0x2657] Received ZCL while uninitialized on endpoint id 1, cluster 0xfcc0 id, hdr: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=True is_reply=True disable_default_response=True> manufacturer=4447 tsn=2 command_id=Command.Report_Attributes>, payload: b'\xf7\x00A$\x01!\xdf\x0b\x03(\x19\x04!\xa8\x01\x05!G\x00\x06$\x04\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01d\x10\x00'
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy.device] [0x2657] Uninitialized device command 'Command.Report_Attributes' args: [[Attribute(attrid=247, value=<TypeValue type=LVBytes, value=b'\x01!\xdf\x0b\x03(\x19\x04!\xa8\x01\x05!G\x00\x06$\x04\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01d\x10\x00'>)]]
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 1, profile: 0x0104, cluster_id: 0xfcc0, data: b'1c5f11020af70041240121df0b0328190421a8010521470006240400000000082111010a2100000c2001641000'
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0]
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [42, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 0, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 0, 0, 32772, b'\xa2\x00W&\x0e\x05\x04\x01\x03\x01\x01\x02\x12\x00\x03\x00\x01\x06\x00', 0, 175, 255, 238, 138, 86, 0, -49]
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 0 to ep 0, cluster 32772: b'\xa2\x00W&\x0e\x05\x04\x01\x03\x01\x01\x02\x12\x00\x03\x00\x01\x06\x00'
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 0, profile: 0x0000, cluster_id: 0x8004, data: b'a20057260e0504010301010212000300010600'
2021-10-11 22:21:41 INFO (MainThread) [zigpy.endpoint] [0x2657:5] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=5, profile=260, device_type=259, device_version=1, input_clusters=[18, 3], output_clusters=[6])
2021-10-11 22:21:41 INFO (MainThread) [zigpy.endpoint] [0x2657:6] Discovering endpoint information
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0xa4 request
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (19, 165, 0, <DeconzAddressEndpoint address_mode=2 address=0x2657 endpoint=0>, 0, <ZDOCmd.Simple_Desc_req: 0x0004>, 0, b'\xa4W&\x06', 2, 0)
2021-10-11 22:21:41 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 165]
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0]
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,)
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 165: 00
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0xa5 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0x2657 endpoint=0>, status: 0x00
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0]
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [42, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 0, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 0, 0, 32772, b'\xa4\x00W&\x0e\x06\x04\x01\x03\x01\x01\x02\x12\x00\x03\x00\x01\x06\x00', 0, 175, 255, 231, 138, 86, 0, -49]
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=False> from ep 0 to ep 0, cluster 32772: b'\xa4\x00W&\x0e\x06\x04\x01\x03\x01\x01\x02\x12\x00\x03\x00\x01\x06\x00'
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 0, profile: 0x0000, cluster_id: 0x8004, data: b'a40057260e0604010301010212000300010600'
2021-10-11 22:21:42 INFO (MainThread) [zigpy.endpoint] [0x2657:6] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=6, profile=260, device_type=259, device_version=1, input_clusters=[18, 3], output_clusters=[6])
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0xa6 request
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (22, 167, 0, <DeconzAddressEndpoint address_mode=2 address=0x2657 endpoint=1>, 260, 0, 1, b'\x00\xa6\x00\x04\x00\x05\x00', 2, 0)
2021-10-11 22:21:42 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 167]
2021-10-11 22:21:43 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0]
2021-10-11 22:21:43 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,)
2021-10-11 22:21:43 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0]
2021-10-11 22:21:43 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 167: 00
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0xa7 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0x2657 endpoint=1>, status: 0x00
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [62, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 1, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 1, 260, 0, b'\x18\xa6\x01\x04\x00\x00B\x04LUMI\x05\x00\x00B\x16lumi.remote.b486opcn01', 0, 175, 255, 231, 138, 86, 0, -49]
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 1, profile: 0x0104, cluster_id: 0x0000, data: b'18a60104000042044c554d4905000042166c756d692e72656d6f74652e623438366f70636e3031'
2021-10-11 22:21:44 INFO (MainThread) [zigpy.device] [0x2657] Read model 'lumi.remote.b486opcn01' and manufacturer 'LUMI' from <Endpoint id=1 in=[basic:0x0000, identify:0x0003, power:0x0001] out=[identify:0x0003, on_off:0x0006, level:0x0008, light_color:0x0300] status=<Status.ZDO_INIT: 1>>
2021-10-11 22:21:44 INFO (MainThread) [zigpy.device] [0x2657] Discovered basic device information for <Device model='lumi.remote.b486opcn01' manuf='LUMI' nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=True>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.application] Device is initialized <Device model='lumi.remote.b486opcn01' manuf='LUMI' nwk=0x2657 ieee=04:cf:8c:df:3c:7c:80:f3 is_initialized=True>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.remote.b486opcn01 (04:cf:8c:df:3c:7c:80:f3)
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.opple_remote.RemoteB486OPCN01V3'>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Fail because input cluster mismatch on at least one endpoint
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.opple_remote.RemoteB486OPCN01V2'>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 6}
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.opple_remote.RemoteB486OPCN01'>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Fail because input cluster mismatch on at least one endpoint
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 6}
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 6}
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 6}
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 6}
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 6}
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1, 2, 3, 4, 5, 6}
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'>
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 6}
2021-10-11 22:21:44 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x2657:04:cf:8c:df:3c:7c:80:f3 entering async_device_initialized - is_new_join: True
2021-10-11 22:21:44 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x2657:04:cf:8c:df:3c:7c:80:f3 has joined the ZHA zigbee network
2021-10-11 22:21:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2657](lumi.remote.b486opcn01): started configuration
2021-10-11 22:21:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2657:ZDO](lumi.remote.b486opcn01): 'async_configure' stage succeeded
2021-10-11 22:21:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2657:1:0x0000]: finished channel configuration
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0xa8 request
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (37, 169, 0, <DeconzAddressEndpoint address_mode=2 address=0x2657 endpoint=0>, 0, <ZDOCmd.Bind_req: 0x0021>, 0, b'\xa8\xf3\x80|<\xdf\x8c\xcf\x04\x01\x08\x00\x03/\x97\x06\xff\xff.!\x00\x01', 2, 0)
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0xaa request
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.device] [0x2657] Extending timeout for 0xac request
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.appdb] Error handling '_save_attribute' event with (04:cf:8c:df:3c:7c:80:f3, 1, 0, 4, 'LUMI') params: FOREIGN KEY constraint failed
2021-10-11 22:21:44 DEBUG (MainThread) [zigpy.appdb] Error handling '_save_attribute' event with (04:cf:8c:df:3c:7c:80:f3, 1, 0, 5, 'lumi.remote.b486opcn01') params: FOREIGN KEY constraint failed


2021-10-11 22:40:31 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2021-10-11 22:40:31 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [31, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 1, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, 4, 260, 18, b'\x18\x19\nU\x00!\x01\x00', 0, 175, 255, 35, 140, 86, 0, -52]
2021-10-11 22:40:31 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x2657>, ep: 4, profile: 0x0104, cluster_id: 0x0012, data: b'18190a5500210100'
2021-10-11 22:40:45 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0]

### Additional information

_No response_