home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
71.57k stars 29.91k forks source link

Osram Smart+ not recognized in ZHA #35534

Closed HydrelioxGitHub closed 3 years ago

HydrelioxGitHub commented 4 years ago

The problem

I've tried to link my Osram Smart + plug to HA using the ZHA integration. A device is added but as "unk model" and "unk manufacturer". There is a switch in lovelace but it's not working at all. I've checked on https://zigbee.blakadder.com/zha.html if this device is supported (I don't know if it's a good reference...). The reference of the Osram plug is AB3257001NJ in blakadder.

Environment

Problem-relevant configuration.yaml

Traceback/Error logs

Additional information

This plug works correctly using zigbee2mqtt.

probot-home-assistant[bot] commented 4 years ago

zha documentation zha source (message by IssueLinks)

probot-home-assistant[bot] commented 4 years ago

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 commented 4 years ago
  1. What kind of radio are you using
  2. remove device: config -> ZHA -> pick device -> remove device
  3. enable debug logging: https://www.home-assistant.io/integrations/zha/#debug-logging
  4. pair device again
  5. post logs
HydrelioxGitHub commented 4 years ago

I'm using a Texas Instruments cc2531 with flashed firmware. Works well with zigbee2mqtt. I will try to re add Zha integration and post log as soon as I can.

Adminiuga commented 4 years ago

I think someone else was reporting similar issues when using CC2531. Remove device from the UI, enable debug logging, re-pair the device. Post logs here.

Variour commented 4 years ago

I have the same problem, this is the output when pairing the OSRAM Smart+ Plug.

logger:
  default: info
  logs:
    homeassistant.core: debug
    homeassistant.components.zha: debug
    bellows.zigbee.application: debug
    bellows.ezsp: debug
    zigpy: debug
    zigpy_cc: debug
    zigpy_deconz.zigbee.application: debug
    zigpy_deconz.api: debug
    zigpy_xbee.zigbee.application: debug
    zigpy_xbee.api: debug
    zigpy_zigate: debug
