-
Notifications
You must be signed in to change notification settings - Fork 13
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Hue motion sensor not work #57
Comments
Exact same behavior here with two SML002 on CC2562R1 and CC2531. |
@lociii can you post debug logs of motion sensor pairing? See ZHA integration docs on how to enable debug logging |
@Adminiuga sure. Here you go. HassOS 4.11 (228) 0.112.3 on Raspberry Pi 4 with CC2531
|
so it seems to be exactly same behavior. Looks like it does communicate with the device during the initial interview, but then something happens and in won't talk any longer so you get
In all this cases a common denominator is CC2531, so I suspect something in |
Guess you can generalize that conclusion to all CC* as my main CC2652R1 has the exact same behavior. |
Nah, sorry, I meant to say something about |
@Adminiuga |
I frankly don't know. Need to check the docs what it does exactly, I assume has something to do with routing |
If one of you guys need an SML001 to reproduce/fix, let me know and I'll sponsor it. |
maybe this should be relevant Koenkk/zigbee2mqtt#310 |
I also found this site |
Hrm, that seems to be outdated. I think threre are ZHA users with HUE motion sensors, because one of them was complaining about LED going off on motion. |
https://zigbee.blakadder.com/Philips_SML002.html |
This is interesting:
A status of 240 ( |
But why zdo if endpoint is 1? |
Oops, you're right. Ignore that part. One other possibility is that since the source and destination endpoints are always the same (I haven't dug into where in zigpy this is set), you will run into problems when endpoints other than
And the corresponding profile that's registered on that endpoint: zigpy-cc/zigpy_cc/zigbee/start_znp.py Lines 34 to 40 in e522adf
Messages are sent to endpoint Try changing |
I think you are on the right track. The src endpoint is set in zigpy.endpoint. Endpoint but really radio should be picking one up. Zigpy-deconz had similar issues and currently defaults to src endpoint 1 |
My Xiaomi wall switches also need ep 2. |
I've change this line : Log :
|
There's a device specific quirk in the works. |
I have the very same issue with SML002 on CC2538. |
Same issue here with the sml001 with my sonoff zigbee dongle cc2531. First my motion sensor didn't got any entities only the device, 2nd try it showed me also entities but as mentioned above, they won't work. |
Any news on this one? Can we help someone with logs or stuff? Should be awesome to have this motion sensor available in ZHA by that dongle. |
@jvalst @lociii I believe this bug has been fixed in https://github.com/zha-ng/zigpy-znp/ and @Adminiuga has tested this sensor specifically with it. Let me know if it works for you, especially if you're using a CC2531 running Z-Stack Home 1.2 (install the latest version from Git or the 0.2.0 release, the previous version used by Home Assistant doesn't support Z-Stack Home 1.2). If it doesn't, please open a new issue: https://github.com/zha-ng/zigpy-znp/issues/new |
Yes, it works! But I've flashed CC2531ZNP-without-SBL.bin (Z-Stack 3.0.1) to my CC2531 stick. |
@puddly I have the feeling this is a bit mixed up now. You're talking about it being fixed in zigpy-znp, however this is a bug report for zigpy-cc. @mateuszlukasik-PL What are you running? Does the SML001 report values? |
I do not know what exactly is the problem , but as far as I known SML001 and SML002 required to bind the various cluster in a particular order. 1/ 0x0406 If you bind them in a different order then most-likely the motion won't work and the lux might not as well |
Oh, I would really try out this one, but someone has to guide me through updating zigpy-cc. I just bought the cc usb stick (https://nl.aliexpress.com/item/4000859025741.html?spm=a2g0s.9042311.0.0.735c4c4dkGEHiA) and plugged it in into my Rpi. Got this from my log today adding the SML001: |
@jvalst That's exactly what it looked like for me. Have switched now to zigpy-znp as I'm running a CC2562R1 with ZStack 3 |
Yeah as it looked in that link, I'm running znp as well. I'm not really into the whole zigpy stuff, so not sure where to start to upgrade it. I'm running latest home assistant, and never touched the firmware of the usb stick itself. |
Problem
When I add Hue motion sensor (SML001) thru ZHA integration, pairing process ends, but none of the sensor function work.
Illuminance, temperature, power is "unknown" state, occupancy is always "clear".
I noticed something strange during pairing operation. When I start adding new devices, after few minutes searching stops, logs stops, but when I only hit "search again", then process is continuing, new entry logs came's up.
Reset and reconfig doesn't help. Tried at HA 111.0, 111.4 and 112.0 version.
Adminiuga sugested this could be a zigpy-cc problem.
https://github.com/home-assistant/core/issues/36162
Environment
Zigbee module : CC2531 USB
ZHA log
Device 0xcf1a (00:17:88:01:06:f7:e9:9d) joined the network
[0xcf1a:zdo] ZDO request ZDOCmd.Device_annce: [0xcf1a, 00:17:88:01:06:f7:e9:9d, 128]
[0xcf1a] Requesting 'Node Descriptor'
Tries remaining: 2
[0xcf1a] Extending timeout for 0x03 request
[0xcf1a] Node Descriptor:
[0xcf1a] Discovering endpoints
Tries remaining: 3
[0xcf1a] Extending timeout for 0x05 request
[0xcf1a] Discovered endpoints: [2, 1]
[0xcf1a:2] Discovering endpoint information
Tries remaining: 3
[0xcf1a] Extending timeout for 0x07 request
[0xcf1a:2] Discovered endpoint information: <Optional endpoint=2 profile=260 device_type=263 device_version=0 input_clusters=[0, 1, 3, 1030, 1024, 1026] output_clusters=[25]>
[0xcf1a] Extending timeout for 0x09 request
[0xcf1a] Extending timeout for 0x0b request
[0xcf1a] Extending timeout for 0x0d request
[0xcf1a:2] Manufacturer: None
[0xcf1a:2] Model: None
[0xcf1a:1] Discovering endpoint information
Tries remaining: 3
[0xcf1a] Extending timeout for 0x0f request
[0xcf1a:1] Discovered endpoint information: <Optional endpoint=1 profile=49246 device_type=2128 device_version=2 input_clusters=[0] output_clusters=[0, 3, 4, 6, 8, 768, 5]>
[0xcf1a] Extending timeout for 0x11 request
[0xcf1a:1:0x0000] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=17 command_id=Command.Read_Attributes_rsp>
[0xcf1a:1] Manufacturer: Philips
[0xcf1a:1] Model: SML001
Checking quirks for Philips SML001 (00:17:88:01:06:f7:e9:9d)
Considering <class 'bellows.zigbee.application.EZSPCoordinator'>
Fail because endpoint list mismatch: {1} {1, 2}
Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
Fail because endpoint list mismatch: {11, 13} {1, 2}
Considering <class 'zhaquirks.lutron.lzl4bwhl01remote.LutronLZL4BWHL01Remote2'>
Fail because endpoint list mismatch: {1} {1, 2}
Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
Fail because endpoint list mismatch: {1} {1, 2}
Considering <class 'zhaquirks.osram.a19twhite.A19TunableWhite'>
Fail because endpoint list mismatch: {3} {1, 2}
Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'>
Fail because endpoint list mismatch: {1} {1, 2}
Considering <class 'zhaquirks.philips.rwl020.PhilipsRWL020'>
Fail because device_type mismatch on at least one endpoint
Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'>
Fail because device_type mismatch on at least one endpoint
Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
Fail because endpoint list mismatch: {1} {1, 2}
Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
Fail because endpoint list mismatch: {1} {1, 2}
Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
Fail because endpoint list mismatch: {232, 230} {1, 2}
Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
Fail because endpoint list mismatch: {232, 230} {1, 2}
Considering <class 'zhaquirks.xiaomi.mija.smoke.MijiaHoneywellSmokeDetectorSensor'>
Fail because endpoint list mismatch: {1} {1, 2}
device - 0xcf1a:00:17:88:01:06:f7:e9:9d entering async_device_initialized - is_new_join: True
device - 0xcf1a:00:17:88:01:06:f7:e9:9d has joined the ZHA zigbee network
0xcf1a: started configuration
0xcf1a:ZDO: 'async_configure' stage succeeded
[0xcf1a] Extending timeout for 0x13 request
[0xcf1a] Extending timeout for 0x15 request
[0xcf1a] Extending timeout for 0x17 request
[0xcf1a:1:0x0000]: bound 'basic' cluster: Status.SUCCESS
[0xcf1a:1:0x0000]: finished channel configuration
[0xcf1a] Extending timeout for 0x19 request
[0xcf1a:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS
[0xcf1a:1:0x0006]: finished channel configuration
[0xcf1a] Extending timeout for 0x1b request
[0xcf1a:1:0x0008]: bound 'level' cluster: Status.SUCCESS
[0xcf1a:1:0x0008]: finished channel configuration
[0xcf1a] Extending timeout for 0x1d request
[0xcf1a:1:0x0000] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=25 command_id=Command.Read_Attributes_rsp>
[0xcf1a:1:0x0000]: initializing channel: from_cache: False
[0xcf1a] Extending timeout for 0x1f request
[0xcf1a:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS
[0xcf1a:1:0x0006]: finished channel configuration
[0xcf1a] Extending timeout for 0x21 request
[0xcf1a:1:0x0005]: bound 'scenes' cluster: Status.SUCCESS
[0xcf1a:1:0x0005]: finished channel configuration
[0xcf1a] Extending timeout for 0x23 request
[0xcf1a:1:0x0300]: bound 'light_color' cluster: Status.SUCCESS
[0xcf1a:1:0x0300]: finished channel configuration
[0xcf1a] Extending timeout for 0x25 request
[0xcf1a:1:0x0000]: 'async_configure' stage succeeded
[0xcf1a:1:0x0006]: 'async_configure' stage succeeded
[0xcf1a:1:0x0008]: 'async_configure' stage succeeded
[0xcf1a:1:0x0006]: 'async_configure' stage succeeded
[0xcf1a:1:0x0005]: 'async_configure' stage succeeded
[0xcf1a:1:0x0300]: 'async_configure' stage succeeded
[0xcf1a:2:0x0001]: bound 'power' cluster: Status.SUCCESS
[0xcf1a] Extending timeout for 0x27 request
[0xcf1a:2:0x0402]: bound 'temperature' cluster: Status.SUCCESS
[0xcf1a] Extending timeout for 0x29 request
[0xcf1a:2:0x0400]: bound 'illuminance' cluster: Status.SUCCESS
[0xcf1a] Extending timeout for 0x2b request
[0xcf1a:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=0 command_id=66>
[0xcf1a:1:0x0006] ZCL request 0x0042: [0, 3000, 0]
[0xcf1a:1:0x0006] No handler for cluster command 66
[0xcf1a:1:0x0006]: received 'on_with_timed_off' command with [0, 3000, 0] args on cluster_id '6' tsn '0'
SEARCHING NEW DEVICE STOPS HERE
BUT WHEN I CLICK ON "SEARCH AGAIN" BUTTON... IT CONTINUES...
[0xcf1a:2:0x0001]: failed to get attributes '['battery_size', 'battery_percentage_remaining', 'battery_voltage', 'battery_quantity']' on 'power' cluster:
[0xcf1a:2:0x0001]: initializing channel: from_cache: False
[0xcf1a] Extending timeout for 0x49 request
[0xcf1a:2:0x0402]: failed to get attributes '['measured_value']' on 'temperature' cluster:
[0xcf1a:2:0x0406]: initializing channel: from_cache: False
[0xcf1a] Extending timeout for 0x4b request
[0xcf1a:2:0x0400]: failed to get attributes '['measured_value']' on 'illuminance' cluster:
[0xcf1a] Extending timeout for 0x4d request
[0xcf1a:2:0x0001]: failed to get attributes '['battery_voltage', 'battery_percentage_remaining']' on 'power' cluster:
[0xcf1a:2:0x0019]: initializing channel: from_cache: False
[0xcf1a:2:0x0406]: failed to get attributes '['occupancy']' on 'occupancy' cluster:
[0xcf1a:2:0x0000]: initializing channel: from_cache: False
[0xcf1a:2:0x0001]: 'async_initialize' stage succeeded
[0xcf1a:2:0x0402]: 'async_initialize' stage succeeded
[0xcf1a:2:0x0400]: 'async_initialize' stage succeeded
[0xcf1a:2:0x0406]: 'async_initialize' stage succeeded
[0xcf1a:2:0x0000]: 'async_initialize' stage succeeded
[0xcf1a:2:0x0019]: 'async_initialize' stage succeeded
0xcf1a: power source: Battery or Unknown
0xcf1a: completed initialization
HASS log
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.zigbee.application] broadcast (0, 54, 0, 0, 0, 0, 1, b'\x01<\x00', <BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>)
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO mgmtPermitJoinReq tsn: 1 {'addrmode': 15, 'dstaddr': 0xfffc, 'duration': 60, 'tcsignificance': 0}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&'
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=54 data=b'\x00' length=1 fcs=82>
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO mgmtPermitJoinReq tsn: None {'status': 0}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO mgmtPermitJoinReq tsn: None {'addrmode': 15, 'dstaddr': <BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>, 'duration': 60, 'tcsignificance': 0}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&'
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=203 data=b'<' length=1 fcs=179>
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO permitJoinInd tsn: None {'duration': 60}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL ledControl tsn: None {'ledid': 3, 'mode': <LedMode.On: 1>}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x02'\n\x03\x01-"
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=54 data=b'\x00' length=1 fcs=82>
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO mgmtPermitJoinReq tsn: None {'status': 0}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=10 data=b'\x00' length=1 fcs=108>
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL ledControl tsn: None {'status': 0}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=182 data=b'\x00\x00\x00' length=3 fcs=240>
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO mgmtPermitJoinRsp tsn: None {'srcaddr': 0x0000, 'status': 0}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL ledControl tsn: None {'ledid': 3, 'mode': <LedMode.On: 1>}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x02'\n\x03\x01-"
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=182 data=b'\x00\x00\x00' length=3 fcs=240>
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO mgmtPermitJoinRsp tsn: None {'srcaddr': 0x0000, 'status': 0}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL ledControl tsn: None {'ledid': 3, 'mode': <LedMode.On: 1>}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x02'\n\x03\x01-"
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=10 data=b'\x00' length=1 fcs=108>
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL ledControl tsn: None {'status': 0}
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=10 data=b'\x00' length=1 fcs=108>
2020-07-03 20:39:28 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL ledControl tsn: None {'status': 0}
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=202 data=b'\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x00\x00' length=12 fcs=77>
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO tcDeviceInd tsn: None {'nwkaddr': 0xcf1a, 'extaddr': 00:17:88:01:06:f7:e9:9d, 'parentaddr': 0x0000}
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: tcDeviceInd
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=193 data=b'\x1a\xcf\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x80' length=13 fcs=18>
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO endDeviceAnnceInd tsn: 0 {'srcaddr': 0xcf1a, 'nwkaddr': 0xcf1a, 'ieeeaddr': 00:17:88:01:06:f7:e9:9d, 'capabilities': 128}
2020-07-03 20:39:32 INFO (MainThread) [zigpy_cc.zigbee.application] New device joined: 0xcf1a, 00:17:88:01:06:f7:e9:9d
2020-07-03 20:39:32 INFO (MainThread) [zigpy.application] Device 0xcf1a (00:17:88:01:06:f7:e9:9d) joined the network
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 0 endDeviceAnnceInd
2020-07-03 20:39:32 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message endDeviceAnnceInd
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy.zdo] [0xcf1a:zdo] ZDO request ZDOCmd.Device_annce: [0xcf1a, 00:17:88:01:06:f7:e9:9d, 128]
2020-07-03 20:39:32 INFO (MainThread) [zigpy.device] [0xcf1a] Requesting 'Node Descriptor'
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy.util] Tries remaining: 2
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x03 request
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Node_Desc_req: 2>, 0, 0, 3, b'\x03\x1a\xcf', True, False)
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.api] waiting for 3 nodeDescReq
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO nodeDescReq tsn: 3 {'dstaddr': 0xcf1a, 'nwkaddrofinterest': 0xcf1a}
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x04%\x02\x1a\xcf\x1a\xcf#'
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=2 data=b'\x00' length=1 fcs=102>
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO nodeDescReq tsn: None {'status': 0}
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=130 data=b'\x1a\xcf\x00\x1a\xcf\x02@\x80\x0b\x10Y?\x00\x00\x00?\x00\x00' length=18 fcs=85>
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO nodeDescRsp tsn: 3 {'srcaddr': 0xcf1a, 'status': 0, 'nwkaddr': 0xcf1a, 'logicaltype_cmplxdescavai_userdescavai': 2, 'apsflags_freqband': 64, 'maccapflags': 128, 'manufacturercode': 4107, 'maxbuffersize': 89, 'maxintransfersize': 63, 'servermask': 0, 'maxouttransfersize': 63, 'descriptorcap': 0}
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 3 nodeDescRsp
2020-07-03 20:39:32 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message nodeDescRsp
2020-07-03 20:39:32 INFO (MainThread) [zigpy.device] [0xcf1a] Node Descriptor:
2020-07-03 20:39:32 INFO (MainThread) [zigpy.device] [0xcf1a] Discovering endpoints
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x05 request
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Active_EP_req: 5>, 0, 0, 5, b'\x05\x1a\xcf', True, False)
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.api] waiting for 5 activeEpReq
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO activeEpReq tsn: 5 {'dstaddr': 0xcf1a, 'nwkaddrofinterest': 0xcf1a}
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x04%\x05\x1a\xcf\x1a\xcf$'
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=5 data=b'\x00' length=1 fcs=97>
2020-07-03 20:39:32 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO activeEpReq tsn: None {'status': 0}
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=133 data=b'\x1a\xcf\x00\x1a\xcf\x02\x02\x01' length=8 fcs=201>
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO activeEpRsp tsn: 5 {'srcaddr': 0xcf1a, 'status': 0, 'nwkaddr': 0xcf1a, 'activeepcount': 2, 'activeeplist': [2, 1]}
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 5 activeEpRsp
2020-07-03 20:39:33 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message activeEpRsp
2020-07-03 20:39:33 INFO (MainThread) [zigpy.device] [0xcf1a] Discovered endpoints: [2, 1]
2020-07-03 20:39:33 INFO (MainThread) [zigpy.endpoint] [0xcf1a:2] Discovering endpoint information
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x07 request
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Simple_Desc_req: 4>, 0, 0, 7, b'\x07\x1a\xcf\x02', True, False)
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.api] waiting for 7 simpleDescReq
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO simpleDescReq tsn: 7 {'dstaddr': 0xcf1a, 'nwkaddrofinterest': 0xcf1a, 'endpoint': 2}
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%\x04\x1a\xcf\x1a\xcf\x02&'
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=4 data=b'\x00' length=1 fcs=96>
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO simpleDescReq tsn: None {'status': 0}
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=132 data=b'\x1a\xcf\x00\x1a\xcf\x16\x02\x04\x01\x07\x01\x00\x06\x00\x00\x01\x00\x03\x00\x06\x04\x00\x04\x02\x04\x01\x19\x00' length=28 fcs=214>
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO simpleDescRsp tsn: 7 {'srcaddr': 0xcf1a, 'status': 0, 'nwkaddr': 0xcf1a, 'len': 22, 'endpoint': 2, 'profileid': 260, 'deviceid': 263, 'deviceversion': 0, 'numinclusters': 6, 'inclusterlist': [0, 1, 3, 1030, 1024, 1026], 'numoutclusters': 1, 'outclusterlist': [25]}
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 7 simpleDescRsp
2020-07-03 20:39:33 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message simpleDescRsp
2020-07-03 20:39:33 INFO (MainThread) [zigpy.endpoint] [0xcf1a:2] Discovered endpoint information: <Optional endpoint=2 profile=260 device_type=263 device_version=0 input_clusters=[0, 1, 3, 1030, 1024, 1026] output_clusters=[25]>
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x09 request
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 0, 2, 2, 9, b'\x00\t\x00\x04\x00\x05\x00', True, False)
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 9 {'dstaddr': 53018, 'destendpoint': 2, 'srcendpoint': 2, 'clusterid': 0, 'transid': 10, 'options': 0, 'radius': 30, 'len': 7, 'data': b'\x00\t\x00\x04\x00\x05\x00'}
2020-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x11$\x01\x1a\xcf\x02\x02\x00\x00\n\x00\x1e\x07\x00\t\x00\x04\x00\x05\x00\xfa'
2020-07-03 20:39:33 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-07-03 20:39:33 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:39:34 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x02\n' length=3 fcs=207>
2020-07-03 20:39:34 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 2, 'transid': 10}
2020-07-03 20:39:34 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:40:02 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x0b request
2020-07-03 20:40:02 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 0, 2, 2, 11, b'\x00\x0b\x00\x04\x00', True, False)
2020-07-03 20:40:02 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 11 {'dstaddr': 53018, 'destendpoint': 2, 'srcendpoint': 2, 'clusterid': 0, 'transid': 12, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x0b\x00\x04\x00'}
2020-07-03 20:40:02 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\x1a\xcf\x02\x02\x00\x00\x0c\x00\x1e\x05\x00\x0b\x00\x04\x00\xe7'
2020-07-03 20:40:02 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-07-03 20:40:02 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:40:02 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x02\x0c' length=3 fcs=201>
2020-07-03 20:40:02 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 2, 'transid': 12}
2020-07-03 20:40:02 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:40:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=203 data=b'\x00' length=1 fcs=143>
2020-07-03 20:40:28 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO permitJoinInd tsn: None {'duration': 0}
2020-07-03 20:40:28 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL ledControl tsn: None {'ledid': 3, 'mode': <LedMode.Off: 0>}
2020-07-03 20:40:28 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x02'\n\x03\x00,"
2020-07-03 20:40:28 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=10 data=b'\x00' length=1 fcs=108>
2020-07-03 20:40:28 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL ledControl tsn: None {'status': 0}
2020-07-03 20:40:30 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x0d request
2020-07-03 20:40:30 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 0, 2, 2, 13, b'\x00\r\x00\x05\x00', True, False)
2020-07-03 20:40:30 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 13 {'dstaddr': 53018, 'destendpoint': 2, 'srcendpoint': 2, 'clusterid': 0, 'transid': 14, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\r\x00\x05\x00'}
2020-07-03 20:40:30 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\x1a\xcf\x02\x02\x00\x00\x0e\x00\x1e\x05\x00\r\x00\x05\x00\xe2'
2020-07-03 20:40:30 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-07-03 20:40:30 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:40:30 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x02\x0e' length=3 fcs=203>
2020-07-03 20:40:30 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 2, 'transid': 14}
2020-07-03 20:40:30 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:40:58 DEBUG (MainThread) [zigpy.endpoint] [0xcf1a:2] Manufacturer: None
2020-07-03 20:40:58 DEBUG (MainThread) [zigpy.endpoint] [0xcf1a:2] Model: None
2020-07-03 20:40:58 INFO (MainThread) [zigpy.endpoint] [0xcf1a:1] Discovering endpoint information
2020-07-03 20:40:58 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2020-07-03 20:40:58 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x0f request
2020-07-03 20:40:58 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Simple_Desc_req: 4>, 0, 0, 15, b'\x0f\x1a\xcf\x01', True, False)
2020-07-03 20:40:58 DEBUG (MainThread) [zigpy_cc.api] waiting for 15 simpleDescReq
2020-07-03 20:40:58 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO simpleDescReq tsn: 15 {'dstaddr': 0xcf1a, 'nwkaddrofinterest': 0xcf1a, 'endpoint': 1}
2020-07-03 20:40:58 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%\x04\x1a\xcf\x1a\xcf\x01%'
2020-07-03 20:40:58 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=4 data=b'\x00' length=1 fcs=96>
2020-07-03 20:40:58 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO simpleDescReq tsn: None {'status': 0}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=132 data=b'\x1a\xcf\x00\x1a\xcf\x18\x01^\xc0P\x08\x02\x01\x00\x00\x07\x00\x00\x03\x00\x04\x00\x06\x00\x08\x00\x00\x03\x05\x00' length=30 fcs=11>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO simpleDescRsp tsn: 15 {'srcaddr': 0xcf1a, 'status': 0, 'nwkaddr': 0xcf1a, 'len': 24, 'endpoint': 1, 'profileid': 49246, 'deviceid': 2128, 'deviceversion': 2, 'numinclusters': 1, 'inclusterlist': [0], 'numoutclusters': 7, 'outclusterlist': [0, 3, 4, 6, 8, 768, 5]}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 15 simpleDescRsp
2020-07-03 20:40:59 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message simpleDescRsp
2020-07-03 20:40:59 INFO (MainThread) [zigpy.endpoint] [0xcf1a:1] Discovered endpoint information: <Optional endpoint=1 profile=49246 device_type=2128 device_version=2 input_clusters=[0] output_clusters=[0, 3, 4, 6, 8, 768, 5]>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x11 request
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 0, 1, 1, 17, b'\x00\x11\x00\x04\x00\x05\x00', True, False)
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 17 {'dstaddr': 53018, 'destendpoint': 1, 'srcendpoint': 1, 'clusterid': 0, 'transid': 18, 'options': 0, 'radius': 30, 'len': 7, 'data': b'\x00\x11\x00\x04\x00\x05\x00'}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x11$\x01\x1a\xcf\x01\x01\x00\x00\x12\x00\x1e\x07\x00\x11\x00\x04\x00\x05\x00\xfa'
2020-07-03 20:40:59 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-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x01\x12' length=3 fcs=212>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 1, 'transid': 18}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=129 data=b'\x00\x00\x00\x00\x1a\xcf\x01\x01\x00Y\x00G\xa7Q\x00\x00\x1a\x18\x11\x01\x04\x00\x00B\x07Philips\x05\x00\x00B\x06SML001\x1a\xcf\x1d' length=46 fcs=56>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF incomingMsg tsn: None {'groupid': 0, 'clusterid': 0, 'srcaddr': 0xcf1a, 'srcendpoint': 1, 'dstendpoint': 1, 'wasbroadcast': 0, 'linkquality': 89, 'securityuse': 0, 'timestamp': 5351239, 'transseqnumber': 0, 'len': 26, 'data': b'\x18\x11\x01\x04\x00\x00B\x07Philips\x05\x00\x00B\x06SML001'}
2020-07-03 20:40:59 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message incomingMsg
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.zcl] [0xcf1a:1:0x0000] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=17 command_id=Command.Read_Attributes_rsp>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.endpoint] [0xcf1a:1] Manufacturer: Philips
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.endpoint] [0xcf1a:1] Model: SML001
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for Philips SML001 (00:17:88:01:06:f7:e9:9d)
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.lutron.lzl4bwhl01remote.LutronLZL4BWHL01Remote2'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.osram.a19twhite.A19TunableWhite'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {3} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl020.PhilipsRWL020'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.mija.smoke.MijiaHoneywellSmokeDetectorSensor'>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2020-07-03 20:40:59 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0xcf1a:00:17:88:01:06:f7:e9:9d entering async_device_initialized - is_new_join: True
2020-07-03 20:40:59 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0xcf1a:00:17:88:01:06:f7:e9:9d has joined the ZHA zigbee network
2020-07-03 20:40:59 DEBUG (MainThread) [homeassistant.components.zha.core.device] 0xcf1a: started configuration
2020-07-03 20:40:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] 0xcf1a:ZDO: 'async_configure' stage succeeded
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x13 request
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Bind_req: 33>, 0, 0, 19, b'\x13\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x00\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01', True, False)
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] waiting for 19 bindReq
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 19 {'dstaddr': 0xcf1a, 'srcaddr': 00:17:88:01:06:f7:e9:9d, 'srcendpoint': 1, 'clusterid': 0, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:14:db:d0:1d, 'dstendpoint': 1}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x00\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01\x85'
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x15 request
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Bind_req: 33>, 0, 0, 21, b'\x15\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x06\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01', True, False)
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] waiting for 21 bindReq
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 21 {'dstaddr': 0xcf1a, 'srcaddr': 00:17:88:01:06:f7:e9:9d, 'srcendpoint': 1, 'clusterid': 6, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:14:db:d0:1d, 'dstendpoint': 1}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x06\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01\x83'
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x17 request
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Bind_req: 33>, 0, 0, 23, b'\x17\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x08\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01', True, False)
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] waiting for 23 bindReq
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 23 {'dstaddr': 0xcf1a, 'srcaddr': 00:17:88:01:06:f7:e9:9d, 'srcendpoint': 1, 'clusterid': 8, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:14:db:d0:1d, 'dstendpoint': 1}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x08\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01\x8d'
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=33 data=b'\x00' length=1 fcs=69>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=33 data=b'\x00' length=1 fcs=69>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0}
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=33 data=b'\x00' length=1 fcs=69>
2020-07-03 20:40:59 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0}
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=161 data=b'\x1a\xcf\x00' length=3 fcs=50>
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 19 {'srcaddr': 0xcf1a, 'status': 0}
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 19 bindRsp
2020-07-03 20:41:00 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp
2020-07-03 20:41:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0000]: bound 'basic' cluster: Status.SUCCESS
2020-07-03 20:41:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0000]: finished channel configuration
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x19 request
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 0, 1, 1, 25, b'\x00\x19\x00\x07\x00', True, False)
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 25 {'dstaddr': 53018, 'destendpoint': 1, 'srcendpoint': 1, 'clusterid': 0, 'transid': 26, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00\x19\x00\x07\x00'}
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\x1a\xcf\x01\x01\x00\x00\x1a\x00\x1e\x05\x00\x19\x00\x07\x00\xe0'
2020-07-03 20:41:00 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-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=161 data=b'\x1a\xcf\x00' length=3 fcs=50>
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 21 {'srcaddr': 0xcf1a, 'status': 0}
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 21 bindRsp
2020-07-03 20:41:00 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp
2020-07-03 20:41:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS
2020-07-03 20:41:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0006]: finished channel configuration
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x1b request
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Bind_req: 33>, 0, 0, 27, b'\x1b\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x06\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01', True, False)
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.api] waiting for 27 bindReq
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 27 {'dstaddr': 0xcf1a, 'srcaddr': 00:17:88:01:06:f7:e9:9d, 'srcendpoint': 1, 'clusterid': 6, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:14:db:d0:1d, 'dstendpoint': 1}
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x06\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01\x83'
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=33 data=b'\x00' length=1 fcs=69>
2020-07-03 20:41:00 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0}
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=161 data=b'\x1a\xcf\x00' length=3 fcs=50>
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 23 {'srcaddr': 0xcf1a, 'status': 0}
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 23 bindRsp
2020-07-03 20:41:01 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp
2020-07-03 20:41:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0008]: bound 'level' cluster: Status.SUCCESS
2020-07-03 20:41:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0008]: finished channel configuration
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x1d request
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Bind_req: 33>, 0, 0, 29, b'\x1d\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x05\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01', True, False)
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] waiting for 29 bindReq
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 29 {'dstaddr': 0xcf1a, 'srcaddr': 00:17:88:01:06:f7:e9:9d, 'srcendpoint': 1, 'clusterid': 5, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:14:db:d0:1d, 'dstendpoint': 1}
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x05\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01\x80'
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=33 data=b'\x00' length=1 fcs=69>
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0}
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x01\x1a' length=3 fcs=220>
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 1, 'transid': 26}
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=129 data=b'\x00\x00\x00\x00\x1a\xcf\x01\x01\x00Y\x00N\xc0Q\x00\x00\x08\x18\x19\x01\x07\x00\x000\x03\x1a\xcf\x1d' length=28 fcs=126>
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF incomingMsg tsn: None {'groupid': 0, 'clusterid': 0, 'srcaddr': 0xcf1a, 'srcendpoint': 1, 'dstendpoint': 1, 'wasbroadcast': 0, 'linkquality': 89, 'securityuse': 0, 'timestamp': 5357646, 'transseqnumber': 0, 'len': 8, 'data': b'\x18\x19\x01\x07\x00\x000\x03'}
2020-07-03 20:41:01 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message incomingMsg
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy.zcl] [0xcf1a:1:0x0000] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=25 command_id=Command.Read_Attributes_rsp>
2020-07-03 20:41:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0000]: initializing channel: from_cache: False
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x1f request
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Bind_req: 33>, 0, 0, 31, b'\x1f\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x00\x03\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01', True, False)
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] waiting for 31 bindReq
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 31 {'dstaddr': 0xcf1a, 'srcaddr': 00:17:88:01:06:f7:e9:9d, 'srcendpoint': 1, 'clusterid': 768, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:14:db:d0:1d, 'dstendpoint': 1}
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x01\x00\x03\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01\x86'
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=161 data=b'\x1a\xcf\x00' length=3 fcs=50>
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 27 {'srcaddr': 0xcf1a, 'status': 0}
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 27 bindRsp
2020-07-03 20:41:01 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp
2020-07-03 20:41:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS
2020-07-03 20:41:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0006]: finished channel configuration
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=33 data=b'\x00' length=1 fcs=69>
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0}
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x21 request
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Bind_req: 33>, 0, 0, 33, b'!\x9d\xe9\xf7\x06\x01\x88\x17\x00\x02\x01\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01', True, False)
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] waiting for 33 bindReq
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 33 {'dstaddr': 0xcf1a, 'srcaddr': 00:17:88:01:06:f7:e9:9d, 'srcendpoint': 2, 'clusterid': 1, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:14:db:d0:1d, 'dstendpoint': 1}
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x02\x01\x00\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01\x87'
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=33 data=b'\x00' length=1 fcs=69>
2020-07-03 20:41:01 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0}
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=161 data=b'\x1a\xcf\x00' length=3 fcs=50>
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 29 {'srcaddr': 0xcf1a, 'status': 0}
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 29 bindRsp
2020-07-03 20:41:02 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp
2020-07-03 20:41:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0005]: bound 'scenes' cluster: Status.SUCCESS
2020-07-03 20:41:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0005]: finished channel configuration
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x23 request
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Bind_req: 33>, 0, 0, 35, b'#\x9d\xe9\xf7\x06\x01\x88\x17\x00\x02\x02\x04\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01', True, False)
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.api] waiting for 35 bindReq
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 35 {'dstaddr': 0xcf1a, 'srcaddr': 00:17:88:01:06:f7:e9:9d, 'srcendpoint': 2, 'clusterid': 1026, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:14:db:d0:1d, 'dstendpoint': 1}
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x02\x02\x04\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01\x80'
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=33 data=b'\x00' length=1 fcs=69>
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0}
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=161 data=b'\x1a\xcf\x00' length=3 fcs=50>
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 31 {'srcaddr': 0xcf1a, 'status': 0}
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 31 bindRsp
2020-07-03 20:41:02 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp
2020-07-03 20:41:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0300]: bound 'light_color' cluster: Status.SUCCESS
2020-07-03 20:41:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0300]: finished channel configuration
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x25 request
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 0, <ZDOCmd.Bind_req: 33>, 0, 0, 37, b'%\x9d\xe9\xf7\x06\x01\x88\x17\x00\x02\x00\x04\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01', True, False)
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.api] waiting for 37 bindReq
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO bindReq tsn: 37 {'dstaddr': 0xcf1a, 'srcaddr': 00:17:88:01:06:f7:e9:9d, 'srcendpoint': 2, 'clusterid': 1024, 'dstaddrmode': 3, 'dstaddress': 00:12:4b:00:14:db:d0:1d, 'dstendpoint': 1}
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17%!\x1a\xcf\x9d\xe9\xf7\x06\x01\x88\x17\x00\x02\x00\x04\x03\x1d\xd0\xdb\x14\x00K\x12\x00\x01\x82'
2020-07-03 20:41:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0000]: 'async_configure' stage succeeded
2020-07-03 20:41:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0006]: 'async_configure' stage succeeded
2020-07-03 20:41:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0008]: 'async_configure' stage succeeded
2020-07-03 20:41:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0006]: 'async_configure' stage succeeded
2020-07-03 20:41:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0005]: 'async_configure' stage succeeded
2020-07-03 20:41:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0300]: 'async_configure' stage succeeded
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=33 data=b'\x00' length=1 fcs=69>
2020-07-03 20:41:02 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO bindReq tsn: None {'status': 0}
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=161 data=b'\x1a\xcf\x00' length=3 fcs=50>
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 33 {'srcaddr': 0xcf1a, 'status': 0}
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 33 bindRsp
2020-07-03 20:41:03 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp
2020-07-03 20:41:03 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0001]: bound 'power' cluster: Status.SUCCESS
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x27 request
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 1, 2, 2, 39, b"\x00'\x06\x00 \x00 \x10\x0e0*\x01", True, False)
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 39 {'dstaddr': 53018, 'destendpoint': 2, 'srcendpoint': 2, 'clusterid': 1, 'transid': 40, 'options': 0, 'radius': 30, 'len': 12, 'data': b"\x00'\x06\x00 \x00 \x10\x0e0*\x01"}
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x16$\x01\x1a\xcf\x02\x02\x01\x00(\x00\x1e\x0c\x00'\x06\x00 \x00 \x10\x0e0*\x01\xf9"
2020-07-03 20:41:03 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-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=161 data=b'\x1a\xcf\x00' length=3 fcs=50>
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 35 {'srcaddr': 0xcf1a, 'status': 0}
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 35 bindRsp
2020-07-03 20:41:03 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp
2020-07-03 20:41:03 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0402]: bound 'temperature' cluster: Status.SUCCESS
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x29 request
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 1026, 2, 2, 41, b'\x00)\x06\x00\x00\x00)\x1e\x00\x84\x032\x00', True, False)
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 41 {'dstaddr': 53018, 'destendpoint': 2, 'srcendpoint': 2, 'clusterid': 1026, 'transid': 42, 'options': 0, 'radius': 30, 'len': 13, 'data': b'\x00)\x06\x00\x00\x00)\x1e\x00\x84\x032\x00'}
2020-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17$\x01\x1a\xcf\x02\x02\x02\x04*\x00\x1e\r\x00)\x06\x00\x00\x00)\x1e\x00\x84\x032\x00u'
2020-07-03 20:41:03 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-07-03 20:41:03 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=161 data=b'\x1a\xcf\x00' length=3 fcs=50>
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO bindRsp tsn: 37 {'srcaddr': 0xcf1a, 'status': 0}
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.zigbee.application] REPLY for 37 bindRsp
2020-07-03 20:41:04 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message bindRsp
2020-07-03 20:41:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0400]: bound 'illuminance' cluster: Status.SUCCESS
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x2b request
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 1024, 2, 2, 43, b'\x00+\x06\x00\x00\x00!\x1e\x00\x84\x03\x01\x00', True, False)
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 43 {'dstaddr': 53018, 'destendpoint': 2, 'srcendpoint': 2, 'clusterid': 1024, 'transid': 44, 'options': 0, 'radius': 30, 'len': 13, 'data': b'\x00+\x06\x00\x00\x00!\x1e\x00\x84\x03\x01\x00'}
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x17$\x01\x1a\xcf\x02\x02\x00\x04,\x00\x1e\r\x00+\x06\x00\x00\x00!\x1e\x00\x84\x03\x01\x00H'
2020-07-03 20:41:04 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-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x02(' length=3 fcs=237>
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 2, 'transid': 40}
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x02*' length=3 fcs=239>
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 2, 'transid': 42}
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x02,' length=3 fcs=233>
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 2, 'transid': 44}
2020-07-03 20:41:04 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:41:07 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=129 data=b'\x00\x00\x06\x00\x1a\xcf\x01\x01\x00Y\x00E\tR\x00\x00\x08\x01\x00B\x00\xb8\x0b\x00\x00\x1a\xcf\x1d' length=28 fcs=125>
2020-07-03 20:41:07 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF incomingMsg tsn: None {'groupid': 0, 'clusterid': 6, 'srcaddr': 0xcf1a, 'srcendpoint': 1, 'dstendpoint': 1, 'wasbroadcast': 0, 'linkquality': 89, 'securityuse': 0, 'timestamp': 5376325, 'transseqnumber': 0, 'len': 8, 'data': b'\x01\x00B\x00\xb8\x0b\x00\x00'}
2020-07-03 20:41:07 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message incomingMsg
2020-07-03 20:41:07 DEBUG (MainThread) [zigpy.zcl] [0xcf1a:1:0x0006] ZCL deserialize: <ZCLHeader frame_control= manufacturer=None tsn=0 command_id=66>
2020-07-03 20:41:07 DEBUG (MainThread) [zigpy.zcl] [0xcf1a:1:0x0006] ZCL request 0x0042: [0, 3000, 0]
2020-07-03 20:41:07 DEBUG (MainThread) [zigpy.zcl] [0xcf1a:1:0x0006] No handler for cluster command 66
2020-07-03 20:41:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:1:0x0006]: received 'on_with_timed_off' command with [0, 3000, 0] args on cluster_id '6' tsn '0'
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.zigbee.application] broadcast (0, 54, 0, 0, 0, 0, 71, b'G<\x00', <BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>)
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO mgmtPermitJoinReq tsn: 71 {'addrmode': 15, 'dstaddr': 0xfffc, 'duration': 60, 'tcsignificance': 0}
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&'
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=54 data=b'\x00' length=1 fcs=82>
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO mgmtPermitJoinReq tsn: None {'status': 0}
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO mgmtPermitJoinReq tsn: None {'addrmode': 15, 'dstaddr': <BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>, 'duration': 60, 'tcsignificance': 0}
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&'
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=203 data=b'<' length=1 fcs=179>
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO permitJoinInd tsn: None {'duration': 60}
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL ledControl tsn: None {'ledid': 3, 'mode': <LedMode.On: 1>}
2020-07-03 20:42:56 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x02'\n\x03\x01-"
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=54 data=b'\x00' length=1 fcs=82>
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO mgmtPermitJoinReq tsn: None {'status': 0}
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=10 data=b'\x00' length=1 fcs=108>
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL ledControl tsn: None {'status': 0}
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=182 data=b'\x00\x00\x00' length=3 fcs=240>
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO mgmtPermitJoinRsp tsn: None {'srcaddr': 0x0000, 'status': 0}
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL ledControl tsn: None {'ledid': 3, 'mode': <LedMode.On: 1>}
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x02'\n\x03\x01-"
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=182 data=b'\x00\x00\x00' length=3 fcs=240>
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO mgmtPermitJoinRsp tsn: None {'srcaddr': 0x0000, 'status': 0}
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL ledControl tsn: None {'ledid': 3, 'mode': <LedMode.On: 1>}
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x02'\n\x03\x01-"
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=10 data=b'\x00' length=1 fcs=108>
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL ledControl tsn: None {'status': 0}
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=10 data=b'\x00' length=1 fcs=108>
2020-07-03 20:42:57 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL ledControl tsn: None {'status': 0}
2020-07-03 20:42:58 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0001]: failed to get attributes '['battery_size', 'battery_percentage_remaining', 'battery_voltage', 'battery_quantity']' on 'power' cluster:
2020-07-03 20:42:58 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0001]: initializing channel: from_cache: False
2020-07-03 20:42:58 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x49 request
2020-07-03 20:42:58 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 1, 2, 2, 73, b'\x00I\x00 \x00!\x00', True, False)
2020-07-03 20:42:58 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 73 {'dstaddr': 53018, 'destendpoint': 2, 'srcendpoint': 2, 'clusterid': 1, 'transid': 74, 'options': 0, 'radius': 30, 'len': 7, 'data': b'\x00I\x00 \x00!\x00'}
2020-07-03 20:42:58 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x11$\x01\x1a\xcf\x02\x02\x01\x00J\x00\x1e\x07\x00I\x00 \x00!\x00\xfb'
2020-07-03 20:42:58 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-07-03 20:42:58 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:42:58 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x02J' length=3 fcs=143>
2020-07-03 20:42:58 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 2, 'transid': 74}
2020-07-03 20:42:58 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:42:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0402]: failed to get attributes '['measured_value']' on 'temperature' cluster:
2020-07-03 20:42:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0406]: initializing channel: from_cache: False
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x4b request
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 1030, 2, 2, 75, b'\x00K\x00\x00\x00', True, False)
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 75 {'dstaddr': 53018, 'destendpoint': 2, 'srcendpoint': 2, 'clusterid': 1030, 'transid': 76, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00K\x00\x00\x00'}
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\x1a\xcf\x02\x02\x06\x04L\x00\x1e\x05\x00K\x00\x00\x00\xe1'
2020-07-03 20:42:59 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-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x02L' length=3 fcs=137>
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 2, 'transid': 76}
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:42:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0400]: failed to get attributes '['measured_value']' on 'illuminance' cluster:
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy.device] [0xcf1a] Extending timeout for 0x4d request
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0xcf1a, 260, 0, 2, 2, 77, b'\x00M\x00\x07\x00', True, False)
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 77 {'dstaddr': 53018, 'destendpoint': 2, 'srcendpoint': 2, 'clusterid': 0, 'transid': 78, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x00M\x00\x07\x00'}
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\x1a\xcf\x02\x02\x00\x00N\x00\x1e\x05\x00M\x00\x07\x00\xe0'
2020-07-03 20:42:59 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-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0}
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x02N' length=3 fcs=139>
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 2, 'transid': 78}
2020-07-03 20:42:59 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm
2020-07-03 20:43:26 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0001]: failed to get attributes '['battery_voltage', 'battery_percentage_remaining']' on 'power' cluster:
2020-07-03 20:43:26 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0019]: initializing channel: from_cache: False
2020-07-03 20:43:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0406]: failed to get attributes '['occupancy']' on 'occupancy' cluster:
2020-07-03 20:43:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0000]: initializing channel: from_cache: False
2020-07-03 20:43:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0001]: 'async_initialize' stage succeeded
2020-07-03 20:43:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0402]: 'async_initialize' stage succeeded
2020-07-03 20:43:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0400]: 'async_initialize' stage succeeded
2020-07-03 20:43:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0406]: 'async_initialize' stage succeeded
2020-07-03 20:43:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0000]: 'async_initialize' stage succeeded
2020-07-03 20:43:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xcf1a:2:0x0019]: 'async_initialize' stage succeeded
2020-07-03 20:43:27 DEBUG (MainThread) [homeassistant.components.zha.core.device] 0xcf1a: power source: Battery or Unknown
2020-07-03 20:43:27 DEBUG (MainThread) [homeassistant.components.zha.core.device] 0xcf1a: completed initialization
2020-07-03 20:43:57 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=203 data=b'\x00' length=1 fcs=143>
2020-07-03 20:43:57 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO permitJoinInd tsn: None {'duration': 0}
2020-07-03 20:43:57 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL ledControl tsn: None {'ledid': 3, 'mode': <LedMode.Off: 0>}
2020-07-03 20:43:57 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x02'\n\x03\x00,"
2020-07-03 20:43:57 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=10 data=b'\x00' length=1 fcs=108>
2020-07-03 20:43:57 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL ledControl tsn: None {'status': 0}
The text was updated successfully, but these errors were encountered: