AXIS Gear Blind Zigbee Broken

synergicmind commented 5 years ago

Home Assistant release with the issue: 0.98.5

Last working Home Assistant release (if known): 0.89

Operating environment (Hass.io/Docker/Windows/etc.): MacOS

Component/platform: Zigbee

Description of problem:

I installed fresh version of 0.98.5 and everything works fine except my Axis Gear Blind control (Zigbee) does not work. It pairs but I get following error in the log. "Failed to parse message (b'18420700002100') on cluster 1, because Data is too short to contain 2 bytes".

First, it paired as a switch rather than dimable light bulb like the previous HA versions which was better because you could control the position of the blind using "dim". Second, turning on/off the switch does nothing. Base on the error, the cluster is now mis-match. How do I get this fixed?

Traceback (if applicable):

Failed to parse message (b'18420700002100') on cluster 1, because Data is too short to contain 2 bytes

probot-home-assistant[bot] commented 5 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!

Adminiuga commented 5 years ago

You would need to enable full debug logging: logger: configuration.yaml to set level permanently

logger:
  default: info
  logs:
    asyncio: debug
    homeassistant.components.zha: debug
    zigpy: debug
    bellows: debug
    zigpy_xbee: debug
    zigpy_deconz: debug
    zigpy_zigate: debug

Please remove the device from ZHA, reset it and re-pair it, and post the logs of pairing. Need to see the signature of the device.

There were change in zha since 0.89 and you may have to override device type in configuration.yaml. However cluster 1 has nothing to do with turning the device on or off. We'll need to see the full logs you trying to control the device after you overrode the device type. Search https://community.home-assistant.io/t/zha-zigbee-tested-devices-please-add-your-device-results/17718?page=20 topic on how to override the device.

mkrishnamu3 commented 5 years ago

Im seeing the same issue with my Axis... I will try and post my logs. I also tried to override the device type and was only able to go between a switch and an outlet, not a dimmable light.

dmulcahey commented 5 years ago

We don't have official support for this and I don't understand what possessed you to pay for these 😸 Just kidding, but man they are expensive!!! My guess is that they do something that doesn't follow the ZCL spec. Technically these should implement the closure cluster but many manufacturers abuse on/off and level control for these devices. Keen home does the same thing for their smart vents. You should be able to configure these as lights using the link Alexi provided above. If you are still having issues please provide the previously requested debug logs.

synergicmind commented 5 years ago

I ran the debug as requested. Here is the dump of what I've got. It generated the whole bunch so I tried to capture of what's relevant. But it still might be more than what was needed.

