Motion sensor triggered:
2020-08-05 22:10:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0xccc5, 00:0d:6f:00:0b:63:6f:d0, 233, -70, [0xd949]]
2020-08-05 22:10:02 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0xccc5, 00:0d:6f:00:0b:63:6f:d0, 233, -70, [0xd949])
2020-08-05 22:10:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'67e4b1ed542e14b25c954b65ab55926275f4e26712316e82b4c64589fc7e3fa7ef34f87e'
2020-08-05 22:10:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-08-05 22:10:02 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00040100050101400100002be9bac5ccffff0909490026000000000004'
2020-08-05 22:10:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1280 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=43>, 233, -70, 0xccc5, 255, 255, b'\tI\x00&\x00\x00\x00\x00\x00']
2020-08-05 22:10:02 DEBUG (MainThread) [zigpy.zcl] [0xccc5:1:0x0500] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=73 command_id=0>
2020-08-05 22:10:02 DEBUG (MainThread) [zigpy.zcl] [0xccc5:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper|Alarm_2: 38>, <bitmap8.0: 0>, 0, 0]
2020-08-05 22:10:02 DEBUG (MainThread) [zigpy.zcl] [0xccc5:1:0x0500] No handler for cluster command 0
2020-08-05 22:10:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xccc5:1:0x0500]: Updated alarm state: ZoneStatus.Alarm_2
Dining Room turns on:
2020-08-05 22:10:04 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining_room: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>]}
2020-08-05 22:10:04 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining_room_1: polling current state - from cache: False
2020-08-05 22:10:04 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xd949, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=89>, 90, b'\x00Y\x00\x00\x00')
2020-08-05 22:10:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'46ee219c5463ccb658924a24ab1593499c177d5daeed97678bfd605d7e'
2020-08-05 22:10:04 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining_room_2: polling current state - from cache: False
2020-08-05 22:10:04 DEBUG (MainThread) [homeassistant.components.zha.entity] light.dining_room_3: polling current state - from cache: False
2 seconds for automation to occur? Not sure if there is way to get higher precision in the logs?
I have a hard time believing it is the automation as I use the exact same automation for all my lights in Node Red. Like they literally flow into the same subflow. I also recently tested with just HA automations and turned off node red and did not see a difference so have ruled that out for now. So when I have ones like this
Landing Motion:
2020-08-05 22:19:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xb1ec:1:0x0500]: Updated alarm state: ZoneStatus.Alarm_2
Landing Light:
2020-08-05 22:19:43 DEBUG (MainThread) [homeassistant.components.zha.entity] light.landing: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>]}
That being said, landing light is not always quick. It has its problems at times as well as seen this morning, the motion sensor seems to never have triggered an event, and the logs show issues related to the nwk 0xb1ec which is the landing motion sensor.
2020-08-06 08:47:23 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0400000000000008040000f9bcb0ecb1ffff0bc95171ff0a006f0d000000'
2020-08-06 08:47:23 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, <EmberApsFrame profileId=0 clusterId=0 sourceEndpoint=0 destinationEndpoint=0 options=1032 groupId=0 sequence=249>, 188, -80, 0xb1ec, 255, 255, b'\xc9Qq\xff\n\x00o\r\x00\x00\x00']
2020-08-06 08:47:23 DEBUG (MainThread) [zigpy.zdo] [0xb1ec:zdo] ZDO request ZDOCmd.NWK_addr_req: [00:0d:6f:00:0a:ff:71:51, 0, 0]
2020-08-06 08:47:23 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xb1ec, <EmberApsFrame profileId=0 clusterId=32768 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=201>, 146, b'\xc9\x00Qq\xff\n\x00o\r\x00\x00\x00\x00\x00')
2020-08-06 08:47:23 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0400000000000008040000f9bcb0ecb1ffff0bc95171ff0a006f0d000000'
2020-08-06 08:47:23 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, <EmberApsFrame profileId=0 clusterId=0 sourceEndpoint=0 destinationEndpoint=0 options=1032 groupId=0 sequence=249>, 188, -80, 0xb1ec, 255, 255, b'\xc9Qq\xff\n\x00o\r\x00\x00\x00']
2020-08-06 08:47:23 DEBUG (MainThread) [zigpy.zdo] [0xb1ec:zdo] ZDO request ZDOCmd.NWK_addr_req: [00:0d:6f:00:0a:ff:71:51, 0, 0]
2020-08-06 08:47:23 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xb1ec, <EmberApsFrame profileId=0 clusterId=32768 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=201>, 146, b'\xc9\x00Qq\xff\n\x00o\r\x00\x00\x00\x00\x00')
2020-08-06 08:47:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'41ce219c54c6a4b25994ca25aa1593499c87b5a524ce36fa02cc63e6f17d5e3fa7ebcd492c7e'
2020-08-06 08:47:23 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'15cea19c5473b6907e'
2020-08-06 08:47:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-08-06 08:47:23 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0059'
2020-08-06 08:47:27 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'25ceb19754c6a4b25994ca25aa1593499c17b5cded93377e'
2020-08-06 08:47:27 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-08-06 08:47:27 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00ecb10000008000004001000059926600'
2020-08-06 08:47:27 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 45548, <EmberApsFrame profileId=0 clusterId=32768 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=89>, 146, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2020-08-06 08:47:27 DEBUG (MainThread) [zigpy.device] [0xb1ec] Delivery error for seq # 0xc9, on endpoint id 0 cluster 0x8000: message send failure
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'35ceb1ed542e14b459954b65ab5592e263f457b51231608382cc6389ec7e3d5f777e'
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'45ceb1ed542e14ba59954b65ab5592e563f457b512316083fdcc6389dcfe3dc7877e'
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010600010140010000abffba701effff07087f0a0000100002'
2020-08-06 08:47:29 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=171>, 255, -70, 0x1e70, 255, 255, b'\x08\x7f\n\x00\x00\x10\x00']
2020-08-06 08:47:29 DEBUG (MainThread) [zigpy.zcl] [0x1e70:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=127 command_id=Command.Report_Attributes>
2020-08-06 08:47:29 DEBUG (MainThread) [zigpy.zcl] [0x1e70:1:0x0006] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=Bool, value=Bool.false>>]]
2020-08-06 08:47:29 DEBUG (MainThread) [zigpy.zcl] [0x1e70:1:0x0006] Attribute report received: on_off=0
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010800010140010000acffba701effff0708000a0000208002'
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=8 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=172>, 255, -70, 0x1e70, 255, 255, b'\x08\x00\n\x00\x00 \x80']
2020-08-06 08:47:29 DEBUG (MainThread) [zigpy.zcl] [0x1e70:1:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=0 command_id=Command.Report_Attributes>
2020-08-06 08:47:29 DEBUG (MainThread) [zigpy.zcl] [0x1e70:1:0x0008] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=uint8_t, value=128>>]]
2020-08-06 08:47:29 DEBUG (MainThread) [zigpy.zcl] [0x1e70:1:0x0008] Attribute report received: current_level=128
2020-08-06 08:47:29 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1e70:1:0x0008]: received attribute: 0 update with value: 128
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1e70, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=127>, 147, b'\x18\x7f\x0b\n\x00')
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'55cf219c545a0bb658924a24ab1593499c31b4aef5b16c81fdf15d7e'
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'56cfa19c547088527e'
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'005a'
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x1e70, <EmberApsFrame profileId=260 clusterId=8 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=0>, 148, b'\x18\x00\x0b\n\x00')
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'66cc219c545a0bb6589c4a24ab1593499c4eb3aef5ce6c81fd7d5de77e'
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'67cca19c54711c8d7e'
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'005b'
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'77ccb197545a0bb658924a24ab1593499c14b4abed498b7e'
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00701e040106000101400100005a930000'
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 7792, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=90>, 147, <EmberStatus.SUCCESS: 0>, b'']
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'07ccb197545a0bb6589c4a24ab1593499c15b3abed32397e'
2020-08-06 08:47:29 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00701e040108000101400100005b940000'
2020-08-06 08:47:29 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 7792, <EmberApsFrame profileId=260 clusterId=8 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=91>, 148, <EmberStatus.SUCCESS: 0>, b'']
2020-08-06 08:47:30 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2020-08-06 08:47:30 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'71cd21ad85377e'
2020-08-06 08:47:30 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'10cda1adb1c97e'
2020-08-06 08:47:30 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-08-06 08:47:30 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2020-08-06 08:47:31 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'20cdb12816c6a4e1f67e'
2020-08-06 08:47:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-08-06 08:47:31 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42ecb1'
2020-08-06 08:47:31 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xb1ec]
2020-08-06 08:47:31 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xb1ec
2020-08-06 08:47:31 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'30cdb12816c6a4d68d7e'
2020-08-06 08:47:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-08-06 08:47:31 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42ecb1'
2020-08-06 08:47:31 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xb1ec]
2020-08-06 08:47:31 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xb1ec
2020-08-06 08:47:32 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'40cdb12816c6a452ec7e'
2020-08-06 08:47:32 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-08-06 08:47:32 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42ecb1'
2020-08-06 08:47:32 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xb1ec]
2020-08-06 08:47:32 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xb1ec
2020-08-06 08:47:32 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'50cdb12816c6a465977e'
2020-08-06 08:47:32 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-08-06 08:47:32 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42ecb1'
2020-08-06 08:47:32 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xb1ec]
2020-08-06 08:47:32 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xb1ec
2020-08-06 08:47:33 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'60cdb12816c6a43c1a7e'
2020-08-06 08:47:33 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-08-06 08:47:33 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42ecb1'
2020-08-06 08:47:33 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xb1ec]
2020-08-06 08:47:33 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xb1ec
2020-08-06 08:47:34 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'70cdb12816c6a40b617e'
2020-08-06 08:47:34 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-08-06 08:47:34 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42ecb1'
2020-08-06 08:47:34 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xb1ec]
2020-08-06 08:47:34 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xb1ec
2020-08-06 08:47:37 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'00cdb1ed542e14b359954b65ab5592ac638e183012316d83d1cc5d89e77e3fa7ebccb37e'
2020-08-06 08:47:37 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-08-06 08:47:37 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010100010140010000e5ffc03f9bffff0a082c0a3e001b00000000'
2020-08-06 08:47:37 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=229>, 255, -64, 0x9b3f, 255, 255, b'\x08,\n>\x00\x1b\x00\x00\x00\x00']
2020-08-06 08:47:37 DEBUG (MainThread) [zigpy.zcl] [0x9b3f:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=44 command_id=Command.Report_Attributes>
2020-08-06 08:47:37 DEBUG (MainThread) [zigpy.zcl] [0x9b3f:1:0x0001] ZCL request 0x000a: [[<Attribute attrid=62 value=<TypeValue type=bitmap32, value=bitmap32.0>>]]
2020-08-06 08:47:37 DEBUG (MainThread) [zigpy.zcl] [0x9b3f:1:0x0001] Attribute report received: battery_alarm_state=0
2020-08-06 08:47:37 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x9b3f, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=44>, 149, b'\x18,\x0b\n\x00')
2020-08-06 08:47:37 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'01d2219c54158eb658954a24ab1593499c62b2aef5e26c81fd28557e'
2020-08-06 08:47:37 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'11d2a19c54766fe57e'
2020-08-06 08:47:37 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-08-06 08:47:37 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'005c'
2020-08-06 08:47:38 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'21d2b19754158eb658954a24ab1592499c12b2abedda7b7e'
2020-08-06 08:47:38 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-08-06 08:47:38 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'003f9b040101000101400000005c950000'
2020-08-06 08:47:38 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 39743, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=64 groupId=0 sequence=92>, 149, <EmberStatus.SUCCESS: 0>, b'']
2020-08-06 08:47:38 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'31d2b1ed542e14b459954b65ab5592e0638e838c12316093c5cc6389ec7e8c647e'
2020-08-06 08:47:38 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-08-06 08:47:38 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010600010140010000a9ffc0a427ffff0718380a00001000'
2020-08-06 08:47:38 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=169>, 255, -64, 0x27a4, 255, 255, b'\x188\n\x00\x00\x10\x00']
2020-08-06 08:47:38 DEBUG (MainThread) [zigpy.zcl] [0x27a4:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=56 command_id=Command.Report_Attributes>
2020-08-06 08:47:38 DEBUG (MainThread) [zigpy.zcl] [0x27a4:1:0x0006] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=Bool, value=Bool.false>>]]
2020-08-06 08:47:38 DEBUG (MainThread) [zigpy.zcl] [0x27a4:1:0x0006] Attribute report received: on_off=0
2020-08-06 08:47:39 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'41d2b1ed542e14b359954b65ab5592ac638e183012316d83d1cc5d89e77e3fa7eb922a7e'
2020-08-06 08:47:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-08-06 08:47:39 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0004010100010140010000e5ffc03f9bffff0a082c0a3e001b00000000'
2020-08-06 08:47:39 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=229>, 255, -64, 0x9b3f, 255, 255, b'\x08,\n>\x00\x1b\x00\x00\x00\x00']
2020-08-06 08:47:39 DEBUG (MainThread) [zigpy.zcl] [0x9b3f:1:0x0001] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=44 command_id=Command.Report_Attributes>
2020-08-06 08:47:39 DEBUG (MainThread) [zigpy.zcl] [0x9b3f:1:0x0001] ZCL request 0x000a: [[<Attribute attrid=62 value=<TypeValue type=bitmap32, value=bitmap32.0>>]]
2020-08-06 08:47:39 DEBUG (MainThread) [zigpy.zcl] [0x9b3f:1:0x0001] Attribute report received: battery_alarm_state=0
2020-08-06 08:47:39 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x9b3f, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=44>, 150, b'\x18,\x0b\n\x00')
2020-08-06 08:47:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'15d3219c54158eb658954a24ab1593499c62b1aef5e26c81fddae17e'
2020-08-06 08:47:39 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'52d3a19c547771657e'
2020-08-06 08:47:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-08-06 08:47:39 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'005d'
2020-08-06 08:47:40 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2020-08-06 08:47:40 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'26d021ada07d337e'
2020-08-06 08:47:40 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'63d0a1ad69527e'
2020-08-06 08:47:40 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-08-06 08:47:40 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2020-08-06 08:47:40 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'73d0b19754158eb658954a24ab1593499c13b1abed08ee7e'
2020-08-06 08:47:40 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-08-06 08:47:40 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'003f9b040101000101400100005d960000'
2020-08-06 08:47:40 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 39743, <EmberApsFrame profileId=260 clusterId=1 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=93>, 150, <EmberStatus.SUCCESS: 0>, b'']
2020-08-06 08:47:41 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'03d0b5cace1a33bc59fb4725fd777e'
2020-08-06 08:47:41 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-08-06 08:47:41 DEBUG (MainThread) [bellows.ezsp] Application frame 98 (incomingSenderEui64Handler) received: b'9a30260e006f0d00'
2020-08-06 08:47:41 DEBUG (MainThread) [bellows.zigbee.application] Received incomingSenderEui64Handler frame with [00:0d:6f:00:0e:26:30:9a]
2020-08-06 08:47:41 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'13d0b1ed502a15b259944a2dae5592b247f2cb1a12316c40acb79c83fc1132a7ebcd219d7e'
2020-08-06 08:47:41 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-08-06 08:47:41 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'0400000000000008040000fbdbbcecb1ffff0bcb5171ff0a006f0d000000'
2020-08-06 08:47:41 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, <EmberApsFrame profileId=0 clusterId=0 sourceEndpoint=0 destinationEndpoint=0 options=1032 groupId=0 sequence=251>, 219, -68, 0xb1ec, 255, 255, b'\xcbQq\xff\n\x00o\r\x00\x00\x00']
2020-08-06 08:47:41 DEBUG (MainThread) [zigpy.zdo] [0xb1ec:zdo] ZDO request ZDOCmd.NWK_addr_req: [00:0d:6f:00:0a:ff:71:51, 0, 0]
2020-08-06 08:47:41 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xb1ec, <EmberApsFrame profileId=0 clusterId=32768 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=203>, 151, b'\xcb\x00Qq\xff\n\x00o\r\x00\x00\x00\x00\x00')
2020-08-06 08:47:41 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'32d1219c54c6a4b25994ca25aa1593499c85b0a526ce36fa02cc63e6f17d5e3fa7ebcd49077e'
2020-08-06 08:47:41 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'24d1a19c5475ddd97e'
2020-08-06 08:47:41 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-08-06 08:47:41 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'005f'
2020-08-06 08:47:43 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'34d1b1f1c2d270684b9f4a4aa75568fe9d07fe83667e'
2020-08-06 08:47:43 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-08-06 08:47:43 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received: b'96f865da120b006f0d00fab70149d9'
2020-08-06 08:47:43 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0xf896, 00:0d:6f:00:0b:12:da:65, 250, -73, [0xd949]]
2020-08-06 08:47:43 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0xf896, 00:0d:6f:00:0b:12:da:65, 250, -73, [0xd949])
2020-08-06 08:47:43 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'44d1b1ed542e14b05d954b65ab5592656bfbb15312316f83dbcc6389d5fb37a323117e'
2020-08-06 08:47:43 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-08-06 08:47:43 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00040102040101400100002cf7b596f8ffff0808260a000029850804'
2020-08-06 08:47:43 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1026 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=44>, 247, -75, 0xf896, 255, 255, b'\x08&\n\x00\x00)\x85\x08']
2020-08-06 08:47:43 DEBUG (MainThread) [zigpy.zcl] [0xf896:1:0x0402] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=38 command_id=Command.Report_Attributes>
2020-08-06 08:47:43 DEBUG (MainThread) [zigpy.zcl] [0xf896:1:0x0402] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=int16s, value=2181>>]]
2020-08-06 08:47:43 DEBUG (MainThread) [zigpy.zcl] [0xf896:1:0x0402] Attribute report received: measured_value=2181
2020-08-06 08:47:43 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xf896, <EmberApsFrame profileId=260 clusterId=1026 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=38>, 152, b'\x18&\x0b\n\x00')
2020-08-06 08:47:43 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'45d6219c54bcedb658964e24ab1593499c68bfaef5e86c81fd7d3a037e'
2020-08-06 08:47:43 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'55d6a19c544a7d8d7e'
2020-08-06 08:47:43 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-08-06 08:47:43 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0060'
2020-08-06 08:47:43 DEBUG (MainThread) [homeassistant.components.zha.entity] light.primary_bath_left: polling current state - from cache: False
2020-08-06 08:47:43 DEBUG (MainThread) [zigpy.device] [0x2c95] Extending timeout for 0x99 request
2020-08-06 08:47:43 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2f:01:e0/0x2c95
2020-08-06 08:47:43 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (b0:ce:18:14:03:2f:01:e0, True)
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'56d721d6b42b3ab14d8c8495ab68877e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'66d7a1d69f7b7e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x2c95, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=153>, 154, b'\x00\x99\x00\x00\x00')
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'67d4219c54bf39b658924a24ab1593499cd7bdaeed57678bfd98a17e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'77d4a19c544b97677e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0061'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'07d4b1f1c106f5b376975e3d64e56df39e6d86dbf3b2487e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received: b'952ce0012f031418ceb0ffba0223a1701e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0x2c95, b0:ce:18:14:03:2f:01:e0, 255, -70, [0xa123, 0x1e70]]
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0x2c95, b0:ce:18:14:03:2f:01:e0, 255, -70, [0xa123, 0x1e70])
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'17d4b1f1c106f5b376975e3d64e56df39e6d86dbf33c857e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received: b'952ce0012f031418ceb0ffba0223a1701e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0x2c95, b0:ce:18:14:03:2f:01:e0, 255, -70, [0xa123, 0x1e70]]
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0x2c95, b0:ce:18:14:03:2f:01:e0, 255, -70, [0xa123, 0x1e70])
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'27d4b1ed542e14b459954b65ab55920563f4b28712316f9364c76389fc6e3fa1c1fb7e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00040106000101400100004cffba952cffff08189901000000100006'
2020-08-06 08:47:44 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=76>, 255, -70, 0x2c95, 255, 255, b'\x18\x99\x01\x00\x00\x00\x10\x00']
2020-08-06 08:47:44 DEBUG (MainThread) [zigpy.zcl] [0x2c95: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=153 command_id=Command.Read_Attributes_rsp>
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'37d4b19754bf39b658924a24ab1592499c2fbdabede4ed7e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00952c04010600010140000000619a0000'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 11413, <EmberApsFrame profileId=260 clusterId=6 sourceEndpoint=1 destinationEndpoint=1 options=64 groupId=0 sequence=97>, 154, <EmberStatus.SUCCESS: 0>, b'']
2020-08-06 08:47:44 DEBUG (MainThread) [zigpy.device] [0x2c95] Extending timeout for 0x9b request
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2f:01:e0/0x2c95
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Send command setExtendedTimeout: (b0:ce:18:14:03:2f:01:e0, True)
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'74d521d6b42b3ab14d8c8495abc9c37e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'40d5a1d6e1cc7e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 126 (setExtendedTimeout) received: b''
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x2c95, <EmberApsFrame profileId=260 clusterId=8 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=155>, 156, b'\x00\x9b\x00\x00\x00')
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'05da219c54bf39b6589c4a24ab1593499cd5bbaeed55678bfd43b77e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'51daa19c5448d0457e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0062'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'61dab19754bf39b6589c4a24ab1593499c2cbbabed2cb87e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00952c04010800010140010000629c0000'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 11413, <EmberApsFrame profileId=260 clusterId=8 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=98>, 156, <EmberStatus.SUCCESS: 0>, b'']
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'71dab1ed542e14ba59954b65ab55920462f4b28712316f9366c76389fc5ec1a186d57e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'00040108000101400100004dfeba952cffff08189b0100000020fe06'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=8 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=77>, 254, -70, 0x2c95, 255, 255, b'\x18\x9b\x01\x00\x00\x00 \xfe']
2020-08-06 08:47:44 DEBUG (MainThread) [zigpy.zcl] [0x2c95:1:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=155 command_id=Command.Read_Attributes_rsp>
2020-08-06 08:47:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2c95:1:0x0008]: received attribute: 0 update with value: 254
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'01dab1f1548c88043b9f4a4aa7556afc9d07fe1d387e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 89 (incomingRouteRecordHandler) received: b'00a69db6620b006f0d00f8b50149d9'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0xa600, 00:0d:6f:00:0b:62:b6:9d, 248, -75, [0xd949]]
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0xa600, 00:0d:6f:00:0b:62:b6:9d, 248, -75, [0xd949])
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'11dab1ed542e14b05d954b65ab55921b71fb270d12316f83b9cc6389d55d37a3c96e7e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received: b'000401020401014001000052edb500a6ffff0808440a000029230804'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, <EmberApsFrame profileId=260 clusterId=1026 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=82>, 237, -75, 0xa600, 255, 255, b'\x08D\n\x00\x00)#\x08']
2020-08-06 08:47:44 DEBUG (MainThread) [zigpy.zcl] [0xa600:1:0x0402] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=68 command_id=Command.Report_Attributes>
2020-08-06 08:47:44 DEBUG (MainThread) [zigpy.zcl] [0xa600:1:0x0402] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=int16s, value=2083>>]]
2020-08-06 08:47:44 DEBUG (MainThread) [zigpy.zcl] [0xa600:1:0x0402] Attribute report received: measured_value=2083
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xa600, <EmberApsFrame profileId=260 clusterId=1026 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=68>, 157, b'\x18D\x0b\n\x00')
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'12db219c542ab3b658964e24ab1593499c0abaaef58a6c81fd7d33da7e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'22dba19c5449e1497e'
2020-08-06 08:47:44 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-08-06 08:47:44 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received: b'0063'
2020-08-06 08:47:45 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'32dbb19754bcedb658964e24ab1593499c2ebfabeddc487e'
2020-08-06 08:47:45 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-08-06 08:47:45 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'0096f80401020401014001000060980000'
2020-08-06 08:47:45 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 63638, <EmberApsFrame profileId=260 clusterId=1026 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=96>, 152, <EmberStatus.SUCCESS: 0>, b'']
2020-08-06 08:47:45 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'42dbb19754c6a4b25994ca25aa1593499c11b0cdedc83f7e'
2020-08-06 08:47:45 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-08-06 08:47:45 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'00ecb1000000800000400100005f976600'
2020-08-06 08:47:45 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 45548, <EmberApsFrame profileId=0 clusterId=32768 sourceEndpoint=0 destinationEndpoint=0 options=320 groupId=0 sequence=95>, 151, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2020-08-06 08:47:45 DEBUG (MainThread) [zigpy.device] [0xb1ec] Delivery error for seq # 0xcb, on endpoint id 0 cluster 0x8000: message send failure
2020-08-06 08:47:48 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'52dbb12816c6a492117e'
2020-08-06 08:47:48 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-08-06 08:47:48 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42ecb1'
2020-08-06 08:47:48 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xb1ec]
2020-08-06 08:47:48 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xb1ec
2020-08-06 08:47:49 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'62dbb197542ab3b658964e24ab1593499c2dbacdede63e7e'
2020-08-06 08:47:49 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-08-06 08:47:49 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received: b'0000a604010204010140010000639d6600'
2020-08-06 08:47:49 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 42496, <EmberApsFrame profileId=260 clusterId=1026 sourceEndpoint=1 destinationEndpoint=1 options=320 groupId=0 sequence=99>, 157, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2020-08-06 08:47:49 DEBUG (MainThread) [zigpy.device] [0xa600] Delivery error for seq # 0x44, on endpoint id 1 cluster 0x0402: message send failure
2020-08-06 08:47:50 DEBUG (MainThread) [bellows.ezsp] Send command nop: ()
2020-08-06 08:47:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'27d821ad7f067e'
2020-08-06 08:47:50 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'73d8a1addb547e'
2020-08-06 08:47:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-08-06 08:47:50 DEBUG (MainThread) [bellows.ezsp] Application frame 5 (nop) received: b''
2020-08-06 08:47:50 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'03d8b12816c6a40e077e'
2020-08-06 08:47:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-08-06 08:47:50 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42ecb1'
2020-08-06 08:47:50 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xb1ec]
2020-08-06 08:47:50 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xb1ec
2020-08-06 08:47:52 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'13d8b12816c6a4397c7e'
2020-08-06 08:47:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-08-06 08:47:52 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'42ecb1'
2020-08-06 08:47:52 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xb1ec]
2020-08-06 08:47:52 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xb1ec
2020-08-06 08:47:52 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'23d8b128162ab357f87e'
2020-08-06 08:47:52 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-08-06 08:47:52 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'4200a6'
2020-08-06 08:47:52 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xa600]
2020-08-06 08:47:52 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xa600
2020-08-06 08:47:54 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'33d8b128162ab360837e'
2020-08-06 08:47:54 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-08-06 08:47:54 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'4200a6'
2020-08-06 08:47:54 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xa600]
2020-08-06 08:47:54 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xa600
2020-08-06 08:47:55 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'43d8b128162ab3e4e27e'
2020-08-06 08:47:55 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-08-06 08:47:55 DEBUG (MainThread) [bellows.ezsp] Application frame 128 (incomingRouteErrorHandler) received: b'4200a6'
2020-08-06 08:47:55 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xa600]
2020-08-06 08:47:55 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xa600
2020-08-06 08:47:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'53d8b1ed542e14ab59954b65aa5592f963f2ab3c12316b8a86c7638bec7e3fa8ebcddea4907e'
2020-08-06 08:47:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
Triggered again 5 minutes later and it was fine and instant again