bath.log

Motion: 0xe41f
ZHA Group: 0x0006
Took ~5 seconds for lights, primary bath, to turn on.

2020-09-18 20:43:45 DEBUG (MainThread) [zigpy.device] [0xbca3] Delivery error for seq # 0x75, on endpoint id 1 cluster 0x0202: message send failure
2020-09-18 20:43:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBCA3:1:0x0202]: failed to get attributes '['fan_mode']' on 'fan' cluster: [0xbca3:1:0x0202]: Message send failure
2020-09-18 20:43:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBCA3:1:0x0006]: 'async_initialize' stage succeeded
2020-09-18 20:43:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBCA3:1:0x0008]: 'async_initialize' stage succeeded
2020-09-18 20:43:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBCA3:1:0x0202]: 'async_initialize' stage succeeded
2020-09-18 20:43:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBCA3:1:0x0000]: 'async_initialize' stage succeeded
2020-09-18 20:43:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBCA3:1:0x0019]: 'async_initialize' stage succeeded
2020-09-18 20:43:45 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBCA3](HBUniversalCFRemote): power source: Mains
2020-09-18 20:43:45 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBCA3](HBUniversalCFRemote): completed initialization
2020-09-18 20:43:47 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2020-09-18 20:43:47 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'37682157542f7f7d5e7e'
2020-09-18 20:43:47 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7468a157542f06b67e'
2020-09-18 20:43:47 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:43:47 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0468b157546f15b658944f24ab1593499cd8f100f22a9874f4cf0289da7e3f58ebcd37467e'
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401000501014001000096d6ab1fe4ffff09096100260000ff0000'
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=150), 214, -85, 0xe41f, 255, 255, b'\ta\x00&\x00\x00\xff\x00\x00']
2020-09-18 20:43:48 DEBUG (MainThread) [zigpy.zcl] [0xe41f: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=97 command_id=0>
2020-09-18 20:43:48 DEBUG (MainThread) [zigpy.zcl] [0xe41f:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper|Alarm_2: 38>, <bitmap8.0: 0>, 255, 0]
2020-09-18 20:43:48 DEBUG (MainThread) [zigpy.zcl] [0xe41f:1:0x0500] No handler for cluster command 0
2020-09-18 20:43:48 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE41F:1:0x0500]: Updated alarm state: ZoneStatus.Alarm_2
2020-09-18 20:43:48 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.primary_bath_motion, old_state=<state binary_sensor.primary_bath_motion=off; friendly_name=Primary Bath Motion, device_class=motion @ 2020-09-18T19:58:54.199936-05:00>, new_state=<state binary_sensor.primary_bath_motion=on; friendly_name=Primary Bath Motion, device_class=motion @ 2020-09-18T20:43:48.086037-05:00>>
2020-09-18 20:43:48 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=brightness_pct=1, transition=1, entity_id=light.primary_bath_right>
2020-09-18 20:43:48 DEBUG (MainThread) [zigpy.device] [0x16b9] Extending timeout for 0x8a request
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2e:c4:ce/0x16b9
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:2e:c4:ce, True)
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'416921575454db7677975e3d64e593a5e07e'
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1569a157545479a37e'
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x16B9, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=138), 139, b'\x01\x8a\x04\x03\n\x00')
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'526e2157541e150b4f904b2daa5493099d4e272166c86601f9c5698986bf7e'
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'266ea157541e15aa92ef7e'
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0018'
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'366eb1575415150b4f904b2daa5493099d4e27b366ce67eec37e'
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'00b91604010800010140010000188b0000'
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 5817, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=24), 139, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'466eb15754aabf0b4f55bc7e'
2020-09-18 20:43:48 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 128 (incomingRouteErrorHandler) received: b'aab916'
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MANY_TO_ONE_ROUTE_FAILURE: 170>, 0x16b9]
2020-09-18 20:43:48 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MANY_TO_ONE_ROUTE_FAILURE, nwk=0x16b9
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'566eb157546f15b658924a24ab1593499c35ef0154d89874fade7783fc7e2fa6006b7e'
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040106000101400100007bc8aab916ffff0718140a00001001'
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=123), 200, -86, 0x16b9, 255, 255, b'\x18\x14\n\x00\x00\x10\x01']
2020-09-18 20:43:49 DEBUG (MainThread) [zigpy.zcl] [0x16b9: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=20 command_id=Command.Report_Attributes>
2020-09-18 20:43:49 DEBUG (MainThread) [zigpy.zcl] [0x16b9:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.true>)]]
2020-09-18 20:43:49 DEBUG (MainThread) [zigpy.zcl] [0x16b9:1:0x0006] Attribute report received: on_off=1
2020-09-18 20:43:49 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.primary_bath_right, old_state=<state light.primary_bath_right=off; off_brightness=None, friendly_name=Primary Bath Right, supported_features=41 @ 2020-09-18T20:08:54.384229-05:00>, new_state=<state light.primary_bath_right=on; brightness=254, off_brightness=None, friendly_name=Primary Bath Right, supported_features=41 @ 2020-09-18T20:43:49.489325-05:00>>
2020-09-18 20:43:49 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.primary_bath, old_state=<state light.primary_bath=off; off_brightness=None, friendly_name=Primary Bath, supported_features=41 @ 2020-09-18T20:08:54.396414-05:00>, new_state=<state light.primary_bath=on; brightness=254, off_brightness=None, friendly_name=Primary Bath, supported_features=41 @ 2020-09-18T20:43:49.494601-05:00>>
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'666eb157546f15b6589c4a24ab1593499c34ed0054d89874f8cee982f87e8d757e'
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040108000101400100007acaabb916ffff05088a0b0400'
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=122), 202, -85, 0x16b9, 255, 255, b'\x08\x8a\x0b\x04\x00']
2020-09-18 20:43:49 DEBUG (MainThread) [zigpy.zcl] [0x16b9:1:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=138 command_id=Command.Default_Response>
2020-09-18 20:43:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x16B9:1:0x0008]: executed 'move_to_level_with_on_off' command with args: '(3, 10.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-09-18 20:43:49 DEBUG (MainThread) [zigpy.device] [0x16b9] Extending timeout for 0x8c request
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2e:c4:ce/0x16b9
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:2e:c4:ce, True)
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'676f21575454db7677975e3d64e593e5f87e'
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'776fa1575454607e7e'
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x16B9, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=140), 141, b'\x01\x8c\x01')
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'706c2157541e150b4f904b23aa5493099d4e272760cd6607fce8f27e'
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'006ca157541e15ab198e7e'
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0019'
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'106cb157546f15b658924a24ab1593499c32ea0754d89874f8ceef82fd7eea987e'
2020-09-18 20:43:49 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040106000101400100007ccdacb916ffff05088c0b0100'
2020-09-18 20:43:49 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=124), 205, -84, 0x16b9, 255, 255, b'\x08\x8c\x0b\x01\x00']
2020-09-18 20:43:49 DEBUG (MainThread) [zigpy.zcl] [0x16b9:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=140 command_id=Command.Default_Response>
2020-09-18 20:43:50 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'206cb1575415150b4f904b23aa5493099d4e27b260ce679f9c7e'
2020-09-18 20:43:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:43:50 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'00b91604010600010140010000198d0000'
2020-09-18 20:43:50 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 5817, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=25), 141, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:43:50 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x16B9:1:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-09-18 20:43:50 DEBUG (MainThread) [homeassistant.components.zha.entity] light.primary_bath_right: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>]}
2020-09-18 20:43:50 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.primary_bath_right, old_state=<state light.primary_bath_right=on; brightness=254, off_brightness=None, friendly_name=Primary Bath Right, supported_features=41 @ 2020-09-18T20:43:49.489325-05:00>, new_state=<state light.primary_bath_right=on; brightness=3, off_brightness=None, friendly_name=Primary Bath Right, supported_features=41 @ 2020-09-18T20:43:49.489325-05:00>>
2020-09-18 20:43:50 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.primary_bath, old_state=<state light.primary_bath=on; brightness=254, off_brightness=None, friendly_name=Primary Bath, supported_features=41 @ 2020-09-18T20:43:49.494601-05:00>, new_state=<state light.primary_bath=on; brightness=3, off_brightness=None, friendly_name=Primary Bath, supported_features=41 @ 2020-09-18T20:43:49.494601-05:00>>
2020-09-18 20:43:50 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'306cb157546f15b6589c4a24ab1593499c33fe0754d89874fade7683fc7e1fa4a3b07e'
2020-09-18 20:43:50 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:43:50 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040108000101400100007dd9acb916ffff0718150a00002003'
2020-09-18 20:43:50 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=125), 217, -84, 0x16b9, 255, 255, b'\x18\x15\n\x00\x00 \x03']
2020-09-18 20:43:50 DEBUG (MainThread) [zigpy.zcl] [0x16b9:1:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=21 command_id=Command.Report_Attributes>
2020-09-18 20:43:50 DEBUG (MainThread) [zigpy.zcl] [0x16b9:1:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=3>)]]
2020-09-18 20:43:50 DEBUG (MainThread) [zigpy.zcl] [0x16b9:1:0x0008] Attribute report received: current_level=3
2020-09-18 20:43:50 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x16B9:1:0x0008]: received attribute: 0 update with value: 3
2020-09-18 20:43:53 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_off, service_data=entity_id=light.main_bath,light.main_bath>
2020-09-18 20:43:53 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=logbook, service=log, service_data=name=main_bath, message=is on. Turning off, domain=light>
2020-09-18 20:43:53 DEBUG (MainThread) [zigpy.device] [0x4f0d] Extending timeout for 0x8e request
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:5d:56:14/0x4f0d
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:5d:56:14, True)
2020-09-18 20:43:53 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event logbook_entry[L]: name=main_bath, message=is on. Turning off, domain=light>
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'046d2157545401e404975e3d64e593087f7e'
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'416da157545486907e'
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x4F0D, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=142), 143, b'\x01\x8e\x00')
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'15722157541e15bf16904b23aa5493099d4e272562cd6605fdf1a07e'
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5272a157541e15a868dc7e'
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'001a'
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6272b157546f15b658924a24ab1593499cebd21ee0819874f8ceed82fc7e193c7e'
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7272b157541515bf16904b23aa5493099d4e27b162ce67ce0b7e'
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010600010140010000a5f5b50d4fffff05088e0b0000'
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=165), 245, -75, 0x4f0d, 255, 255, b'\x08\x8e\x0b\x00\x00']
2020-09-18 20:43:53 DEBUG (MainThread) [zigpy.zcl] [0x4f0d:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=142 command_id=Command.Default_Response>
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0272b157546f15b658924a24ab1593499ce8d11ee0819874fade3183fc7e2fa7f4607e'
2020-09-18 20:43:53 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'000d4f040106000101400100001a8f0000'
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 20237, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=26), 143, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010600010140010000a6f6b50d4fffff0718520a00001000'
2020-09-18 20:43:53 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=166), 246, -75, 0x4f0d, 255, 255, b'\x18R\n\x00\x00\x10\x00']
2020-09-18 20:43:53 DEBUG (MainThread) [zigpy.zcl] [0x4f0d: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=82 command_id=Command.Report_Attributes>
2020-09-18 20:43:53 DEBUG (MainThread) [zigpy.zcl] [0x4f0d:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.false>)]]
2020-09-18 20:43:53 DEBUG (MainThread) [zigpy.zcl] [0x4f0d:1:0x0006] Attribute report received: on_off=0
2020-09-18 20:43:53 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.main_bath, old_state=<state light.main_bath=on; brightness=64, off_brightness=None, friendly_name=Main Bath, supported_features=41 @ 2020-09-18T20:40:11.243769-05:00>, new_state=<state light.main_bath=off; off_brightness=None, friendly_name=Main Bath, supported_features=41 @ 2020-09-18T20:43:53.618500-05:00>>
2020-09-18 20:43:53 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.lights, old_state=<state light.lights=on; min_mireds=153, max_mireds=588, effect_list=['Strobe epilepsy!', 'Strobe color', 'Facebook', 'WhatsApp', 'Slow Temp', 'Alarm', 'Twitter', 'Stop', 'RGB', 'Police2', 'Random Loop', 'Fast Random Loop', 'Christmas', 'LSD', 'Police', 'Slowdown', 'Disco'], brightness=121, color_temp=310, hs_color=(0.0, 50.0), rgb_color=(255, 127, 127), xy_color=(0.526, 0.313), entity_id=['light.family_room', 'light.garage', 'light.landing', 'light.main_bath', 'light.office', 'light.kitchen', 'light.kitchen_cabinets', 'light.living_room', 'light.living_room_front_entrance', 'light.living_room_lamp', 'light.dining_room', 'light.sunroom', 'light.hallway', 'light.hallway_stairs', 'light.girls_bath', 'light.girls_room', 'light.master', 'light.master_bath', 'light.master_closet'], friendly_name=Lights, supported_features=63 @ 2020-09-18T12:43:29.457452-05:00>, new_state=<state light.lights=on; min_mireds=153, max_mireds=588, effect_list=['Strobe epilepsy!', 'Strobe color', 'Facebook', 'WhatsApp', 'Slow Temp', 'Alarm', 'Twitter', 'Stop', 'RGB', 'Police2', 'Random Loop', 'Fast Random Loop', 'Christmas', 'LSD', 'Police', 'Slowdown', 'Disco'], brightness=128, color_temp=310, hs_color=(0.0, 50.0), rgb_color=(255, 127, 127), xy_color=(0.526, 0.313), entity_id=['light.family_room', 'light.garage', 'light.landing', 'light.main_bath', 'light.office', 'light.kitchen', 'light.kitchen_cabinets', 'light.living_room', 'light.living_room_front_entrance', 'light.living_room_lamp', 'light.dining_room', 'light.sunroom', 'light.hallway', 'light.hallway_stairs', 'light.girls_bath', 'light.girls_room', 'light.master', 'light.master_bath', 'light.master_closet'], friendly_name=Lights, supported_features=63 @ 2020-09-18T12:43:29.457452-05:00>>
2020-09-18 20:43:53 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4F0D:1:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: [0, <Status.SUCCESS: 0>]
2020-09-18 20:43:53 DEBUG (MainThread) [homeassistant.components.zha.entity] light.main_bath: turned off: [0, <Status.SUCCESS: 0>]
2020-09-18 20:43:57 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2020-09-18 20:43:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'21732157542f00be7e'
2020-09-18 20:43:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1373a157542f794a7e'
2020-09-18 20:43:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:43:57 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2373b157546f15b658944f24ab1593499cd9d51d575e9874f4cf5089d87e3fa7ebcd23557e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401000501014001000097f2b6ba90ffff09093300240000000000'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=151), 242, -74, 0x90ba, 255, 255, b'\t3\x00$\x00\x00\x00\x00\x00']
2020-09-18 20:44:00 DEBUG (MainThread) [zigpy.zcl] [0x90ba: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=51 command_id=0>
2020-09-18 20:44:00 DEBUG (MainThread) [zigpy.zcl] [0x90ba:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper: 36>, <bitmap8.0: 0>, 0, 0]
2020-09-18 20:44:00 DEBUG (MainThread) [zigpy.zcl] [0x90ba:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x90BA:1:0x0500]: Updated alarm state: ZoneStatus.0
2020-09-18 20:44:00 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.hallway_motion, old_state=<state binary_sensor.hallway_motion=on; friendly_name=Hallway Motion, device_class=motion @ 2020-09-18T20:42:08.409465-05:00>, new_state=<state binary_sensor.hallway_motion=off; friendly_name=Hallway Motion, device_class=motion @ 2020-09-18T20:44:00.466656-05:00>>
2020-09-18 20:44:00 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=brightness_pct=1, color_name=red, entity_id=light.hallway_stairs, light.hallway>
2020-09-18 20:44:00 DEBUG (MainThread) [zigpy.device] [0x956c] Extending timeout for 0x90 request
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2f:4b:f5/0x956c
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:2f:4b:f5, True)
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'337021575454e0f976975e3d64e5932bc87e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3470a1575454a52d7e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x956C, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=144), 145, b'\x01\x90\x04\x03\x01\x00')
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'44712157541e15decc904b2daa5493099d4e273b7cc8661bf9c562897d38127e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4571a157541e15a95ad37e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'001b'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5571b157541515decc904b2daa5493099d4e27b07cce6735ca7e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'006c95040108000101400100001b910000'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 38252, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=27), 145, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6571b157546f15b6589c4a24ab1593499cbbdf6b815b9874f8cef382f87e52fd7e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010800010140010000f5f8c06c95ffff0508900b0400'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=245), 248, -64, 0x956c, 255, 255, b'\x08\x90\x0b\x04\x00']
2020-09-18 20:44:00 DEBUG (MainThread) [zigpy.zcl] [0x956c:1:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=144 command_id=Command.Default_Response>
2020-09-18 20:44:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x956C:1:0x0008]: executed 'move_to_level_with_on_off' command with args: '(3, 1)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-09-18 20:44:00 DEBUG (MainThread) [zigpy.device] [0x956c] Extending timeout for 0x92 request
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2f:4b:f5/0x956c
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:2f:4b:f5, True)
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'577621575454e0f976975e3d64e5930c007e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7676a157545489f87e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x956C, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=146), 147, b'\x01\x92\x01')
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'60772157541e15decc904b23aa5493099d4e27397d5ecd6619fc1c377e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0777a157541e15aef2677e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'001c'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1777b157546f15b658924a24ab1593499cb8df6b815b9874f8cef182fd7e495e7e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010600010140010000f6f8c06c95ffff0508920b0100'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=246), 248, -64, 0x956c, 255, 255, b'\x08\x92\x0b\x01\x00']
2020-09-18 20:44:00 DEBUG (MainThread) [zigpy.zcl] [0x956c:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=146 command_id=Command.Default_Response>
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2777b157541515decc904b23aa5493099d4e27b77ece673db47e'
2020-09-18 20:44:00 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'006c95040106000101400100001c930000'
2020-09-18 20:44:00 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 38252, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=28), 147, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:44:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x956C:1:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-09-18 20:44:00 DEBUG (MainThread) [homeassistant.components.zha.entity] light.hallway_stairs: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>]}
2020-09-18 20:44:01 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3777b157546f15b658944f24ab1593499cb6c31b69439874f4cf7689d87e3fa7ebcdae1d7e'
2020-09-18 20:44:01 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:44:01 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010005010140010000f8e4b0848dffff09091500240000000000'
2020-09-18 20:44:01 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=248), 228, -80, 0x8d84, 255, 255, b'\t\x15\x00$\x00\x00\x00\x00\x00']
2020-09-18 20:44:01 DEBUG (MainThread) [zigpy.zcl] [0x8d84: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=21 command_id=0>
2020-09-18 20:44:01 DEBUG (MainThread) [zigpy.zcl] [0x8d84:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper: 36>, <bitmap8.0: 0>, 0, 0]
2020-09-18 20:44:01 DEBUG (MainThread) [zigpy.zcl] [0x8d84:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:01 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8D84:1:0x0500]: Updated alarm state: ZoneStatus.0
2020-09-18 20:44:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.living_room_back_motion, old_state=<state binary_sensor.living_room_back_motion=on; friendly_name=Living Room Back Motion, device_class=motion @ 2020-09-18T20:42:09.181707-05:00>, new_state=<state binary_sensor.living_room_back_motion=off; friendly_name=Living Room Back Motion, device_class=motion @ 2020-09-18T20:44:01.263987-05:00>>
2020-09-18 20:44:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4777b157546f15b6589c4a24ab1593499c53d91082cd9874fade6f83fc7e1f59ee547e'
2020-09-18 20:44:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:44:02 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040108000101400100001dfebb6f03ffff07180c0a000020fe'
2020-09-18 20:44:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=29), 254, -69, 0x036f, 255, 255, b'\x18\x0c\n\x00\x00 \xfe']
2020-09-18 20:44:02 DEBUG (MainThread) [zigpy.zcl] [0x036f:1:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=12 command_id=Command.Report_Attributes>
2020-09-18 20:44:02 DEBUG (MainThread) [zigpy.zcl] [0x036f:1:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=254>)]]
2020-09-18 20:44:02 DEBUG (MainThread) [zigpy.zcl] [0x036f:1:0x0008] Attribute report received: current_level=254
2020-09-18 20:44:02 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x036F:1:0x0008]: received attribute: 0 update with value: 254
2020-09-18 20:44:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5777b157546f15b658954a24ab1593499cb6dc1898069874face3d83dc7e1fbb17ea7e'
2020-09-18 20:44:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:44:02 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010100010140010000f8fbb375c8ffff07085e0a2000201c'
2020-09-18 20:44:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=248), 251, -77, 0xc875, 255, 255, b'\x08^\n \x00 \x1c']
2020-09-18 20:44:02 DEBUG (MainThread) [zigpy.zcl] [0xc875: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=94 command_id=Command.Report_Attributes>
2020-09-18 20:44:02 DEBUG (MainThread) [zigpy.zcl] [0xc875:1:0x0001] ZCL request 0x000a: [[Attribute(attrid=32, value=<TypeValue type=uint8_t, value=28>)]]
2020-09-18 20:44:02 DEBUG (MainThread) [zigpy.zcl] [0xc875:1:0x0001] Attribute report received: battery_voltage=28
2020-09-18 20:44:02 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xC875, EmberApsFrame(profileId=260, clusterId=1, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=94), 148, b'\x18^\x0b\n\x00')
2020-09-18 20:44:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'76742157541e15c791904b24aa5493099d4e27f579cb7fd5f6cc63b7227e'
2020-09-18 20:44:03 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6074a157541e15af70647e'
2020-09-18 20:44:03 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:44:03 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'001d'
2020-09-18 20:44:03 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7074b157546f15b658944f24ab1593499c4bd01ea5019874f4cf4a89d87e3fa7ebcdfc0b7e'
2020-09-18 20:44:03 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:44:03 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401000501014001000005f7b548cfffff09092900240000000000'
2020-09-18 20:44:03 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=5), 247, -75, 0xcf48, 255, 255, b'\t)\x00$\x00\x00\x00\x00\x00']
2020-09-18 20:44:03 DEBUG (MainThread) [zigpy.zcl] [0xcf48: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=41 command_id=0>
2020-09-18 20:44:03 DEBUG (MainThread) [zigpy.zcl] [0xcf48:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper: 36>, <bitmap8.0: 0>, 0, 0]
2020-09-18 20:44:03 DEBUG (MainThread) [zigpy.zcl] [0xcf48:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF48:1:0x0500]: Updated alarm state: ZoneStatus.0
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.living_room_entrance_motion, old_state=<state binary_sensor.living_room_entrance_motion=on; friendly_name=Living Room Entrance Motion, device_class=motion @ 2020-09-18T20:42:07.274975-05:00>, new_state=<state binary_sensor.living_room_entrance_motion=off; friendly_name=Living Room Entrance Motion, device_class=motion @ 2020-09-18T20:44:03.311062-05:00>>
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event ios.became_active[R]>
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.iphone_activity_2, old_state=<state sensor.iphone_activity_2=Stationary; Confidence=High, Types=['Stationary'], friendly_name=iPhone Activity, icon=mdi:human-male @ 2020-09-18T19:13:50.196915-05:00>, new_state=<state sensor.iphone_activity_2=Unknown; Confidence=High, Types=['Unknown'], friendly_name=iPhone Activity, icon=mdi:help-circle @ 2020-09-18T20:44:03.467211-05:00>>
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.iphone_distance_2, old_state=<state sensor.iphone_distance_2=6577; unit_of_measurement=m, friendly_name=iPhone Distance, icon=mdi:hiking @ 2020-09-18T19:13:50.197320-05:00>, new_state=<state sensor.iphone_distance_2=6598; unit_of_measurement=m, friendly_name=iPhone Distance, icon=mdi:hiking @ 2020-09-18T20:44:03.467561-05:00>>
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.iphone_steps_2, old_state=<state sensor.iphone_steps_2=9278; unit_of_measurement=steps, friendly_name=iPhone Steps, icon=mdi:walk @ 2020-09-18T19:13:50.197923-05:00>, new_state=<state sensor.iphone_steps_2=9307; unit_of_measurement=steps, friendly_name=iPhone Steps, icon=mdi:walk @ 2020-09-18T20:44:03.468043-05:00>>
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.iphone_battery_level_2, old_state=<state sensor.iphone_battery_level_2=87; Battery State=Charging, Low Power Mode=False, unit_of_measurement=%, friendly_name=iPhone Battery Level, icon=mdi:battery-charging-80, device_class=battery @ 2020-09-18T20:38:51.432671-05:00>, new_state=<state sensor.iphone_battery_level_2=88; Battery State=Not Charging, Low Power Mode=False, unit_of_measurement=%, friendly_name=iPhone Battery Level, icon=mdi:battery-80, device_class=battery @ 2020-09-18T20:44:03.468371-05:00>>
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.iphone_battery_state_2, old_state=<state sensor.iphone_battery_state_2=Charging; Battery Level=87, Low Power Mode=False, friendly_name=iPhone Battery State, icon=mdi:battery-charging-80, device_class=battery @ 2020-09-18T19:13:50.198655-05:00>, new_state=<state sensor.iphone_battery_state_2=Not Charging; Battery Level=88, Low Power Mode=False, friendly_name=iPhone Battery State, icon=mdi:battery-80, device_class=battery @ 2020-09-18T20:44:03.468614-05:00>>
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.iphone_storage, old_state=<state sensor.iphone_storage=11.26; Available=3.00 GB, Available (Important)=4.88 GB, Available (Opportunistic)=3.60 GB, Total=31.98 GB, unit_of_measurement=% available, friendly_name=iPhone Storage, icon=mdi:database @ 2020-09-18T20:38:51.433263-05:00>, new_state=<state sensor.iphone_storage=11.24; Available=2.99 GB, Available (Important)=4.88 GB, Available (Opportunistic)=3.59 GB, Total=31.98 GB, unit_of_measurement=% available, friendly_name=iPhone Storage, icon=mdi:database @ 2020-09-18T20:44:03.468872-05:00>>
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.iphone_bssid_2, old_state=<state sensor.iphone_bssid_2=8:2:8e:91:56:fa; friendly_name=iPhone BSSID, icon=mdi:wifi-star @ 2020-09-18T16:43:30.101998-05:00>, new_state=<state sensor.iphone_bssid_2=e:2:8e:91:56:f8; friendly_name=iPhone BSSID, icon=mdi:wifi-star @ 2020-09-18T20:44:03.469184-05:00>>
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.iphone_last_update_trigger_2, old_state=<state sensor.iphone_last_update_trigger_2=Background Fetch; friendly_name=iPhone Last Update Trigger, icon=mdi:cellphone-wireless @ 2020-09-18T19:13:50.274900-05:00>, new_state=<state sensor.iphone_last_update_trigger_2=Signaled; friendly_name=iPhone Last Update Trigger, icon=mdi:cellphone-wireless @ 2020-09-18T20:44:03.469651-05:00>>
2020-09-18 20:44:03 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event ios.entered_background[R]>
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0074b157546f15b658944f24ab1593499c48dc1da5019874f4cf4989da7e3fa7e8cd01777e'
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401000501014001000006fbb648cfffff09092a00260000000300'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=6), 251, -74, 0xcf48, 255, 255, b'\t*\x00&\x00\x00\x00\x03\x00']
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.zcl] [0xcf48: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=42 command_id=0>
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.zcl] [0xcf48:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper|Alarm_2: 38>, <bitmap8.0: 0>, 0, 3]
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.zcl] [0xcf48:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF48:1:0x0500]: Updated alarm state: ZoneStatus.Alarm_2
2020-09-18 20:44:04 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.living_room_entrance_motion, old_state=<state binary_sensor.living_room_entrance_motion=off; friendly_name=Living Room Entrance Motion, device_class=motion @ 2020-09-18T20:44:03.311062-05:00>, new_state=<state binary_sensor.living_room_entrance_motion=on; friendly_name=Living Room Entrance Motion, device_class=motion @ 2020-09-18T20:44:04.257281-05:00>>
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1074b157546f15b6589c4a24ab1593499c53d91082cd9874fade6f83fc7e1f59154f7e'
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040108000101400100001dfebb6f03ffff07180c0a000020fe'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=29), 254, -69, 0x036f, 255, 255, b'\x18\x0c\n\x00\x00 \xfe']
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.zcl] [0x036f:1:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=12 command_id=Command.Report_Attributes>
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.zcl] [0x036f:1:0x0008] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=254>)]]
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.zcl] [0x036f:1:0x0008] Attribute report received: current_level=254
2020-09-18 20:44:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x036F:1:0x0008]: received attribute: 0 update with value: 254
2020-09-18 20:44:04 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_off, service_data=entity_id=light.landing,light.landing>
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.device] [0xd652] Extending timeout for 0x95 request
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2e:f4:6a/0xd652
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:2e:f4:6a, True)
2020-09-18 20:44:04 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=logbook, service=log, service_data=name=landing, message=is on. Turning off, domain=light>
2020-09-18 20:44:04 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event logbook_entry[L]: name=landing, message=is on. Turning off, domain=light>
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'0275215754547f4677975e3d64e5937d5e887e'
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2175a1575454dfff7e'
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xD652, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=149), 150, b'\x01\x95\x00')
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7d337a2157541e15e08f904b23aa5493099d4e273e7bcd661efd0fa87e'
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'327aa157541e15ac364d7e'
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'001e'
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'427ab157546f15b658924a24ab1593499c37d810bf189874f8cef682fc7eff347e'
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401060001014001000079ffbb52d6ffff0508950b0000'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=121), 255, -69, 0xd652, 255, 255, b'\x08\x95\x0b\x00\x00']
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.zcl] [0xd652:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=149 command_id=Command.Default_Response>
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'527ab157541515e08f904b23aa5493099d4e27b57bce67a25e7e'
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'0052d6040106000101400100001e960000'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 54866, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=30), 150, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:44:04 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xD652:1:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: [0, <Status.SUCCESS: 0>]
2020-09-18 20:44:04 DEBUG (MainThread) [homeassistant.components.zha.entity] light.landing: turned off: [0, <Status.SUCCESS: 0>]
2020-09-18 20:44:04 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.landing, old_state=<state light.landing=on; brightness=128, off_brightness=None, friendly_name=Landing, supported_features=41 @ 2020-09-18T20:42:00.784924-05:00>, new_state=<state light.landing=off; off_brightness=None, friendly_name=Landing, supported_features=41 @ 2020-09-18T20:44:04.959033-05:00>>
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'627ab157546f15b658924a24ab1593499c34d810bf189874fade5f83fc7e2fa767357e'
2020-09-18 20:44:04 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040106000101400100007affbb52d6ffff07183c0a00001000'
2020-09-18 20:44:04 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=122), 255, -69, 0xd652, 255, 255, b'\x18<\n\x00\x00\x10\x00']
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.zcl] [0xd652: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=60 command_id=Command.Report_Attributes>
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.zcl] [0xd652:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.false>)]]
2020-09-18 20:44:04 DEBUG (MainThread) [zigpy.zcl] [0xd652:1:0x0006] Attribute report received: on_off=0
2020-09-18 20:44:07 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2020-09-18 20:44:07 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'277b2157542f8f727e'
2020-09-18 20:44:07 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'737ba157542f247f7e'
2020-09-18 20:44:07 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:44:07 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
2020-09-18 20:44:07 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'037bb157541515c791904b24aa5493099d4e27b679a86796777e'
2020-09-18 20:44:07 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:44:07 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'0075c8040101000101400100001d946600'
2020-09-18 20:44:07 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 51317, EmberApsFrame(profileId=260, clusterId=1, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=29), 148, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2020-09-18 20:44:07 DEBUG (MainThread) [zigpy.device] [0xc875] Delivery error for seq # 0x5e, on endpoint id 1 cluster 0x0001: message send failure
2020-09-18 20:44:12 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'137bb157546f15b658944f24ab1593499ca5c2079b799874f4cf6589d87e3f58ebcd45c87e'
2020-09-18 20:44:12 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:44:12 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010005010140010000ebe5ac76b7ffff09090600240000ff0000'
2020-09-18 20:44:12 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=235), 229, -84, 0xb776, 255, 255, b'\t\x06\x00$\x00\x00\xff\x00\x00']
2020-09-18 20:44:12 DEBUG (MainThread) [zigpy.zcl] [0xb776: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=6 command_id=0>
2020-09-18 20:44:12 DEBUG (MainThread) [zigpy.zcl] [0xb776:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper: 36>, <bitmap8.0: 0>, 255, 0]
2020-09-18 20:44:12 DEBUG (MainThread) [zigpy.zcl] [0xb776:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:12 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB776:1:0x0500]: Updated alarm state: ZoneStatus.0
2020-09-18 20:44:12 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.primary_motion, old_state=<state binary_sensor.primary_motion=on; friendly_name=Primary Motion, device_class=motion @ 2020-09-18T20:43:37.848437-05:00>, new_state=<state binary_sensor.primary_motion=off; friendly_name=Primary Motion, device_class=motion @ 2020-09-18T20:44:12.456801-05:00>>
2020-09-18 20:44:16 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'237bb157546f15b658954a24ab1593499ca8d61f07759874face7983dc7e1fbded173e7e'
2020-09-18 20:44:16 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:44:16 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010100010140010000e6f1b4eabbffff07081a0a2000201a06'
2020-09-18 20:44:16 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=230), 241, -76, 0xbbea, 255, 255, b'\x08\x1a\n \x00 \x1a']
2020-09-18 20:44:16 DEBUG (MainThread) [zigpy.zcl] [0xbbea: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=26 command_id=Command.Report_Attributes>
2020-09-18 20:44:16 DEBUG (MainThread) [zigpy.zcl] [0xbbea:1:0x0001] ZCL request 0x000a: [[Attribute(attrid=32, value=<TypeValue type=uint8_t, value=26>)]]
2020-09-18 20:44:16 DEBUG (MainThread) [zigpy.zcl] [0xbbea:1:0x0001] Attribute report received: battery_voltage=26
2020-09-18 20:44:16 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xBBEA, EmberApsFrame(profileId=260, clusterId=1, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=26), 151, b'\x18\x1a\x0b\n\x00')
2020-09-18 20:44:16 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'33782157541e1558e2904b24aa5493099d4e27b17acb7f91f6cc630e5b7e'
2020-09-18 20:44:16 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3478a157541e15adc6447e'
2020-09-18 20:44:16 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:44:16 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'001f'
2020-09-18 20:44:16 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4478b15754151558e2904b24aa5493099d4e27b47ace6797b07e'
2020-09-18 20:44:16 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:44:16 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'00eabb040101000101400100001f970000'
2020-09-18 20:44:16 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 48106, EmberApsFrame(profileId=260, clusterId=1, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=31), 151, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:44:17 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2020-09-18 20:44:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'45792157542f1fa97e'
2020-09-18 20:44:17 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5579a157542fd8157e'
2020-09-18 20:44:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:44:17 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
2020-09-18 20:44:17 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6579b157546f15b658924a24ab1593499c46d51806569874face5c83fc7e2fa7ac9f7e'
2020-09-18 20:44:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:44:17 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401060001014001000008f2b3eb98ffff07083f0a00001000'
2020-09-18 20:44:17 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=8), 242, -77, 0x98eb, 255, 255, b'\x08?\n\x00\x00\x10\x00']
2020-09-18 20:44:17 DEBUG (MainThread) [zigpy.zcl] [0x98eb: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=63 command_id=Command.Report_Attributes>
2020-09-18 20:44:17 DEBUG (MainThread) [zigpy.zcl] [0x98eb:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.false>)]]
2020-09-18 20:44:17 DEBUG (MainThread) [zigpy.zcl] [0x98eb:1:0x0006] Attribute report received: on_off=0
2020-09-18 20:44:17 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x98EB, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=63), 152, b'\x18?\x0b\n\x00')
2020-09-18 20:44:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'577d5e2157541e1559c1904b23aa5493099d4e279475cb7fb4f6cc637ae37e'
2020-09-18 20:44:17 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'767ea157541e1592d9ab7e'
2020-09-18 20:44:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:44:17 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0020'
2020-09-18 20:44:17 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'067eb15754151559c1904b23aa5493099d4e278b75ce67eae77e'
2020-09-18 20:44:17 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:44:17 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'00eb980401060001014001000020980000'
2020-09-18 20:44:17 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 39147, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=32), 152, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:44:20 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'167eb157546f15b658964d24ab1593499ce9d21fe0819874f4de3083fc7a15a7ebcd2b3b7e'
2020-09-18 20:44:20 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:44:20 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010207010140010000a7f5b40d4fffff0918530a00042a000000'
2020-09-18 20:44:20 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1794, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=167), 245, -76, 0x4f0d, 255, 255, b'\x18S\n\x00\x04*\x00\x00\x00']
2020-09-18 20:44:20 DEBUG (MainThread) [zigpy.zcl] [0x4f0d:1:0x0702] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=83 command_id=Command.Report_Attributes>
2020-09-18 20:44:20 DEBUG (MainThread) [zigpy.zcl] [0x4f0d:1:0x0702] ZCL request 0x000a: [[Attribute(attrid=1024, value=<TypeValue type=int24s, value=0>)]]
2020-09-18 20:44:20 DEBUG (MainThread) [zigpy.zcl] [0x4f0d:1:0x0702] Attribute report received: instantaneous_demand=0
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'267eb157546f15b658944f24ab1593499c82d718232c9874f4cf6889da7e3f58ebcd84f57e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010005010140010000ccf0b3cee2ffff09090b00260000ff0000'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=204), 240, -77, 0xe2ce, 255, 255, b'\t\x0b\x00&\x00\x00\xff\x00\x00']
2020-09-18 20:44:21 DEBUG (MainThread) [zigpy.zcl] [0xe2ce: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=11 command_id=0>
2020-09-18 20:44:21 DEBUG (MainThread) [zigpy.zcl] [0xe2ce:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper|Alarm_2: 38>, <bitmap8.0: 0>, 255, 0]
2020-09-18 20:44:21 DEBUG (MainThread) [zigpy.zcl] [0xe2ce:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:21 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE2CE:1:0x0500]: Updated alarm state: ZoneStatus.Alarm_2
2020-09-18 20:44:21 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.landing_motion, old_state=<state binary_sensor.landing_motion=off; friendly_name=Landing Motion, device_class=motion @ 2020-09-18T20:43:04.823438-05:00>, new_state=<state binary_sensor.landing_motion=on; friendly_name=Landing Motion, device_class=motion @ 2020-09-18T20:44:21.285077-05:00>>
2020-09-18 20:44:21 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=brightness_pct=50, transition=1, entity_id=light.landing>
2020-09-18 20:44:21 DEBUG (MainThread) [zigpy.device] [0xd652] Extending timeout for 0x99 request
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2e:f4:6a/0xd652
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:2e:f4:6a, True)
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'637f215754547f4677975e3d64e5937ac07e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'377fa15754540e347e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xD652, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=153), 154, b'\x01\x99\x04\x80\n\x00')
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'747c2157541e15e08f904b2daa5493099d4e273277c86612f946698939eb7e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'407ca157541e15936f7e7e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0021'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'507cb157546f15b6589c4a24ab1593499c35d810bf189874f8cefa82f87e64dc7e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040108000101400100007bffbb52d6ffff0508990b0400'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=123), 255, -69, 0xd652, 255, 255, b'\x08\x99\x0b\x04\x00']
2020-09-18 20:44:21 DEBUG (MainThread) [zigpy.zcl] [0xd652:1:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=153 command_id=Command.Default_Response>
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'607cb157541515e08f904b2daa5493099d4e278a77ce67d9d37e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'0052d604010800010140010000219a0000'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 54866, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=33), 154, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:44:21 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xD652:1:0x0008]: executed 'move_to_level_with_on_off' command with args: '(128, 10.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-09-18 20:44:21 DEBUG (MainThread) [zigpy.device] [0xd652] Extending timeout for 0x9b request
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2e:f4:6a/0xd652
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:2e:f4:6a, True)
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'077d5d215754547f4677975e3d64e593a0ad7e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'717da1575454ad467e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xD652, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=155), 156, b'\x01\x9b\x01')
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'10022157541e15e08f904b23aa5493099d4e273071cd6610fc4df67e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'017db157546f15b658924a24ab1593499c32d810bf189874fade5e83fc7e2fa62f757e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1202a157541e1590ad367e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040106000101400100007cffbb52d6ffff07183d0a00001001'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=124), 255, -69, 0xd652, 255, 255, b'\x18=\n\x00\x00\x10\x01']
2020-09-18 20:44:21 DEBUG (MainThread) [zigpy.zcl] [0xd652: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=61 command_id=Command.Report_Attributes>
2020-09-18 20:44:21 DEBUG (MainThread) [zigpy.zcl] [0xd652:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.true>)]]
2020-09-18 20:44:21 DEBUG (MainThread) [zigpy.zcl] [0xd652:1:0x0006] Attribute report received: on_off=1
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0022'
2020-09-18 20:44:21 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.landing, old_state=<state light.landing=off; off_brightness=None, friendly_name=Landing, supported_features=41 @ 2020-09-18T20:44:04.959033-05:00>, new_state=<state light.landing=on; brightness=128, off_brightness=None, friendly_name=Landing, supported_features=41 @ 2020-09-18T20:44:21.422052-05:00>>
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2202b157546f15b658924a24ab1593499c33db10bf189874f8cef882fd7e13167e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040106000101400100007dfcbb52d6ffff05089b0b0100'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=125), 252, -69, 0xd652, 255, 255, b'\x08\x9b\x0b\x01\x00']
2020-09-18 20:44:21 DEBUG (MainThread) [zigpy.zcl] [0xd652:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=155 command_id=Command.Default_Response>
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3202b157541515e08f904b23aa5493099d4e278971ce67fb627e'
2020-09-18 20:44:21 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'0052d604010600010140010000229c0000'
2020-09-18 20:44:21 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 54866, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=34), 156, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:44:21 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xD652:1:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-09-18 20:44:21 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>]}
2020-09-18 20:44:27 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2020-09-18 20:44:27 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'24032157542f5e397e'
2020-09-18 20:44:27 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4303a157542f14587e'
2020-09-18 20:44:27 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:44:27 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
2020-09-18 20:44:28 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=persistent_notification, service=dismiss, service_data=notification_id=config_entry_discovery>
2020-09-18 20:44:30 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.girls_bed, old_state=<state light.girls_bed=off; min_mireds=153, max_mireds=588, effect_list=['Strobe color', 'Police', 'Christmas', 'RGB', 'Random Loop', 'Fast Random Loop', 'LSD', 'Slowdown', 'Disco', 'Strobe epilepsy!', 'Alarm', 'Police2', 'WhatsApp', 'Facebook', 'Twitter', 'Slow Temp', 'Stop'], flowing=False, friendly_name=Girl's Bed, icon=mdi:bunk-bed, supported_features=63 @ 2020-09-18T19:52:11.066125-05:00>, new_state=<state light.girls_bed=on; min_mireds=153, max_mireds=588, effect_list=['Strobe color', 'Police', 'Christmas', 'RGB', 'Random Loop', 'Fast Random Loop', 'LSD', 'Slowdown', 'Disco', 'Strobe epilepsy!', 'Alarm', 'Police2', 'WhatsApp', 'Facebook', 'Twitter', 'Slow Temp', 'Stop'], brightness=128, color_temp=250, hs_color=(120.0, 100.0), rgb_color=(0, 255, 0), xy_color=(0.172, 0.747), flowing=False, friendly_name=Girl's Bed, icon=mdi:bunk-bed, supported_features=63 @ 2020-09-18T20:44:30.619656-05:00>>
2020-09-18 20:44:30 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.girls_room, old_state=<state light.girls_room=on; min_mireds=153, max_mireds=588, effect_list=['Strobe epilepsy!', 'Strobe color', 'Facebook', 'WhatsApp', 'Slow Temp', 'Alarm', 'Twitter', 'Stop', 'RGB', 'Police2', 'Random Loop', 'Fast Random Loop', 'Christmas', 'LSD', 'Police', 'Slowdown', 'Disco'], entity_id=['light.girls_ceiling', 'light.girls_bed'], friendly_name=Girls Room, supported_features=63 @ 2020-09-18T20:32:16.227083-05:00>, new_state=<state light.girls_room=on; min_mireds=153, max_mireds=588, effect_list=['Strobe epilepsy!', 'Strobe color', 'Facebook', 'WhatsApp', 'Slow Temp', 'Alarm', 'Twitter', 'Stop', 'RGB', 'Police2', 'Random Loop', 'Fast Random Loop', 'Christmas', 'LSD', 'Police', 'Slowdown', 'Disco'], brightness=128, color_temp=250, hs_color=(120.0, 100.0), rgb_color=(0, 255, 0), xy_color=(0.172, 0.747), entity_id=['light.girls_ceiling', 'light.girls_bed'], friendly_name=Girls Room, supported_features=63 @ 2020-09-18T20:32:16.227083-05:00>>
2020-09-18 20:44:30 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.lights, old_state=<state light.lights=on; min_mireds=153, max_mireds=588, effect_list=['Strobe epilepsy!', 'Strobe color', 'Facebook', 'WhatsApp', 'Slow Temp', 'Alarm', 'Twitter', 'Stop', 'RGB', 'Police2', 'Random Loop', 'Fast Random Loop', 'Christmas', 'LSD', 'Police', 'Slowdown', 'Disco'], brightness=128, color_temp=310, hs_color=(0.0, 50.0), rgb_color=(255, 127, 127), xy_color=(0.526, 0.313), entity_id=['light.family_room', 'light.garage', 'light.landing', 'light.main_bath', 'light.office', 'light.kitchen', 'light.kitchen_cabinets', 'light.living_room', 'light.living_room_front_entrance', 'light.living_room_lamp', 'light.dining_room', 'light.sunroom', 'light.hallway', 'light.hallway_stairs', 'light.girls_bath', 'light.girls_room', 'light.master', 'light.master_bath', 'light.master_closet'], friendly_name=Lights, supported_features=63 @ 2020-09-18T12:43:29.457452-05:00>, new_state=<state light.lights=on; min_mireds=153, max_mireds=588, effect_list=['Strobe epilepsy!', 'Strobe color', 'Facebook', 'WhatsApp', 'Slow Temp', 'Alarm', 'Twitter', 'Stop', 'RGB', 'Police2', 'Random Loop', 'Fast Random Loop', 'Christmas', 'LSD', 'Police', 'Slowdown', 'Disco'], brightness=128, color_temp=290, hs_color=(40.0, 66.667), rgb_color=(255, 198, 84), xy_color=(0.491, 0.427), entity_id=['light.family_room', 'light.garage', 'light.landing', 'light.main_bath', 'light.office', 'light.kitchen', 'light.kitchen_cabinets', 'light.living_room', 'light.living_room_front_entrance', 'light.living_room_lamp', 'light.dining_room', 'light.sunroom', 'light.hallway', 'light.hallway_stairs', 'light.girls_bath', 'light.girls_room', 'light.master', 'light.master_bath', 'light.master_closet'], friendly_name=Lights, supported_features=63 @ 2020-09-18T12:43:29.457452-05:00>>
2020-09-18 20:44:30 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5303b157546f15b658944f24ab1593499cd9b000f22a9874f4cf0189d87e3f58ebcdd8097e'
2020-09-18 20:44:30 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:44:30 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100050101400100009797ab1fe4ffff09096200240000ff0000'
2020-09-18 20:44:30 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=151), 151, -85, 0xe41f, 255, 255, b'\tb\x00$\x00\x00\xff\x00\x00']
2020-09-18 20:44:30 DEBUG (MainThread) [zigpy.zcl] [0xe41f: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=98 command_id=0>
2020-09-18 20:44:30 DEBUG (MainThread) [zigpy.zcl] [0xe41f:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper: 36>, <bitmap8.0: 0>, 255, 0]
2020-09-18 20:44:30 DEBUG (MainThread) [zigpy.zcl] [0xe41f:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE41F:1:0x0500]: Updated alarm state: ZoneStatus.0
2020-09-18 20:44:30 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.primary_bath_motion, old_state=<state binary_sensor.primary_bath_motion=on; friendly_name=Primary Bath Motion, device_class=motion @ 2020-09-18T20:43:48.086037-05:00>, new_state=<state binary_sensor.primary_bath_motion=off; friendly_name=Primary Bath Motion, device_class=motion @ 2020-09-18T20:44:30.705096-05:00>>
2020-09-18 20:44:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_off, service_data=entity_id=light.primary_closet,light.primary_closet>
2020-09-18 20:44:31 DEBUG (MainThread) [zigpy.device] [0x5b62] Extending timeout for 0x9d request
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:5d:50:7c/0x5b62
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:5d:50:7c, True)
2020-09-18 20:44:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=logbook, service=log, service_data=name=primary_closet, message=is on. Turning off, domain=light>
2020-09-18 20:44:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event logbook_entry[L]: name=primary_closet, message=is on. Turning off, domain=light>
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'36002157545469e204975e3d64e5931cf67e'
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6400a1575454c83f7e'
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x5B62, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=157), 158, b'\x01\x9d\x00')
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'47012157541e15d002904b23aa5493099d4e273673cd6616fdf8bd7e'
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7501a157541e15912f357e'
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0023'
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0501b157546f15b658924a24ab1593499c0afd1a8f959874f8cefe82fc7e54757e'
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401060001014001000044dab1625bffff05089d0b0000'
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=68), 218, -79, 0x5b62, 255, 255, b'\x08\x9d\x0b\x00\x00']
2020-09-18 20:44:31 DEBUG (MainThread) [zigpy.zcl] [0x5b62:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=157 command_id=Command.Default_Response>
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1501b157541515d002904b23aa5493099d4e278873ce673d257e'
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2501b157546f15b658924a24ab1593499c0bcc198f959874fade5b83fc7e2fa757927e'
2020-09-18 20:44:31 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'00625b04010600010140010000239e0000'
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 23394, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=35), 158, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401060001014001000045ebb2625bffff0718380a00001000'
2020-09-18 20:44:31 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=69), 235, -78, 0x5b62, 255, 255, b'\x188\n\x00\x00\x10\x00']
2020-09-18 20:44:31 DEBUG (MainThread) [zigpy.zcl] [0x5b62: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-09-18 20:44:31 DEBUG (MainThread) [zigpy.zcl] [0x5b62:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.false>)]]
2020-09-18 20:44:31 DEBUG (MainThread) [zigpy.zcl] [0x5b62:1:0x0006] Attribute report received: on_off=0
2020-09-18 20:44:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.primary_closet, old_state=<state light.primary_closet=on; brightness=3, off_brightness=None, friendly_name=Primary Closet, supported_features=41 @ 2020-09-18T20:43:25.810250-05:00>, new_state=<state light.primary_closet=off; off_brightness=None, friendly_name=Primary Closet, supported_features=41 @ 2020-09-18T20:44:31.485698-05:00>>
2020-09-18 20:44:31 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5B62:1:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: [0, <Status.SUCCESS: 0>]
2020-09-18 20:44:31 DEBUG (MainThread) [homeassistant.components.zha.entity] light.primary_closet: turned off: [0, <Status.SUCCESS: 0>]
2020-09-18 20:44:37 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2020-09-18 20:44:37 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'53062157542ff0b37e'
2020-09-18 20:44:37 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3606a157542f31927e'
2020-09-18 20:44:37 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:44:37 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
2020-09-18 20:44:38 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4606b157546f15b658944f24ab1593499cd6d41d575e9874f4cf5789da7e3fa7ebcd19e47e'
2020-09-18 20:44:38 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:44:38 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401000501014001000098f3b6ba90ffff09093400260000000000'
2020-09-18 20:44:38 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=152), 243, -74, 0x90ba, 255, 255, b'\t4\x00&\x00\x00\x00\x00\x00']
2020-09-18 20:44:38 DEBUG (MainThread) [zigpy.zcl] [0x90ba: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=52 command_id=0>
2020-09-18 20:44:38 DEBUG (MainThread) [zigpy.zcl] [0x90ba:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper|Alarm_2: 38>, <bitmap8.0: 0>, 0, 0]
2020-09-18 20:44:38 DEBUG (MainThread) [zigpy.zcl] [0x90ba:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:38 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x90BA:1:0x0500]: Updated alarm state: ZoneStatus.Alarm_2
2020-09-18 20:44:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.hallway_motion, old_state=<state binary_sensor.hallway_motion=off; friendly_name=Hallway Motion, device_class=motion @ 2020-09-18T20:44:00.466656-05:00>, new_state=<state binary_sensor.hallway_motion=on; friendly_name=Hallway Motion, device_class=motion @ 2020-09-18T20:44:38.888703-05:00>>
2020-09-18 20:44:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=brightness_pct=1, color_name=red, entity_id=light.hallway_stairs, light.hallway>
2020-09-18 20:44:38 DEBUG (MainThread) [zigpy.device] [0x956c] Extending timeout for 0x9f request
2020-09-18 20:44:38 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2f:4b:f5/0x956c
2020-09-18 20:44:38 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:2f:4b:f5, True)
2020-09-18 20:44:38 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'650721575454e0f976975e3d64e59399a17e'
2020-09-18 20:44:38 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5707a15754544e877e'
2020-09-18 20:44:38 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:44:38 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:44:38 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x956C, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=159), 160, b'\x01\x9f\x04\x03\x01\x00')
2020-09-18 20:44:38 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'76042157541e15decc904b2daa5493099d4e27344dc86614f9c5628995867e'
2020-09-18 20:44:38 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6004a157541e1596537f7e'
2020-09-18 20:44:38 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:44:38 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0024'
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7004b157541515decc904b2daa5493099d4e278f4dce67769a7e'
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'006c950401080001014001000024a00000'
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 38252, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=36), 160, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0004b157546f15b6589c4a24ab1593499cb9de14815b9874f8cefc82f87e9bd37e'
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010800010140010000f7f9bf6c95ffff05089f0b0400'
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=247), 249, -65, 0x956c, 255, 255, b'\x08\x9f\x0b\x04\x00']
2020-09-18 20:44:39 DEBUG (MainThread) [zigpy.zcl] [0x956c:1:0x0008] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=159 command_id=Command.Default_Response>
2020-09-18 20:44:39 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x956C:1:0x0008]: executed 'move_to_level_with_on_off' command with args: '(3, 1)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2020-09-18 20:44:39 DEBUG (MainThread) [zigpy.device] [0x956c] Extending timeout for 0xa1 request
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2f:4b:f5/0x956c
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:2f:4b:f5, True)
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'010521575454e0f976975e3d64e59343cc7e'
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1105a1575454edf57e'
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 126 (setExtendedTimeout) received: b''
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x956C, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=161), 162, b'\x01\xa1\x01')
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'120a2157541e15decc904b23aa5493099d4e270a4fcd662afc51b87e'
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'220aa157541e159708a07e'
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0025'
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'320ab157546f15b658924a24ab1593499cb6d86b815b9874f8cec282fd7e46967e'
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010600010140010000f8ffc06c95ffff0508a10b0100'
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=248), 255, -64, 0x956c, 255, 255, b'\x08\xa1\x0b\x01\x00']
2020-09-18 20:44:39 DEBUG (MainThread) [zigpy.zcl] [0x956c:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=161 command_id=Command.Default_Response>
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'420ab157541515decc904b23aa5493099d4e278e4fce67c6067e'
2020-09-18 20:44:39 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'006c950401060001014001000025a20000'
2020-09-18 20:44:39 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 38252, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=37), 162, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:44:39 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x956C:1:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-09-18 20:44:39 DEBUG (MainThread) [homeassistant.components.zha.entity] light.hallway_stairs: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': [1, <Status.SUCCESS: 0>]}
2020-09-18 20:44:40 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'520ab157546f15b658944f24ab1593499cb7fe1a69439874f4cf7589da7e3fa7ebcd0a4c7e'
2020-09-18 20:44:40 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:44:40 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010005010140010000f9d9b1848dffff09091600260000000000'
2020-09-18 20:44:40 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=249), 217, -79, 0x8d84, 255, 255, b'\t\x16\x00&\x00\x00\x00\x00\x00']
2020-09-18 20:44:40 DEBUG (MainThread) [zigpy.zcl] [0x8d84: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=22 command_id=0>
2020-09-18 20:44:40 DEBUG (MainThread) [zigpy.zcl] [0x8d84:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper|Alarm_2: 38>, <bitmap8.0: 0>, 0, 0]
2020-09-18 20:44:40 DEBUG (MainThread) [zigpy.zcl] [0x8d84:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:40 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8D84:1:0x0500]: Updated alarm state: ZoneStatus.Alarm_2
2020-09-18 20:44:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.living_room_back_motion, old_state=<state binary_sensor.living_room_back_motion=off; friendly_name=Living Room Back Motion, device_class=motion @ 2020-09-18T20:44:01.263987-05:00>, new_state=<state binary_sensor.living_room_back_motion=on; friendly_name=Living Room Back Motion, device_class=motion @ 2020-09-18T20:44:40.257434-05:00>>
2020-09-18 20:44:45 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'620ab157546f15b658944f24ab1593499c3afa1d9fd89874f4cf7289da7e3fa7ebcdaf9d7e'
2020-09-18 20:44:45 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:44:45 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401000501014001000074ddb67216ffff09091100260000000000'
2020-09-18 20:44:45 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=116), 221, -74, 0x1672, 255, 255, b'\t\x11\x00&\x00\x00\x00\x00\x00']
2020-09-18 20:44:45 DEBUG (MainThread) [zigpy.zcl] [0x1672: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=17 command_id=0>
2020-09-18 20:44:45 DEBUG (MainThread) [zigpy.zcl] [0x1672:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper|Alarm_2: 38>, <bitmap8.0: 0>, 0, 0]
2020-09-18 20:44:45 DEBUG (MainThread) [zigpy.zcl] [0x1672:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1672:1:0x0500]: Updated alarm state: ZoneStatus.Alarm_2
2020-09-18 20:44:45 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.living_room_front_motion, old_state=<state binary_sensor.living_room_front_motion=off; friendly_name=Living Room Front Motion, device_class=motion @ 2020-09-18T20:43:04.248836-05:00>, new_state=<state binary_sensor.living_room_front_motion=on; friendly_name=Living Room Front Motion, device_class=motion @ 2020-09-18T20:44:45.275830-05:00>>
2020-09-18 20:44:45 ERROR (MainThread) [homeassistant.components.roku] Error fetching roku data: Invalid response from API: Error occurred while communicating with device
2020-09-18 20:44:45 WARNING (MainThread) [homeassistant.config_entries] Config entry for roku not ready yet. Retrying in 80 seconds
2020-09-18 20:44:47 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2020-09-18 20:44:47 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'270b2157542f92f47e'
2020-09-18 20:44:47 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'730ba157542f39f97e'
2020-09-18 20:44:47 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:44:47 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
2020-09-18 20:44:47 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'030bb15754aa5736d4f0247e'
2020-09-18 20:44:47 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:44:47 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 128 (incomingRouteErrorHandler) received: b'42848d'
2020-09-18 20:44:47 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0x8d84]
2020-09-18 20:44:47 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0x8d84
2020-09-18 20:44:51 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'130bb157546f15b658964e24ab1593499c64f601fd6e9874f5ce2683fc7e16f4e3bb547e'
2020-09-18 20:44:51 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:44:51 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040102040101400100002ad1aa10a0ffff0808450a0000295308'
2020-09-18 20:44:51 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1026, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=42), 209, -86, 0xa010, 255, 255, b'\x08E\n\x00\x00)S\x08']
2020-09-18 20:44:51 DEBUG (MainThread) [zigpy.zcl] [0xa010: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=69 command_id=Command.Report_Attributes>
2020-09-18 20:44:51 DEBUG (MainThread) [zigpy.zcl] [0xa010:1:0x0402] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=int16s, value=2131>)]]
2020-09-18 20:44:51 DEBUG (MainThread) [zigpy.zcl] [0xa010:1:0x0402] Attribute report received: measured_value=2131
2020-09-18 20:44:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.office_motion_temperature, old_state=<state sensor.office_motion_temperature=70.0; unit_of_measurement=°F, friendly_name=Office Motion Temperature, device_class=temperature @ 2020-09-18T19:14:50.433113-05:00>, new_state=<state sensor.office_motion_temperature=70.3; unit_of_measurement=°F, friendly_name=Office Motion Temperature, device_class=temperature @ 2020-09-18T20:44:51.271556-05:00>>
2020-09-18 20:44:51 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xA010, EmberApsFrame(profileId=260, clusterId=1026, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=69), 163, b'\x18E\x0b\n\x00')
2020-09-18 20:44:51 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'32082157541e15a2f9904b27ae5493099d4e27ee4ecb7fcef6cc6309827e'
2020-09-18 20:44:51 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2408a157541e1594d8eb7e'
2020-09-18 20:44:51 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:44:51 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0026'
2020-09-18 20:44:53 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3408b157546f15b658944f24ab1593499c83ce1a232c9874f4cf6f89d87e3f58ebcdeedd7e'
2020-09-18 20:44:53 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:44:53 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010005010140010000cde9b1cee2ffff09090c00240000ff0000'
2020-09-18 20:44:53 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=205), 233, -79, 0xe2ce, 255, 255, b'\t\x0c\x00$\x00\x00\xff\x00\x00']
2020-09-18 20:44:53 DEBUG (MainThread) [zigpy.zcl] [0xe2ce: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=12 command_id=0>
2020-09-18 20:44:53 DEBUG (MainThread) [zigpy.zcl] [0xe2ce:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper: 36>, <bitmap8.0: 0>, 255, 0]
2020-09-18 20:44:53 DEBUG (MainThread) [zigpy.zcl] [0xe2ce:1:0x0500] No handler for cluster command 0
2020-09-18 20:44:53 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE2CE:1:0x0500]: Updated alarm state: ZoneStatus.0
2020-09-18 20:44:53 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.landing_motion, old_state=<state binary_sensor.landing_motion=on; friendly_name=Landing Motion, device_class=motion @ 2020-09-18T20:44:21.285077-05:00>, new_state=<state binary_sensor.landing_motion=off; friendly_name=Landing Motion, device_class=motion @ 2020-09-18T20:44:53.537101-05:00>>
2020-09-18 20:44:56 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4408b157546f15b658964d24ab1593499c08ca198f959874f4de5a83fc7a15a7ebcdf5d67e'
2020-09-18 20:44:56 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:44:56 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401020701014001000046edb2625bffff0918390a00042a000000'
2020-09-18 20:44:56 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1794, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=70), 237, -78, 0x5b62, 255, 255, b'\x189\n\x00\x04*\x00\x00\x00']
2020-09-18 20:44:56 DEBUG (MainThread) [zigpy.zcl] [0x5b62:1:0x0702] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=True> manufacturer=None tsn=57 command_id=Command.Report_Attributes>
2020-09-18 20:44:56 DEBUG (MainThread) [zigpy.zcl] [0x5b62:1:0x0702] ZCL request 0x000a: [[Attribute(attrid=1024, value=<TypeValue type=int24s, value=0>)]]
2020-09-18 20:44:56 DEBUG (MainThread) [zigpy.zcl] [0x5b62:1:0x0702] Attribute report received: instantaneous_demand=0
2020-09-18 20:44:57 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2020-09-18 20:44:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'45092157542f022f7e'
2020-09-18 20:44:57 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5509a157542fc5937e'
2020-09-18 20:44:57 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:44:57 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
2020-09-18 20:44:58 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6509b15754aa57a2f9fccf7e'
2020-09-18 20:44:58 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2020-09-18 20:44:58 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 128 (incomingRouteErrorHandler) received: b'4210a0'
2020-09-18 20:44:58 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [<EmberStatus.MAC_INDIRECT_TIMEOUT: 66>, 0xa010]
2020-09-18 20:44:58 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=EmberStatus.MAC_INDIRECT_TIMEOUT, nwk=0xa010
2020-09-18 20:45:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7509b157546f15b658924a24ab1593499c97fd1840159874face5c83fc7e2fa6ef4e057e'
2020-09-18 20:45:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2020-09-18 20:45:02 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'0004010600010140010000d9dab3addbffff07083f0a0000100104'
2020-09-18 20:45:02 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=217), 218, -77, 0xdbad, 255, 255, b'\x08?\n\x00\x00\x10\x01']
2020-09-18 20:45:02 DEBUG (MainThread) [zigpy.zcl] [0xdbad: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=63 command_id=Command.Report_Attributes>
2020-09-18 20:45:02 DEBUG (MainThread) [zigpy.zcl] [0xdbad:1:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=Bool, value=Bool.true>)]]
2020-09-18 20:45:02 DEBUG (MainThread) [zigpy.zcl] [0xdbad:1:0x0006] Attribute report received: on_off=1
2020-09-18 20:45:02 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xDBAD, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=63), 164, b'\x18?\x0b\n\x00')
2020-09-18 20:45:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'500e2157541e151f82904b23aa5493099d4e279449cb7fb4f6cc638c237e'
2020-09-18 20:45:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'060ea157541e15959d217e'
2020-09-18 20:45:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2020-09-18 20:45:02 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'0027'
2020-09-18 20:45:02 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'160eb1575415151f82904b23aa5493099d4e278c49ce67bc767e'
2020-09-18 20:45:02 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2020-09-18 20:45:02 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'00addb0401060001014001000027a40000'
2020-09-18 20:45:02 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 56237, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=39), 164, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:45:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'260eb157541515a2f9904b27ae5493099d4e278d4ece672ab07e'
2020-09-18 20:45:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2020-09-18 20:45:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'0010a00401020401014001000026a30000'
2020-09-18 20:45:06 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 40976, EmberApsFrame(profileId=260, clusterId=1026, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=38), 163, <EmberStatus.SUCCESS: 0>, b'']
2020-09-18 20:45:07 DEBUG (MainThread) [bellows.ezsp.protocol] Send command nop: ()
2020-09-18 20:45:07 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'630f2157542f77437e'
2020-09-18 20:45:07 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'370fa157542fdc4e7e'
2020-09-18 20:45:07 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2020-09-18 20:45:07 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 5 (nop) received: b''
2020-09-18 20:45:11 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'470fb157546f15b658944f24ab1593499cd7da1d575e9874f4cf5689d87e3fa7ebcd2b367e'
2020-09-18 20:45:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2020-09-18 20:45:11 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'000401000501014001000099fdb6ba90ffff09093500240000000000'
2020-09-18 20:45:11 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=153), 253, -74, 0x90ba, 255, 255, b'\t5\x00$\x00\x00\x00\x00\x00']
2020-09-18 20:45:11 DEBUG (MainThread) [zigpy.zcl] [0x90ba: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=53 command_id=0>
2020-09-18 20:45:11 DEBUG (MainThread) [zigpy.zcl] [0x90ba:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper: 36>, <bitmap8.0: 0>, 0, 0]
2020-09-18 20:45:11 DEBUG (MainThread) [zigpy.zcl] [0x90ba:1:0x0500] No handler for cluster command 0
2020-09-18 20:45:11 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x90BA:1:0x0500]: Updated alarm state: ZoneStatus.0
2020-09-18 20:45:11 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.hallway_motion, old_state=<state binary_sensor.hallway_motion=on; friendly_name=Hallway Motion, device_class=motion @ 2020-09-18T20:44:38.888703-05:00>, new_state=<state binary_sensor.hallway_motion=off; friendly_name=Hallway Motion, device_class=motion @ 2020-09-18T20:45:11.464375-05:00>>
2020-09-18 20:45:11 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=brightness_pct=1, color_name=red, entity_id=light.hallway_stairs, light.hallway>
2020-09-18 20:45:11 DEBUG (MainThread) [zigpy.device] [0x956c] Extending timeout for 0xa5 request
2020-09-18 20:45:11 DEBUG (MainThread) [bellows.zigbee.application] Extending timeout for b0:ce:18:14:03:2f:4b:f5/0x956c
2020-09-18 20:45:11 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (b0:ce:18:14:03:2f:4b:f5, True)
2020-09-18 20:45:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'750c21575454e0f976975e3d64e593b1e37e'
2020-09-18 20:45:11 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'570fb157546f15b658944f24ab1593499c53d31195db9874f4cf4589d87e3f58ebcd8b567e'
2020-09-18 20:45:11 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2020-09-18 20:45:11 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100050101400100001df4ba7815ffff09092600240000ff0000'
2020-09-18 20:45:11 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=29), 244, -70, 0x1578, 255, 255, b'\t&\x00$\x00\x00\xff\x00\x00']
2020-09-18 20:45:11 DEBUG (MainThread) [zigpy.zcl] [0x1578: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=38 command_id=0>
2020-09-18 20:45:11 DEBUG (MainThread) [zigpy.zcl] [0x1578:1:0x0500] ZCL request 0x0000: [<ZoneStatus.Restore_reports|Tamper: 36>, <bitmap8.0: 0>, 255, 0]
2020-09-18 20:45:11 DEBUG (MainThread) [zigpy.zcl] [0x1578:1:0x0500] No handler for cluster command 0
2020-09-18 20:45:11 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1578:1:0x0500]: Updated alarm state: ZoneStatus.0
2020-09-18 20:45:11 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.kitchen_motion, old_state=<state binary_sensor.kitchen_motion=on; friendly_name=Kitchen Motion, device_class=motion @ 2020-09-18T20:43:28.545253-05:00>, new_state=<state binary_sensor.kitchen_motion=off; friendly_name=Kitchen Motion, device_class=motion @ 2020-09-18T20:45:11.493061-05:00>>