Log ```` 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO permitJoinInd tsn: None {'duration': 0} 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.zigbee.application] broadcast (0, 54, 0, 0, 0, 0, 223, b'\xdf<\x00', ) 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO mgmtPermitJoinReq tsn: 223 {'addrmode': 15, 'dstaddr': 0xfffc, 'duration': 60, 'tcsignificance': 0} 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&' 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO mgmtPermitJoinReq tsn: None {'status': 0} 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO mgmtPermitJoinReq tsn: None {'addrmode': 15, 'dstaddr': 65532, 'duration': 60, 'tcsignificance': 0} 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&' 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO permitJoinInd tsn: None {'duration': 60} 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO mgmtPermitJoinReq tsn: None {'status': 0} 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO mgmtPermitJoinRsp tsn: None {'srcaddr': 0x0000, 'status': 0} 2020-05-17 17:28:27 WARNING (MainThread) [zigpy_cc.zigbee.application] missing tsn from mgmtPermitJoinRsp, maybe not a reply 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:27 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO mgmtPermitJoinRsp tsn: None {'srcaddr': 0x0000, 'status': 0} 2020-05-17 17:28:27 WARNING (MainThread) [zigpy_cc.zigbee.application] missing tsn from mgmtPermitJoinRsp, maybe not a reply 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: \xb0|\x00\x00' length=12 fcs=166> 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO tcDeviceInd tsn: None {'nwkaddr': 0x7acd, 'extaddr': 7c:b0:3e:aa:0a:06:75:b3, 'parentaddr': 0x0000} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: tcDeviceInd 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: \xb0|\x8e' length=13 fcs=149> 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO endDeviceAnnceInd tsn: None {'srcaddr': 0x7acd, 'nwkaddr': 0x7acd, 'ieeeaddr': 7c:b0:3e:aa:0a:06:75:b3, 'capabilities': 142} 2020-05-17 17:28:39 INFO (MainThread) [zigpy_cc.zigbee.application] New device joined: 0x7acd, 7c:b0:3e:aa:0a:06:75:b3 2020-05-17 17:28:39 INFO (MainThread) [zigpy.application] Device 0x7acd (7c:b0:3e:aa:0a:06:75:b3) joined the network 2020-05-17 17:28:39 INFO (MainThread) [zigpy_cc.zigbee.application] REPLY for 0 endDeviceAnnceInd 2020-05-17 17:28:39 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message endDeviceAnnceInd 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy.zdo] [0x7acd:zdo] ZDO request ZDOCmd.Device_annce: [0x7acd, 7c:b0:3e:aa:0a:06:75:b3, 142] 2020-05-17 17:28:39 INFO (MainThread) [zigpy.device] [0x7acd] Requesting 'Node Descriptor' 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy.device] [0x7acd] Extending timeout for 0xe1 request 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 0, , 0, 0, 225, b'\xe1\xcdz', True, False) 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] waiting for 225 nodeDescReq 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO nodeDescReq tsn: 225 {'dstaddr': 0x7acd, 'nwkaddrofinterest': 0x7acd} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x04%\x02\xcdz\xcdz#' 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO nodeDescReq tsn: None {'status': 0} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO nodeDescRsp tsn: 225 {'srcaddr': 0x7acd, 'status': 0, 'nwkaddr': 0x7acd, 'logicaltype_cmplxdescavai_userdescavai': 1, 'apsflags_freqband': 64, 'maccapflags': 142, 'manufacturercode': 48042, 'maxbuffersize': 64, 'maxintransfersize': 0, 'servermask': 0, 'maxouttransfersize': 0, 'descriptorcap': 3} 2020-05-17 17:28:39 INFO (MainThread) [zigpy_cc.zigbee.application] REPLY for 225 nodeDescRsp 2020-05-17 17:28:39 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message nodeDescRsp 2020-05-17 17:28:39 INFO (MainThread) [zigpy.device] [0x7acd] Node Descriptor: 2020-05-17 17:28:39 INFO (MainThread) [zigpy.device] [0x7acd] Discovering endpoints 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 0, , 0, 0, 227, b'\xe3\xcdz', True, False) 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] waiting for 227 activeEpReq 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO activeEpReq tsn: 227 {'dstaddr': 0x7acd, 'nwkaddrofinterest': 0x7acd} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x04%\x05\xcdz\xcdz$' 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO activeEpReq tsn: None {'status': 0} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO activeEpRsp tsn: 227 {'srcaddr': 0x7acd, 'status': 0, 'nwkaddr': 0x7acd, 'activeepcount': 1, 'activeeplist': [3]} 2020-05-17 17:28:39 INFO (MainThread) [zigpy_cc.zigbee.application] REPLY for 227 activeEpRsp 2020-05-17 17:28:39 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message activeEpRsp 2020-05-17 17:28:39 INFO (MainThread) [zigpy.device] [0x7acd] Discovered endpoints: [3] 2020-05-17 17:28:39 INFO (MainThread) [zigpy.endpoint] [0x7acd:3] Discovering endpoint information 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 0, , 0, 0, 229, b'\xe5\xcdz\x03', True, False) 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] waiting for 229 simpleDescReq 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO simpleDescReq tsn: 229 {'dstaddr': 0x7acd, 'nwkaddrofinterest': 0x7acd, 'endpoint': 3} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x05%\x04\xcdz\xcdz\x03'" 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO simpleDescReq tsn: None {'status': 0} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO simpleDescRsp tsn: 229 {'srcaddr': 0x7acd, 'status': 0, 'nwkaddr': 0x7acd, 'len': 26, 'endpoint': 3, 'profileid': 49246, 'deviceid': 16, 'deviceversion': 2, 'numinclusters': 8, 'inclusterlist': [4096, 0, 3, 4, 5, 6, 2820, 64527], 'numoutclusters': 1, 'outclusterlist': [25]} 2020-05-17 17:28:39 INFO (MainThread) [zigpy_cc.zigbee.application] REPLY for 229 simpleDescRsp 2020-05-17 17:28:39 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message simpleDescRsp 2020-05-17 17:28:39 INFO (MainThread) [zigpy.endpoint] [0x7acd:3] Discovered endpoint information: 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 0, 3, 3, 231, b'\x00\xe7\x00\x04\x00\x05\x00', True, False) 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 231 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 0, 'transid': 232, 'options': 0, 'radius': 30, 'len': 7, 'data': b'\x00\xe7\x00\x04\x00\x05\x00'} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x11$\x01\xcdz\x03\x03\x00\x00\xe8\x00\x1e\x07\x00\xe7\x00\x04\x00\x05\x00\x94' 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 232} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 232} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 232} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 232} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 232} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 232} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 232} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 232} 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 232} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 0, 3, 3, 233, b'\x00\xe9\x00\x04\x00', True, False) 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 233 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 0, 'transid': 234, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\xe9\x00\x04\x00'} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x00\x00\xea\x00\x1e\x05\x00\xe9\x00\x04\x00\x81' 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 234} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 234} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 234} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 234} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 234} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 234} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 234} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 234} 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 234} 2020-05-17 17:28:49 INFO (MainThread) [homeassistant.components.esphome] Can't connect to ESPHome API for espcam01.local: Error resolving IP address: [Errno -2] Name does not resolve 2020-05-17 17:28:49 INFO (MainThread) [homeassistant.components.esphome] Trying to reconnect in 60 seconds 2020-05-17 17:28:49 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 0, 3, 3, 235, b'\x00\xeb\x00\x05\x00', True, False) 2020-05-17 17:28:49 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 235 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 0, 'transid': 236, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\xeb\x00\x05\x00'} 2020-05-17 17:28:49 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x00\x00\xec\x00\x1e\x05\x00\xeb\x00\x05\x00\x84' 2020-05-17 17:28:49 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:49 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 236} 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 236} 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 236} 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 236} 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 236} 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 236} 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 236} 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 236} 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:28:51 INFO (MainThread) [homeassistant.components.esphome] Can't connect to ESPHome API for s26_01.local: Error resolving IP address: [Errno -2] Name does not resolve 2020-05-17 17:28:51 INFO (MainThread) [homeassistant.components.esphome] Trying to reconnect in 60 seconds 2020-05-17 17:28:52 INFO (MainThread) [homeassistant.components.esphome] Can't connect to ESPHome API for hexaleaf01.local: Error resolving IP address: [Errno -2] Name does not resolve 2020-05-17 17:28:52 INFO (MainThread) [homeassistant.components.esphome] Trying to reconnect in 60 seconds 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.endpoint] [0x7acd:3] Manufacturer: None 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.endpoint] [0x7acd:3] Model: None 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for None None (7c:b0:3e:aa:0a:06:75:b3) 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Considering 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {3} 2020-05-17 17:29:00 DEBUG (MainThread) [homeassistant.core] Bus:Handling 2020-05-17 17:29:00 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x7acd:7c:b0:3e:aa:0a:06:75:b3 entering async_device_initialized - is_new_join: True 2020-05-17 17:29:00 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x7acd:7c:b0:3e:aa:0a:06:75:b3 has joined the ZHA zigbee network 2020-05-17 17:29:00 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x7acd](unk_model): started configuration 2020-05-17 17:29:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:ZDO](unk_model): 'async_configure' stage succeeded 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 0, , 0, 0, 237, b'\xed\xb3u\x06\n\xaa>\xb0|\x03\x06\x00\x03D\t;\x19\x00K\x12\x00\x01', True, False) 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] waiting for 237 bindReq 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 237 {'dstaddr': 0x7acd, 'srcaddr': 7c:b0:3e:aa:0a:06:75:b3, 'srcendpoint': 3, 'clusterid': 6, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:19:3b:09:44, 'dstendpoint': 1} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\xcdz\xb3u\x06\n\xaa>\xb0|\x03\x06\x00\x03D\t;\x19\x00K\x12\x00\x01\x07' 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 0, , 0, 0, 239, b'\xef\xb3u\x06\n\xaa>\xb0|\x03\x00\x10\x03D\t;\x19\x00K\x12\x00\x01', True, False) 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] waiting for 239 bindReq 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 239 {'dstaddr': 0x7acd, 'srcaddr': 7c:b0:3e:aa:0a:06:75:b3, 'srcendpoint': 3, 'clusterid': 4096, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:19:3b:09:44, 'dstendpoint': 1} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\xcdz\xb3u\x06\n\xaa>\xb0|\x03\x00\x10\x03D\t;\x19\x00K\x12\x00\x01\x11' 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 0, , 0, 0, 241, b'\xf1\xb3u\x06\n\xaa>\xb0|\x03\x04\x0b\x03D\t;\x19\x00K\x12\x00\x01', True, False) 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] waiting for 241 bindReq 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 241 {'dstaddr': 0x7acd, 'srcaddr': 7c:b0:3e:aa:0a:06:75:b3, 'srcendpoint': 3, 'clusterid': 2820, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:19:3b:09:44, 'dstendpoint': 1} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\xcdz\xb3u\x06\n\xaa>\xb0|\x03\x04\x0b\x03D\t;\x19\x00K\x12\x00\x01\x0e' 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 237 {'srcaddr': 0x7acd, 'status': 0} 2020-05-17 17:29:00 INFO (MainThread) [zigpy_cc.zigbee.application] REPLY for 237 bindRsp 2020-05-17 17:29:00 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp 2020-05-17 17:29:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0006]: bound 'on_off' cluster: Status.SUCCESS 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 6, 3, 3, 243, b'\x00\xf3\x06\x00\x00\x00\x10\x00\x00\x84\x03', True, False) 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 243 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 6, 'transid': 244, 'options': 0, 'radius': 30, 'len': 11, 'data': b'\x00\xf3\x06\x00\x00\x00\x10\x00\x00\x84\x03'} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x15$\x01\xcdz\x03\x03\x06\x00\xf4\x00\x1e\x0b\x00\xf3\x06\x00\x00\x00\x10\x00\x00\x84\x03\x02' 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 239 {'srcaddr': 0x7acd, 'status': 0} 2020-05-17 17:29:00 INFO (MainThread) [zigpy_cc.zigbee.application] REPLY for 239 bindRsp 2020-05-17 17:29:00 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp 2020-05-17 17:29:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x1000]: bound 'lightlink' cluster: Status.SUCCESS 2020-05-17 17:29:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x1000]: finished channel configuration 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 0, , 0, 0, 245, b'\xf5\xb3u\x06\n\xaa>\xb0|\x03\x00\x00\x03D\t;\x19\x00K\x12\x00\x01', True, False) 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] waiting for 245 bindReq 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 245 {'dstaddr': 0x7acd, 'srcaddr': 7c:b0:3e:aa:0a:06:75:b3, 'srcendpoint': 3, 'clusterid': 0, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:19:3b:09:44, 'dstendpoint': 1} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\xcdz\xb3u\x06\n\xaa>\xb0|\x03\x00\x00\x03D\t;\x19\x00K\x12\x00\x01\x01' 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 244} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 244} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 244} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 244} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 244} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 244} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 244} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 244} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 244} 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:00 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 244} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 241 {'srcaddr': 0x7acd, 'status': 0} 2020-05-17 17:29:01 INFO (MainThread) [zigpy_cc.zigbee.application] REPLY for 241 bindRsp 2020-05-17 17:29:01 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp 2020-05-17 17:29:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: bound 'electrical_measurement' cluster: Status.SUCCESS 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 2820, 3, 3, 247, b'\x00\xf7\x06\x00\x0b\x05)\x1e\x00\x84\x03\x01\x00', True, False) 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 247 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 2820, 'transid': 248, 'options': 0, 'radius': 30, 'len': 13, 'data': b'\x00\xf7\x06\x00\x0b\x05)\x1e\x00\x84\x03\x01\x00'} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17$\x01\xcdz\x03\x03\x04\x0b\xf8\x00\x1e\r\x00\xf7\x06\x00\x0b\x05)\x1e\x00\x84\x03\x01\x00/' 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 248} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 248} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 248} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 248} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 248} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 248} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 248} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 248} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 248} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 248} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 245 {'srcaddr': 0x7acd, 'status': 0} 2020-05-17 17:29:01 INFO (MainThread) [zigpy_cc.zigbee.application] REPLY for 245 bindRsp 2020-05-17 17:29:01 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp 2020-05-17 17:29:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0000]: bound 'basic' cluster: Status.SUCCESS 2020-05-17 17:29:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0000]: finished channel configuration 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 0, 3, 3, 249, b'\x00\xf9\x00\x07\x00', True, False) 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 249 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 0, 'transid': 250, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\xf9\x00\x07\x00'} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x00\x00\xfa\x00\x1e\x05\x00\xf9\x00\x07\x00\x82' 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 250} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 250} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 250} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 250} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 250} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 250} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 250} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 250} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 250} 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:01 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 250} 2020-05-17 17:29:05 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0006]: failed to set reporting for 'on_off' attr on 'on_off' cluster: 2020-05-17 17:29:05 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0006]: finished channel configuration 2020-05-17 17:29:05 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 0, , 0, 0, 251, b'\xfb\xb3u\x06\n\xaa>\xb0|\x03\x19\x00\x03D\t;\x19\x00K\x12\x00\x01', True, False) 2020-05-17 17:29:05 DEBUG (MainThread) [zigpy_cc.api] waiting for 251 bindReq 2020-05-17 17:29:05 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 251 {'dstaddr': 0x7acd, 'srcaddr': 7c:b0:3e:aa:0a:06:75:b3, 'srcendpoint': 3, 'clusterid': 25, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:19:3b:09:44, 'dstendpoint': 1} 2020-05-17 17:29:05 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\xcdz\xb3u\x06\n\xaa>\xb0|\x03\x19\x00\x03D\t;\x19\x00K\x12\x00\x01\x18' 2020-05-17 17:29:05 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:05 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 251 {'srcaddr': 0x7acd, 'status': 0} 2020-05-17 17:29:06 INFO (MainThread) [zigpy_cc.zigbee.application] REPLY for 251 bindRsp 2020-05-17 17:29:06 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0019]: bound 'ota' cluster: Status.SUCCESS 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0019]: finished channel configuration 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: failed to set reporting for 'active_power' attr on 'electrical_measurement' cluster: 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: finished channel configuration 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0000]: initializing channel: from_cache: False 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0006]: 'async_configure' stage succeeded 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x1000]: 'async_configure' stage succeeded 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: 'async_configure' stage succeeded 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0000]: 'async_configure' stage succeeded 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0019]: 'async_configure' stage succeeded 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x7acd](unk_model): completed configuration 2020-05-17 17:29:06 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x7acd](unk_model): stored in registry: ZhaDeviceEntry(name='unk_manufacturer unk_model', ieee='7c:b0:3e:aa:0a:06:75:b3', last_seen=1589729346.0746844) 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 3, 3, 3, 253, b'\x01\xfd@\x02\x00', True, False) 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 253 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 3, 'transid': 254, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x01\xfd@\x02\x00'} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x03\x00\xfe\x00\x1e\x05\x01\xfd@\x02\x00\xc5' 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 254} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 254} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 254} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 254} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 254} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 254} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 254} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 254} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 254} 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:06 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 254} 2020-05-17 17:29:11 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0003]: command failed: trigger_effect exception: 2020-05-17 17:29:11 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x7acd](unk_model): started initialization 2020-05-17 17:29:11 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:ZDO](unk_model): 'async_initialize' stage succeeded 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 6, 3, 3, 255, b'\x00\xff\x00\x00\x00', True, False) 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 255 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 6, 'transid': 0, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\xff\x00\x00\x00'} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x06\x00\x00\x00\x1e\x05\x00\xff\x00\x00\x00\x7f' 2020-05-17 17:29:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x1000]: initializing channel: from_cache: False 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 2820, 3, 3, 1, b'\x00\x01\x00\x0b\x05', True, False) 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 1 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 2820, 'transid': 2, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x01\x00\x0b\x05'} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x04\x0b\x02\x00\x1e\x05\x00\x01\x00\x0b\x05\x84' 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 0, 3, 3, 3, b'\x00\x03\x00\x07\x00', True, False) 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 3 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 0, 'transid': 4, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x03\x00\x07\x00'} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x00\x00\x04\x00\x1e\x05\x00\x03\x00\x07\x00\x86' 2020-05-17 17:29:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: async_update 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 2820, 3, 3, 5, b'\x00\x05\x00\x0b\x05', True, False) 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 5 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 2820, 'transid': 6, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x05\x00\x0b\x05'} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x04\x0b\x06\x00\x1e\x05\x00\x05\x00\x0b\x05\x84' 2020-05-17 17:29:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0006]: attempting to update onoff state - from cache: False 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 6, 3, 3, 7, b'\x00\x07\x00\x00\x00', True, False) 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 7 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 6, 'transid': 8, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x07\x00\x00\x00'} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x06\x00\x08\x00\x1e\x05\x00\x07\x00\x00\x00\x8f' 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 16} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 2} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 4} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 6} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 0} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 2} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 6} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 4} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 2} +{'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 6} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:12 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 2} 2020-05-17 17:29:17 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0006]: initializing channel: from_cache: False 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 6, 3, 3, 9, b'\x00\t\x00\x00\x00', True, False) 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 9 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 6, 'transid': 10, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\t\x00\x00\x00'} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x06\x00\n\x00\x1e\x05\x00\t\x00\x00\x00\x83' 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:17 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0000]: initializing channel: from_cache: False 2020-05-17 17:29:17 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0019]: initializing channel: from_cache: False 2020-05-17 17:29:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling 2020-05-17 17:29:17 INFO (MainThread) [homeassistant.helpers.entity_registry] Registered new sensor.zha entity: sensor.unk_manufacturer_unk_model_b375060a_electrical_measurement 2020-05-17 17:29:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling 2020-05-17 17:29:17 DEBUG (MainThread) [homeassistant.core] Bus:Handling > 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 2820, 3, 3, 11, b'\x00\x0b\x00\x05\x06\x03\x04\x04\x06\x02\x04', True, False) 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 11 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 2820, 'transid': 12, 'options': 0, 'radius': 30, 'len': 11, 'data': b'\x00\x0b\x00\x05\x06\x03\x04\x04\x06\x02\x04'} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x15$\x01\xcdz\x03\x03\x04\x0b\x0c\x00\x1e\x0b\x00\x0b\x00\x05\x06\x03\x04\x04\x06\x02\x04\x9a' 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 10} +{'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 12} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:17 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 10} 2020-05-17 17:29:22 INFO (MainThread) [homeassistant.helpers.entity_registry] Registered new switch.zha entity: switch.unk_manufacturer_unk_model_b375060a_on_off 2020-05-17 17:29:22 DEBUG (MainThread) [homeassistant.core] Bus:Handling 2020-05-17 17:29:22 DEBUG (MainThread) [homeassistant.core] Bus:Handling > 2020-05-17 17:29:22 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/alexa/state_report.py", line 150, in async_send_add_or_update_message alexa_entity = ENTITY_ADAPTERS[domain](hass, config, hass.states.get(entity_id)) File "/usr/src/homeassistant/homeassistant/components/alexa/entities.py", line 212, in __init__ self.entity_conf = config.entity_config.get(entity.entity_id, {}) AttributeError: 'NoneType' object has no attribute 'entity_id' 2020-05-17 17:29:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: failed to get attributes '['ac_power_divisor', 'power_divisor', 'ac_power_multiplier', 'power_multiplier']' on 'electrical_measurement' cluster: 2020-05-17 17:29:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: initializing channel: from_cache: False 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 2820, 3, 3, 13, b'\x00\r\x00\x0b\x05', True, False) 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 13 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 2820, 'transid': 14, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\r\x00\x0b\x05'} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x04\x0b\x0e\x00\x1e\x05\x00\r\x00\x0b\x05\x84' 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:22 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:22 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 14} 2020-05-17 17:29:27 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:27 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO permitJoinInd tsn: None {'duration': 0} 2020-05-17 17:29:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: failed to get attributes '['active_power']' on 'electrical_measurement' cluster: 2020-05-17 17:29:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0006]: 'async_initialize' stage succeeded 2020-05-17 17:29:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x1000]: 'async_initialize' stage succeeded 2020-05-17 17:29:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: 'async_initialize' stage succeeded 2020-05-17 17:29:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0000]: 'async_initialize' stage succeeded 2020-05-17 17:29:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0019]: 'async_initialize' stage succeeded 2020-05-17 17:29:27 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x7acd](unk_model): power source: Mains 2020-05-17 17:29:27 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x7acd](unk_model): completed initialization 2020-05-17 17:29:48 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: async_update 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 2820, 3, 3, 15, b'\x00\x0f\x00\x0b\x05', True, False) 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 15 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 2820, 'transid': 16, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x0f\x00\x0b\x05'} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x04\x0b\x10\x00\x1e\x05\x00\x0f\x00\x0b\x05\x98' 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:29:48 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 16} 2020-05-17 17:29:52 INFO (MainThread) [homeassistant.components.esphome] Can't connect to ESPHome API for espcam01.local: Error resolving IP address: [Errno -2] Name does not resolve 2020-05-17 17:29:52 INFO (MainThread) [homeassistant.components.esphome] Trying to reconnect in 60 seconds 2020-05-17 17:29:54 INFO (MainThread) [homeassistant.components.esphome] Can't connect to ESPHome API for s26_01.local: Error resolving IP address: [Errno -2] Name does not resolve 2020-05-17 17:29:54 INFO (MainThread) [homeassistant.components.esphome] Trying to reconnect in 60 seconds 2020-05-17 17:29:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling , new_state=> 2020-05-17 17:29:55 INFO (MainThread) [homeassistant.components.esphome] Can't connect to ESPHome API for hexaleaf01.local: Error resolving IP address: [Errno -2] Name does not resolve 2020-05-17 17:29:55 INFO (MainThread) [homeassistant.components.esphome] Trying to reconnect in 60 seconds 2020-05-17 17:30:19 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: async_update 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 2820, 3, 3, 17, b'\x00\x11\x00\x0b\x05', True, False) 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 17 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 2820, 'transid': 18, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x11\x00\x0b\x05'} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x04\x0b\x12\x00\x1e\x05\x00\x11\x00\x0b\x05\x84' 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:19 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 18} 2020-05-17 17:30:29 DEBUG (MainThread) [homeassistant.components.zha.entity] light.hall_ceiling: polling current state 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xb422, 260, 6, 11, 11, 19, b'\x00\x13\x00\x00\x00', True, False) 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 19 {'dstaddr': 46114, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 6, 'transid': 20, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x13\x00\x00\x00'} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01"\xb4\x0b\x0b\x06\x00\x14\x00\x1e\x05\x00\x13\x00\x00\x00\xa6' 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:29 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 20} 2020-05-17 17:30:31 DEBUG (MainThread) [homeassistant.components.zha.entity] light.kitchen_table2: polling current state 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xfdcb, 260, 6, 11, 11, 21, b'\x00\x15\x00\x00\x00', True, False) 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 21 {'dstaddr': 64971, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 6, 'transid': 22, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x15\x00\x00\x00'} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcb\xfd\x0b\x0b\x06\x00\x16\x00\x1e\x05\x00\x15\x00\x00\x00\x02' 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 24} +{'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:31 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 22} 2020-05-17 17:30:34 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xb422, 260, 8, 11, 11, 23, b'\x00\x17\x00\x00\x00', True, False) 2020-05-17 17:30:34 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 23 {'dstaddr': 46114, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 8, 'transid': 24, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x17\x00\x00\x00'} 2020-05-17 17:30:34 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01"\xb4\x0b\x0b\x08\x00\x18\x00\x1e\x05\x00\x17\x00\x00\x00\xa0' 2020-05-17 17:30:34 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:34 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:34 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:35 WARNING (MainThread) [zigpy_cc.api] Waiter already cancelled: future= timeout=10000 sequence=None> 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 24} 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 24} 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 24} 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 24} 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 24} 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 24} 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 24} 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 24} 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 24} 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:35 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 24} 2020-05-17 17:30:36 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xfdcb, 260, 8, 11, 11, 25, b'\x00\x19\x00\x00\x00', True, False) 2020-05-17 17:30:36 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 25 {'dstaddr': 64971, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 8, 'transid': 26, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x19\x00\x00\x00'} 2020-05-17 17:30:36 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcb\xfd\x0b\x0b\x08\x00\x1a\x00\x1e\x05\x00\x19\x00\x00\x00\x0c' 2020-05-17 17:30:36 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:36 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:36 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 26} 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 26} 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 26} 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 26} 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 26} 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 26} 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 26} 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 26} 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 26} 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:37 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 26} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xb422, 260, 768, 11, 11, 27, b'\x00\x1b\x00\x07\x00\x03\x00\x04\x00\x02@', True, False) 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 27 {'dstaddr': 46114, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 768, 'transid': 28, 'options': 0, 'radius': 30, 'len': 11, 'data': b'\x00\x1b\x00\x07\x00\x03\x00\x04\x00\x02@'} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x15$\x01"\xb4\x0b\x0b\x00\x03\x1c\x00\x1e\x0b\x00\x1b\x00\x07\x00\x03\x00\x04\x00\x02@\xf5' 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 28} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 28} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 28} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 28} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 28} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 28} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 28} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 28} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 28} 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:40 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 28} 2020-05-17 17:30:42 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xfdcb, 260, 768, 11, 11, 29, b'\x00\x1d\x00\x07\x00\x03\x00\x04\x00\x02@', True, False) 2020-05-17 17:30:42 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 29 {'dstaddr': 64971, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 768, 'transid': 30, 'options': 0, 'radius': 30, 'len': 11, 'data': b'\x00\x1d\x00\x07\x00\x03\x00\x04\x00\x02@'} 2020-05-17 17:30:42 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x15$\x01\xcb\xfd\x0b\x0b\x00\x03\x1e\x00\x1e\x0b\x00\x1d\x00\x07\x00\x03\x00\x04\x00\x02@Q' 2020-05-17 17:30:42 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:42 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:42 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 30} 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 30} 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 30} 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 30} 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 30} 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 30} 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 30} 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 30} 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 30} 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:43 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 30} 2020-05-17 17:30:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xb422:11:0x0300]: failed to get attributes '['color_temperature', 'current_x', 'current_y', 'color_loop_active']' on 'light_color' cluster: 2020-05-17 17:30:47 DEBUG (MainThread) [homeassistant.components.zha.entity] light.hall_ball: polling current state 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x24f3, 260, 6, 11, 11, 31, b'\x00\x1f\x00\x00\x00', True, False) 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 31 {'dstaddr': 9459, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 6, 'transid': 32, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x1f\x00\x00\x00'} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xf3$\x0b\x0b\x06\x00 \x00\x1e\x05\x00\x1f\x00\x00\x00\xdf' 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 32} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 32} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 32} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 32} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 32} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 32} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 32} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 32} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 32} 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:47 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 32} 2020-05-17 17:30:48 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xfdcb:11:0x0300]: failed to get attributes '['color_temperature', 'current_x', 'current_y', 'color_loop_active']' on 'light_color' cluster: 2020-05-17 17:30:50 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: async_update 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 2820, 3, 3, 33, b'\x00!\x00\x0b\x05', True, False) 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 33 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 2820, 'transid': 34, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00!\x00\x0b\x05'} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x04\x0b"\x00\x1e\x05\x00!\x00\x0b\x05\x84' 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 34} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 34} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 34} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 34} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 34} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 34} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 34} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 34} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 34} 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:50 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 34} 2020-05-17 17:30:52 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x24f3, 260, 8, 11, 11, 35, b'\x00#\x00\x00\x00', True, False) 2020-05-17 17:30:52 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 35 {'dstaddr': 9459, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 8, 'transid': 36, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00#\x00\x00\x00'} 2020-05-17 17:30:52 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xf3$\x0b\x0b\x08\x00$\x00\x1e\x05\x00#\x00\x00\x00\xe9' 2020-05-17 17:30:52 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:52 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:52 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 36} 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 36} 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 36} 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 36} 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 36} 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 36} 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 36} 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 36} 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 36} 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:53 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 36} 2020-05-17 17:30:55 INFO (MainThread) [homeassistant.components.esphome] Can't connect to ESPHome API for espcam01.local: Error resolving IP address: [Errno -2] Name does not resolve 2020-05-17 17:30:55 INFO (MainThread) [homeassistant.components.esphome] Trying to reconnect in 60 seconds 2020-05-17 17:30:57 INFO (MainThread) [homeassistant.components.esphome] Can't connect to ESPHome API for s26_01.local: Error resolving IP address: [Errno -2] Name does not resolve 2020-05-17 17:30:57 INFO (MainThread) [homeassistant.components.esphome] Trying to reconnect in 60 seconds 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x24f3, 260, 768, 11, 11, 37, b'\x00%\x00\x07\x00\x03\x00\x04\x00\x02@', True, False) 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 37 {'dstaddr': 9459, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 768, 'transid': 38, 'options': 0, 'radius': 30, 'len': 11, 'data': b'\x00%\x00\x07\x00\x03\x00\x04\x00\x02@'} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x15$\x01\xf3$\x0b\x0b\x00\x03&\x00\x1e\x0b\x00%\x00\x07\x00\x03\x00\x04\x00\x02@\xb0' 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:30:58 INFO (MainThread) [homeassistant.components.esphome] Can't connect to ESPHome API for hexaleaf01.local: Error resolving IP address: [Errno -2] Name does not resolve 2020-05-17 17:30:58 INFO (MainThread) [homeassistant.components.esphome] Trying to reconnect in 60 seconds 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 38} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 38} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 38} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 38} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 38} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 38} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 38} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 38} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 38} 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:30:58 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 38} 2020-05-17 17:31:03 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x24f3:11:0x0300]: failed to get attributes '['color_temperature', 'current_x', 'current_y', 'color_loop_active']' on 'light_color' cluster: 2020-05-17 17:31:04 DEBUG (MainThread) [homeassistant.components.zha.entity] light.kitchen_table1: polling current state 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x457a, 260, 6, 11, 11, 39, b"\x00'\x00\x00\x00", True, False) 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 39 {'dstaddr': 17786, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 6, 'transid': 40, 'options': 0, 'radius': 30, 'len': 5, 'data': b"\x00'\x00\x00\x00"} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x0f$\x01zE\x0b\x0b\x06\x00(\x00\x1e\x05\x00'\x00\x00\x00\x07" 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 11, 'transid': 40} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 11, 'transid': 40} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 11, 'transid': 40} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 11, 'transid': 40} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 11, 'transid': 40} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 11, 'transid': 40} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 11, 'transid': 40} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 11, 'transid': 40} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 11, 'transid': 40} 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:31:04 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 11, 'transid': 40} 2020-05-17 17:31:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling , new_state=> 2020-05-17 17:31:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling , new_state=> 2020-05-17 17:31:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling , new_state=> 2020-05-17 17:31:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling , new_state=> 2020-05-17 17:31:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling , new_state=> 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x457a, 260, 8, 11, 11, 41, b'\x00)\x00\x00\x00', True, False) 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 41 {'dstaddr': 17786, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 8, 'transid': 42, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00)\x00\x00\x00'} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01zE\x0b\x0b\x08\x00*\x00\x1e\x05\x00)\x00\x00\x00\x05' 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 11, 'transid': 42} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 11, 'transid': 42} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 11, 'transid': 42} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 11, 'transid': 42} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 11, 'transid': 42} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 11, 'transid': 42} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 11, 'transid': 42} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 11, 'transid': 42} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 11, 'transid': 42} 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:31:09 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 11, 'transid': 42} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x457a, 260, 768, 11, 11, 43, b'\x00+\x00\x07\x00\x03\x00\x04\x00\x02@', True, False) 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 43 {'dstaddr': 17786, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 768, 'transid': 44, 'options': 0, 'radius': 30, 'len': 11, 'data': b'\x00+\x00\x07\x00\x03\x00\x04\x00\x02@'} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x15$\x01zE\x0b\x0b\x00\x03,\x00\x1e\x0b\x00+\x00\x07\x00\x03\x00\x04\x00\x02@\\' 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 11, 'transid': 44} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 11, 'transid': 44} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 11, 'transid': 44} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 11, 'transid': 44} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 11, 'transid': 44} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 11, 'transid': 44} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 11, 'transid': 44} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 11, 'transid': 44} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 11, 'transid': 44} 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:31:14 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 11, 'transid': 44} 2020-05-17 17:31:17 DEBUG (MainThread) [homeassistant.components.zha.entity] light.living_uplight: polling current state 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x9417, 260, 6, 11, 11, 45, b'\x00-\x00\x00\x00', True, False) 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 45 {'dstaddr': 37911, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 6, 'transid': 46, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00-\x00\x00\x00'} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\x17\x94\x0b\x0b\x06\x00.\x00\x1e\x05\x00-\x00\x00\x00\xb7' 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 46} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 46} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 46} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 46} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 46} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 46} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 46} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 46} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 46} 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:31:17 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 46} 2020-05-17 17:31:19 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x457a:11:0x0300]: failed to get attributes '['color_temperature', 'current_x', 'current_y', 'color_loop_active']' on 'light_color' cluster: 2020-05-17 17:31:21 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: async_update 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 2820, 3, 3, 47, b'\x00/\x00\x0b\x05', True, False) 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 47 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 2820, 'transid': 48, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00/\x00\x0b\x05'} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x04\x0b0\x00\x1e\x05\x00/\x00\x0b\x05\x98' 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 48} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 48} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 48} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 48} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 48} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 48} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 48} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 48} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 48} 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:31:21 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 48} 2020-05-17 17:31:22 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x9417, 260, 8, 11, 11, 49, b'\x001\x00\x00\x00', True, False) 2020-05-17 17:31:22 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 49 {'dstaddr': 37911, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 8, 'transid': 50, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x001\x00\x00\x00'} 2020-05-17 17:31:22 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\x17\x94\x0b\x0b\x08\x002\x00\x1e\x05\x001\x00\x00\x00\xb9' 2020-05-17 17:31:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:22 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:31:22 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 50} 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 50} 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 50} 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 50} 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 50} 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 50} 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 50} 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 50} 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 50} 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:31:23 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 50} 2020-05-17 17:31:28 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x9417, 260, 768, 11, 11, 51, b'\x003\x00\x07\x00\x03\x00\x04\x00\x02@', True, False) 2020-05-17 17:31:28 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 51 {'dstaddr': 37911, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 768, 'transid': 52, 'options': 0, 'radius': 30, 'len': 11, 'data': b'\x003\x00\x07\x00\x03\x00\x04\x00\x02@'} 2020-05-17 17:31:28 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x15$\x01\x17\x94\x0b\x0b\x00\x034\x00\x1e\x0b\x003\x00\x07\x00\x03\x00\x04\x00\x02@\xe0' 2020-05-17 17:31:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:28 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:31:28 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 52} 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 52} 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 52} 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 52} 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 52} 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 52} 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 52} 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 52} 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 52} 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:31:29 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 52} 2020-05-17 17:31:34 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9417:11:0x0300]: failed to get attributes '['color_temperature', 'current_x', 'current_y', 'color_loop_active']' on 'light_color' cluster: 2020-05-17 17:31:46 DEBUG (MainThread) [homeassistant.core] Bus:Handling , new_state=> 2020-05-17 17:31:52 DEBUG (MainThread) [homeassistant.components.zha.entity] light.bedroom_floorlampmid: polling current state 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7767, 260, 6, 11, 11, 53, b'\x005\x00\x00\x00', True, False) 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 53 {'dstaddr': 30567, 'destendpoint': 11, 'srcendpoint': 11, 'clusterid': 6, 'transid': 54, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x005\x00\x00\x00'} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01gw\x0b\x0b\x06\x006\x00\x1e\x05\x005\x00\x00\x00$' 2020-05-17 17:31:52 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x7acd:3:0x0b04]: async_update 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 2820, 3, 3, 55, b'\x007\x00\x0b\x05', True, False) 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 55 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 2820, 'transid': 56, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x007\x00\x0b\x05'} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x04\x0b8\x00\x1e\x05\x007\x00\x0b\x05\x88' 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 54} +{'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 56} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.uart] Frame received: 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 1, 'transid': 140} +{'status': 205, 'endpoint': 11, 'transid': 54} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 156} +{'status': 205, 'endpoint': 11, 'transid': 54} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 158} +{'status': 205, 'endpoint': 11, 'transid': 54} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 172} +{'status': 205, 'endpoint': 11, 'transid': 54} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 174} +{'status': 205, 'endpoint': 11, 'transid': 54} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 11, 'transid': 176} +{'status': 205, 'endpoint': 11, 'transid': 54} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 236} +{'status': 205, 'endpoint': 11, 'transid': 54} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] payload missmatch -{'endpoint': 3, 'transid': 8} +{'status': 205, 'endpoint': 11, 'transid': 54} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 54} 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm 2020-05-17 17:31:52 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 205, 'endpoint': 11, 'transid': 54} ````
Adminiuga commented 4 years ago

