8000 No zha_event for KE TRADFRI open/close remote · Issue #36484 · home-assistant/core · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

No zha_event for KE TRADFRI open/close remote #36484

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
perosb opened this issue Jun 5, 2020 · 15 comments · Fixed by #36489
Closed

No zha_event for KE TRADFRI open/close remote #36484

perosb opened this issue Jun 5, 2020 · 15 comments · Fixed by #36489
Assignees

Comments

@perosb
Copy link
Contributor
perosb commented Jun 5, 2020

The problem

Remote doesn't send any events even after re-pair, reset re-add. This is the remote https://zigbee.blakadder.com/Ikea_E1766.html (not confirmed there to work with zha)

Other type of remote works (https://zigbee.blakadder.com/Ikea_E1810.html)

Environment

Docker
Home Assistant 0.111.0b0 using Silicon Labs EZSP

  • Home Assistant Core release with the issue:
  • Last working Home Assistant Core release (if known):
  • Operating environment (Home Assistant/Supervised/Docker/venv):
  • Integration causing this issue:
  • Link to integration documentation on our website:

Problem-relevant configuration.yaml

Traceback/Error logs

2020-06-05 16:20:42 DEBUG (MainThread) [bellows.ezsp] Send command permitJoining: (60,)
2020-06-05 16:20:42 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'05da218a685af87e'
2020-06-05 16:20:42 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'51daa18a540a497e'
2020-06-05 16:20:42 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:20:42 DEBUG (MainThread) [bellows.ezsp] Application frame 34 (permitJoining) received: b'00'
2020-06-05 16:20:46 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2020-06-05 16:20:46 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'16db21ad7c0b7e'
2020-06-05 16:20:46 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'62dba1adef177e'
2020-06-05 16:20:46 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:20:46 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2020-06-05 16:20:47 WARNING (Thread-42) [pychromecast.socket_client] [Ellies(192.168.1.3):8009] Heartbeat timeout, resetting connection
2020-06-05 16:20:52 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'72dbb18b562be5f7a012a2db55e889a5989ab57e'
2020-06-05 16:20:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:20:52 DEBUG (MainThread) [bellows.ezsp] Application frame 35 (childJoinHandler) received: b'0201f045f986e8feffbd1bec04'
2020-06-05 16:20:52 DEBUG (MainThread) [bellows.zigbee.application] Received childJoinHandler frame with [2, <Bool.true: 1>, 0x45f0, ec:1b:bd:ff:fe:e8:86:f9, <EmberNodeType.SLEEPY_END_DEVICE: 4>]
2020-06-05 16:20:52 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'02dbb18ca46fec34b16ab598b1b993499c4e47987e'
2020-06-05 16:20:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:20:52 DEBUG (MainThread) [bellows.ezsp] Application frame 36 (trustCenterJoinHandler) received: b'f045f986e8feffbd1bec01000000'
2020-06-05 16:20:52 DEBUG (MainThread) [bellows.zigbee.application] Received trustCenterJoinHandler frame with [0x45f0, ec:1b:bd:ff:fe:e8:86:f9, <EmberDeviceUpdate.STANDARD_SECURITY_UNSECURED_JOIN: 1>, <EmberJoinDecision.USE_PRECONFIGURED_KEY: 0>, 0x0000]
2020-06-05 16:20:54 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'12dbb58b562ae5f7a012a2db55e889a59846747e'
2020-06-05 16:20:54 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:20:54 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'22dbb18b562bec3aa012a2db55e889a59898627e'
2020-06-05 16:20:54 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:20:54 DEBUG (MainThread) [bellows.ezsp] Application frame 35 (childJoinHandler) received: b'0200f045f986e8feffbd1bec04'
2020-06-05 16:20:54 DEBUG (MainThread) [bellows.zigbee.application] Received childJoinHandler frame with [2, <Bool.false: 0>, 0x45f0, ec:1b:bd:ff:fe:e8:86:f9, <EmberNodeType.SLEEPY_END_DEVICE: 4>]
2020-06-05 16:20:54 DEBUG (MainThread) [bellows.ezsp] Application frame 35 (childJoinHandler) received: b'0201f988f986e8feffbd1bec04'
2020-06-05 16:20:54 DEBUG (MainThread) [bellows.zigbee.application] Received childJoinHandler frame with [2, <Bool.true: 1>, 0x88f9, ec:1b:bd:ff:fe:e8:86:f9, <EmberNodeType.SLEEPY_END_DEVICE: 4>]
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'32dbb18cada2ec34b16ab598b1b993499c4e74567e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 36 (trustCenterJoinHandler) received: b'f988f986e8feffbd1bec01000000'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Received trustCenterJoinHandler frame with [0x88f9, ec:1b:bd:ff:fe:e8:86:f9, <EmberDeviceUpdate.STANDARD_SECURITY_UNSECURED_JOIN: 1>, <EmberJoinDecision.USE_PRECONFIGURED_KEY: 0>, 0x0000]
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'42dbb5caadacfd4ca62951c93b4f7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 98 (incomingSenderEui64Handler) received: b'f986e8feffbd1bec'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Received incomingSenderEui64Handler frame with [ec:1b:bd:ff:fe:e8:86:f9]
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'52dbb1ed502a15a159944a2dae5592e263bdde2312316b0a044e9a0f1480c01af0215ec9f77e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0400001300000008040000abfff3f988ffff0c81f988f986e8feffbd1bec80'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, <EmberApsFrame profileId=0 clusterId=19 sourceEndpoint=0 destinationEndpoint=0 options=1032 groupId=0 sequence=171>, 255, -13, 0x88f9, 255, 255, b'\x81\xf9\x88\xf9\x86\xe8\xfe\xff\xbd\x1b\xec\x80']
2020-06-05 16:20:55 INFO (MainThread) [bellows.zigbee.application] ZDO Device announce: 0x88f9, ec:1b:bd:ff:fe:e8:86:f9
2020-06-05 16:20:55 INFO (MainThread) [zigpy.application] Device 0x88f9 (ec:1b:bd:ff:fe:e8:86:f9) joined the network
2020-06-05 16:20:55 DEBUG (MainThread) [zigpy.zdo] [0x88f9:zdo] ZDO request ZDOCmd.Device_annce: [0x88f9, ec:1b:bd:ff:fe:e8:86:f9, 128]
2020-06-05 16:20:55 INFO (MainThread) [zigpy.device] [0x88f9] Requesting 'Node Descriptor'
2020-06-05 16:20:55 DEBUG (MainThread) [zigpy.util] Tries remaining: 2
2020-06-05 16:20:55 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xdc request
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'26d821d6adacfd4ca62951c9ab450b7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'63d8a1d60f0f7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=2 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=220>, 221, b'\xdc\xf9\x88')
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'37d9219c54d39db259964a25aa1593499c92faa83137ef84a57e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'74d9a19c54aa95f27e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0080'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'04d9b1ed542a15b0d9944a65ab5592e563bdde2312317657fd3feb8bbcfe43b6b99fde6fa3adc7db792a7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'14d9b19754d39db259964a25aa1593499ccefaabed33027e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000000280000040010000acfff3f988ffff11dc00f9880240807c11525200002c520000'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32770 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=172>, 255, -13, 0x88f9, 255, 255, b'\xdc\x00\xf9\x88\x02@\x80|\x11RR\x00\x00,R\x00\x00']
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880000020000004001000080dd0000'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=2 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=128>, 221, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:55 INFO (MainThread) [zigpy.device] [0x88f9] Node Descriptor: <Optional byte1=2 byte2=64 mac_capability_flags=128 manufacturer_code=4476 maximum_buffer_size=82 maximum_incoming_transfer_size=82 server_mask=11264 maximum_outgoing_transfer_size=82 descriptor_capability_field=0>
2020-06-05 16:20:55 INFO (MainThread) [zigpy.device] [0x88f9] Discovering endpoints
2020-06-05 16:20:55 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2020-06-05 16:20:55 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xde request
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'42de21d6adacfd4ca62951c9ab3c207e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'25dea1d6f4aa7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=5 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=222>, 223, b'\xde\xf9\x88')
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'53df219c54d39db259914a25aa1593499c90f8a83337ef0cc87e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'36dfa19c54aba9067e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0081'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'46dfb1ed542a15b7d9944a65ab5592e463bdde2312316155fd3feb88fddab77e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'56dfb19754d39db259914a25aa1593499ccff8abed3e8c7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000000580000040010000adfff3f988ffff06de00f9880101'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32773 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=173>, 255, -13, 0x88f9, 255, 255, b'\xde\x00\xf9\x88\x01\x01']
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880000050000004001000081df0000'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=5 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=129>, 223, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:55 INFO (MainThread) [zigpy.device] [0x88f9] Discovered endpoints: [1]
2020-06-05 16:20:55 INFO (MainThread) [zigpy.endpoint] [0x88f9:1] Discovering endpoint information
2020-06-05 16:20:55 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2020-06-05 16:20:55 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xe0 request
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'66dc21d6adacfd4ca62951c9ab120f7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'67dca1d6193e7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=4 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=224>, 225, b'\xe0\xf9\x88\x01')
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'77dd219c54d39db259904a25aa1593499caec6af0d37ef8a2c437e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'70dda19c54a83a177e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0082'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'00ddb1ed542a15b6d9944a65ab5592e763bdde2312314e6bfd3febadfd7a3ea4e9ccd96f8ffec7d8d5db69ac4623b9908a3ca6ea7182479844260ab1e271380c135e7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'10ddb19754d39db259904a25aa1593499cccc6abedd4e77e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000000480000040010000aefff3f988ffff29e000f98824010401030201070000010003000900200000107cfc070300040006000800190002010010'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32772 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=174>, 255, -13, 0x88f9, 255, 255, b'\xe0\x00\xf9\x88$\x01\x04\x01\x03\x02\x01\x07\x00\x00\x01\x00\x03\x00\t\x00 \x00\x00\x10|\xfc\x07\x03\x00\x04\x00\x06\x00\x08\x00\x19\x00\x02\x01\x00\x10']
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880000040000004001000082e10000'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=4 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=130>, 225, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:55 INFO (MainThread) [zigpy.endpoint] [0x88f9:1] Discovered endpoint information: <Optional endpoint=1 profile=260 device_type=515 device_version=1 input_clusters=[0, 1, 3, 9, 32, 4096, 64636] output_clusters=[3, 4, 6, 8, 25, 258, 4096]>
2020-06-05 16:20:55 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xe2 request
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'02e221d6adacfd4ca62951c9ab297c7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'21e2a1d68e9f7e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=226>, 227, b'\x00\xe2\x00\x04\x00\x05\x00')
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7d33e3219c54d39db658944a24ab1593499cacc4aced2c678ffdc363f5e97e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'32e3a19c54a908207e'
2020-06-05 16:20:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:20:55 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0083'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'42e3b1ed542e14b259954b65ab5592e663bdde2312314e931fc76789fc3c3ca5a088db6f8fbdde8f87932dca146a8983065ecbc516ee2eeb290661d48d1f4c79a8777e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'52e3b19754d39db658944a24ab1593499ccdc4abede01a7e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010000010140010000affff3f988ffff2918e2010400004203024b45050000421954524144465249206f70656e2f636c6f73652072656d6f7465'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=175>, 255, -13, 0x88f9, 255, 255, b'\x18\xe2\x01\x04\x00\x00B\x03\x02KE\x05\x00\x00B\x19TRADFRI open/close remote']
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0000] 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-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880401000001014001000083e30000'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=131>, 227, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.endpoint] [0x88f9:1] Manufacturer: KE
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.endpoint] [0x88f9:1] Model: TRADFRI open/close remote
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for KE TRADFRI open/close remote (ec:1b:bd:ff:fe:e8:86:f9)
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1}
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.lutron.lzl4bwhl01remote.LutronLZL4BWHL01Remote2'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.osram.a19twhite.A19TunableWhite'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoi
8000
nt list mismatch: {3} {1}
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl020.PhilipsRWL020'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1}
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1}
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1}
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1}
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.mija.smoke.MijiaHoneywellSmokeDetectorSensor'>
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2020-06-05 16:20:56 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x88f9:ec:1b:bd:ff:fe:e8:86:f9 entering async_device_initialized - is_new_join: True
2020-06-05 16:20:56 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x88f9:ec:1b:bd:ff:fe:e8:86:f9 has joined the ZHA zigbee network
2020-06-05 16:20:56 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x88f9](TRADFRI open/close remote): started configuration
2020-06-05 16:20:56 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:ZDO](TRADFRI open/close remote): 'async_configure' stage succeeded
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xe4 request
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xe6 request
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:56 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xe8 request
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'26e021d6adacfd4ca62951c9ab07537e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'63e0a1d6630b7e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'37e121d6adacfd4ca62951c9ab57f17e'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=228>, 229, b'\xe4\xf9\x86\xe8\xfe\xff\xbd\x1b\xec\x01\x01\x00\x03i9\x05\r\x00o\r\x00\x01')
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'74e1a1d61eb17e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'40e621d6adacfd4ca62951c9abf4be7e'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=32 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=230>, 231, b'\x00\xe6\x02\x00\x00#\x903\x00\x00')
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'05e6a1d6afe07e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'51e7219c54d39db259b54a25aa1593499caac2bd0937e1630339de92107f3ea7e8a4e76a82ffa8d6d5d3a7997e'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=232>, 233, b'\xe8\xf9\x86\xe8\xfe\xff\xbd\x1b\xec\x01\x00\x10\x03i9\x05\r\x00o\r\x00\x01')
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'16e7a19c54aec2687e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'62e4219c54d39db658b44a24ab1593499ca8c0a1ed28658bfde5f3bafc7d5e937c7e'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0084'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'27e4a19c54af56b77e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'73e5219c54d39db259b54a25aa1593499ca6cebd0537e1630339de92107f3fb7e8a4e76a82ffa8d6d5d3c22a7e'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0085'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'30e5a19c54ac1e407e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0086'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'04ea21ad78517e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'41eaa1adb1107e'
2020-06-05 16:20:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:20:56 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'51eab1ed542a1593d9944a65ab5592f963bdde231231656ffd4be07e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000002180000040010000b0fff3f988ffff02e400'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=176>, 255, -13, 0x88f9, 255, 255, b'\xe4\x00']
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'61eab19754d39db259b54a25aa1593499ccac2abed37a57e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880000210000004001000084e50000'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=132>, 229, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'71eab1ed542e149259954b65ab5592f863bdde23123163931bc263b5697e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004012000010140010000b1fff3f988ffff0418e60400'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=32 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=177>, 255, -13, 0x88f9, 255, 255, b'\x18\xe6\x04\x00']
2020-06-05 16:20:57 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0020] 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.Write_Attributes_rsp>
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'01eab19754d39db658b44a24ab1593499ccbc0abed06697e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880401200001014001000085e70000'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=32 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=133>, 231, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'11eab1ed542a1593d9944a65ab5592fb63bdde2312316563fdbf177e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'21eab19754d39db259b54a25aa1593499cc8ceabedb4da7e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:20:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0001]: bound 'power' cluster: Status.SUCCESS
2020-06-05 16:20:57 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xea request
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000002180000040010000b2fff3f988ffff02e800'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=178>, 255, -13, 0x88f9, 255, 255, b'\xe8\x00']
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880000210000004001000086e90000'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=134>, 233, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7d33eb21d6adacfd4ca62951c9ab62767e'
2020-06-05 16:20:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0020]: 3300.0s check-in interval set: [[<WriteAttributesStatusRecord status=Status.SUCCESS>]]
2020-06-05 16:20:57 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xec request
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x1000]: bound 'lightlink' cluster: Status.SUCCESS
2020-06-05 16:20:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x1000]: finished channel configuration
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'32eba1d690757e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'24e821d6adacfd4ca62951c9ab963d7e'
2020-06-05 16:20:57 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xee request
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'43e8a1d6fde47e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'35e921d6adacfd4ca62951c9abc69f7e'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=234>, 235, b'\x00\xea\x06\x00 \x00 \x10\x0e0*\x01')
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=236>, 237, b'\xec\xf9\x86\xe8\xfe\xff\xbd\x1b\xec\x01 \x00\x03i9\x05\r\x00o\r\x00\x01')
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'54e9a1d6805e7e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'46ee219c54d39db658954a24ab1593499ca4cca7ed24618bddc64399f24e15a6c3447e'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=238>, 239, b'\xee\xf9\x86\xe8\xfe\xff\xbd\x1b\xec\x01\x00\x00\x03i9\x05\r\x00o\r\x00\x01')
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'65eea19c54add10b7e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'57ef219c54d39db259b54a25aa1593499ca2cabd0137e1630339de92107f1fa7e8a4e76a82ffa8d6d5d310397e'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0087'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'76efa19c54a25ed17e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0088'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'60ec219c54d39db259b54a25aa1593499ca0c8bd0337e1630339de92107f3fa7e8a4e76a82ffa8d6d5d30cd87e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'07eca19c54a3a01e7e'
2020-06-05 16:20:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:20:57 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0089'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'17ecb1ed542e14b359954b65ab5592fd63bdde231231638317c163409e7e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'27ecb19754d39db658954a24ab1593499cc9ccabed9fd27e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010100010140010000b4fff3f988ffff0408ea0700'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=180>, 255, -13, 0x88f9, 255, 255, b'\x08\xea\x07\x00']
2020-06-05 16:20:58 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=234 command_id=Command.Configure_Reporting_rsp>
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'37ecb1ed542a1593d9944a65ab5592fc63bdde2312316567fd67327e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880401010001014001000087eb0000'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=135>, 235, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'47ecb19754d39db259b54a25aa1593499cc6caabedbd517e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000002180000040010000b5fff3f988ffff02ec00'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=181>, 255, -13, 0x88f9, 255, 255, b'\xec\x00']
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880000210000004001000088ed0000'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=136>, 237, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'57ecb1ed542a1593d9944a65ab5592ff63bdde2312316565fde8077e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:20:58 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0001]: reporting 'battery_voltage' attr on 'power' cluster: 3600/10800/1: Result: '[[<ConfigureReportingResponseRecord status=Status.SUCCESS>]]'
2020-06-05 16:20:58 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xf0 request
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'67ecb19754d39db259b54a25aa1593499cc7c8abeda83e7e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000002180000040010000b6fff3f988ffff02ee00'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=182>, 255, -13, 0x88f9, 255, 255, b'\xee\x00']
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'77ed21d6adacfd4ca62951c9ab1b5d7e'
2020-06-05 16:20:58 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0020]: bound 'poll_control' cluster: Status.SUCCESS
2020-06-05 16:20:58 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0020]: finished channel configuration
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880000210000004001000089ef0000'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=137>, 239, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:58 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xf2 request
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'70eda1d6a1217e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'00f221d6adacfd4ca62951c9ab94ea7e'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:58 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0000]: bound 'basic' cluster: Status.SUCCESS
2020-06-05 16:20:58 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0000]: finished channel configuration
2020-06-05 16:20:58 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xf4 request
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'01f2a1d6fab27e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7d31f321d6adacfd4ca62951c9abc4487e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'12f3a1d64df97e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=240>, 241, b'\x00\xf0\x06\x00!\x00 \x10\x0e0*\x01')
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'22f0219c54d39db658954a24ab1593499cbed6a7ed3e618bdcc64399f24e15a6a5fb7e'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=242>, 243, b'\xf2\xf9\x86\xe8\xfe\xff\xbd\x1b\xec\x01\x06\x00\x03i9\x05\r\x00o\r\x00\x01')
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=244>, 245, b'\x00\xf4\x00\x07\x00')
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'23f0a19c54a13c847e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'008b'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'33f1219c54d39db259b54a25aa1593499cbcd4bd1f37e1630339de92107f39a7e8a4e76a82ffa8d6d5d3d1457e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'34f1a19c54a634f77e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'44f6219c54d39db658944a24ab1593499cbad2aeed3a678cfdeed07e'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'008c'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'45f6a19c54a7433e7e'
2020-06-05 16:20:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:20:58 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'008d'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'55f6b1ed542e14b359954b65ab5592fe63bdde23123163830dc163fe5e7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010100010140010000b7fff3f988ffff0408f00700'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=183>, 255, -13, 0x88f9, 255, 255, b'\x08\xf0\x07\x00']
2020-06-05 16:20:59 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=240 command_id=Command.Configure_Reporting_rsp>
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'65f6b19754d39db658954a24ab1593499cc5d6abed49757e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f988040101000101400100008bf10000'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=139>, 241, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'75f6b1ed542a1593d9944a65ab5592f163bdde2312316579fdad617e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'05f6b19754d39db259b54a25aa1593499cc2d4abed32f57e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000002180000040010000b8fff3f988ffff02f200'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=184>, 255, -13, 0x88f9, 255, 255, b'\xf2\x00']
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f988000021000000400100008cf30000'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=140>, 243, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0001]: reporting 'battery_percentage_remaining' attr on 'power' cluster: 3600/10800/1: Result: '[[<ConfigureReportingResponseRecord status=Status.SUCCESS>]]'
2020-06-05 16:20:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0001]: finished channel configuration
2020-06-05 16:20:59 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xf6 request
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'15f6b1ed542e14b259954b65ab5592f063bdde2312316f9309c76489fc4e3cc2937e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'25f6b19754d39db658944a24ab1593499cc3d2abedaa2f7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'53f721d6adacfd4ca62951c9ab198a7e'
2020-06-05 16:20:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS
2020-06-05 16:20:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0006]: finished channel configuration
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010000010140010000b9fff3f988ffff0818f4010700003003'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=185>, 255, -13, 0x88f9, 255, 255, b'\x18\xf4\x01\x07\x00\x000\x03']
2020-06-05 16:20:59 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=244 command_id=Command.Read_Attributes_rsp>
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f988040100000101400100008df50000'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFra
8000
me profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=141>, 245, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:20:59 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xf8 request
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'36f7a1d66c867e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'64f421d6adacfd4ca62951c9abedc17e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'47f4a1d601177e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=246>, 247, b'\xf6\xf9\x86\xe8\xfe\xff\xbd\x1b\xec\x01\x08\x00\x03i9\x05\r\x00o\r\x00\x01')
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'75f5219c54d39db259b54a25aa1593499cb8d0bd1b37e1630339de92107f37a7e8a4e76a82ffa8d6d5d35bb77e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'50f5a19c54a4c40a7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:20:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0000]: initializing channel: from_cache: False
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=248>, 249, b'\xf8\xf9\x86\xe8\xfe\xff\xbd\x1b\xec\x01\x06\x00\x03i9\x05\r\x00o\r\x00\x01')
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'008e'
2020-06-05 16:20:59 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xfa request
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'06fa219c54d39db259b54a25aa1593499cb6debd1537e1630339de92107f39a7e8a4e76a82ffa8d6d5d3525e7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'61faa19c54a5dbfe7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'008f'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'17fb21d6adacfd4ca62951c9ab508b7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'72fba1d6bd8a7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=250>, 251, b'\xfa\xf9\x86\xe8\xfe\xff\xbd\x1b\xec\x01\x19\x00\x03i9\x05\r\x00o\r\x00\x01')
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'20f8219c54d39db259b54a25aa1593499cb4dcbd1737e1630339de92107f26a7e8a4e76a82ffa8d6d5d3d6237e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'03f8a19c54baa8fb7e'
2020-06-05 16:20:59 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:20:59 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0090'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'13f8b1ed542a1593d9944a65ab5592f363bdde231231657dfd701d7e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000002180000040010000bafff3f988ffff02f600'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=186>, 255, -13, 0x88f9, 255, 255, b'\xf6\x00']
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'23f8b19754d39db259b54a25aa1593499cc0d0abedd2837e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f988000021000000400100008ef70000'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=142>, 247, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'33f8b1ed542a1593d9944a65ab5592f263bdde2312316573fd0bdf7e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000002180000040010000bbfff3f988ffff02f800'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=187>, 255, -13, 0x88f9, 255, 255, b'\xf8\x00']
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'43f8b19754d39db259b54a25aa1593499cc1deabeda9fb7e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'53f8b1ed542a1593d9944a65ab5592f563bdde2312316571fd29df7e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f988000021000000400100008ff90000'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=143>, 249, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0008]: bound 'level' cluster: Status.SUCCESS
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0008]: finished channel configuration
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0000002180000040010000bcfff3f988ffff02fa00'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=188>, 255, -13, 0x88f9, 255, 255, b'\xfa\x00']
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'63f8b19754d39db259b54a25aa1593499cdedcabed05697e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0006]: finished channel configuration
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880000210000004001000090fb0000'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=144>, 251, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0019]: bound 'ota' cluster: Status.SUCCESS
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0019]: finished channel configuration
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0001]: 'async_configure' stage succeeded
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0020]: 'async_configure' stage succeeded
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x1000]: 'async_configure' stage succeeded
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0000]: 'async_configure' stage succeeded
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0006]: 'async_configure' stage succeeded
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0008]: 'async_configure' stage succeeded
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0006]: 'async_configure' stage succeeded
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0019]: 'async_configure' stage succeeded
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x88f9](TRADFRI open/close remote): completed configuration
2020-06-05 16:21:00 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x88f9](TRADFRI open/close remote): stored in registry: ZhaDeviceEntry(name='\x02KE TRADFRI open/close remote', ieee='ec:1b:bd:ff:fe:e8:86:f9', last_seen=1591374060.7386498)
2020-06-05 16:21:00 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xfc request
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'37f921d6adacfd4ca62951c9ab7b097e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'74f9a1d6f4737e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=3 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=252>, 253, b'\x01\xfc@\x02\x00')
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'40fe219c54d39db658974a24ab1593499cb2daaeec322789fde8e87e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'05fea19c54bbf8be7e'
2020-06-05 16:21:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:21:00 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0091'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'15feb1ed542e14b159954b65ab5592f463bdde231231628301cd238907077e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'25feb19754d39db658974a24ab1593499cdfdaabedef3d7e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010300010140010000bdfff3f988ffff0508fc0b4000'
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=3 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=189>, 255, -13, 0x88f9, 255, 255, b'\x08\xfc\x0b@\x00']
2020-06-05 16:21:01 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0003] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=252 command_id=Command.Default_Response>
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880401030001014001000091fd0000'
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=3 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=145>, 253, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0003]: executed 'trigger_effect' command with args: '(2, 0)' kwargs: '{}' result: [64, <Status.SUCCESS: 0>]
2020-06-05 16:21:01 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x88f9](TRADFRI open/close remote): started initialization
2020-06-05 16:21:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:ZDO](TRADFRI open/close remote): 'async_initialize' stage succeeded
2020-06-05 16:21:01 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0xfe request
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:21:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0020]: initializing channel: from_cache: False
2020-06-05 16:21:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x1000]: initializing channel: from_cache: False
2020-06-05 16:21:01 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0x00 request
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:21:01 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0x02 request
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'53ff21d6adacfd4ca62951c9ab02227e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'36ffa1d6c5277e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'64fc21d6adacfd4ca62951c9abf6697e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'47fca1d6a8b67e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'75fd21d6adacfd4ca62951c9aba6cb7e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'50fda1d6d50c7e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=254>, 255, b'\x00\xfe\x001\x00!\x00 \x003\x00')
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=0>, 1, b'\x00\x00\x00\x07\x00')
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'0682219c54d39db658954a24ab1593499cb0d8a0ed3067bafde763a9fc4d3f7b407e'
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=2>, 3, b'\x00\x02\x00\x00\x00')
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6182a19c54b807c97e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'1783219c54d39db658944a24ab1593499c4e26aeedce678cfd974d7e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7283a19c54b969dd7e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'2080219c54d39db658924a24ab1593499c4c24aeedcc678bfd71287e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0380a19c54bef7d47e'
2020-06-05 16:21:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0092'
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0093'
2020-06-05 16:21:01 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0094'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1380b1ed502a158459944a2daa5592f763bdde231231648949c7721b7e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0400003600000008000000befff3f988ffff0302b401'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, <EmberApsFrame profileId=0 clusterId=54 sourceEndpoint=0 destinationEndpoint=0 options=8 groupId=0 sequence=190>, 255, -13, 0x88f9, 255, 255, b'\x02\xb4\x01']
2020-06-05 16:21:02 DEBUG (MainThread) [zigpy.zdo] [0x88f9:zdo] ZDO request ZDOCmd.Mgmt_Permit_Joining_req: [180, <Bool.true: 1>]
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2380b1ed502e14b15995b52dab5592f663bdde231231648affc789767e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'040401030001ff08010000bffff3f988ffff03010201'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, <EmberApsFrame profileId=260 clusterId=3 sourceEndpoint=1 destinationEndpoint=255 options=264 groupId=0 sequence=191>, 255, -13, 0x88f9, 255, 255, b'\x01\x02\x01']
2020-06-05 16:21:02 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0003] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=2 command_id=1>
2020-06-05 16:21:02 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0003] ZCL request 0x0001: []
2020-06-05 16:21:02 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0003] No handler for cluster command 1
2020-06-05 16:21:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0003]: received 'identify_query' command with [] args on cluster_id '3' tsn '2'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3380b1ed542e14b359954b65ab55928963bdde231231749303c752897a5f3fa7cba9fe6f8fdfc7e8d5547eb87e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4380b19754d39db658954a24ab1593499cdcd8abedd65b7e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010100010140010000c0fff3f988ffff1318fe0131008621000020642000002000330086'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=192>, 255, -13, 0x88f9, 255, 255, b'\x18\xfe\x011\x00\x86!\x00\x00 d \x00\x00 \x003\x00\x86']
2020-06-05 16:21:02 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0001] 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-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5380b1ed542e14b259954b65ab55928863bdde2312316f93fdc76489fc4e3cad5b7e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880401010001014001000092ff0000'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=146>, 255, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010000010140010000c1fff3f988ffff081800010700003003'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=193>, 255, -13, 0x88f9, 255, 255, b'\x18\x00\x01\x07\x00\x000\x03']
2020-06-05 16:21:02 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0000] 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-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6380b19754d39db658944a24ab1593499cdd26abed56727e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7380b1ed542e14b459954b65ab55928b63bdde2312316193ffc763897a0d177e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0380b19754d39db658924a24ab1593499cda24abed74cc7e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:21:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0001]: initializing channel: from_cache: False
2020-06-05 16:21:02 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0x04 request
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880401000001014001000093010000'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=147>, 1, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010600010140010000c2fff3f988ffff06180201000086'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=194>, 255, -13, 0x88f9, 255, 255, b'\x18\x02\x01\x00\x00\x86']
2020-06-05 16:21:02 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0006] 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-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880401060001014001000094030000'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=148>, 3, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'318121d6adacfd4ca62951c9ab6b7a7e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1481a1d6dc087e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:21:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0000]: initializing channel: from_cache: False
2020-06-05 16:21:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0006]: initializing channel: from_cache: False
2020-06-05 16:21:02 DEBUG (MainThread) [zigpy.device] [0x88f9] Extending timeout for 0x06 request
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for ec:1b:bd:ff:fe:e8:86:f9/0x88f9
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (ec:1b:bd:ff:fe:e8:86:f9, True)
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=4>, 5, b'\x00\x04\x00 \x00!\x00')
2020-06-05 16:21:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0008]: initializing channel: from_cache: False
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'428621d6adacfd4ca62951c9abcd987e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2586a1d603c57e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:21:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0006]: initializing channel: from_cache: False
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'5387219c54d39db658954a24ab1593499c4a22acedca67abfde7632e017e'
2020-06-05 16:21:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0019]: initializing channel: from_cache: False
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=6>, 7, b'\x00\x06\x00\x00\x00')
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3687a19c54bfecac7e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'6484219c54d39db658924a24ab1593499c4820aeedc8678bfdc09f7e'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0095'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4784a19c54bc32217e'
2020-06-05 16:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0096'
2020-06-05 16:21:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5784b1ed542e14b359954b65ab55928a63bdde2312316a93f9c74389fc5e3f86ebcdfe0bc53f7e'
2020-06-05 16:21:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:21:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6784b19754d39db658954a24ab1593499cdb22abed1f297e'
2020-06-05 16:21:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:21:04 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010100010140010000c3fff3f988ffff0d18040120000020002100002064'
2020-06-05 16:21:04 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=195>, 255, -13, 0x88f9, 255, 255, b'\x18\x04\x01 \x00\x00 \x00!\x00\x00 d']
2020-06-05 16:21:04 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0001] 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-06-05 16:21:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7784b1ed542e14b459954b65ab55928d63bdde2312316193fbc763897aeedd7e'
2020-06-05 16:21:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:21:04 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880401010001014001000095050000'
2020-06-05 16:21:04 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=149>, 5, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0784b19754d39db658924a24ab1593499cd820abedf4137e'
2020-06-05 16:21:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:21:04 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010600010140010000c4fff3f988ffff06180601000086'
2020-06-05 16:21:04 DEBUG (MainThre
8000
ad) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=196>, 255, -13, 0x88f9, 255, 255, b'\x18\x06\x01\x00\x00\x86']
2020-06-05 16:21:04 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0006] 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-06-05 16:21:04 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880401060001014001000096070000'
2020-06-05 16:21:04 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=150>, 7, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0001]: 'async_initialize' stage succeeded
2020-06-05 16:21:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0020]: 'async_initialize' stage succeeded
2020-06-05 16:21:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x1000]: 'async_initialize' stage succeeded
2020-06-05 16:21:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0000]: 'async_initialize' stage succeeded
2020-06-05 16:21:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0006]: 'async_initialize' stage succeeded
2020-06-05 16:21:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0008]: 'async_initialize' stage succeeded
2020-06-05 16:21:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0006]: 'async_initialize' stage succeeded
2020-06-05 16:21:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x88f9:1:0x0019]: 'async_initialize' stage succeeded
2020-06-05 16:21:04 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x88f9](TRADFRI open/close remote): power source: Battery or Unknown
2020-06-05 16:21:04 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x88f9](TRADFRI open/close remote): completed initialization
2020-06-05 16:21:06 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2020-06-05 16:21:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'718521ad313b7e'
2020-06-05 16:21:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1085a1ad05c57e'
2020-06-05 16:21:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:21:07 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2020-06-05 16:21:10 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2085b1ed502a15b459944a2dab55928c63bdde2312316e8800396788fd673fa7e1c57e'
2020-06-05 16:21:10 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:21:10 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0400000600000008010000c5fff3f988ffff0903fdff040101190000'
2020-06-05 16:21:10 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, <EmberApsFrame profileId=0 clusterId=6 sourceEndpoint=0 destinationEndpoint=0 options=264 groupId=0 sequence=197>, 255, -13, 0x88f9, 255, 255, b'\x03\xfd\xff\x04\x01\x01\x19\x00\x00']
2020-06-05 16:21:10 DEBUG (MainThread) [zigpy.zdo] [0x88f9:zdo] ZDO request ZDOCmd.Match_Desc_req: [0xfffd, 260, [25], []]
2020-06-05 16:21:10 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=0 clusterId=32774 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=3>, 8, b'\x03\x00\x00\x00\x01\x01')
2020-06-05 16:21:10 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'038a219c54d39db25992ca25aa1593499c4d2fadeece678bfcc77a3f7e'
2020-06-05 16:21:10 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'318aa19c54bd25d57e'
2020-06-05 16:21:10 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:21:10 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0097'
2020-06-05 16:21:10 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'418ab19754d39db25992ca25aa1593499cd92fabeddc8f7e'
2020-06-05 16:21:10 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-06-05 16:21:10 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880000068000004001000097080000'
2020-06-05 16:21:10 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=0 clusterId=32774 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=151>, 8, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'518ab1ed542e14ab59954b65aa55928f63bdde231231698afec762f5edbb2e96edccfc6e8f35aa7e'
2020-06-05 16:21:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-06-05 16:21:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004011900010140000000c6fff3f988ffff0e010301017c11c511310601220100'
2020-06-05 16:21:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=25 sourceEndpoint=1 destinationEndpoint=1 options=64 groupId=0 sequence=198>, 255, -13, 0x88f9, 255, 255, b'\x01\x03\x01\x01|\x11\xc5\x111\x06\x01"\x01\x00']
2020-06-05 16:21:12 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0019] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=3 command_id=1>
2020-06-05 16:21:12 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0019] ZCL request 0x0001: [1, 4476, 4549, 570492465, 1]
2020-06-05 16:21:12 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0019] OTA query_next_image handler for 'KE TRADFRI open/close remote': field_control=1, manufacture_id=4476, image_type=4549, current_file_version=570492465, hardware_version=1
2020-06-05 16:21:12 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0019] OTA image version: 570492465, size: 179838. Update needed: False
2020-06-05 16:21:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x88f9, <EmberApsFrame profileId=260 clusterId=25 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=3>, 9, b'\x19\x03\x02\x98')
2020-06-05 16:21:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'168b219c54d39db6588d4a24ab1593499c4d2eaff4cd657d332c747e'
2020-06-05 16:21:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'628ba19c54b2c01f7e'
2020-06-05 16:21:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:21:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0098'
2020-06-05 16:21:13 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'728bb19754d39db6588d4a24ab1593499cd62eabed76167e'
2020-06-05 16:21:13 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:21:13 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00f9880401190001014001000098090000'
2020-06-05 16:21:13 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 35065, <EmberApsFrame profileId=260 clusterId=25 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=152>, 9, <EmberStatus.SUCCESS: 0>, b'']
2020-06-05 16:21:17 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2020-06-05 16:21:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'208821ad70e57e'
2020-06-05 16:21:17 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0388a1adc7ef7e'
2020-06-05 16:21:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-06-05 16:21:17 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2020-06-05 16:21:27 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2020-06-05 16:21:27 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'318921ad2ac67e'
2020-06-05 16:21:27 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1489a1adba557e'
2020-06-05 16:21:27 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-06-05 16:21:27 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2020-06-05 16:21:28 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2489b1ed562e14b05895b529ab55928e63bede231231648af9c6f3d67e'
2020-06-05 16:21:28 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-06-05 16:21:28 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'020401020101ff0c010000c7fff0f988ffff03010400'
2020-06-05 16:21:28 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, <EmberApsFrame profileId=260 clusterId=258 sourceEndpoint=1 destinationEndpoint=255 options=268 groupId=0 sequence=199>, 255, -16, 0x88f9, 255, 255, b'\x01\x04\x00']
2020-06-05 16:21:28 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=4 command_id=0>
2020-06-05 16:21:28 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] ZCL request 0x0000: []
2020-06-05 16:21:28 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] No handler for cluster command 0
2020-06-05 16:21:37 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2020-06-05 16:21:37 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'438e21ad004b7e'
2020-06-05 16:21:37 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'358ea1ad7e3f7e'
2020-06-05 16:21:37 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-06-05 16:21:37 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''