2019-09-22 15:18:11 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:18:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'361921ad03d27e'
2019-09-22 15:18:11 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6419a1ad80197e'
2019-09-22 15:18:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:18:11 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:18:21 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:18:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'471e21adb2837e'
2019-09-22 15:18:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'751ea1ad689a7e'
2019-09-22 15:18:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:18:21 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:18:31 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:18:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'501f21adcf397e'
2019-09-22 15:18:31 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'061fa1ad86037e'
2019-09-22 15:18:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:18:31 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:18:41 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:18:41 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'611c21adcc347e'
2019-09-22 15:18:41 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'171ca1adb2407e'
2019-09-22 15:18:41 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:18:41 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:18:50 DEBUG (MainThread) [bellows.ezsp] Send command sendBroadcast: (<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>, <EmberApsFrame profileId=0 clusterId=54 sourceEndpoint=0 destinationEndpoint=0 options=0 groupId=0 sequence=20>, 0, 20, b'\x14<\x00')
2019-09-22 15:18:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'721d219ea8d515b26f944a25aa559249884e33a8f9f26775437e'
2019-09-22 15:18:50 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'201da19e54d0e8c47e'
2019-09-22 15:18:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:18:50 DEBUG (MainThread) [bellows.ezsp] Application frame 54 (sendBroadcast) received: b'00fa'
2019-09-22 15:18:50 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'301db1ed512a158459944a2daa5592b3634e27ab1231649fc1c6cd0a7e'
2019-09-22 15:18:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:18:50 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0500003600000008000000faff000000ffff03143c00'
2019-09-22 15:18:50 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST_LOOPBACK: 5>, <EmberApsFrame profileId=0 clusterId=54 sourceEndpoint=0 destinationEndpoint=0 options=8 groupId=0 sequence=250>, 255, 0, 0x0000, 255, 255, b'\x14<\x00']
2019-09-22 15:18:50 DEBUG (MainThread) [zigpy.zdo] [0x0000:zdo] ZDO request ZDOCmd.Mgmt_Permit_Joining_req: [60, <Bool.false: 0>]
2019-09-22 15:18:51 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'401db19750d6eab259a24a25aa5d92499cb433abedbcd17e'
2019-09-22 15:18:51 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:18:51 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'04fcff00003600000008000000fa140000'
2019-09-22 15:18:51 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_MULTICAST_WITH_ALIAS: 4>, 65532, <EmberApsFrame profileId=0 clusterId=54 sourceEndpoint=0 destinationEndpoint=0 options=8 groupId=0 sequence=250>, 20, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:18:51 DEBUG (MainThread) [bellows.ezsp] Send command permitJoining: (60,)
2019-09-22 15:18:51 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'0522218a6840767e'
2019-09-22 15:18:51 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5122a18a5410c77e'
2019-09-22 15:18:51 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:18:51 DEBUG (MainThread) [bellows.ezsp] Application frame 34 (permitJoining) received: b'00'
2019-09-22 15:18:51 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:18:51 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'162321ad36f87e'
2019-09-22 15:18:51 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6223a1ada5e47e'
2019-09-22 15:18:51 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:18:51 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:19:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7223b18b552bee9864a45925aa13b64998370c7e'
2019-09-22 15:19:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:01 DEBUG (MainThread) [bellows.ezsp] Application frame 35 (childJoinHandler) received: b'0101fb2a3d3013000046240004'
2019-09-22 15:19:01 DEBUG (MainThread) [bellows.zigbee.application] Received childJoinHandler frame with [1, <Bool.true: 1>, 0x2afb, 00:24:46:00:00:13:30:3d, <EmberNodeType.SLEEPY_END_DEVICE: 4>]
2019-09-22 15:19:01 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:19:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'202021ad64d87e'
2019-09-22 15:19:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0320a1add3d27e'
2019-09-22 15:19:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:01 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1320b18caf0028824a944a638e5593499c4e791e7e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 36 (trustCenterJoinHandler) received: b'fb2a3d3013000046240001000000'
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] Received trustCenterJoinHandler frame with [0x2afb, 00:24:46:00:00:13:30:3d, <EmberDeviceUpdate.STANDARD_SECURITY_UNSECURED_JOIN: 1>, <EmberJoinDecision.USE_PRECONFIGURED_KEY: 0>, 0x0000]
2019-09-22 15:19:02 INFO (MainThread) [zigpy.application] Device 0x2afb (00:24:46:00:00:13:30:3d) joined the network
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.application] Device 00:24:46:00:00:13:30:3d changed id (0x4b17 => 0x2afb)
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for AXIS Gear (00:24:46:00:00:13:30:3d)
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zigpy.quirks.smartthings.SmartthingsMultiPurposeSensor'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.lutron.lzl4bwhl01remote.LutronLZL4BWHL01Remote2'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.osram.a19twhite.A19TunableWhite'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {3} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XbeeSensor'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.mija.smoke.MijiaHoneywellSmokeDetectorSensor'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'>
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:02 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x2afb:00:24:46:00:00:13:30:3d entering async_device_initialized - is_new_join: False
2019-09-22 15:19:02 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x2afb:00:24:46:00:00:13:30:3d has been reset and readded or its nwk address changed
2019-09-22 15:19:02 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] skipping discovery for previously discovered device - 0x2afb:00:24:46:00:00:13:30:3d
2019-09-22 15:19:02 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2afb](Gear): started configuration
2019-09-22 15:19:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x2afb:ZDO](Gear): channel: 'async_configure' stage succeeded
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x2afb
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x2afb
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'322121d6697d3a06b259d26e25ab35d27e'
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x2afb
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2421a1d64d7d7e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'432621d6697d3a06b259d26e25ab19f67e'
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x2afb, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=21>, 21, b'\x15=0\x13\x00\x00F$\x00\x01\x00\x00\x03\xa2\xce\x00\x12\x00o\r\x00\x01')
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3526a1d6a5fe7e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x2afb, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=22>, 22, b'\x16=0\x13\x00\x00F$\x00\x01\x06\x00\x03\xa2\xce\x00\x12\x00o\r\x00\x01')
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'542721d6697d3a06b259d26e25abc63f7e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4627a1d64b677e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'6524219c54d13fb259b54a25aa1593499c5b32bdf8f35798fdc625adfc7f3fa7e86f106f9dffa8d6d5d3a41c7e'
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x2afb, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=23>, 23, b'\x17=0\x13\x00\x00F$\x00\x01\x01\x00\x03\xa2\xce\x00\x12\x00o\r\x00\x01')
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5724a19c54d6cf2d7e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'00fc'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7625219c54d13fb259b54a25aa1593499c5831bdfbf35798fdc625adfc7f39a7e86f106f9dffa8d6d5d3c19b7e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6025a19c54d792907e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'072a219c54d13fb259b54a25aa1593499c5930bdfaf35798fdc625adfc7f3ea7e86f106f9dffa8d6d5d3ea5d7e'
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'00fd'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'712aa19c54d4982e7e'
2019-09-22 15:19:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'00fe'
2019-09-22 15:19:09 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'012ab12816d13fdc2e7e'
2019-09-22 15:19:09 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:09 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42fb2a'
2019-09-22 15:19:09 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0x2afb]
2019-09-22 15:19:09 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'112ab12816d13feb557e'
2019-09-22 15:19:09 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:09 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42fb2a'
2019-09-22 15:19:09 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0x2afb]
2019-09-22 15:19:09 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'212ab12816d13fb2d87e'
2019-09-22 15:19:09 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:09 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42fb2a'
2019-09-22 15:19:09 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0x2afb]
2019-09-22 15:19:09 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'312ab12816d13f85a37e'
2019-09-22 15:19:09 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:09 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42fb2a'
2019-09-22 15:19:09 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0x2afb]
2019-09-22 15:19:11 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'412ab58b552aee9864a45925aa13b64998054f7e'
2019-09-22 15:19:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:11 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'512ab18b552b0ba964a45925aa13b64998af5c7e'
2019-09-22 15:19:11 DEBUG (MainThread) [bellows.ezsp] Application frame 35 (childJoinHandler) received: b'0100fb2a3d3013000046240004'
2019-09-22 15:19:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:11 DEBUG (MainThread) [bellows.zigbee.application] Received childJoinHandler frame with [1, <Bool.false: 0>, 0x2afb, 00:24:46:00:00:13:30:3d, <EmberNodeType.SLEEPY_END_DEVICE: 4>]
2019-09-22 15:19:11 DEBUG (MainThread) [bellows.ezsp] Application frame 35 (childJoinHandler) received: b'01011e1b3d3013000046240004'
2019-09-22 15:19:11 DEBUG (MainThread) [bellows.zigbee.application] Received childJoinHandler frame with [1, <Bool.true: 1>, 0x1b1e, 00:24:46:00:00:13:30:3d, <EmberNodeType.SLEEPY_END_DEVICE: 4>]
2019-09-22 15:19:11 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:19:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'162b21ad9f597e'
2019-09-22 15:19:11 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'622ba1ad0c457e'
2019-09-22 15:19:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:11 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:19:11 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'722bb18c4a3128824a944a638e5593499c4e282c7e'
2019-09-22 15:19:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:11 DEBUG (MainThread) [bellows.ezsp] Application frame 36 (trustCenterJoinHandler) received: b'1e1b3d3013000046240001000000'
2019-09-22 15:19:11 DEBUG (MainThread) [bellows.zigbee.application] Received trustCenterJoinHandler frame with [0x1b1e, 00:24:46:00:00:13:30:3d, <EmberDeviceUpdate.STANDARD_SECURITY_UNSECURED_JOIN: 1>, <EmberJoinDecision.USE_PRECONFIGURED_KEY: 0>, 0x0000]
2019-09-22 15:19:11 INFO (MainThread) [zigpy.application] Device 0x1b1e (00:24:46:00:00:13:30:3d) joined the network
2019-09-22 15:19:11 DEBUG (MainThread) [zigpy.application] Device 00:24:46:00:00:13:30:3d changed id (0x2afb => 0x1b1e)
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for AXIS Gear (00:24:46:00:00:13:30:3d)
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zigpy.quirks.smartthings.SmartthingsMultiPurposeSensor'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.lutron.lzl4bwhl01remote.LutronLZL4BWHL01Remote2'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.osram.a19twhite.A19TunableWhite'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {3} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XbeeSensor'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.mija.smoke.MijiaHoneywellSmokeDetectorSensor'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 196}
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x1b1e:00:24:46:00:00:13:30:3d entering async_device_initialized - is_new_join: False
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x1b1e:00:24:46:00:00:13:30:3d has been reset and readded or its nwk address changed
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] skipping discovery for previously discovered device - 0x1b1e:00:24:46:00:00:13:30:3d
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1b1e](Gear): started configuration
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x1b1e:ZDO](Gear): channel: 'async_configure' stage succeeded
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'202821d6697d3a06b259d26e25abb17d5d7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0328a1d6b58f7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'312921d6697d3a06b259d26e25abe1df7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=24>, 24, b'\x18=0\x13\x00\x00F$\x00\x01\x00\x00\x03\xa2\xce\x00\x12\x00o\r\x00\x01')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1429a1d6c8357e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'422e21d6697d3a06b259d26e25ab473d7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=25>, 25, b'\x19=0\x13\x00\x00F$\x00\x01\x01\x00\x03\xa2\xce\x00\x12\x00o\r\x00\x01')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'252ea1d617f87e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'532f219c54340eb259b54a25aa1593499c563fbdf5f35798fdc625adfc7f3fa7e86f106f9dffa8d6d5d3a5307e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=26>, 26, b'\x1a=0\x13\x00\x00F$\x00\x01\x06\x00\x03\xa2\xce\x00\x12\x00o\r\x00\x01')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'362fa19c542a17f97e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'642c219c54340eb259b54a25aa1593499c573ebdf4f35798fdc625adfc7f3ea7e86f106f9dffa8d6d5d3f5b57e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0000'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'472ca19c542be9367e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0001'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'752d219c54340eb259b54a25aa1593499c543dbdf7f35798fdc625adfc7f39a7e86f106f9dffa8d6d5d30ec07e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'502da19c5428a1c17e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0002'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'602db5ca691a06b259d26e25144d7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 98 (incomingSenderEui64Handler) received: b'3d30130000462400'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingSenderEui64Handler frame with [00:24:46:00:00:13:30:3d]
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'702db1ed502a15a159944a2dae55927363f539b012316b0ae3dd5eb9ef7e3fe1cfcd5eaa6c7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'04000013000000080400003affbb1e1bffff0c811e1b3d3013000046240080'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, <EmberApsFrame profileId=0 clusterId=19 sourceEndpoint=0 destinationEndpoint=0 options=1032 groupId=0 sequence=58>, 255, -69, 0x1b1e, 255, 255, b'\x81\x1e\x1b=0\x13\x00\x00F$\x00\x80']
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zdo] [0x1b1e:zdo] ZDO request ZDOCmd.Device_annce: [0x1b1e, 00:24:46:00:00:13:30:3d, 128]
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1b1e](Gear): started initialization
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x1b1e:ZDO](Gear): entry loaded from storage: ZhaDeviceEntry(name='AXIS Gear', ieee='00:24:46:00:00:13:30:3d', last_seen=1568596793.083701)
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x1b1e:ZDO](Gear): channel: 'async_initialize' stage succeeded
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'003221d6697d3a06b259d26e25abb6077e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0132a1d6dc457e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7d313321d6697d3a06b259d26e25abe6a57e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=27>, 27, b'\x00\x1b\x00\x07\x00')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1233a5d6a7ca7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'223021d6697d3a06b259d26e25ab17437e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=28>, 28, b'\x00\x1c\x001\x00')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2232b1ed5077d7b359508e2dab55927263f539b012314093fccc6389dc7d3aa7cb32d86fae0038dcd5906ede2753c0883e7aa1ea378a71a96216239fd0406ab17e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3330a1d673a47e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'045dc20100c4c4080100003bffbb1e1bffff2718010a00002003050020ff060021ffff07004207526170696448410400420830312e30302e3030'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, <EmberApsFrame profileId=49757 clusterId=1 sourceEndpoint=196 destinationEndpoint=196 options=264 groupId=0 sequence=59>, 255, -69, 0x1b1e, 255, 255, b'\x18\x01\n\x00\x00 \x03\x05\x00 \xff\x06\x00!\xff\xff\x07\x00B\x07RapidHA\x04\x00B\x0801.00.00']
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=1 command_id=Command.Report_Attributes>
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'3431219c54340eb658944a24ab1593499c553caeedd5678cfd911b7e'
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=uint8_t, value=3>>, <Attribute attrid=5 value=<TypeValue type=uint8_t, value=255>>, <Attribute attrid=6 value=<TypeValue type=uint16_t, value=65535>>, <Attribute attrid=7 value=<TypeValue type=CharacterString, value=RapidHA>>, <Attribute attrid=4 value=<TypeValue type=CharacterString, value=01.00.00>>]]
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] Attribute report received: mains_voltage=3, 5=255, 6=65535, 7=RapidHA, 4=01.00.00
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=29>, 29, b'\x00\x1d\x00\x00\x00')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4431a59c5429e8457e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5430b1ed5477d7b359508e65ab55927563f539b012316e9bffc66b89f57e35a79be17e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0003'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'005dc20100c4c4400100003cffbb1e1bffff09100200080009000a00'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'4636219c54340eb658954a24ab1593499c523baeedd267bafd54407e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=49757 clusterId=1 sourceEndpoint=196 destinationEndpoint=196 options=320 groupId=0 sequence=60>, 255, -69, 0x1b1e, 255, 255, b'\x10\x02\x00\x08\x00\t\x00\n\x00']
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=2 command_id=Command.Read_Attributes>
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] ZCL request 0x0000: [[8, 9, 10]]
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] No handler for general command Command.Read_Attributes
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6536a59c542e8fde7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7531b1ed542a1593d9944a65ab55927463f539b012316593fd2b0b7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0004'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'5037219c54340eb658924a24ab1593499c533aaeedd3678bfd22237e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00000021800000400100003dffbb1e1bffff021800'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=61>, 255, -69, 0x1b1e, 255, 255, b'\x18\x00']
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0536b19754340eb259b54a25aa1593499c4e3fabed74c67e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b0000210000004001000000180000'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1637a19c542f74237e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=0>, 24, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0000]: bound 'basic' cluster: Status.SUCCESS
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0000]: finished channel configuration
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0005'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'623421d6697d3a06b259d26e25ab40477e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2734a1d67e327e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=30>, 30, b'\x00\x1e\x00\x07\x00')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7335219c54340eb658944a24ab1593499c5039aeedd0678cfd67767e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3035a59c542c72db7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4034b1ed542a1593d9944a65ab55927763f539b012316592fd2df37e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0006'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00000021800000400100003effbb1e1bffff021900'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=62>, 255, -69, 0x1b1e, 255, 255, b'\x19\x00']
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5035b19754340eb259b54a25aa1593499c4f3eabed4c617e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b0000210000004001000001190000'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=1>, 25, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: bound 'power' cluster: Status.SUCCESS
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'063a21d6697d3a06b259d26e25ab22c47e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'613aa1d62c367e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=31>, 31, b'\x00\x1f\x06\x00 \x00 \x10\x0e0*\x01')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'173b219c54340eb658954a24ab1593499c5138a7edd1618bddc64399f24e15a6b7107e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'723ba19c542d86f37e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0007'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'023bb1ed542a1593d9944a65ab55927663f539b012316591fddead7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00000021800000400100003fffbb1e1bffff021a00'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=0 clusterId=32801 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=63>, 255, -69, 0x1b1e, 255, 255, b'\x1a\x00']
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'123bb19754340eb259b54a25aa1593499c4c3dabed2e457e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b00002100000040010000021a0000'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=2>, 26, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'223821d6697d3a06b259d26e25ab0ceb7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2338a1d6c1a27e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=32>, 32, b'\x00 \x06\x00\x00\x00\x10\x00\x00\x84\x03')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'3339219c54340eb658924a24ab1593499c6e07a0edee618bfdc67389fcfa3ca7f27e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3338b1ed542e14b259954b65ab55920963f539b012316f93e6c76489fc4e3c5d4c7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401000001014001000040ffbb1e1bffff08181b010700003003'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=64>, 255, -69, 0x1b1e, 255, 255, b'\x18\x1b\x01\x07\x00\x000\x03']
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=27 command_id=Command.Read_Attributes_rsp>
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4439a19c542291f27e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0008'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5439b19754340eb658944a24ab1593499c4d3cabed92d27e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b04010000010140010000031b0000'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=3>, 27, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0000]: initializing channel: from_cache: False
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0000]: channel: 'async_initialize' stage succeeded
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6439b1ed542e14b359954b65ab55920863f539b012316f93e1c75289fc4ec05aad7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401010001014001000041ffbb1e1bffff08181c0131000030ff'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=65>, 255, -69, 0x1b1e, 255, 255, b'\x18\x1c\x011\x00\x000\xff']
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=28 command_id=Command.Read_Attributes_rsp>
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7439b19754340eb658954a24ab1593499c4a3babed48a17e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b04010100010140010000041c0000'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=4>, 28, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'403e21d6697d3a06b259d26e25abfaab7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'053ea5d6af117e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=33>, 33, b'\x00!\x00!\x00')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'513f219c54340eb658954a24ab1593499c6f06aeedef67aafdadb07e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1539b1ed542e14b459954b65ab55920b63f539b012316f93e0c76389fc6e3f85e17e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'253eb1ed542e14b259954b65ab55920a63f539b012316f93e3c76489fc4e3c8de97e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401060001014001000042ffbb1e1bffff08181d010000001000'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=66>, 255, -69, 0x1b1e, 255, 255, b'\x18\x1d\x01\x00\x00\x00\x10\x00']
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'353eb19754340eb658944a24ab1593499c4839abed8e457e'
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=29 command_id=Command.Read_Attributes_rsp>
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401000001014001000043ffbb1e1bffff08181e010700003003'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=67>, 255, -69, 0x1b1e, 255, 255, b'\x18\x1e\x01\x07\x00\x000\x03']
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'463fa59c54230de77e'
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=30 command_id=Command.Read_Attributes_rsp>
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b04010000010140010000061e0000'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=6>, 30, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'563eb1ed542e14b359954b65ab55920d63f539b012316093e2c16389dc7e0a757e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0009'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401010001014001000044ffbb1e1bffff07181f0700002000'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=68>, 255, -69, 0x1b1e, 255, 255, b'\x18\x1f\x07\x00\x00 \x00']
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=31 command_id=Command.Configure_Reporting_rsp>
2019-09-22 15:19:12 ERROR (MainThread) [bellows.zigbee.application] Failed to parse message (b'181f0700002000') on cluster 1, because Data is too short to contain 2 bytes
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0000]: initializing channel: from_cache: False
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'663fb1ed542e14b459954b65ab55920c63f539b012316093ddc16389fc7e31277e'
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0000]: channel: 'async_configure' stage succeeded
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401060001014001000045ffbb1e1bffff0718200700000000'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=69>, 255, -69, 0x1b1e, 255, 255, b'\x18 \x07\x00\x00\x00\x00']
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=32 command_id=Command.Configure_Reporting_rsp>
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'763fb19754340eb658924a24ab1593499c4607abedb97b7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b0401060001014001000008200000'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=8>, 32, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0006]: reporting 'on_off' attr on 'on_off' cluster: 0/900/1: Result: '[[<ConfigureReportingResponseRecord status=Status.SUCCESS>, <ConfigureReportingResponseRecord status=Status.SUCCESS>, <ConfigureReportingResponseRecord status=Status.SUCCESS>, <ConfigureReportingResponseRecord status=Status.SUCCESS>]]'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'063fb1ed542e14b359954b65ab55920f63f539b012316f93dcc74289fc5e7fb3e87e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'163fb19754340eb658954a24ab1593499c4706abede6797e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401010001014001000046ffbb1e1bffff081821012100002040'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=70>, 255, -69, 0x1b1e, 255, 255, b'\x18!\x01!\x00\x00 @']
2019-09-22 15:19:12 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=33 command_id=Command.Read_Attributes_rsp>
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b0401010001014001000009210000'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=9>, 33, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'623c21d6697d3a06b259d26e25ab5bef7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'273ca1d6d7937e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=34>, 34, b'\x00"\x00 \x00')
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'733d219c54340eb658954a24ab1593499c6c05aeedec67abfdc74c7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'303da19c54207b8b7e'
2019-09-22 15:19:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'000a'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'403db1ed542e14b359954b65ab55920e63f539b012316f93dfc74389fc5ec0a7c17e'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'503db19754340eb658954a24ab1593499c4405abed88937e'
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401010001014001000047ffbb1e1bffff0818220120000020ff'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=71>, 255, -69, 0x1b1e, 255, 255, b'\x18"\x01 \x00\x00 \xff']
2019-09-22 15:19:13 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=34 command_id=Command.Read_Attributes_rsp>
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b040101000101400100000a220000'
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=10>, 34, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'06c221d6697d3a06b259d26e25ab177d5d7e'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'61c2a1d666c57e'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=35>, 35, b'\x00#\x003\x00')
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'17c3219c54340eb658954a24ab1593499c6d04aeeded67b8fdaf727e'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'72c3a19c54217a047e'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'000b'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'02c3b1ed542e14b359954b65ab55920163f539b012316f93dec75089fc5e3f74fd7e'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'12c3b19754340eb658954a24ab1593499c4504abed03dc7e'
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401010001014001000048ffbb1e1bffff081823013300002000'
2019-09-22 15:19:13 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=72>, 255, -69, 0x1b1e, 255, 255, b'\x18#\x013\x00\x00 \x00']
2019-09-22 15:19:13 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=35 command_id=Command.Read_Attributes_rsp>
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b040101000101400100000b230000'
2019-09-22 15:19:13 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=11>, 35, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:13 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: initializing channel: from_cache: False
2019-09-22 15:19:13 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: channel: 'async_initialize' stage succeeded
2019-09-22 15:19:13 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0006]: finished channel configuration
2019-09-22 15:19:13 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0006]: channel: 'async_configure' stage succeeded
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'22c3b1ed5477d7b359508e65ab55920063f539b012316e9bfec66b89f57e35a7f8e37e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'005dc20100c4c44001000049ffbb1e1bffff09100300080009000a00'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=49757 clusterId=1 sourceEndpoint=196 destinationEndpoint=196 options=320 groupId=0 sequence=73>, 255, -69, 0x1b1e, 255, 255, b'\x10\x03\x00\x08\x00\t\x00\n\x00']
2019-09-22 15:19:14 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=3 command_id=Command.Read_Attributes>
2019-09-22 15:19:14 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] ZCL request 0x0000: [[8, 9, 10]]
2019-09-22 15:19:14 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] No handler for general command Command.Read_Attributes
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'32c3b19754d13fb259b54a25aa1592499cb232cded6b367e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00fb2a00002100000040000000fc156600'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 11003, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=64 groupId=0 sequence=252>, 21, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2019-09-22 15:19:14 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0000]: Failed to bind 'basic' cluster: [0x2afb:0:0x0021]: message send failure: EmberStatus.DELIVERY_FAILED
2019-09-22 15:19:14 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0000]: finished channel configuration
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'24c021d6697d3a06b259d26e25abb6397e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'43c0a5d61e477e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=36>, 36, b'\x00$\x00\x07\x00')
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'35c1219c54340eb658944a24ab1593499c6a03aeedea678cfd93907e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'53c3b19754d13fb259b54a25aa1592499cb331cded87e97e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00fb2a00002100000040000000fd166600'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 11003, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=64 groupId=0 sequence=253>, 22, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2019-09-22 15:19:14 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0006]: Failed to bind 'on_off' cluster: [0x2afb:0:0x0021]: message send failure: EmberStatus.DELIVERY_FAILED
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'64c1a19c5426d9057e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'47c621d6697d3a06b259d26e25ab057d3a7e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'000c'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'74c1b19754d13fb259b54a25aa1592499cb030cded44587e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00fb2a00002100000040000000fe176600'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 11003, <EmberApsFrame profileId=0 clusterId=33 sourceEndpoint=0 destinationEndpoint=0 options=64 groupId=0 sequence=254>, 23, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2019-09-22 15:19:14 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: Failed to bind 'power' cluster: [0x2afb:0:0x0021]: message send failure: EmberStatus.DELIVERY_FAILED
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'05c6a1d629267e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'51c721d6697d3a06b259d26e25ab9fb07e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=37>, 37, b'\x00%\x06\x00\x00\x00\x10\x00\x00\x84\x03')
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'16c7a1d69e6d7e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'62c4219c54340eb658924a24ab1593499c6b02a0edeb618bfdc67389fcfa3cbf547e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=38>, 38, b'\x00&\x06\x00 \x00 \x10\x0e0*\x01')
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'27c4a59c542784727e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'37c7b1ed542e14b259954b65ab55920363f539b012316f93d9c76489fc4e3cba307e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'000d'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'47c4b19754340eb658944a24ab1593499c4203abed7bfb7e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00040100000101400100004affbb1e1bffff081824010700003003'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=74>, 255, -69, 0x1b1e, 255, 255, b'\x18$\x01\x07\x00\x000\x03']
2019-09-22 15:19:14 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=36 command_id=Command.Read_Attributes_rsp>
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'75c5219c54340eb658954a24ab1593499c6801a7ede8618bddc64399f24e15a698c67e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b040100000101400100000c240000'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=0 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=12>, 36, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:14 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0000]: initializing channel: from_cache: False
2019-09-22 15:19:14 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0000]: channel: 'async_configure' stage succeeded
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'50c5a19c5424596c7e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'000e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'60c5b1ed542e14b459954b65ab55920263f539b012316093d8c16389fc7ee1007e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'70c5b19754340eb658924a24ab1593499c4302abed8e047e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00040106000101400100004bffbb1e1bffff0718250700000000'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=75>, 255, -69, 0x1b1e, 255, 255, b'\x18%\x07\x00\x00\x00\x00']
2019-09-22 15:19:14 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=37 command_id=Command.Configure_Reporting_rsp>
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'00c5b1ed542e14b359954b65ab55920563f539b012316093dbc16389dc7e2ec27e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b040106000101400100000d250000'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=13>, 37, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00040101000101400100004cffbb1e1bffff0718260700002000'
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'10c5b19754340eb658954a24ab1593499c4001abed520e7e'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=76>, 255, -69, 0x1b1e, 255, 255, b'\x18&\x07\x00\x00 \x00']
2019-09-22 15:19:14 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:14 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=38 command_id=Command.Configure_Reporting_rsp>
2019-09-22 15:19:14 ERROR (MainThread) [bellows.zigbee.application] Failed to parse message (b'18260700002000') on cluster 1, because Data is too short to contain 2 bytes
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b040101000101400100000e260000'
2019-09-22 15:19:14 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=14>, 38, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:14 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0006]: reporting 'on_off' attr on 'on_off' cluster: 0/900/1: Result: '[[<ConfigureReportingResponseRecord status=Status.SUCCESS>, <ConfigureReportingResponseRecord status=Status.SUCCESS>, <ConfigureReportingResponseRecord status=Status.SUCCESS>, <ConfigureReportingResponseRecord status=Status.SUCCESS>]]'
2019-09-22 15:19:14 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0006]: finished channel configuration
2019-09-22 15:19:14 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0006]: channel: 'async_configure' stage succeeded
2019-09-22 15:19:15 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'20c5b1ed5477d7b359508e65ab55920463f539b012316e9bf9c66b89f57e35a7da6a7e'
2019-09-22 15:19:15 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:15 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'005dc20100c4c4400100004dffbb1e1bffff09100400080009000a00'
2019-09-22 15:19:15 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=49757 clusterId=1 sourceEndpoint=196 destinationEndpoint=196 options=320 groupId=0 sequence=77>, 255, -69, 0x1b1e, 255, 255, b'\x10\x04\x00\x08\x00\t\x00\n\x00']
2019-09-22 15:19:15 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=4 command_id=Command.Read_Attributes>
2019-09-22 15:19:15 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] ZCL request 0x0000: [[8, 9, 10]]
2019-09-22 15:19:15 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:196:0x0001] No handler for general command Command.Read_Attributes
2019-09-22 15:19:17 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'30c5b1ed502a15b459944a2dab55920763f539b012316e8a00396788fd673fa7cbed7e'
2019-09-22 15:19:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:17 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'04000006000000080100004effbb1e1bffff0901fdff040101190000'
2019-09-22 15:19:17 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, <EmberApsFrame profileId=0 clusterId=6 sourceEndpoint=0 destinationEndpoint=0 options=264 groupId=0 sequence=78>, 255, -69, 0x1b1e, 255, 255, b'\x01\xfd\xff\x04\x01\x01\x19\x00\x00']
2019-09-22 15:19:17 DEBUG (MainThread) [zigpy.zdo] [0x1b1e:zdo] ZDO request ZDOCmd.Match_Desc_req: [0xfffd, 260, [25], []]
2019-09-22 15:19:17 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=0 clusterId=32774 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=39>, 39, b"'\x00\x00\x00\x01\x01")
2019-09-22 15:19:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'04ca219c54340eb25992ca25aa1593499c6900adcace678bfcc7bca77e'
2019-09-22 15:19:17 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'41caa19c542573907e'
2019-09-22 15:19:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:17 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'000f'
2019-09-22 15:19:17 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'51cab19754340eb25992ca25aa1593499c4100abed55eb7e'
2019-09-22 15:19:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:17 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b000006800000400100000f270000'
2019-09-22 15:19:17 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=0 clusterId=32774 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=15>, 39, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'61cab1ed542e14b459954b65ab55920663f539b012316f93e0c76389fc6e3f8f0b7e'
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'71cab19754340eb658924a24ab1593499c4b3aabed87957e'
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00040106000101400100004fffbb1e1bffff08181d010000001000'
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=79>, 255, -69, 0x1b1e, 255, 255, b'\x18\x1d\x01\x00\x00\x00\x10\x00']
2019-09-22 15:19:21 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=29 command_id=Command.Read_Attributes_rsp>
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.zigbee.application] [0x1b1e:1:0x0006]: Invalid state on future - probably duplicate response: invalid state
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b04010600010140010000051d0000'
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=5>, 29, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:21 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0006]: initializing channel: from_cache: False
2019-09-22 15:19:21 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0006]: channel: 'async_initialize' stage succeeded
2019-09-22 15:19:21 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1b1e](Gear): power source: Battery or Unknown
2019-09-22 15:19:21 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1b1e](Gear): completed initialization
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'01cab1ed542e14b359954b65ab55921963f539b012316093e2c16389dc7eb7e97e'
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'11cab19754340eb658954a24ab1593499c4938abed1a1b7e'
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401010001014001000050ffbb1e1bffff07181f0700002000'
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=80>, 255, -69, 0x1b1e, 255, 255, b'\x18\x1f\x07\x00\x00 \x00']
2019-09-22 15:19:21 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=31 command_id=Command.Configure_Reporting_rsp>
2019-09-22 15:19:21 ERROR (MainThread) [bellows.zigbee.application] Failed to parse message (b'181f0700002000') on cluster 1, because Data is too short to contain 2 bytes
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b04010100010140010000071f0000'
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=7>, 31, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'12cb21adf5997e'
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'22cba1adc2e87e'
2019-09-22 15:19:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:21 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:19:32 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:19:32 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'23c821adf6947e'
2019-09-22 15:19:32 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'33c8a1adf6ab7e'
2019-09-22 15:19:32 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:32 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:19:42 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:19:42 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'34c921ad8b2e7e'
2019-09-22 15:19:42 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'44c9a1add2c37e'
2019-09-22 15:19:42 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:42 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:19:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: failed to set reporting for 'battery_voltage' attr on 'power' cluster: 
2019-09-22 15:19:42 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:42 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:42 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'45ce21d6697d3a06b259d26e25ab94747e'
2019-09-22 15:19:43 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'55cea1d6f5bc7e'
2019-09-22 15:19:43 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:43 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:43 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=40>, 40, b'\x00(\x06\x00!\x00 \x10\x0e0*\x01')
2019-09-22 15:19:43 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'56cf219c54340eb658954a24ab1593499c660fa7ede6618bdcc64399f24e15a6d2937e'
2019-09-22 15:19:43 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'66cfa19c543a4e507e'
2019-09-22 15:19:43 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:19:43 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0010'
2019-09-22 15:19:43 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'76cfb1ed542e14b359954b65ab55921863f339b012316093d5c16389dd7ebb717e'
2019-09-22 15:19:43 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:19:43 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'06cfb19754340eb658954a24ab1593499c5e0fabed74967e'
2019-09-22 15:19:43 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401010001014001000051ffbd1e1bffff0718280700002100'
2019-09-22 15:19:43 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:19:43 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=81>, 255, -67, 0x1b1e, 255, 255, b'\x18(\x07\x00\x00!\x00']
2019-09-22 15:19:43 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=40 command_id=Command.Configure_Reporting_rsp>
2019-09-22 15:19:43 ERROR (MainThread) [bellows.zigbee.application] Failed to parse message (b'18280700002100') on cluster 1, because Data is too short to contain 2 bytes
2019-09-22 15:19:43 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b0401010001014001000010280000'
2019-09-22 15:19:43 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=16>, 40, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: failed to set reporting for 'battery_voltage' attr on 'power' cluster: 
2019-09-22 15:19:50 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 15:19:50 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 15:19:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'61cc21d6697d3a06b259d26e25abba5b7e'
2019-09-22 15:19:50 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'17cca1d618287e'
2019-09-22 15:19:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:19:50 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 15:19:50 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=41>, 41, b'\x00)\x06\x00!\x00 \x10\x0e0*\x01')
2019-09-22 15:19:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'72cd219c54340eb658954a24ab1593499c670ea7ede7618bdcc64399f24e15a63fa67e'
2019-09-22 15:19:50 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'20cda19c543bfd037e'
2019-09-22 15:19:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:19:50 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0011'
2019-09-22 15:19:50 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'30cdb1ed542e14b359954b65ab55921b63f339b012316093d4c16389dd7ebdd97e'
2019-09-22 15:19:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:19:50 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'40cdb19754340eb658954a24ab1593499c5f0eabed99747e'
2019-09-22 15:19:50 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401010001014001000052ffbd1e1bffff0718290700002100'
2019-09-22 15:19:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:19:50 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=82>, 255, -67, 0x1b1e, 255, 255, b'\x18)\x07\x00\x00!\x00']
2019-09-22 15:19:50 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=41 command_id=Command.Configure_Reporting_rsp>
2019-09-22 15:19:50 ERROR (MainThread) [bellows.zigbee.application] Failed to parse message (b'18290700002100') on cluster 1, because Data is too short to contain 2 bytes
2019-09-22 15:19:50 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b0401010001014001000011290000'
2019-09-22 15:19:50 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=17>, 41, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 15:19:52 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:19:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'05d221ad62e17e'
2019-09-22 15:19:52 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'51d2a1adc6b37e'
2019-09-22 15:19:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:19:52 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:20:02 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:20:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'16d321add5aa7e'
2019-09-22 15:20:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'62d3a1ad46b67e'
2019-09-22 15:20:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:20:02 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:20:11 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: failed to set reporting for 'battery_percentage_remaining' attr on 'power' cluster: 
2019-09-22 15:20:11 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: finished channel configuration
2019-09-22 15:20:11 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: channel: 'async_configure' stage succeeded
2019-09-22 15:20:11 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1b1e](Gear): completed configuration
2019-09-22 15:20:11 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1b1e](Gear): stored in registry: ZhaDeviceEntry(name='AXIS Gear', ieee='00:24:46:00:00:13:30:3d', last_seen=1569187161.7661161)
2019-09-22 15:20:12 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:20:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'27d021add6a77e'
2019-09-22 15:20:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'73d0a1ad72f57e'
2019-09-22 15:20:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:20:12 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:20:18 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: failed to set reporting for 'battery_percentage_remaining' attr on 'power' cluster: 
2019-09-22 15:20:19 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: finished channel configuration
2019-09-22 15:20:19 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x4b17:1:0x0001]: channel: 'async_configure' stage succeeded
2019-09-22 15:20:19 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1b1e](Gear): completed configuration
2019-09-22 15:20:19 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1b1e](Gear): stored in registry: ZhaDeviceEntry(name='AXIS Gear', ieee='00:24:46:00:00:13:30:3d', last_seen=1569187161.7661161)
2019-09-22 15:20:22 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:20:22 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'30d121adab1d7e'
2019-09-22 15:20:22 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'04d1a1ad569d7e'
2019-09-22 15:20:22 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:20:22 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:20:32 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:20:32 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'41d621ad7d3a4c7e'
2019-09-22 15:20:32 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'15d6a1adbe1e7e'
2019-09-22 15:20:32 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:20:32 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:20:42 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:20:42 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'52d721adad077e'
2019-09-22 15:20:42 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'26d7a1ad3e1b7e'
2019-09-22 15:20:42 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 15:20:42 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:20:52 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:20:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'63d421adae0a7e'
2019-09-22 15:20:52 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'37d4a1ad0a587e'
2019-09-22 15:20:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 15:20:52 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:21:02 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'74d521add3b07e'
2019-09-22 15:21:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'40d5a1ad2e307e'
2019-09-22 15:21:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 15:21:02 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:21:03 DEBUG (MainThread) [homeassistant.components.zha.api] Get bindable devices: source_ieee: [00:24:46:00:00:13:3c:a0] bindable devices:: [[]]
2019-09-22 15:21:12 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:21:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'05da21adcb407e'
2019-09-22 15:21:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'51daa1ad6f127e'
2019-09-22 15:21:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 15:21:12 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:21:14 INFO (MainThread) [homeassistant.components.websocket_api.http.connection.4542795960] Connection closed by client
2019-09-22 15:21:22 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:21:22 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'16db21ad7c0b7e'
2019-09-22 15:21:22 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'62dba1adef177e'
2019-09-22 15:21:22 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 15:21:22 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:21:32 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:21:32 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'27d821ad7f067e'
2019-09-22 15:21:32 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'73d8a1addb547e'
2019-09-22 15:21:32 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 15:21:32 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:21:42 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:21:42 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'30d921ad02bc7e'
2019-09-22 15:21:42 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'04d9a1adff3c7e'
2019-09-22 15:21:42 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 15:21:42 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 15:21:52 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 15:21:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'41de21adb3ed7e'
2019-09-22 15:21:52 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'15dea1ad17bf7e'
2019-09-22 15:21:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 15:21:52 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''