it does look like something in zigpy-cc These

2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x03\xe8' length=3 fcs=44>
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 24}
+{'status': 0, 'endpoint': 3, 'transid': 232}
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 1, 'transid': 140}
+{'status': 0, 'endpoint': 3, 'transid': 232}
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 156}
+{'status': 0, 'endpoint': 3, 'transid': 232}
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 158}
+{'status': 0, 'endpoint': 3, 'transid': 232}
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 172}
+{'status': 0, 'endpoint': 3, 'transid': 232}
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 174}
+{'status': 0, 'endpoint': 3, 'transid': 232}
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 176}
+{'status': 0, 'endpoint': 3, 'transid': 232}
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 232}
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-05-17 17:28:39 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 232}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 0, 3, 3, 233, b'\x00\xe9\x00\x04\x00', True, False)
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 233 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 0, 'transid': 234, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\xe9\x00\x04\x00'}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x00\x00\xea\x00\x1e\x05\x00\xe9\x00\x04\x00\x81'
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.AF command_id=1 data=b'\x00' length=1 fcs=100>
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x03\xea' length=3 fcs=46>
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 24}
+{'status': 0, 'endpoint': 3, 'transid': 234}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 1, 'transid': 140}
+{'status': 0, 'endpoint': 3, 'transid': 234}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 156}
+{'status': 0, 'endpoint': 3, 'transid': 234}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 158}
+{'status': 0, 'endpoint': 3, 'transid': 234}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 172}
+{'status': 0, 'endpoint': 3, 'transid': 234}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 174}
+{'status': 0, 'endpoint': 3, 'transid': 234}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 176}
+{'status': 0, 'endpoint': 3, 'transid': 234}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 234}
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-05-17 17:28:44 DEBUG (MainThread) [zigpy_cc.api] res AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 234}
2020-05-17 17:28:49 INFO (MainThread) [homeassistant.components.esphome] Can't connect to ESPHome API for espcam01.local: Error resolving IP address: [Errno -2] Name does not resolve
2020-05-17 17:28:49 INFO (MainThread) [homeassistant.components.esphome] Trying to reconnect in 60 seconds
2020-05-17 17:28:49 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x7acd, 260, 0, 3, 3, 235, b'\x00\xeb\x00\x05\x00', True, False)
2020-05-17 17:28:49 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 235 {'dstaddr': 31437, 'destendpoint': 3, 'srcendpoint': 3, 'clusterid': 0, 'transid': 236, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\xeb\x00\x05\x00'}
2020-05-17 17:28:49 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\xcdz\x03\x03\x00\x00\xec\x00\x1e\x05\x00\xeb\x00\x05\x00\x84'
2020-05-17 17:28:49 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.AF command_id=1 data=b'\x00' length=1 fcs=100>
2020-05-17 17:28:49 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x03\xec' length=3 fcs=40>
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 24}
+{'status': 0, 'endpoint': 3, 'transid': 236}
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 1, 'transid': 140}
+{'status': 0, 'endpoint': 3, 'transid': 236}
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 156}
+{'status': 0, 'endpoint': 3, 'transid': 236}
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 158}
+{'status': 0, 'endpoint': 3, 'transid': 236}
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 172}
+{'status': 0, 'endpoint': 3, 'transid': 236}
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 174}
+{'status': 0, 'endpoint': 3, 'transid': 236}
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] payload missmatch
-{'endpoint': 11, 'transid': 176}
+{'status': 0, 'endpoint': 3, 'transid': 236}
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 3, 'transid': 236}
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-05-17 17:28:50 DEBUG (MainThread) [zigpy_cc.api] waiting for dataConfirm

Don't look good and we did not get Manufacturer and Model

2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.endpoint] [0x7acd:3] Manufacturer: None
2020-05-17 17:29:00 DEBUG (MainThread) [zigpy.endpoint] [0x7acd:3] Model: None

@sanyatuning can you take a look at this one? Let me know if you would like to move this issue to zigpy-cc repo for visibility

pveras commented 4 years ago

@Adminiuga, @sanyatuning was any progress made on this? I have OSRAM Smart+ lights that present similar issues but they work fine on zigbee2mqtt. Let me know if you would like any debug info to help solve this

Adminiuga commented 4 years ago

You could try alternative implementation of znp protocol via https://github.com/zha-ng/zha-custom-radios Take backups. After installing custom radios, edit .storage/core.config_entries and change radio_type to znp (needs checking)

Variour commented 4 years ago

I have tried it with zha-custom-radios and zigpy-znp, which is linked as a replacement for zha-custom-radios.

My core.config_entries entry looks like this

{
    "connection_class": "local_push",
    "data": {
        "device": {
            "path": "/dev/ttyACM0"
        },
        "radio_type": "znp"
    },
    "domain": "zha",
    "entry_id": "86bebfc8d292426ba81f6272bedf676c",
    "options": {},
    "source": "user",
    "system_options": {
        "disable_new_entities": false
    },
    "title": "/dev/ttyACM0",
    "unique_id": null,
    "version": 2
}