Event button press #1 and #2:

2020-06-05 16:24:49 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'61a2b1ed562e14b05895b529ab55928577fcde231231648af4c6bbbb7e'
2020-06-05 16:24:49 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 16:24:49 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'020401020101ff0c010000ccebb2f988ffff03010900'
2020-06-05 16:24:49 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, <EmberApsFrame profileId=260 clusterId=258 sourceEndpoint=1 destinationEndpoint=255 options=268 groupId=0 sequence=204>, 235, -78, 0x88f9, 255, 255, b'\x01\t\x00']
2020-06-05 16:24:49 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=9 command_id=0>
2020-06-05 16:24:49 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] ZCL request 0x0000: []
2020-06-05 16:24:49 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] No handler for cluster command 0



2020-06-05 16:24:52 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'71a2b1ed562e14b05895b529ab559284638ede231231648af7c715c57e'
2020-06-05 16:24:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-06-05 16:24:52 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'020401020101ff0c010000cdffc0f988ffff03010a01'
2020-06-05 16:24:52 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, <EmberApsFrame profileId=260 clusterId=258 sourceEndpoint=1 destinationEndpoint=255 options=268 groupId=0 sequence=205>, 255, -64, 0x88f9, 255, 255, b'\x01\n\x01']
2020-06-05 16:24:52 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=10 command_id=1>
2020-06-05 16:24:52 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] ZCL request 0x0001: []
2020-06-05 16:24:52 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] No handler for cluster command 1

Additional information

Seems similar to this issue #31734

@probot-home-assistant
Copy link

zha documentation
zha source
(message by IssueLinks)

@probot-home-assistant
Copy link

Hey there @dmulcahey, @Adminiuga, mind taking a look at this issue as its been labeled with a integration (zha) you are listed as a codeowner for? Thanks!
(message by CodeOwnersMention)

@Adminiuga
Copy link
Contributor

Seems similar to this issue #31734

Nah, just need to add WindowsCovering client channel as a ZhaEvent channel, although I'd expect it to be the default. Will take a look

@perosb
Copy link
Contributor Author
perosb commented Jun 5, 2020

Is that the same as "bind group"?
image

The "bind" button doesn't get enabled when checking anything here tho..

@Adminiuga
Copy link
Contributor

nah, not that. Need to take a look at the sources. HA is getting commands from the remote,

2020-06-05 16:24:49 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, <EmberApsFrame profileId=260 clusterId=258 sourceEndpoint=1 destinationEndpoint=255 options=268 groupId=0 sequence=204>, 235, -78, 0x88f9, 255, 255, b'\x01\t\x00']
2020-06-05 16:24:49 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=9 command_id=0>
2020-06-05 16:24:49 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] ZCL request 0x0000: []
2020-06-05 16:24:49 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] No handler for cluster command 0