Adminiuga commented 5 years ago

Did you remove the device prior resetting it? I wanted to see device signature, but since it was already in the database it skipped the discovery phase.

2019-09-22 15:19:02 INFO (MainThread) [zigpy.application] Device 0x2afb (00:24:46:00:00:13:30:3d) joined the network
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.application] Device 00:24:46:00:00:13:30:3d changed id (0x4b17 => 0x2afb)

I see the On_Off cluster, but didn't see the Level Cluster. Can you do sqlite3 zigbee.db .dump | grep 00:24:46:00:00:13:30:3d ?

Adminiuga commented 5 years ago

2019-09-22 15:19:43 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=81>, 255, -67, 0x1b1e, 255, 255, b'\x18(\x07\x00\x00!\x00']
2019-09-22 15:19:43 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=40 command_id=Command.Configure_Reporting_rsp>
2019-09-22 15:19:43 ERROR (MainThread) [bellows.zigbee.application] Failed to parse message (b'18280700002100') on cluster 1, because Data is too short to contain 2 bytes

The response to "configure attribute reporting" command is not following Zigbee Cluster Library specifications, which states:

Note that attribute status records are not included for successfully configured attributes, in order to save bandwidth. In the case of successful configuration of all attributes, only a single attribute status record SHALL be included in the command, with the status field set to SUCCESS and the direction and attribute identifier fields omitted.

It includes the Status of Success, but also includes the rest of the "Attribute Status Record" which makes zigpy think it has other "attribute status record", but it is not so data underrun is happening.

synergicmind commented 5 years ago

Did you remove the device prior resetting it? I wanted to see device signature, but since it was already in the database it skipped the discovery phase.
2019-09-22 15:19:02 INFO (MainThread) [zigpy.application] Device 0x2afb (00:24:46:00:00:13:30:3d) joined the network
2019-09-22 15:19:02 DEBUG (MainThread) [zigpy.application] Device 00:24:46:00:00:13:30:3d changed id (0x4b17 => 0x2afb)
I see the On_Off cluster, but didn't see the Level Cluster. Can you do sqlite3 zigbee.db .dump | grep 00:24:46:00:00:13:30:3d ?

I ran the script and this is what it gave me.

INSERT INTO devices VALUES('00:24:46:00:00:13:30:3d',6942,2);
INSERT INTO endpoints VALUES('00:24:46:00:00:13:30:3d',1,260,512,1);
INSERT INTO endpoints VALUES('00:24:46:00:00:13:30:3d',196,49757,512,1);
INSERT INTO clusters VALUES('00:24:46:00:00:13:30:3d',1,0);
INSERT INTO clusters VALUES('00:24:46:00:00:13:30:3d',1,4);
INSERT INTO clusters VALUES('00:24:46:00:00:13:30:3d',1,5);
INSERT INTO clusters VALUES('00:24:46:00:00:13:30:3d',1,6);
INSERT INTO clusters VALUES('00:24:46:00:00:13:30:3d',1,8);
INSERT INTO clusters VALUES('00:24:46:00:00:13:30:3d',1,32);
INSERT INTO clusters VALUES('00:24:46:00:00:13:30:3d',1,1);
INSERT INTO clusters VALUES('00:24:46:00:00:13:30:3d',196,1);
INSERT INTO output_clusters VALUES('00:24:46:00:00:13:30:3d',196,1);
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',1,0,4,'AXIS');
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',1,0,5,'Gear');
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',196,1,0,3);
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',196,1,5,255);
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',196,1,6,65535);
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',196,1,7,'RapidHA');
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',196,1,4,'01.00.00');
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',1,1,49,255);
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',1,1,51,0);
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',1,0,7,3);
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',1,1,32,255);
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',1,6,0,0);
INSERT INTO attributes VALUES('00:24:46:00:00:13:30:3d',1,1,33,60);
INSERT INTO node_descriptors VALUES('00:24:46:00:00:13:30:3d',X'0240809a105280000000800000');

Adminiuga commented 5 years ago

for future reference, please include log files or outputs like above in triple back-ticks, so it doesn't mess up the formatting. I've edited your message to use triple back-ticks.

So you do have the level cluster. Check https://community.home-assistant.io/t/zha-zigbee-tested-devices-please-add-your-device-results/17718/1167?u=quatuor You should add something like to your configuration.yaml

zha:
  device_config:
    00:24:46:00:00:13:30:3d-1:
       type: 'light'

synergicmind commented 5 years ago

I followed your instruction. Now the device shows as light bulb but nothing happens when "light" is on. Here is the log.

2019-09-22 20:18:41 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 20:18:41 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'177d3321ad85e97e'
2019-09-22 20:18:41 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7213a1ad7be67e'
2019-09-22 20:18:41 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 20:18:41 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 20:18:51 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 20:18:51 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'201021ada17d5d7e'
2019-09-22 20:18:51 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0310a1ad16777e'
2019-09-22 20:18:51 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 20:18:51 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 20:19:01 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 20:19:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'317d3121adfb5e7e'
2019-09-22 20:19:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1411a1ad6bcd7e'
2019-09-22 20:19:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2019-09-22 20:19:01 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 20:19:11 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 20:19:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'421621ada7677e'
2019-09-22 20:19:11 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2516a1adb4007e'
2019-09-22 20:19:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2019-09-22 20:19:11 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 20:19:21 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2019-09-22 20:19:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'531721adfd447e'
2019-09-22 20:19:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3617a1ad034b7e'
2019-09-22 20:19:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2019-09-22 20:19:21 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2019-09-22 20:19:23 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for 00:24:46:00:00:13:30:3d/0x1b1e
2019-09-22 20:19:23 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (00:24:46:00:00:13:30:3d, True)
2019-09-22 20:19:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'641421d6697d3a06b259d26e25aba18c7e'
2019-09-22 20:19:23 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4714a1d6a1267e'
2019-09-22 20:19:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2019-09-22 20:19:23 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2019-09-22 20:19:23 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1b1e, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=16>, 16, b'\x01\x10\x01')
2019-09-22 20:19:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7515219c54340eb658924a24ab1593499c5e37a8ecde66fd0b7e'
2019-09-22 20:19:23 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5015a19c54fc24fb7e'
2019-09-22 20:19:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2019-09-22 20:19:23 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'00d6'
2019-09-22 20:19:28 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6015b1ed542e14b459954b65ab5592ca63f039b012316293edcd62895cc07e'
2019-09-22 20:19:28 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2019-09-22 20:19:28 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7015b19754340eb658924a24ab1593499c9837abedaa887e'
2019-09-22 20:19:28 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401060001014001000083ffbe1e1bffff0518100b0100'
2019-09-22 20:19:28 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2019-09-22 20:19:28 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=131>, 255, -66, 0x1b1e, 255, 255, b'\x18\x10\x0b\x01\x00']
2019-09-22 20:19:28 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=16 command_id=Command.Default_Response>
2019-09-22 20:19:28 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'001e1b04010600010140010000d6100000'
2019-09-22 20:19:28 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 6942, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=214>, 16, <EmberStatus.SUCCESS: 0>, b'']
2019-09-22 20:19:28 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x1b1e:1:0x0006]: executed command: on with args: () with kwargs: {} and result: [1, <Status.SUCCESS: 0>]
2019-09-22 20:19:28 DEBUG (MainThread) [homeassistant.components.zha.entity] light.axis_gear_0013303d_1: turned on: {'on_off': [1, <Status.SUCCESS: 0>]}
2019-09-22 20:19:28 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0015b1ed542e14b459954b65ab5592cd63f039b012316093e3cc6389ec7fb70d7e'
2019-09-22 20:19:28 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 20:19:28 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401060001014001000084ffbe1e1bffff07181e0a00001001'
2019-09-22 20:19:28 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=132>, 255, -66, 0x1b1e, 255, 255, b'\x18\x1e\n\x00\x00\x10\x01']
2019-09-22 20:19:28 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=30 command_id=Command.Report_Attributes>
2019-09-22 20:19:28 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=Bool, value=Bool.true>>]]
2019-09-22 20:19:28 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] Attribute report received: on_off=Bool.true