With both I get

Logger: homeassistant.config_entries
Source: components/zha/core/gateway.py:146
First occurred: 23:34:57 (1 occurrences)
Last logged: 23:34:57

Error setting up entry /dev/ttyACM0 for zha
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 219, in async_setup
    result = await component.async_setup_entry(  # type: ignore
  File "/usr/src/homeassistant/homeassistant/components/zha/__init__.py", line 100, in async_setup_entry
    await zha_gateway.async_initialize()
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 146, in async_initialize
    self.application_controller = await app_controller_cls.new(
  File "/usr/local/lib/python3.8/site-packages/zigpy/application.py", line 65, in new
    await app.startup(auto_form)
  File "/usr/local/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 384, in startup
    await self.form_network()
  File "/usr/local/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 553, in form_network
    await self.update_network(
  File "/usr/local/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 490, in update_network
    await self._znp.request(
  File "/usr/local/lib/python3.8/site-packages/zigpy_znp/api.py", line 324, in request
    raise CommandNotRecognized(
zigpy_znp.exceptions.CommandNotRecognized: Fatal request error RPCError.CommandNotRecognized.Rsp(ErrorCode=<ErrorCode.InvalidSubsystem: 1>, RequestHeader=CommandHeader(id=0x08, subsystem=Subsystem.APPConfig, type=CommandType.SREQ)) in response to AppConfig.BDBSetChannel.Req(IsPrimary=<Bool.true: 1>, Channel=<Channels.CHANNEL_25|CHANNEL_20|CHANNEL_15: 34635776>)

Edit: The problem is probably that I am not running Z-Stack 3.0.1, but 1.2 on my CC2531.

makuser commented 4 years ago

I have tried it with zha-custom-radios and zigpy-znp, which is linked as a replacement for zha-custom-radios.

The problem is probably that I am not running Z-Stack 3.0.1, but 1.2 on my CC2531.

Same here, I also switched to zigpy-znp using the custom_component, upgraded my CC2531 to 3.0.1 again, reset the NVRAM and I was finally able to read the proper MODEL_INFO.

I am now waiting for my custom quirk to be merged: https://github.com/zigpy/zha-device-handlers/pull/491

Just for the record; using the CC2531 both with Z-Stack 3.0.1 (20190425) as well as 1.2 (20190608) using the ti_cc radio type did not work for me, at the moment I only have some Osram Smart+ bulbs to test though. I was able to add the bulbs, but they are not recognized properly, actually their signature is partially even correct (only the model info was missing), but for some reason it still used the zha profile to talk to a bulb that clearly identified itself using the zll profile, so I was not able to control it at all.

Great that it all works, it's my first time using the zha component, I only used zigbee2mqtt before.

TheJulianJES commented 3 years ago

As far as I understand, this issue should be fixed by using zigpy-znp instead of zigpy-cc. A "migration guide" for users still experiencing this issue can be found here: https://github.com/zigpy/zigpy-znp#home-assistant (I think this issue can be closed)

pixelspark commented 3 years ago

As far as I understand, this issue should be fixed by using zigpy-znp instead of zigpy-cc. A "migration guide" for users still experiencing this issue can be found here: https://github.com/zigpy/zigpy-znp#home-assistant (I think this issue can be closed)

I am actually using zigpy-znp (I followed the linked guide earlier).

In my case, the Smart+ plugs are recognized, but it seems sometimes their state becomes out of sync (i.e. automations will not change the state of the plug because HA thinks the plug is already in the desired state - manually toggling on/off however still works). When I manually toggle the switch using the button, this does not sync to HA either.

I am seeing a few logs related to the device (0xF351 below) which seem to indicate mostly normal operation (other devices are using the plug as router looks like. Some fragments:

2020-12-12 14:56:23 INFO (MainThread) [zigpy_znp.zigbee.application] ZDO device relays: ZDO.SrcRtgInd.Callback(DstAddr=0xF351, Relays=[])
2020-12-12 14:56:23 INFO (MainThread) [zigpy_znp.zigbee.application] TC device join: ZDO.TCDevInd.Callback(SrcNwk=0x3142, SrcIEEE=00:17:88:01:08:72:8e:0e, ParentNwk=0xF351)
2020-12-12 15:06:19 INFO (MainThread) [zigpy_znp.zigbee.application] ZDO device relays: ZDO.SrcRtgInd.Callback(DstAddr=0x2ADF, Relays=[0xF351])
2020-12-12 15:07:03 INFO (MainThread) [zigpy_znp.zigbee.application] ZDO device relays: ZDO.SrcRtgInd.Callback(DstAddr=0xF351, Relays=[])
2020-12-12 15:17:28 WARNING (MainThread) [zigpy_znp.zigbee.application] Failed to send request AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0xF351), DstEndpoint=3, DstPanId=0x0000, SrcEndpoint=1, ClusterId=0, TSN=40, Options=<TransmitOptions.RouteDiscovery|APSAck: 48>, Radius=30, Data=b'\x00\x28\x00\x04\x00'): Status.MAC_NO_ACK

2020-12-14 10:17:29 INFO (MainThread) [zigpy_znp.zigbee.application] ZDO device relays: ZDO.SrcRtgInd.Callback(DstAddr=0x8DF3, Relays=[0xF351])
2020-12-14 10:19:51 INFO (MainThread) [zigpy_znp.zigbee.application] ZDO device relays: ZDO.SrcRtgInd.Callback(DstAddr=0x8DF3, Relays=[0xF351])
2020-12-14 10:19:51 INFO (MainThread) [zigpy_znp.zigbee.application] ZDO device relays: ZDO.SrcRtgInd.Callback(DstAddr=0x8DF3, Relays=[0xF351])
2020-12-14 10:20:22 INFO (MainThread) [zigpy_znp.zigbee.application] ZDO device relays: ZDO.SrcRtgInd.Callback(DstAddr=0xF351, Relays=[])

2020-12-07 17:40:29 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.osram_outlet_1_electrical_measurement is taking over 10 seconds
2020-12-07 17:40:35 INFO (MainThread) [buienradar.buienradar_json] Parse ws data: latitude: 52.07871146877499, longitude: 5.111322104930879
2020-12-07 17:40:37 WARNING (MainThread) [zigpy_znp.api] Received an unhandled command: AF.DataConfirm.Callback(Status=<Status.APS_NO_ACK: 183>, Endpoint=1, TSN=157)
2020-12-07 17:40:42 WARNING (MainThread) [zigpy_znp.api] Received an unhandled command: AF.DataConfirm.Callback(Status=<Status.APS_NO_ACK: 183>, Endpoint=1, TSN=158)
2020-12-07 17:41:07 WARNING (MainThread) [zigpy_znp.api] Received an unhandled command: AF.DataConfirm.Callback(Status=<Status.APS_NO_ACK: 183>, Endpoint=1, TSN=161)
2020-12-07 17:41:11 WARNING (MainThread) [zigpy_znp.api] Received an unhandled command: AF.DataConfirm.Callback(Status=<Status.APS_NO_ACK: 183>, Endpoint=1, TSN=162)

One minor other thing is that the device seems to report a 'power sensor' but it only shows erroneous data. Not sure if the device actually has such a sensor but in any case something isn't recognized properly.

If you want me to open a separate issue, let me know.

TheJulianJES commented 3 years ago

I've also got a couple of these OSRAM Smart+ plugs. The weird sensor happens because they send "ElectricalMeasurement", but they don't even have a current sensor. I guess a quirk could be added to https://github.com/zigpy/zha-device-handlers/ to not even add the entity to Hass, but for now I just disabled the entity in Home Assistant. (Also another note: the devices seems like it's not a great router. So if you have issues, always try to use another router (not any OSRAM/LEDVANCE device).)

Regarding the issue that your OSRAM plugs seem to loose some messages, I would just create another issue here. The logs are probably a good starting point.

Adminiuga commented 3 years ago

Just disable the entity for em sensor

pixelspark commented 3 years ago

I've also got a couple of these OSRAM Smart+ plugs. The weird sensor happens because they send "ElectricalMeasurement", but they don't even have a current sensor. I guess a quirk could be added to https://github.com/zigpy/zha-device-handlers/ to not even add the entity to Hass, but for now I just disabled the entity in Home Assistant. (Also another note: the devices seems like it's not a great router. So if you have issues, always try to use another router (not any OSRAM/LEDVANCE device).)

Regarding the issue that your OSRAM plugs seem to loose some messages, I would just create another issue here. The logs are probably a good starting point.

Will do. Not seeing any routing issues yet. Reading all this it seems like the best solution is just to get rid of the plugs altogether. Will nevertheless open a separate issue for the syncing problem.

Thanks all, this is probably the only small issue I have encountered with ZHA/HA so far. Really grateful for everyone's effort.

github-actions[bot] commented 3 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.