The default ZHA Event channel should have handled that.
Can you enable debug logging for homeassistant.core: debug and post the logs similar to the above when you press the button?

@perosb
Copy link
Contributor Author
perosb commented Jun 5, 2020

There is nothing from core getting logged:

2020-06-05 17:00:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6697b1ed562e14b05895b529ab55929a35e3de231231648aedc6a1297e'
2020-06-05 17:00:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-06-05 17:00:01 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'020401020101ff0c010000d3a9adf988ffff03011000'
2020-06-05 17:00:01 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_MULTICAST: 2>, <EmberApsFrame profileId=260 clusterId=258 sourceEndpoint=1 destinationEndpoint=255 options=268 groupId=0 sequence=211>, 169, -83, 0x88f9, 255, 255, b'\x01\x10\x00']
2020-06-05 17:00:01 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=16 command_id=0>
2020-06-05 17:00:01 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] ZCL request 0x0000: []
2020-06-05 17:00:01 DEBUG (MainThread) [zigpy.zcl] [0x88f9:1:0x0102] No handler for cluster command 0

For my other 5btn IKEA remote I see "Bus:Handling" tho.

2020-06-05 17:00:42 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event zha_event[L]: device_ieee=00:0b:57:ff:fe:14:41:46, unique_id=00:0b:57:ff:fe:14:41:46:1:0x0006, endpoint_id=1, cluster_id=6, command=toggle, args=[]>