Adminiuga commented 5 years ago

Try changing the brightness. From ZHA/zigpy point of view it told the device to turn on, command was sent successfully, device replied with confirmation and sent "attribute report" stating the device was turned on.

dmulcahey commented 5 years ago

@tjshin what do you mean nothing happens when the light is on? Did you attempt to change the level? does toggling between on and off cause anything to happen?

2019-09-22 20:19:28 DEBUG (MainThread) [homeassistant.components.zha.core.channels] [0x1b1e:1:0x0006]: executed command: on with args: () with kwargs: {} and result: [1, <Status.SUCCESS: 0>]
2019-09-22 20:19:28 DEBUG (MainThread) [homeassistant.components.zha.entity] light.axis_gear_0013303d_1: turned on: {'on_off': [1, <Status.SUCCESS: 0>]}
2019-09-22 20:19:28 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0015b1ed542e14b459954b65ab5592cd63f039b012316093e3cc6389ec7fb70d7e'
2019-09-22 20:19:28 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2019-09-22 20:19:28 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401060001014001000084ffbe1e1bffff07181e0a00001001'
2019-09-22 20:19:28 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=132>, 255, -66, 0x1b1e, 255, 255, b'\x18\x1e\n\x00\x00\x10\x01']
2019-09-22 20:19:28 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=30 command_id=Command.Report_Attributes>
2019-09-22 20:19:28 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=Bool, value=Bool.true>>]]
2019-09-22 20:19:28 DEBUG (MainThread) [zigpy.zcl] [0x1b1e:1:0x0006] Attribute report received: on_off=Bool.true

The device received the command, responded with a success response and even reported the state correctly... Try interacting with the level please.

stale[bot] commented 4 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 now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

home-assistant / core

AXIS Gear Blind Zigbee Broken #26683