@Adminiuga
Copy link
Contributor

wanna give #36489 a try?
copy https://github.com/Adminiuga/home-assistant/tree/ac/zha-cover-event/homeassistant/components/zha as zha folder into your /config/custom_components folder and restart HA

@perosb
Copy link
Contributor Author
perosb commented Jun 5, 2020

Awesome @Adminiuga, works like a charm!
Also see the Bus:Handling now.

{
    "event_type": "zha_event",
    "data": {
        "device_ieee": "ec:1b:bd:ff:fe:e8:86:f9",
       
103CE
 "unique_id": "ec:1b:bd:ff:fe:e8:86:f9:1:0x0102",
        "endpoint_id": 1,
        "cluster_id": 258,
        "command": "up_open",
        "args": []
    },
    "origin": "LOCAL",
    "time_fired": "2020-06-05T19:36:45.425826+00:00",
    "context": {
        "id": "1f68ae87b1054639bf53d098aab14a37",
        "parent_id": null,
        "user_id": null
    }
}

@Adminiuga
Copy link
Contributor
Adminiuga commented Jun 5, 2020

excellent. Once it gets merged into rc branch (hopefuly 0.111.0b2), don't forget to remove the zha folder from /config/custom_components to switch back to upstream zha

@thd6n75
Copy link
thd6n75 commented Sep 12, 2020

@Adminiuga was this ever merged? I'm using the homeassistant/home-assistant:0.114.4 docker image and I have the same behavior with my E1766 remote: I don't see any events from this when clicking the buttons.

@Adminiuga
Copy link
Contributor

#36489

@thd6n75
Copy link
thd6n75 commented Sep 12, 2020

Hm, ok. Am I supposed to see anything in WindowCovering binding?

zha-binds

This is what I get when joining the device. I end up with a battery sensor (sensor.xxx) and a binary_sensor which reports as open. But pushing the buttons doesnt generate any event when listening for zha_event and the binary_sensor never changes state.

2020-09-12 16:54:02 DEBUG (MainThread) [bellows.ezsp] Send command sendBroadcast: (<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>, <EmberApsFrame profileId=0 clusterId=54 sourceEndpoint=0 destinationEndpoint=0 options=0 groupId=0 sequence=103>, 0, 104, b'g<\x00')
2020-09-12 16:54:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7745219ea8d515b26f944a25aa559249fb4e4fa88af267e9ec7e'
2020-09-12 16:54:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7045a19e5418d70b7e'
2020-09-12 16:54:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-12 16:54:02 DEBUG (MainThread) [bellows.ezsp] Application frame 54 (sendBroadcast) received: b'0032'
2020-09-12 16:54:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0045b1ed512a158459944a2daa55927b634e27ab123164ecc1c6f37b7e'
2020-09-12 16:54:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-12 16:54:02 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'050000360000000800000032ff000000ffff03673c00'
2020-09-12 16:54:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST_LOOPBACK: 5>, <EmberApsFrame profileId=0 clusterId=54 sourceEndpoint=0 destinationEndpoint=0 options=8 groupId=0 sequence=50>, 255, 0, 0x0000, 255, 255, b'g<\x00']
2020-09-12 16:54:02 DEBUG (MainThread) [zigpy.zdo] [0x0000:zdo] ZDO request ZDOCmd.Mgmt_Permit_Joining_req: [60, <Bool.false: 0>]
2020-09-12 16:54:03 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1045b19750d6eab259a24a25aa5d92499c7c4fabedd9e37e'
2020-09-12 16:54:03 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-12 16:54:03 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'04fcff0000360000000800000032680000'
2020-09-12 16:54:03 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_MULTICAST_WITH_ALIAS: 4>, 65532, <EmberApsFrame profileId=0 clusterId=54 sourceEndpoint=0 destinationEndpoint=0 options=8 groupId=0 sequence=50>, 104, <EmberStatus.SUCCESS: 0>, b'']
2020-09-12 16:54:03 DEBUG (MainThread) [bellows.ezsp] Send command permitJoining: (60,)
2020-09-12 16:54:03 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'024a218a68fbb37e'
2020-09-12 16:54:03 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'214aa18a54d1507e'
2020-09-12 16:54:03 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-12 16:54:03 DEBUG (MainThread) [bellows.ezsp] Application frame 34 (permitJoining) received: b'00'
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'314ab197543273b259b54a25aa1592499c6145cded35457e'
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001866000021000000400000002f626600'
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 26136, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=64 groupId=0 sequence=47>, 98, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2020-09-12 16:54:04 DEBUG (MainThread) [zigpy.device] [0x6618] Delivery error for seq # 0x61, on endpoint id 0 cluster 0x0021: message send failure
2020-09-12 16:54:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x6618:1:0x0020]: Failed to bind 'poll_control' cluster: [0x6618:0:0x0021]: Message send failure
2020-09-12 16:54:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x6618:1:0x0020]: finished channel configuration
2020-09-12 16:54:04 DEBUG (MainThread) [zigpy.device] [0x6618] Extending timeout for 0x69 request
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for d0:cf:5e:ff:fe:ce:3c:38/0x6618
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (d0:cf:5e:ff:fe:ce:3c:38, True)
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'144b21d66c16db4ca6ca85f5ab645f7e'
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'424ba1d66f9c7e'
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x6618, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=105>, 106, b'i8<\xce\xfe\xff^\xcf\xd0\x01\x06\x00\x03\x9e\x05\x13\x0b\x00o\r\x00\x01')
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'2548219c543273b259b54a25aa1593499c274dbd84f65b4503393d462c7f39a7e853db7c84ffa8d6d5d355c77e'
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5348a19c541973d87e'
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0033'
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6348b197543273b259b54a25aa1592499c7e43cded0dbc7e'
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'0018660000210000004000000030646600'
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 26136, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=64 groupId=0 sequence=48>, 100, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2020-09-12 16:54:04 DEBUG (MainThread) [zigpy.device] [0x6618] Delivery error for seq # 0x63, on endpoint id 0 cluster 0x0021: message send failure
2020-09-12 16:54:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x6618:1:0x0000]: Failed to bind 'basic' cluster: [0x6618:0:0x0021]: Message send failure
2020-09-12 16:54:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x6618:1:0x0000]: finished channel configuration
2020-09-12 16:54:04 DEBUG (MainThread) [zigpy.device] [0x6618] Extending timeout for 0x6b request
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for d0:cf:5e:ff:fe:ce:3c:38/0x6618
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (d0:cf:5e:ff:fe:ce:3c:38, True)
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'374921d66c16db4ca6ca85f5ab80787e'
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7449a1d60a8c7e'
2020-09-12 16:54:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-12 16:54:04 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''

@Adminiuga
Copy link
Contributor

it didn't finish the configuration

2020-09-12 16:54:04 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 26136, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=64 groupId=0 sequence=47>, 98, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2020-09-12 16:54:04 DEBUG (MainThread) [zigpy.device] [0x6618] Delivery error for seq # 0x61, on endpoint id 0 cluster 0x0021: message send failure
2020-09-12 16:54:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x6618:1:0x0020]: Failed to bind 'poll_control' cluster: [0x6618:0:0x0021]: Message send failure

if it failed to configure this cluster, means it probably failed to configure other clusters as well. Remove the device, w B589 ait 45s. Try-rejoining and keep device awake during the process by pressing the buttons.

@thd6n75
Copy link
thd6n75 commented Sep 13, 2020

Thanks for the response. I tried to do that, and I got the same result: my device shows up with 2 entities, and I don't see any events when listening for zha_event and pushing the buttons.

Log: https://pastebin.com/rrQbR4Ju

I think the log is long because I kept pushing each button every few seconds to keep it awake

@balloob
Copy link
Member
balloob commented Sep 13, 2020

Please open a new issue. This issue has been resolved.

@home-assistant home-assistant locked as resolved and limited conversation to collaborators Sep 13, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants
0