2023-02-23 10:06:22.274 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=16), 192, -52, 0x9441, 255, 255, b'\x18\xab\x01\x04\x00\x00B\x04LUMI\x05\x00\x00B\x17lumi.sensor_smoke.acn03']
2023-02-23 10:06:22.274 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=16, profile_id=260, cluster_id=0, data=Serialized[b'\x18\xab\x01\x04\x00\x00B\x04LUMI\x05\x00\x00B\x17lumi.sensor_smoke.acn03'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-52)
2023-02-23 10:06:22.275 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0000] Received ZCL frame: b'\x18\xab\x01\x04\x00\x00B\x04LUMI\x05\x00\x00B\x17lumi.sensor_smoke.acn03'
2023-02-23 10:06:22.276 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0000] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=171, command_id=1, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
2023-02-23 10:06:22.280 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0000] Decoded ZCL frame: Basic:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0004, status=<Status.SUCCESS: 0>, value=TypeValue(type=CharacterString, value='LUMI')), ReadAttributeRecord(attrid=0x0005, status=<Status.SUCCESS: 0>, value=TypeValue(type=CharacterString, value='lumi.sensor_smoke.acn03'))])
2023-02-23 10:06:22.301 DEBUG (MainThread) [zigpy.appdb] Error handling '_save_attribute' event with (54:ef:44:10:00:71:1d:00, 1, 0, 1, 17) params: FOREIGN KEY constraint failed
2023-02-23 10:06:22.303 INFO (MainThread) [zigpy.device] [0x9441] Read model 'lumi.sensor_smoke.acn03' and manufacturer 'LUMI' from <Endpoint id=1 in=[basic:0x0000, ias_zone:0x0500, identify:0x0003, power:0x0001] out=[ota:0x0019] status=<Status.ZDO_INIT: 1>>
2023-02-23 10:06:22.304 INFO (MainThread) [zigpy.device] [0x9441] Discovered basic device information for <Device model='lumi.sensor_smoke.acn03' manuf='LUMI' nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=True>
2023-02-23 10:06:22.304 DEBUG (MainThread) [zigpy.application] Device is initialized <Device model='lumi.sensor_smoke.acn03' manuf='LUMI' nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=True>
2023-02-23 10:06:22.305 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.sensor_smoke.acn03 (54:ef:44:10:00:71:1d:00)
2023-02-23 10:06:22.306 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'xiaomi.smoke.LumiSensorSmokeAcn03'>
2023-02-23 10:06:22.306 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 54:ef:44:10:00:71:1d:00: <class 'xiaomi.smoke.LumiSensorSmokeAcn03'>
2023-02-23 10:06:22.320 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'binary_sensor' component -> 'IASZone' using ['ias_zone']
2023-02-23 10:06:22.322 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'button' component -> 'ZHAIdentifyButton' using ['identify']
2023-02-23 10:06:22.322 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'DeviceTemperature' using ['device_temperature']
2023-02-23 10:06:22.324 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'RSSISensor' using ['basic']
2023-02-23 10:06:22.324 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'LQISensor' using ['basic']
2023-02-23 10:06:22.329 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x9441:54:ef:44:10:00:71:1d:00 entering async_device_initialized - is_new_join: True
2023-02-23 10:06:22.329 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x9441:54:ef:44:10:00:71:1d:00 has joined the ZHA zigbee network
2023-02-23 10:06:22.330 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9441](lumi.sensor_smoke.acn03): started configuration
2023-02-23 10:06:22.331 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:ZDO](lumi.sensor_smoke.acn03): 'async_configure' stage succeeded
2023-02-23 10:06:22.343 DEBUG (MainThread) [zigpy.appdb] Error handling '_save_attribute' event with (54:ef:44:10:00:71:1d:00, 1, 0, 4, 'LUMI') params: FOREIGN KEY constraint failed
2023-02-23 10:06:22.347 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: started IASZoneChannel configuration
2023-02-23 10:06:22.348 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: bound 'ias_zone' cluster: Status.SUCCESS
2023-02-23 10:06:22.350 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: wrote cie_addr: 38:5c:fb:ff:fe:e3:73:71 to 'ias_zone' cluster: [WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]
2023-02-23 10:06:22.351 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: Sending pro-active IAS enroll response
2023-02-23 10:06:22.352 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: finished IASZoneChannel configuration
2023-02-23 10:06:22.353 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0000]: Configuring cluster attribute reporting
2023-02-23 10:06:22.353 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0000]: finished channel configuration
2023-02-23 10:06:22.354 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0003]: Configuring cluster attribute reporting
2023-02-23 10:06:22.354 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0003]: finished channel configuration
2023-02-23 10:06:22.354 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: Performing cluster binding
2023-02-23 10:06:22.355 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: bound 'device_temperature' cluster: Status.SUCCESS
2023-02-23 10:06:22.355 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: Configuring cluster attribute reporting
2023-02-23 10:06:22.356 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: Successfully configured reporting for '{'current_temperature': (30, 900, 50)}' on 'device_temperature' cluster: [ConfigureReportingResponseRecord(status=<Status.SUCCESS: 0>)]
2023-02-23 10:06:22.356 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: finished channel configuration
2023-02-23 10:06:22.357 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0xfcc0]: Performing cluster binding
2023-02-23 10:06:22.358 DEBUG (MainThread) [zigpy.device] [0x9441] Extending timeout for 0xad request
2023-02-23 10:06:22.358 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), dst_ep=0, source_route=None, extended_timeout=True, tsn=173, profile_id=0, cluster_id=<ZDOCmd.Bind_req: 0x0021>, data=Serialized[b'\xad\x00\x1dq\x00\x10D\xefT\x01\xc0\xfc\x03qs\xe3\xfe\xff\xfb\\8\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-02-23 10:06:22.359 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (54:ef:44:10:00:71:1d:00, True)
2023-02-23 10:06:22.360 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'254b21a92a2a15af28945a614501935eb97e'
2023-02-23 10:06:22.363 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0019]: finished channel configuration
2023-02-23 10:06:22.367 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'534ba1a92a2a9e397e'
2023-02-23 10:06:22.367 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2023-02-23 10:06:22.376 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0500] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False, *is_reply=False), tsn=175, command_id=0, *direction=<Direction.Server_to_Client: 0>, *is_reply=False)
2023-02-23 10:06:22.378 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0500] Sending request: enroll_response(enroll_response_code=<EnrollResponse.Success: 0>, zone_id=0)
2023-02-23 10:06:22.379 DEBUG (MainThread) [zigpy.device] [0x9441] Extending timeout for 0xaf request
2023-02-23 10:06:22.379 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), dst_ep=1, source_route=None, extended_timeout=True, tsn=175, profile_id=260, cluster_id=1280, data=Serialized[b'\x01\xaf\x00\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-02-23 10:06:22.381 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setExtendedTimeout: []
2023-02-23 10:06:22.415 DEBUG (MainThread) [zigpy.appdb] Error handling '_save_attribute' event with (54:ef:44:10:00:71:1d:00, 1, 0, 5, 'lumi.sensor_smoke.acn03') params: FOREIGN KEY constraint failed
2023-02-23 10:06:22.420 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x9441, EmberApsFrame(profileId=0, clusterId=33, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=173), 174, b'\xad\x00\x1dq\x00\x10D\xefT\x01\xc0\xfc\x03qs\xe3\xfe\xff\xfb\\8\x01')
2023-02-23 10:06:22.423 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'364821a9602a15f3cd944a04aa5592499d4e270643d8ca8be0b76399b8916ba62b31dd1efc1c39242e8e518dde4d7e'
2023-02-23 10:06:22.438 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6448a1a9602a15df05fb7e'
2023-02-23 10:06:22.439 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2023-02-23 10:06:22.458 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 109]
2023-02-23 10:06:22.467 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (54:ef:44:10:00:71:1d:00, True)
2023-02-23 10:06:22.469 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'474921a92a2a15af28945a6145019352bf7e'
2023-02-23 10:06:22.477 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7549a1a92a2a62537e'
2023-02-23 10:06:22.477 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2023-02-23 10:06:22.479 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setExtendedTimeout: []
2023-02-23 10:06:22.482 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x9441, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=175), 176, b'\x01\xaf\x00\x00\x00')
2023-02-23 10:06:22.491 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'504e21a9602a15f3cd904b25af5493499d4e27045dcb6624fdc66326887e'
2023-02-23 10:06:22.501 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'064ea1a9602a15dc96a37e'
2023-02-23 10:06:22.501 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2023-02-23 10:06:22.508 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 110]
2023-02-23 10:06:23.470 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'164eb1a96b2a15f3cd944a04aa5592499d4e27c643ce67b4ac7e'
2023-02-23 10:06:23.471 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2023-02-23 10:06:23.475 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=0, clusterId=33, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=109), 174, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 10:06:23.475 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=0, clusterId=33, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=109), 174, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 10:06:23.485 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'264eb1a9112a15b259b5ca25aa1593499c5fe767ac5a9874ff6b638b126a7e'
2023-02-23 10:06:23.485 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2023-02-23 10:06:23.488 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32801, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=17), 192, -52, 0x9441, 255, 255, b'\xad\x00']
2023-02-23 10:06:23.490 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32801, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=17), 192, -52, 0x9441, 255, 255, b'\xad\x00']
2023-02-23 10:06:23.491 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=17, profile_id=0, cluster_id=32801, data=Serialized[b'\xad\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-52)
2023-02-23 10:06:23.503 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0xfcc0]: bound 'manufacturer_specific' cluster: Status.SUCCESS
2023-02-23 10:06:23.504 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0xfcc0]: Configuring cluster attribute reporting
2023-02-23 10:06:23.504 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0xfcc0]: finished channel configuration
2023-02-23 10:06:23.513 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: 'async_configure' stage succeeded
2023-02-23 10:06:23.514 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0000]: 'async_configure' stage succeeded
2023-02-23 10:06:23.514 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0003]: 'async_configure' stage succeeded
2023-02-23 10:06:23.515 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: 'async_configure' stage succeeded
2023-02-23 10:06:23.515 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0xfcc0]: 'async_configure' stage succeeded
2023-02-23 10:06:23.515 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0019]: 'async_configure' stage succeeded
2023-02-23 10:06:23.522 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9441](lumi.sensor_smoke.acn03): completed configuration
2023-02-23 10:06:23.524 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False, *is_reply=False), tsn=177, command_id=64, *direction=<Direction.Server_to_Client: 0>, *is_reply=False)
2023-02-23 10:06:23.525 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0003] Sending request: trigger_effect(effect_id=<EffectIdentifier.Okay: 2>, effect_variant=<EffectVariant.Default: 0>)
2023-02-23 10:06:23.526 DEBUG (MainThread) [zigpy.device] [0x9441] Extending timeout for 0xb1 request
2023-02-23 10:06:23.527 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), dst_ep=1, source_route=None, extended_timeout=True, tsn=177, profile_id=260, cluster_id=3, data=Serialized[b'\x01\xb1@\x02\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-02-23 10:06:23.528 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (54:ef:44:10:00:71:1d:00, True)
2023-02-23 10:06:23.530 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'634f21a92a2a15af28945a614501935f7d5e7e'
2023-02-23 10:06:23.539 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'374fa1a92a2a4e867e'
2023-02-23 10:06:23.540 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2023-02-23 10:06:23.544 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setExtendedTimeout: []
2023-02-23 10:06:23.550 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x9441, EmberApsFrame(profileId=260, clusterId=3, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=177), 178, b'\x01\xb1@\x02\x00')
2023-02-23 10:06:23.553 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'744c21a9602a15f3cd904b26aa5493499d4e277d3a5fcb663abdc4636b067e'
2023-02-23 10:06:23.562 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'404ca1a9602a15dd907a7e'
2023-02-23 10:06:23.563 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2023-02-23 10:06:23.565 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 111]
2023-02-23 10:06:23.687 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'504cb1a96b2a15f3cd904b25af5493499d4e27c55dce67fb1a7e'
2023-02-23 10:06:23.687 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2023-02-23 10:06:23.690 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=110), 176, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 10:06:23.691 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=260, clusterId=1280, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=110), 176, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 10:06:24.894 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'604cb1a96b2a15f3cd904b26aa5493499d4e27c45fce673fc57e'
2023-02-23 10:06:24.894 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2023-02-23 10:06:24.896 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=260, clusterId=3, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=111), 178, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 10:06:24.897 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=260, clusterId=3, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=111), 178, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 10:06:24.904 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'704cb1a9112a15b658974a24ab1593499c5ce767ac5a9874f8ded282bc7e3dfbae7e'
2023-02-23 10:06:24.904 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2023-02-23 10:06:24.907 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=3, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=18), 192, -52, 0x9441, 255, 255, b'\x18\xb1\x0b@\x00']
2023-02-23 10:06:24.908 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=3, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=18), 192, -52, 0x9441, 255, 255, b'\x18\xb1\x0b@\x00']
2023-02-23 10:06:24.908 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=18, profile_id=260, cluster_id=3, data=Serialized[b'\x18\xb1\x0b@\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-52)
2023-02-23 10:06:24.909 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0003] Received ZCL frame: b'\x18\xb1\x0b@\x00'
2023-02-23 10:06:24.910 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0003] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=177, command_id=11, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
2023-02-23 10:06:24.911 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0003] Decoded ZCL frame: Identify:Default_Response(command_id=64, status=<Status.SUCCESS: 0>)
2023-02-23 10:06:24.918 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0003]: executed 'trigger_effect' command with args: '()' kwargs: '{'effect_id': <EffectIdentifier.Okay: 2>, 'effect_variant': <EffectVariant.Default: 0>}' result: Default_Response(command_id=64, status=<Status.SUCCESS: 0>)
2023-02-23 10:06:24.919 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9441](lumi.sensor_smoke.acn03): started initialization
2023-02-23 10:06:24.919 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:ZDO](lumi.sensor_smoke.acn03): 'async_initialize' stage succeeded
2023-02-23 10:06:24.927 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: initializing channel: from_cache: False
2023-02-23 10:06:24.928 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: initializing cached channel attributes: ['zone_status', 'zone_type']
2023-02-23 10:06:24.929 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: Reading attributes in chunks: ['zone_status', 'zone_type']
2023-02-23 10:06:24.930 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: initializing uncached channel attributes: ['zone_state'] - from cache[False]
2023-02-23 10:06:24.930 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: Reading attributes in chunks: ['zone_state']
2023-02-23 10:06:24.931 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: finished channel initialization
2023-02-23 10:06:24.932 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0000]: initializing channel: from_cache: False
2023-02-23 10:06:24.932 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0000]: finished channel initialization
2023-02-23 10:06:24.932 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0003]: initializing channel: from_cache: False
2023-02-23 10:06:24.933 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0003]: finished channel initialization
2023-02-23 10:06:24.933 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: initializing channel: from_cache: False
2023-02-23 10:06:24.933 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: initializing uncached channel attributes: ['current_temperature'] - from cache[False]
2023-02-23 10:06:24.934 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: Reading attributes in chunks: ['current_temperature']
2023-02-23 10:06:24.934 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: finished channel initialization
2023-02-23 10:06:24.935 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0xfcc0]: initializing channel: from_cache: False
2023-02-23 10:06:24.935 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0xfcc0]: Performing channel specific initialization: []
2023-02-23 10:06:24.935 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0xfcc0]: finished channel initialization
2023-02-23 10:06:24.936 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0019]: initializing channel: from_cache: False
2023-02-23 10:06:24.936 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0019]: finished channel initialization
2023-02-23 10:06:24.943 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: 'async_initialize' stage succeeded
2023-02-23 10:06:24.944 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0000]: 'async_initialize' stage succeeded
2023-02-23 10:06:24.944 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0003]: 'async_initialize' stage succeeded
2023-02-23 10:06:24.945 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: 'async_initialize' stage succeeded
2023-02-23 10:06:24.945 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0xfcc0]: 'async_initialize' stage succeeded
2023-02-23 10:06:24.945 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0019]: 'async_initialize' stage succeeded
2023-02-23 10:06:24.962 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9441](lumi.sensor_smoke.acn03): power source: Mains
2023-02-23 10:06:24.963 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9441](lumi.sensor_smoke.acn03): completed initialization
2023-02-23 10:06:25.052 DEBUG (MainThread) [zigpy.appdb] Error handling '_unsupported_attribute_added' event with (54:ef:44:10:00:71:1d:00, 1, 2, 0) params: FOREIGN KEY constraint failed
2023-02-23 10:06:26.244 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2023-02-23 10:06:26.246 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'004d21a9a52a3b567e'
2023-02-23 10:06:26.263 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'014da1a9a52a11b22f941221fa559f49904e2eabe4ce2f8be5c66389f07e3fa7efcdda6f8fffc3dbd1d2698c4623a9ec763ba5ea758241984c2613b1e070381c0e07bbe5ca658a459a4d9e4f9ff7c3d9d46a35a25190482435f47e'
2023-02-23 10:06:26.264 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2023-02-23 10:06:26.266 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received readCounters: [[4, 118, 1112, 80, 13, 12, 9, 9, 72, 24, 0, 12, 0, 4, 4, 0, 4, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]]
2023-02-23 10:06:26.270 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_FREE_BUFFERS: 3>,)
2023-02-23 10:06:26.274 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7d315221a9fe2a165d6d7e'
2023-02-23 10:06:26.285 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1252a1a9fe2a15b3c088177e'
2023-02-23 10:06:26.285 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2023-02-23 10:06:26.290 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\x99']
2023-02-23 10:06:26.294 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 153
2023-02-23 10:06:26.294 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 5, MAC_TX_BROADCAST = 2837, MAC_RX_UNICAST = 10190, MAC_TX_UNICAST_SUCCESS = 146, MAC_TX_UNICAST_RETRY = 13, MAC_TX_UNICAST_FAILED = 18, APS_DATA_RX_BROADCAST = 11, APS_DATA_TX_BROADCAST = 11, APS_DATA_RX_UNICAST = 168, APS_DATA_TX_UNICAST_SUCCESS = 66, APS_DATA_TX_UNICAST_RETRY = 0, APS_DATA_TX_UNICAST_FAILED = 18, ROUTE_DISCOVERY_INITIATED = 0, NEIGHBOR_ADDED = 4, NEIGHBOR_REMOVED = 4, NEIGHBOR_STALE = 0, JOIN_INDICATION = 4, CHILD_REMOVED = 4, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 153]
2023-02-23 10:06:36.296 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2023-02-23 10:06:36.299 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'225321a9a52a4eec7e'
2023-02-23 10:06:36.317 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2353a1a9a52a11b22e942921fa559f49904e2eabe4ce2f8be5c66389f07e3fa7efcdda6f8fffc3dbd1d2698c4623a9ec763ba5ea758241984c2613b1e070381c0e07bbe5ca658a459a4d9e4f9ff7c3d9d46a35a2519048247c6c7e'
2023-02-23 10:06:36.317 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2023-02-23 10:06:36.318 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received readCounters: [[4, 119, 1123, 80, 13, 12, 9, 9, 72, 24, 0, 12, 0, 4, 4, 0, 4, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]]
2023-02-23 10:06:36.323 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_FREE_BUFFERS: 3>,)
2023-02-23 10:06:36.324 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'335021a9fe2a16d8387e'
2023-02-23 10:06:36.331 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3450a1a9fe2a15b3c0fac57e'
2023-02-23 10:06:36.331 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2023-02-23 10:06:36.332 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\x99']
2023-02-23 10:06:36.338 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 153
2023-02-23 10:06:36.338 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 5, MAC_TX_BROADCAST = 2838, MAC_RX_UNICAST = 10201, MAC_TX_UNICAST_SUCCESS = 146, MAC_TX_UNICAST_RETRY = 13, MAC_TX_UNICAST_FAILED = 18, APS_DATA_RX_BROADCAST = 11, APS_DATA_TX_BROADCAST = 11, APS_DATA_RX_UNICAST = 168, APS_DATA_TX_UNICAST_SUCCESS = 66, APS_DATA_TX_UNICAST_RETRY = 0, APS_DATA_TX_UNICAST_FAILED = 18, ROUTE_DISCOVERY_INITIATED = 0, NEIGHBOR_ADDED = 4, NEIGHBOR_REMOVED = 4, NEIGHBOR_STALE = 0, JOIN_INDICATION = 4, CHILD_REMOVED = 4, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 153]
2023-02-23 10:06:46.340 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2023-02-23 10:06:46.343 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'445121a9a52ad8967e'
2023-02-23 10:06:46.360 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4551a1a9a52a11b221942521fa559f49904e2eabe4ce2f8be5c66389f07e3fa7efcdda6f8fffc3dbd1d2698c4623a9ec763ba5ea758241984c2613b1e070381c0e07bbe5ca658a459a4d9e4f9ff7c3d9d46a35a251904824198f7e'
2023-02-23 10:06:46.361 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2023-02-23 10:06:46.365 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received readCounters: [[4, 120, 1135, 80, 13, 12, 9, 9, 72, 24, 0, 12, 0, 4, 4, 0, 4, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]]
2023-02-23 10:06:46.368 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_FREE_BUFFERS: 3>,)
2023-02-23 10:06:46.371 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'555621a9fe2a1647e67e'
2023-02-23 10:06:46.378 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5656a1a9fe2a15b3c0444c7e'
2023-02-23 10:06:46.379 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2023-02-23 10:06:46.380 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\x99']
2023-02-23 10:06:46.385 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 153
2023-02-23 10:06:46.385 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 5, MAC_TX_BROADCAST = 2839, MAC_RX_UNICAST = 10213, MAC_TX_UNICAST_SUCCESS = 146, MAC_TX_UNICAST_RETRY = 13, MAC_TX_UNICAST_FAILED = 18, APS_DATA_RX_BROADCAST = 11, APS_DATA_TX_BROADCAST = 11, APS_DATA_RX_UNICAST = 168, APS_DATA_TX_UNICAST_SUCCESS = 66, APS_DATA_TX_UNICAST_RETRY = 0, APS_DATA_TX_UNICAST_FAILED = 18, ROUTE_DISCOVERY_INITIATED = 0, NEIGHBOR_ADDED = 4, NEIGHBOR_REMOVED = 4, NEIGHBOR_STALE = 0, JOIN_INDICATION = 4, CHILD_REMOVED = 4, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 153]
2023-02-23 10:06:53.171 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6656b1a9112a15b65854b624ab5593499c5de767ac5a9874bada3c983d74c8a7aaf3df4e05f3c4f3ccd64824472688ff763d81e075824198440702b0ea51381c0227ba83ea66ed659b25bfe79f57e2d9d4cb15a2f3b048873209187e2f0acfcfddcaac7e'
2023-02-23 10:06:53.171 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2023-02-23 10:06:53.174 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=64704, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=19), 192, -52, 0x9441, 255, 255, b'\x1c_\x11\xc1\n\xf7\x00A>\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\n\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00']
2023-02-23 10:06:53.174 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=64704, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=19), 192, -52, 0x9441, 255, 255, b'\x1c_\x11\xc1\n\xf7\x00A>\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\n\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00']
2023-02-23 10:06:53.175 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=19, profile_id=260, cluster_id=64704, data=Serialized[b'\x1c_\x11\xc1\n\xf7\x00A>\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\n\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-52)
2023-02-23 10:06:53.179 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0xfcc0] Received ZCL frame: b'\x1c_\x11\xc1\n\xf7\x00A>\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\n\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00'
2023-02-23 10:06:53.181 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0xfcc0] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=True, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), manufacturer=4447, tsn=193, command_id=10, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
2023-02-23 10:06:53.183 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0xfcc0] Decoded ZCL frame: XiaomiAqaraE1Cluster:Report_Attributes(attribute_reports=[Attribute(attrid=0x00F7, value=TypeValue(type=LVBytes, value=b'\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\n\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00'))])
2023-02-23 10:06:53.185 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0xfcc0] Received command 0x0A (TSN 193): Report_Attributes(attribute_reports=[Attribute(attrid=0x00F7, value=TypeValue(type=LVBytes, value=b'\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\n\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00'))])
2023-02-23 10:06:53.187 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0xfcc0] Attribute report received: 0x00F7=b'\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\n\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00'
2023-02-23 10:06:53.188 WARNING (MainThread) [xiaomi] 54:ef:44:10:00:71:1d:00 - Attribute report. attribute_id: [247] value: [{'battery_voltage_mV': 3210, 'temperature': 25, 'X-attrib-4': 424, 'X-attrib-5': 19, 'X-attrib-6': 10, '0xff01-8': 273, 'path': 0, '0xff01-12': 1, '0xff01-102': 3, '0xff01-103': 1, '0xff01-104': 168, 'smoke': 0, '0xff01-161': 0, '0xff01-162': 0, '0xff01-163': 0, '0xff01-164': 0, '0xff01-165': 0}]
2023-02-23 10:06:53.191 ERROR (MainThread) [bellows.ezsp] Exception running handler
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/bellows/ezsp/__init__.py", line 351, in handle_callback
    handler(*args)
  File "/usr/local/lib/python3.10/site-packages/bellows/zigbee/application.py", line 470, in ezsp_callback_handler
    self._handle_frame(*args)
  File "/usr/local/lib/python3.10/site-packages/bellows/zigbee/application.py", line 515, in _handle_frame
    self.packet_received(
  File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 873, in packet_received
    self.handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 379, in handle_message
    return sender.handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 370, in handle_message
    self.endpoints[src_ep].handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/endpoint.py", line 224, in handle_message
    handler(hdr, args, dst_addressing=dst_addressing)
  File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 377, in handle_message
    self.handle_cluster_general_request(hdr, args, dst_addressing=dst_addressing)
  File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 423, in handle_cluster_general_request
    self._update_attribute(attr.attrid, value)
  File "/config/custom_zha_quirks/xiaomi/__init__.py", line 258, in _update_attribute
    self.endpoint.device.battery_bus.listener_event(
AttributeError: 'LumiSensorSmokeAcn03' object has no attribute 'battery_bus'
2023-02-23 10:06:56.170 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7656b1a9112a15b65854b624ab5593499c5ae767ac5a9874bada3c983e74c8a7aaf3df4e05f3c4f3ccd64824472688ff763d81eb75824198440702b0ea51381c0227ba83ea66ed659b25bfe79f57e2d9d4cb15a2f3b048873209187e2f0acfcfdd6bed7e'
2023-02-23 10:06:56.171 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2023-02-23 10:06:56.174 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=64704, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=20), 192, -52, 0x9441, 255, 255, b'\x1c_\x11\xc2\n\xf7\x00A>\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\x01\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00']
2023-02-23 10:06:56.174 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=64704, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=20), 192, -52, 0x9441, 255, 255, b'\x1c_\x11\xc2\n\xf7\x00A>\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\x01\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00']
2023-02-23 10:06:56.175 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=20, profile_id=260, cluster_id=64704, data=Serialized[b'\x1c_\x11\xc2\n\xf7\x00A>\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\x01\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-52)
2023-02-23 10:06:56.178 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0xfcc0] Received ZCL frame: b'\x1c_\x11\xc2\n\xf7\x00A>\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\x01\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00'
2023-02-23 10:06:56.180 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0xfcc0] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=True, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), manufacturer=4447, tsn=194, command_id=10, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
2023-02-23 10:06:56.183 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0xfcc0] Decoded ZCL frame: XiaomiAqaraE1Cluster:Report_Attributes(attribute_reports=[Attribute(attrid=0x00F7, value=TypeValue(type=LVBytes, value=b'\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\x01\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00'))])
2023-02-23 10:06:56.184 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0xfcc0] Received command 0x0A (TSN 194): Report_Attributes(attribute_reports=[Attribute(attrid=0x00F7, value=TypeValue(type=LVBytes, value=b'\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\x01\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00'))])
2023-02-23 10:06:56.185 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0xfcc0] Attribute report received: 0x00F7=b'\x01!\x8a\x0c\x03(\x19\x04!\xa8\x01\x05!\x13\x00\x06$\x01\x00\x00\x00\x00\x08!\x11\x01\n!\x00\x00\x0c \x01f \x03g \x01h!\xa8\x00\xa0!\x00\x00\xa1 \x00\xa2 \x00\xa3 \x00\xa4 \x00\xa5 \x00'
2023-02-23 10:06:56.186 WARNING (MainThread) [xiaomi] 54:ef:44:10:00:71:1d:00 - Attribute report. attribute_id: [247] value: [{'battery_voltage_mV': 3210, 'temperature': 25, 'X-attrib-4': 424, 'X-attrib-5': 19, 'X-attrib-6': 1, '0xff01-8': 273, 'path': 0, '0xff01-12': 1, '0xff01-102': 3, '0xff01-103': 1, '0xff01-104': 168, 'smoke': 0, '0xff01-161': 0, '0xff01-162': 0, '0xff01-163': 0, '0xff01-164': 0, '0xff01-165': 0}]
2023-02-23 10:06:56.189 ERROR (MainThread) [bellows.ezsp] Exception running handler
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/bellows/ezsp/__init__.py", line 351, in handle_callback
    handler(*args)
  File "/usr/local/lib/python3.10/site-packages/bellows/zigbee/application.py", line 470, in ezsp_callback_handler
    self._handle_frame(*args)
  File "/usr/local/lib/python3.10/site-packages/bellows/zigbee/application.py", line 515, in _handle_frame
    self.packet_received(
  File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 873, in packet_received
    self.handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 379, in handle_message
    return sender.handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 370, in handle_message
    self.endpoints[src_ep].handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/endpoint.py", line 224, in handle_message
    handler(hdr, args, dst_addressing=dst_addressing)
  File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 377, in handle_message
    self.handle_cluster_general_request(hdr, args, dst_addressing=dst_addressing)
  File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 423, in handle_cluster_general_request
    self._update_attribute(attr.attrid, value)
  File "/config/custom_zha_quirks/xiaomi/__init__.py", line 258, in _update_attribute
    self.endpoint.device.battery_bus.listener_event(
AttributeError: 'LumiSensorSmokeAcn03' object has no attribute 'battery_bus'
2023-02-23 10:06:56.387 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2023-02-23 10:06:56.390 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'605721a9a52a26ba7e'
2023-02-23 10:06:56.407 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0757a1a9a52a11b221943621fa559f49904e2eabe4ce2d8be5c66389f07e3fa7efcdda6f8fffc3dbd1d2698c4623a9ec763ba5ea758241984c2613b1e070381c0e07bbe5ca658a459a4d9e4f9ff7c3d9d46a35a25190482421f37e'
2023-02-23 10:06:56.408 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2023-02-23 10:06:56.410 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received readCounters: [[4, 120, 1148, 80, 13, 12, 9, 9, 74, 24, 0, 12, 0, 4, 4, 0, 4, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]]
2023-02-23 10:06:56.413 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_FREE_BUFFERS: 3>,)
2023-02-23 10:06:56.416 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'715421a9fe2a1663967e'
2023-02-23 10:06:56.425 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1054a1a9fe2a15b3c0cebb7e'
2023-02-23 10:06:56.425 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2023-02-23 10:06:56.427 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\x99']
2023-02-23 10:06:56.432 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 153
2023-02-23 10:06:56.433 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 5, MAC_TX_BROADCAST = 2839, MAC_RX_UNICAST = 10226, MAC_TX_UNICAST_SUCCESS = 146, MAC_TX_UNICAST_RETRY = 13, MAC_TX_UNICAST_FAILED = 18, APS_DATA_RX_BROADCAST = 11, APS_DATA_TX_BROADCAST = 11, APS_DATA_RX_UNICAST = 170, APS_DATA_TX_UNICAST_SUCCESS = 66, APS_DATA_TX_UNICAST_RETRY = 0, APS_DATA_TX_UNICAST_FAILED = 18, ROUTE_DISCOVERY_INITIATED = 0, NEIGHBOR_ADDED = 4, NEIGHBOR_REMOVED = 4, NEIGHBOR_STALE = 0, JOIN_INDICATION = 4, CHILD_REMOVED = 4, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 153]
2023-02-23 10:06:57.249 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBC5C](lumi.sensor_smoke.acn03): Device seen - marking the device available and resetting counter
2023-02-23 10:06:57.250 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBC5C](lumi.sensor_smoke.acn03): Update device availability -  device available: True - new availability: True - changed: False
2023-02-23 10:07:05.821 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x61A0](lumi.sensor_smoke.acn03): Device seen - marking the device available and resetting counter
2023-02-23 10:07:05.822 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x61A0](lumi.sensor_smoke.acn03): Update device availability -  device available: True - new availability: True - changed: False
2023-02-23 10:07:06.436 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2023-02-23 10:07:06.439 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'025521a9a52ab6617e'
2023-02-23 10:07:06.456 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2155a1a9a52a11b22094cd21fa559f49904e2eabe4ce2d8be5c66389f07e3fa7efcdda6f8fffc3dbd1d2698c4623a9ec763ba5ea758241984c2613b1e070381c0e07bbe5ca658a459a4d9e4f9ff7c3d9d46a35a2519048241fd37e'
2023-02-23 10:07:06.456 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2023-02-23 10:07:06.459 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received readCounters: [[4, 121, 1159, 80, 13, 12, 9, 9, 74, 24, 0, 12, 0, 4, 4, 0, 4, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]]
2023-02-23 10:07:06.461 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_FREE_BUFFERS: 3>,)
2023-02-23 10:07:06.463 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'7d335a21a9fe2a1630cc7e'
2023-02-23 10:07:06.469 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'325aa1a9fe2a15b3c031317e'
2023-02-23 10:07:06.470 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2023-02-23 10:07:06.475 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\x99']
2023-02-23 10:07:06.479 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 153
2023-02-23 10:07:06.479 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 5, MAC_TX_BROADCAST = 2840, MAC_RX_UNICAST = 10237, MAC_TX_UNICAST_SUCCESS = 146, MAC_TX_UNICAST_RETRY = 13, MAC_TX_UNICAST_FAILED = 18, APS_DATA_RX_BROADCAST = 11, APS_DATA_TX_BROADCAST = 11, APS_DATA_RX_UNICAST = 170, APS_DATA_TX_UNICAST_SUCCESS = 66, APS_DATA_TX_UNICAST_RETRY = 0, APS_DATA_TX_UNICAST_FAILED = 18, ROUTE_DISCOVERY_INITIATED = 0, NEIGHBOR_ADDED = 4, NEIGHBOR_REMOVED = 4, NEIGHBOR_STALE = 0, JOIN_INDICATION = 4, CHILD_REMOVED = 4, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 153]
2023-02-23 10:07:16.481 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2023-02-23 10:07:16.484 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'245b21a9a52ac1207e'
2023-02-23 10:07:16.502 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'435ba1a9a52a11b22094de21fa559f49904e2eabe4ce2d8be5c66389f07e3fa7efcdda6f8fffc3dbd1d2698c4623a9ec763ba5ea758241984c2613b1e070381c0e07bbe5ca658a459a4d9e4f9ff7c3d9d46a35a2519048242f277e'
2023-02-23 10:07:16.502 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2023-02-23 10:07:16.504 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received readCounters: [[4, 121, 1172, 80, 13, 12, 9, 9, 74, 24, 0, 12, 0, 4, 4, 0, 4, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]]
2023-02-23 10:07:16.505 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_FREE_BUFFERS: 3>,)
2023-02-23 10:07:16.507 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'355821a9fe2a16745f7e'
2023-02-23 10:07:16.513 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5458a1a9fe2a15b3c01c3a7e'
2023-02-23 10:07:16.513 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2023-02-23 10:07:16.516 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\x99']
2023-02-23 10:07:16.517 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 153
2023-02-23 10:07:16.517 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 5, MAC_TX_BROADCAST = 2840, MAC_RX_UNICAST = 10250, MAC_TX_UNICAST_SUCCESS = 146, MAC_TX_UNICAST_RETRY = 13, MAC_TX_UNICAST_FAILED = 18, APS_DATA_RX_BROADCAST = 11, APS_DATA_TX_BROADCAST = 11, APS_DATA_RX_UNICAST = 170, APS_DATA_TX_UNICAST_SUCCESS = 66, APS_DATA_TX_UNICAST_RETRY = 0, APS_DATA_TX_UNICAST_FAILED = 18, ROUTE_DISCOVERY_INITIATED = 0, NEIGHBOR_ADDED = 4, NEIGHBOR_REMOVED = 4, NEIGHBOR_STALE = 0, JOIN_INDICATION = 4, CHILD_REMOVED = 4, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 153]
2023-02-23 10:07:23.318 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9441](lumi.sensor_smoke.acn03): Device seen - marking the device available and resetting counter
2023-02-23 10:07:23.319 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9441](lumi.sensor_smoke.acn03): Update device availability -  device available: True - new availability: True - changed: False
2023-02-23 10:07:26.520 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2023-02-23 10:07:26.523 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'465921a9a52a51fb7e'
2023-02-23 10:07:26.540 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6559a1a9a52a11b22394d521fa559f49904e2eabe4ce2d8be5c66389f07e3fa7efcdda6f8fffc3dbd1d2698c4623a9ec763ba5ea758241984c2613b1e070381c0e07bbe5ca658a459a4d9e4f9ff7c3d9d46a35a251904824d11d7e'
2023-02-23 10:07:26.540 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2023-02-23 10:07:26.543 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received readCounters: [[4, 122, 1183, 80, 13, 12, 9, 9, 74, 24, 0, 12, 0, 4, 4, 0, 4, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]]
2023-02-23 10:07:26.546 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_FREE_BUFFERS: 3>,)
2023-02-23 10:07:26.549 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'575e21a9fe2a162a477e'
2023-02-23 10:07:26.555 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'765ea1a9fe2a15b3c0fd6a7e'
2023-02-23 10:07:26.556 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2023-02-23 10:07:26.558 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\x99']
2023-02-23 10:07:26.561 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 153
2023-02-23 10:07:26.561 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 5, MAC_TX_BROADCAST = 2841, MAC_RX_UNICAST = 10261, MAC_TX_UNICAST_SUCCESS = 146, MAC_TX_UNICAST_RETRY = 13, MAC_TX_UNICAST_FAILED = 18, APS_DATA_RX_BROADCAST = 11, APS_DATA_TX_BROADCAST = 11, APS_DATA_RX_UNICAST = 170, APS_DATA_TX_UNICAST_SUCCESS = 66, APS_DATA_TX_UNICAST_RETRY = 0, APS_DATA_TX_UNICAST_FAILED = 18, ROUTE_DISCOVERY_INITIATED = 0, NEIGHBOR_ADDED = 4, NEIGHBOR_REMOVED = 4, NEIGHBOR_STALE = 0, JOIN_INDICATION = 4, CHILD_REMOVED = 4, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 153]
```

I also triggered the smoke alarm with the logs open. I didn't see a log pop up when the alarm was triggered -- or at least it popped up kinda late. There were some attributes logged:

Logs
```
2023-02-23 10:13:13.689 DEBUG (MainThread) [bellows.ezsp.protocol] Send command permitJoining: (254,)
2023-02-23 10:13:13.694 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'762421a9762aeb93077e'
2023-02-23 10:13:13.701 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6024a1a9762a1529587e'
2023-02-23 10:13:13.701 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2023-02-23 10:13:13.705 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received permitJoining: [<EmberStatus.SUCCESS: 0>]
2023-02-23 10:15:18.916 ERROR (MainThread) [custom_components.ultimaker.sensor]  Timeout error occurred while polling ultimaker printer using url http://<IP_ADDRESS>/api/v1/printer
2023-02-23 10:15:18.920 ERROR (MainThread) [custom_components.ultimaker.sensor] Cannot parse data received from Ultimaker printer local variable 'response' referenced before assignment
2023-02-23 10:15:30.571 WARNING (MainThread) [xiaomi] 54:ef:44:10:00:71:1d:00 - Attribute report. attribute_id: [247] value: [{'battery_voltage_mV': 3214, 'temperature': 25, 'X-attrib-4': 5032, 'X-attrib-5': 19, 'X-attrib-6': 6, '0xff01-8': 273, 'path': 0, '0xff01-12': 1, '0xff01-102': 3, '0xff01-103': 1, '0xff01-104': 168, 'smoke': 1, '0xff01-161': 4, '0xff01-162': 0, '0xff01-163': 1, '0xff01-164': 0, '0xff01-165': 0}]
2023-02-23 10:15:30.575 ERROR (MainThread) [bellows.ezsp] Exception running handler
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/bellows/ezsp/__init__.py", line 351, in handle_callback
    handler(*args)
  File "/usr/local/lib/python3.10/site-packages/bellows/zigbee/application.py", line 470, in ezsp_callback_handler
    self._handle_frame(*args)
  File "/usr/local/lib/python3.10/site-packages/bellows/zigbee/application.py", line 515, in _handle_frame
    self.packet_received(
  File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 873, in packet_received
    self.handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 379, in handle_message
    return sender.handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 370, in handle_message
    self.endpoints[src_ep].handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/endpoint.py", line 224, in handle_message
    handler(hdr, args, dst_addressing=dst_addressing)
  File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 377, in handle_message
    self.handle_cluster_general_request(hdr, args, dst_addressing=dst_addressing)
  File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 423, in handle_cluster_general_request
    self._update_attribute(attr.attrid, value)
  File "/config/custom_zha_quirks/xiaomi/__init__.py", line 258, in _update_attribute
    self.endpoint.device.battery_bus.listener_event(
AttributeError: 'LumiSensorSmokeAcn03' object has no attribute 'battery_bus'
2023-02-23 10:15:54.961 WARNING (MainThread) [xiaomi] 54:ef:44:10:00:71:1d:00 - Attribute report. attribute_id: [247] value: [{'battery_voltage_mV': 3214, 'temperature': 25, 'X-attrib-4': 5032, 'X-attrib-5': 19, 'X-attrib-6': 4, '0xff01-8': 273, 'path': 0, '0xff01-12': 1, '0xff01-102': 3, '0xff01-103': 1, '0xff01-104': 168, 'smoke': 1, '0xff01-161': 1, '0xff01-162': 0, '0xff01-163': 1, '0xff01-164': 0, '0xff01-165': 0}]
2023-02-23 10:15:54.965 ERROR (MainThread) [bellows.ezsp] Exception running handler
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/bellows/ezsp/__init__.py", line 351, in handle_callback
    handler(*args)
  File "/usr/local/lib/python3.10/site-packages/bellows/zigbee/application.py", line 470, in ezsp_callback_handler
    self._handle_frame(*args)
  File "/usr/local/lib/python3.10/site-packages/bellows/zigbee/application.py", line 515, in _handle_frame
    self.packet_received(
  File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 873, in packet_received
    self.handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 379, in handle_message
    return sender.handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 370, in handle_message
    self.endpoints[src_ep].handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/endpoint.py", line 224, in handle_message
    handler(hdr, args, dst_addressing=dst_addressing)
  File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 377, in handle_message
    self.handle_cluster_general_request(hdr, args, dst_addressing=dst_addressing)
  File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 423, in handle_cluster_general_request
    self._update_attribute(attr.attrid, value)
  File "/config/custom_zha_quirks/xiaomi/__init__.py", line 258, in _update_attribute
    self.endpoint.device.battery_bus.listener_event(
AttributeError: 'LumiSensorSmokeAcn03' object has no attribute 'battery_bus'
```

Then after resetting the device I did see 'smoke': 0:
2023-02-23 10:16:44.266 WARNING (MainThread) [xiaomi] 54:ef:44:10:00:71:1d:00 - Attribute report. attribute_id: [247] value: [{'battery_voltage_mV': 3195, 'temperature': 25, 'X-attrib-4': 5032, 'X-attrib-5': 20, 'X-attrib-6': 1, '0xff01-8': 273, 'path': 0, '0xff01-12': 1, '0xff01-102': 3, '0xff01-103': 1, '0xff01-104': 168, 'smoke': 0, '0xff01-161': 0, '0xff01-162': 0, '0xff01-163': 0, '0xff01-164': 0, '0xff01-165': 0}]

So I guess that's the thing that needs to be hooked up to a HA entity.

Hmm, I pushed another commit to add the battery_bus for now.
I'd have expected to have 'smoke': 1 when there's smoke, but that doesn't look like it's the case?

That fixes the battery_bus error! No change in smoke behavior though. But strangely even when I trigger the smoke alarm I'm not getting any logs.
I'm literally right next to my Home Assistant Yellow making smoke in the server closet so it shouldn't be a signal strength thing :) Home assistant shows it last heard from the device the same minute I made smoke (~10:45a), but yet I'm not seeing updates in the logs from that time.

Logs
```
2023-02-23 10:31:44.668 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\x99']
2023-02-23 10:31:44.672 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 153
2023-02-23 10:31:44.673 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 2, MAC_TX_BROADCAST = 28, MAC_RX_UNICAST = 257, MAC_TX_UNICAST_SUCCESS = 33, MAC_TX_UNICAST_RETRY = 8, MAC_TX_UNICAST_FAILED = 0, APS_DATA_RX_BROADCAST = 7, APS_DATA_TX_BROADCAST = 7, APS_DATA_RX_UNICAST = 24, APS_DATA_TX_UNICAST_SUCCESS = 11, APS_DATA_TX_UNICAST_RETRY = 0, APS_DATA_TX_UNICAST_FAILED = 0, ROUTE_DISCOVERY_INITIATED = 0, NEIGHBOR_ADDED = 2, NEIGHBOR_REMOVED = 2, NEIGHBOR_STALE = 0, JOIN_INDICATION = 2, CHILD_REMOVED = 2, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 153]
2023-02-23 10:31:52.469 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBC5C](lumi.sensor_smoke.acn03): Device seen - marking the device available and resetting counter
2023-02-23 10:31:52.470 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBC5C](lumi.sensor_smoke.acn03): Update device availability -  device available: True - new availability: True - changed: False
```

Edit edit: Nevermind the logging is in init.py which I didn't change. Strange I'm not seeing any Attribute report. attribute_id when I trigger the alarm

Did you change the import in the smoke.py file again?

Good catch I did not. I need to probably pull these files into git so i'm not forgetting manual changes.

Also. This should be enough to enable debug logging for quirks in general right?
logger:
  default: info
  logs:
    zhaquirks: debug
    custom_zha_quirks: debug

zhaquirks: debug will put all official quirks into debug logger mode, yes.
For the custom quirks, it depends on the folder structure. Looking at your logs, it looks like the logger is called xiaomi:

WARNING (MainThread) [xiaomi]

So xiaomi: debug would change that logger to debug. I guess you have xiaomi -> smoke folder -> both files?
(The import in smoke.py still needs to be changed to use the custom quirk __init__.py file as long as it's a custom quirk).

I have both files in a dir named xiaomi
config/custom_zha_quirks/
∟xiaomi/
  ∟__init__.py
  ∟smoke.py

So I would do this?
logger:
  default: info
  logs:
    zhaquirks: debug
    custom_zha_quirks: debug
    xiaomi: debug

Ok changers are made and I've restarted HA and re-paired the detector. Here are the logs from pairing:

Logs during discovery
```
2023-02-23 11:20:20.296 INFO (SyncWorker_1) [homeassistant.loader] Loaded iqvia from homeassistant.components.iqvia
2023-02-23 11:20:20.298 INFO (SyncWorker_1) [homeassistant.loader] Loaded hisense_aehw4a1 from homeassistant.components.hisense_aehw4a1
2023-02-23 11:20:20.299 INFO (SyncWorker_1) [homeassistant.loader] Loaded solaredge from homeassistant.components.solaredge
2023-02-23 11:20:20.300 INFO (SyncWorker_1) [homeassistant.loader] Loaded mikrotik from homeassistant.components.mikrotik
2023-02-23 11:20:20.302 INFO (SyncWorker_1) [homeassistant.loader] Loaded samsungtv from homeassistant.components.samsungtv
2023-02-23 11:20:44.372 INFO (MainThread) [homeassistant.components.zha.api] Removing node 54:ef:44:10:00:71:1d:00
2023-02-23 11:20:44.375 INFO (MainThread) [zigpy.application] Removing device 0x9441 (54:ef:44:10:00:71:1d:00)
2023-02-23 11:24:47.807 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=11, profile_id=0, cluster_id=<ZDOCmd.Mgmt_Permit_Joining_req: 0x0036>, data=Serialized[b'\x0b\xfe\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-02-23 11:24:47.810 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendBroadcast: (0xfffc, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=11), 0, 12, b'\x0b\xfe\x00')
2023-02-23 11:24:47.813 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'229321a9622ae94d59947c25aa5592489c4e2cabe1cd6c75fd93747e'
2023-02-23 11:24:47.817 DEBUG (MainThread) [bellows.ezsp.protocol] Send command addTransientLinkKey: (ff:ff:ff:ff:ff:ff:ff:ff, [90, 105, 103, 66, 101, 101, 65, 108, 108, 105, 97, 110, 99, 101, 48, 57])
2023-02-23 11:24:47.825 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2393a1a9622a15f446137e'
2023-02-23 11:24:47.825 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2023-02-23 11:24:47.828 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'339021a9fb2aea4da66bb5da55aac820fb0c42ceaca20be29ca800eccc473b4c7e'
2023-02-23 11:24:47.830 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendBroadcast: [<EmberStatus.SUCCESS: 0>, 70]
2023-02-23 11:24:47.831 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3393b5a94d2a89d29d7e'
2023-02-23 11:24:47.832 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2023-02-23 11:24:47.834 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4393b1a9112a10b259a24a25aa5593499c08d8abedce9874fecd9d896ae97e'
2023-02-23 11:24:47.834 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2023-02-23 11:24:47.839 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received stackStatusHandler: [<EmberStatus.NETWORK_OPENED: 156>]
2023-02-23 11:24:47.840 DEBUG (MainThread) [bellows.zigbee.application] Received stackStatusHandler frame with [<EmberStatus.NETWORK_OPENED: 156>]
2023-02-23 11:24:47.841 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_BROADCAST_LOOPBACK: 5>, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=70), 255, 0, 0x0000, 255, 255, b'\x0b\xfe\x00']
2023-02-23 11:24:47.841 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST_LOOPBACK: 5>, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=70), 255, 0, 0x0000, 255, 255, b'\x0b\xfe\x00']
2023-02-23 11:24:47.842 DEBUG (MainThread) [bellows.zigbee.application] Ignoring message type: <EmberIncomingMessageType.INCOMING_BROADCAST_LOOPBACK: 5>
2023-02-23 11:24:47.847 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'5490a1a9fb2a1535157e'
2023-02-23 11:24:47.848 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2023-02-23 11:24:47.850 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received addTransientLinkKey: [<EmberStatus.SUCCESS: 0>]
2023-02-23 11:24:47.855 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setPolicy: (<EzspPolicyId.TRUST_CENTER_POLICY: 0>, <EzspDecisionBitmask.ALLOW_UNSECURED_REJOINS|ALLOW_JOINS: 3>)
2023-02-23 11:24:47.859 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'469121a9012a15b1595e5f7e'
2023-02-23 11:24:47.867 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'6591a1a9012a15b5ca7e'
2023-02-23 11:24:47.867 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2023-02-23 11:24:47.869 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setPolicy: [<EzspStatus.SUCCESS: 0>]
2023-02-23 11:24:48.453 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2023-02-23 11:24:48.456 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'579621a9a52a589e7e'
2023-02-23 11:24:48.474 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7696a1a9a52a15b268942c25ab5592499c4e24abefce618bfec66389fc7e3fa7eacdde6f8bffc7dbd4d2698c4623a9ec763ba5ea758241984c2613b1e070381c0e07bbe5ca658a459a4d9e4f9ff7c3d9d46a35a25190482476e37e'
2023-02-23 11:24:48.474 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2023-02-23 11:24:48.480 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received readCounters: [[0, 49, 102, 1, 0, 0, 3, 2, 6, 3, 0, 0, 0, 1, 0, 4, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]]
2023-02-23 11:24:48.485 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_FREE_BUFFERS: 3>,)
2023-02-23 11:24:48.488 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'609721a9fe2a169c5c7e'
2023-02-23 11:24:48.494 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0797a1a9fe2a15b3cf1e257e'
2023-02-23 11:24:48.495 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2023-02-23 11:24:48.505 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\x96']
2023-02-23 11:24:48.511 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 150
2023-02-23 11:24:48.511 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 0, MAC_TX_BROADCAST = 49, MAC_RX_UNICAST = 102, MAC_TX_UNICAST_SUCCESS = 1, MAC_TX_UNICAST_RETRY = 0, MAC_TX_UNICAST_FAILED = 0, APS_DATA_RX_BROADCAST = 3, APS_DATA_TX_BROADCAST = 2, APS_DATA_RX_UNICAST = 6, APS_DATA_TX_UNICAST_SUCCESS = 3, APS_DATA_TX_UNICAST_RETRY = 0, APS_DATA_TX_UNICAST_FAILED = 0, ROUTE_DISCOVERY_INITIATED = 0, NEIGHBOR_ADDED = 1, NEIGHBOR_REMOVED = 0, NEIGHBOR_STALE = 4, JOIN_INDICATION = 0, CHILD_REMOVED = 1, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 150]
2023-02-23 11:24:48.828 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1797b1a96b2a134ea6944a13aa5592499d4e27ede1ce67b0ce7e'
2023-02-23 11:24:48.828 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2023-02-23 11:24:48.831 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65532, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=70), 12, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:48.831 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65532, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=70), 12, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:48.833 DEBUG (MainThread) [bellows.ezsp.protocol] Send command permitJoining: (254,)
2023-02-23 11:24:48.836 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'729421a9762aeba96d7e'
2023-02-23 11:24:48.842 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2094a1a9762a150f187e'
2023-02-23 11:24:48.844 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2023-02-23 11:24:48.850 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received permitJoining: [<EmberStatus.SUCCESS: 0>]
2023-02-23 11:24:55.033 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'3094b1a9702a542659893b25ba117d1d9d4e27ab286e7e'
2023-02-23 11:24:55.034 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2023-02-23 11:24:55.038 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received trustCenterJoinHandler: [0x9441, 54:ef:44:10:00:71:1d:00, <EmberDeviceUpdate.STANDARD_SECURITY_UNSECURED_JOIN: 1>, <EmberJoinDecision.USE_PRECONFIGURED_KEY: 0>, 0x0000]
2023-02-23 11:24:55.039 DEBUG (MainThread) [bellows.zigbee.application] Received trustCenterJoinHandler frame with [0x9441, 54:ef:44:10:00:71:1d:00, <EmberDeviceUpdate.STANDARD_SECURITY_UNSECURED_JOIN: 1>, <EmberJoinDecision.USE_PRECONFIGURED_KEY: 0>, 0x0000]
2023-02-23 11:24:55.040 INFO (MainThread) [zigpy.application] New device 0x9441 (54:ef:44:10:00:71:1d:00) joined the network
2023-02-23 11:24:55.044 DEBUG (MainThread) [zigpy.device] [0x9441] Scheduling initialization
2023-02-23 11:24:55.049 DEBUG (MainThread) [bellows.ezsp.protocol] Send command findKeyTableEntry: (54:ef:44:10:00:71:1d:00, True)
2023-02-23 11:24:55.053 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'049521a9212a15af28945a61450193ed1f7e'
2023-02-23 11:24:55.054 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setManufacturerCode: (4447,)
2023-02-23 11:24:55.055 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2023-02-23 11:24:55.056 INFO (MainThread) [zigpy.device] [0x9441] Requesting 'Node Descriptor'
2023-02-23 11:24:55.056 DEBUG (MainThread) [zigpy.util] Tries remaining: 2
2023-02-23 11:24:55.056 DEBUG (MainThread) [zigpy.device] [0x9441] Extending timeout for 0x0d request
2023-02-23 11:24:55.057 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), dst_ep=0, source_route=None, extended_timeout=True, tsn=13, profile_id=0, cluster_id=<ZDOCmd.Node_Desc_req: 0x0002>, data=Serialized[b'\rA\x94'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-02-23 11:24:55.058 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (54:ef:44:10:00:71:1d:00, True)
2023-02-23 11:24:55.060 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'4195a1a9212aea846d7e'
2023-02-23 11:24:55.061 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2023-02-23 11:24:55.063 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'159a21a9412a4aa3e7e97e'
2023-02-23 11:24:55.067 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received findKeyTableEntry: [255]
2023-02-23 11:24:55.069 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'529aa1a9412a91fa7e'
2023-02-23 11:24:55.069 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2023-02-23 11:24:55.070 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'269b21a92a2a15af28945a6145019307aa7e'
2023-02-23 11:24:55.077 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'639ba1a92a2a86577e'
2023-02-23 11:24:55.077 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2023-02-23 11:24:55.087 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setManufacturerCode: []
2023-02-23 11:24:55.087 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setExtendedTimeout: []
2023-02-23 11:24:55.103 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x9441, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=13), 14, b'\rA\x94')
2023-02-23 11:24:55.105 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'379821a9602a15f3cd944a27aa5592499d4e27a6e3cd6aca69af5a7e'
2023-02-23 11:24:55.115 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'7498a1a9602a15fa0de67e'
2023-02-23 11:24:55.115 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2023-02-23 11:24:55.117 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 72]
2023-02-23 11:24:55.302 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'0498b1a9112a11b259874a25aa5593499c48eb64ac5a9874f115221dfc634ea7fb89313b0b53307e'
2023-02-23 11:24:55.302 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2023-02-23 11:24:55.304 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=19, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=6), 204, -49, 0x9441, 255, 255, b'\xd3A\x94\x00\x1dq\x00\x10D\xefT\x84']
2023-02-23 11:24:55.305 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=19, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=6), 204, -49, 0x9441, 255, 255, b'\xd3A\x94\x00\x1dq\x00\x10D\xefT\x84']
2023-02-23 11:24:55.306 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=6, profile_id=0, cluster_id=19, data=Serialized[b'\xd3A\x94\x00\x1dq\x00\x10D\xefT\x84'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=204, rssi=-49)
2023-02-23 11:24:55.307 INFO (MainThread) [zigpy.application] Device 0x9441 (54:ef:44:10:00:71:1d:00) joined the network
2023-02-23 11:24:55.308 DEBUG (MainThread) [zigpy.device] [0x9441] Scheduling initialization
2023-02-23 11:24:55.308 DEBUG (MainThread) [zigpy.device] [0x9441] Canceling old initialize call
2023-02-23 11:24:55.311 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=False> from ep 0 to ep 0, cluster 19: b'\xd3A\x94\x00\x1dq\x00\x10D\xefT\x84'
2023-02-23 11:24:55.312 DEBUG (MainThread) [zigpy.zdo] [0x9441:zdo] ZDO request ZDOCmd.Device_annce: [0x9441, 54:ef:44:10:00:71:1d:00, 132]
2023-02-23 11:24:55.314 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2023-02-23 11:24:55.314 INFO (MainThread) [zigpy.device] [0x9441] Requesting 'Node Descriptor'
2023-02-23 11:24:55.315 DEBUG (MainThread) [zigpy.util] Tries remaining: 2
2023-02-23 11:24:55.315 DEBUG (MainThread) [zigpy.device] [0x9441] Extending timeout for 0x0f request
2023-02-23 11:24:55.316 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), dst_ep=0, source_route=None, extended_timeout=True, tsn=15, profile_id=0, cluster_id=<ZDOCmd.Node_Desc_req: 0x0002>, data=Serialized[b'\x0fA\x94'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-02-23 11:24:55.317 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (54:ef:44:10:00:71:1d:00, True)
2023-02-23 11:24:55.318 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'1498b1a9772a14b318004a38db55820d731a23fe247e'
2023-02-23 11:24:55.318 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2023-02-23 11:24:55.322 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received childJoinHandler: [1, <Bool.true: 1>, 0x9441, 54:ef:44:10:00:71:1d:00, <EmberNodeType.SLEEPY_END_DEVICE: 4>]
2023-02-23 11:24:55.323 DEBUG (MainThread) [bellows.zigbee.application] Received childJoinHandler frame with [1, <Bool.true: 1>, 0x9441, 54:ef:44:10:00:71:1d:00, <EmberNodeType.SLEEPY_END_DEVICE: 4>]
2023-02-23 11:24:55.323 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'429921a92a2a15af28945a61450193ddc77e'
2023-02-23 11:24:55.331 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'2599a1a92a2a25257e'
2023-02-23 11:24:55.331 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2023-02-23 11:24:55.335 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setExtendedTimeout: []
2023-02-23 11:24:55.343 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x9441, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=15), 16, b'\x0fA\x94')
2023-02-23 11:24:55.348 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'539e21a9602a15f3cd944a27aa5592499d4e27a4fdcd68ca696deb7e'
2023-02-23 11:24:55.358 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'369ea1a9602a15fbc5947e'
2023-02-23 11:24:55.358 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2023-02-23 11:24:55.359 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 73]
2023-02-23 11:24:55.590 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'469eb1a9112a15b259964a25aa1593499c49f77bac5a9874fe126389feafaa7e'
2023-02-23 11:24:55.591 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2023-02-23 11:24:55.601 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=7), 208, -48, 0x9441, 255, 255, b'\xd4\x00\x00']
2023-02-23 11:24:55.602 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=7), 208, -48, 0x9441, 255, 255, b'\xd4\x00\x00']
2023-02-23 11:24:55.603 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=7, profile_id=0, cluster_id=2, data=Serialized[b'\xd4\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=208, rssi=-48)
2023-02-23 11:24:55.605 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=False> from ep 0 to ep 0, cluster 2: b'\xd4\x00\x00'
2023-02-23 11:24:55.605 DEBUG (MainThread) [zigpy.zdo] [0x9441:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000]
2023-02-23 11:24:55.606 DEBUG (MainThread) [zigpy.zdo] [0x9441:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000])
2023-02-23 11:24:55.792 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'569eb5a96b2a15f3cd944a27aa5592499d4e27e2fdce67b3387e'
2023-02-23 11:24:55.793 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2023-02-23 11:24:55.796 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=73), 16, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:55.798 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=73), 16, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:55.802 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'669eb5a96b2a134fa6944a36aa5592499d4e27ad12ce670cfc7e'
2023-02-23 11:24:55.802 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2023-02-23 11:24:55.804 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65533, EmberApsFrame(profileId=0, clusterId=19, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=6), 255, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:55.804 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65533, EmberApsFrame(profileId=0, clusterId=19, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=6), 255, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:55.805 DEBUG (MainThread) [bellows.zigbee.application] Unexpected message send notification tag: 255
2023-02-23 11:24:55.812 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'769eb1a9112a15b25996ca25aa1593499c46e366ac5a9874ecc963c8687c7f23b4dca10b8fffebbfd5d26b186e7e'
2023-02-23 11:24:55.812 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2023-02-23 11:24:55.815 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32770, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=8), 196, -51, 0x9441, 255, 255, b'\x0f\x00A\x94\x02@\x84_\x11\x7fd\x00\x00,d\x00\x00']
2023-02-23 11:24:55.816 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32770, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=8), 196, -51, 0x9441, 255, 255, b'\x0f\x00A\x94\x02@\x84_\x11\x7fd\x00\x00,d\x00\x00']
2023-02-23 11:24:55.816 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=8, profile_id=0, cluster_id=32770, data=Serialized[b'\x0f\x00A\x94\x02@\x84_\x11\x7fd\x00\x00,d\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-51)
2023-02-23 11:24:55.818 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=False> from ep 0 to ep 0, cluster 32770: b'\x0f\x00A\x94\x02@\x84_\x11\x7fd\x00\x00,d\x00\x00'
2023-02-23 11:24:55.833 INFO (MainThread) [zigpy.device] [0x9441] Got Node Descriptor: NodeDescriptor(logical_type=<LogicalType.EndDevice: 2>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.AllocateAddress|MainsPowered: 132>, manufacturer_code=4447, maximum_buffer_size=127, maximum_incoming_transfer_size=100, server_mask=11264, maximum_outgoing_transfer_size=100, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=False, *is_coordinator=False, *is_end_device=True, *is_full_function_device=False, *is_mains_powered=True, *is_receiver_on_when_idle=False, *is_router=False, *is_security_capable=False)
2023-02-23 11:24:55.835 INFO (MainThread) [zigpy.device] [0x9441] Discovering endpoints
2023-02-23 11:24:55.836 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2023-02-23 11:24:55.837 DEBUG (MainThread) [zigpy.device] [0x9441] Extending timeout for 0x11 request
2023-02-23 11:24:55.837 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), dst_ep=0, source_route=None, extended_timeout=True, tsn=17, profile_id=0, cluster_id=<ZDOCmd.Active_EP_req: 0x0005>, data=Serialized[b'\x11A\x94'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-02-23 11:24:55.839 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (54:ef:44:10:00:71:1d:00, True)
2023-02-23 11:24:55.844 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'609f21a92a2a15af28945a61450193066d7e'
2023-02-23 11:24:55.846 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'069eb1a9cf2a15af28945a6145019421827e'
2023-02-23 11:24:55.846 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2023-02-23 11:24:55.859 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'179fa1a92a2a4c6c7e'
2023-02-23 11:24:55.859 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2023-02-23 11:24:55.860 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received zigbeeKeyEstablishmentHandler: [54:ef:44:10:00:71:1d:00, <EmberKeyStatus.TC_RESPONDED_TO_KEY_REQUEST: 6>]
2023-02-23 11:24:55.861 DEBUG (MainThread) [bellows.zigbee.application] Received zigbeeKeyEstablishmentHandler frame with [54:ef:44:10:00:71:1d:00, <EmberKeyStatus.TC_RESPONDED_TO_KEY_REQUEST: 6>]
2023-02-23 11:24:55.870 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setExtendedTimeout: []
2023-02-23 11:24:55.881 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x9441, EmberApsFrame(profileId=0, clusterId=5, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=17), 18, b'\x11A\x94')
2023-02-23 11:24:55.884 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'729c21a9602a15f3cd944a20aa5592499d4e27baffcd76ca69877d317e'
2023-02-23 11:24:55.894 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'209ca1a9602a15fe48ad7e'
2023-02-23 11:24:55.894 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2023-02-23 11:24:55.898 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 76]
2023-02-23 11:24:56.115 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'309cb1a9cf2a15af28945a614501a6c4a47e'
2023-02-23 11:24:56.116 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2023-02-23 11:24:56.118 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received zigbeeKeyEstablishmentHandler: [54:ef:44:10:00:71:1d:00, <EmberKeyStatus.TC_REQUESTER_VERIFY_KEY_SUCCESS: 52>]
2023-02-23 11:24:56.118 DEBUG (MainThread) [bellows.zigbee.application] Received zigbeeKeyEstablishmentHandler frame with [54:ef:44:10:00:71:1d:00, <EmberKeyStatus.TC_REQUESTER_VERIFY_KEY_SUCCESS: 52>]
2023-02-23 11:24:56.206 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'409cb1a96b2a15f3cd944a20aa5592499d4e27e7ffce67ab307e'
2023-02-23 11:24:56.206 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2023-02-23 11:24:56.210 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=0, clusterId=5, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=76), 18, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:56.211 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=0, clusterId=5, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=76), 18, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:56.220 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'509cb1a9112a15b25991ca25aa1593499c45f37aac5a9874fbd763c8687f3ea5d3707e'
2023-02-23 11:24:56.221 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2023-02-23 11:24:56.225 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32773, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=11), 212, -47, 0x9441, 255, 255, b'\x11\x00A\x94\x01\x01']
2023-02-23 11:24:56.226 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32773, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=11), 212, -47, 0x9441, 255, 255, b'\x11\x00A\x94\x01\x01']
2023-02-23 11:24:56.226 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=11, profile_id=0, cluster_id=32773, data=Serialized[b'\x11\x00A\x94\x01\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=212, rssi=-47)
2023-02-23 11:24:56.227 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=False> from ep 0 to ep 0, cluster 32773: b'\x11\x00A\x94\x01\x01'
2023-02-23 11:24:56.231 INFO (MainThread) [zigpy.device] [0x9441] Discovered endpoints: [1]
2023-02-23 11:24:56.232 INFO (MainThread) [zigpy.device] [0x9441] Initializing endpoints [<Endpoint id=1 in=[] out=[] status=<Status.NEW: 0>>]
2023-02-23 11:24:56.233 INFO (MainThread) [zigpy.endpoint] [0x9441:1] Discovering endpoint information
2023-02-23 11:24:56.233 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2023-02-23 11:24:56.233 DEBUG (MainThread) [zigpy.device] [0x9441] Extending timeout for 0x13 request
2023-02-23 11:24:56.234 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), dst_ep=0, source_route=None, extended_timeout=True, tsn=19, profile_id=0, cluster_id=<ZDOCmd.Simple_Desc_req: 0x0004>, data=Serialized[b'\x13A\x94\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-02-23 11:24:56.235 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (54:ef:44:10:00:71:1d:00, True)
2023-02-23 11:24:56.241 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'069d21a92a2a15af28945a6145019391d97e'
2023-02-23 11:24:56.247 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'619da1a92a2ac0927e'
2023-02-23 11:24:56.247 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2023-02-23 11:24:56.253 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setExtendedTimeout: []
2023-02-23 11:24:56.259 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x9441, EmberApsFrame(profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=19), 20, b'\x13A\x94\x01')
2023-02-23 11:24:56.262 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'17a221a9602a15f3cd944a21aa5592499d4e27b8f9ca74ca69c742eb7e'
2023-02-23 11:24:56.271 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'72a2a1a9602a15fc47287e'
2023-02-23 11:24:56.271 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2023-02-23 11:24:56.274 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 78]
2023-02-23 11:24:56.316 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'02a2b1a9112a11b259a24a25aa5593499c42f37aac5a9874fe13d788feab4a7e'
2023-02-23 11:24:56.316 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2023-02-23 11:24:56.321 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=12), 212, -47, 0x9441, 255, 255, b'\xd5\xb4\x01']
2023-02-23 11:24:56.322 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=12), 212, -47, 0x9441, 255, 255, b'\xd5\xb4\x01']
2023-02-23 11:24:56.323 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=12, profile_id=0, cluster_id=54, data=Serialized[b'\xd5\xb4\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=212, rssi=-47)
2023-02-23 11:24:56.325 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=False> from ep 0 to ep 0, cluster 54: b'\xd5\xb4\x01'
2023-02-23 11:24:56.326 DEBUG (MainThread) [zigpy.zdo] [0x9441:zdo] ZDO request ZDOCmd.Mgmt_Permit_Joining_req: [180, <Bool.true: 1>]
2023-02-23 11:24:56.715 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'12a2b1a96b2a15f3cd944a27aa5592499c4e27e3e3a86788647e'
2023-02-23 11:24:56.715 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2023-02-23 11:24:56.720 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_NONE: 0>, groupId=0, sequence=72), 14, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2023-02-23 11:24:56.721 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_NONE: 0>, groupId=0, sequence=72), 14, <EmberStatus.DELIVERY_FAILED: 102>, b'']
2023-02-23 11:24:56.722 DEBUG (MainThread) [bellows.zigbee.application] Unexpected message send notification tag: 14
2023-02-23 11:24:56.767 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'22a2b1a96b2a134ea6944a13aa5592499d4e27a712ce67a0157e'
2023-02-23 11:24:56.768 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2023-02-23 11:24:56.770 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65532, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=12), 255, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:56.770 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65532, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=12), 255, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:56.771 DEBUG (MainThread) [bellows.zigbee.application] Unexpected message send notification tag: 255
2023-02-23 11:24:57.644 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'32a2b1a9112a15b658944a24ab5593499c43fb78ac5a9874dfdeda83f97e7db087b8b306a18ca2b5a6bd1bd3354ec6871315c4891bb272994c0602b368497e'
2023-02-23 11:24:57.644 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2023-02-23 11:24:57.650 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=13), 220, -45, 0x9441, 255, 255, b'\x18\xb9\n\x05\x00B\x17lumi.sensor_smoke.acn03\x01\x00 \x11']
2023-02-23 11:24:57.651 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=13), 220, -45, 0x9441, 255, 255, b'\x18\xb9\n\x05\x00B\x17lumi.sensor_smoke.acn03\x01\x00 \x11']
2023-02-23 11:24:57.651 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=13, profile_id=260, cluster_id=0, data=Serialized[b'\x18\xb9\n\x05\x00B\x17lumi.sensor_smoke.acn03\x01\x00 \x11'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=220, rssi=-45)
2023-02-23 11:24:57.652 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=False> from ep 1 to ep 1, cluster 0: b'\x18\xb9\n\x05\x00B\x17lumi.sensor_smoke.acn03\x01\x00 \x11'
2023-02-23 11:24:57.653 DEBUG (MainThread) [zigpy.device] Ignoring message (b'18b90a050042176c756d692e73656e736f725f736d6f6b652e61636e303301002011') on cluster 0: unknown endpoint or cluster id: 'No cluster ID 0x0000 on (54:ef:44:10:00:71:1d:00, 1)'
2023-02-23 11:24:57.656 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'42a2b1a96b2a15f3cd944a21aa5592499d4e27e5f9ce67c8227e'
2023-02-23 11:24:57.656 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2023-02-23 11:24:57.669 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'52a2b1a9112a15b25990ca25aa1593499c40cf7dac5a9874ead563c8686c3ea3eacfda6e8bffc7dbd0d1698d4622b0ec7419387e'
2023-02-23 11:24:57.669 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2023-02-23 11:24:57.678 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=78), 20, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:57.678 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=78), 20, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:57.679 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32772, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=14), 232, -42, 0x9441, 255, 255, b'\x13\x00A\x94\x12\x01\x04\x01\x02\x04\x01\x04\x00\x00\x00\x05\x03\x00\x01\x00\x01\x19\x00']
2023-02-23 11:24:57.680 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32772, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=14), 232, -42, 0x9441, 255, 255, b'\x13\x00A\x94\x12\x01\x04\x01\x02\x04\x01\x04\x00\x00\x00\x05\x03\x00\x01\x00\x01\x19\x00']
2023-02-23 11:24:57.681 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=14, profile_id=0, cluster_id=32772, data=Serialized[b'\x13\x00A\x94\x12\x01\x04\x01\x02\x04\x01\x04\x00\x00\x00\x05\x03\x00\x01\x00\x01\x19\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=232, rssi=-42)
2023-02-23 11:24:57.683 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model=None manuf=None nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=False> from ep 0 to ep 0, cluster 32772: b'\x13\x00A\x94\x12\x01\x04\x01\x02\x04\x01\x04\x00\x00\x00\x05\x03\x00\x01\x00\x01\x19\x00'
2023-02-23 11:24:57.698 INFO (MainThread) [zigpy.endpoint] [0x9441:1] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=1, profile=260, device_type=1026, device_version=1, input_clusters=[0, 1280, 3, 1], output_clusters=[25])
2023-02-23 11:24:57.701 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0000] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True, *is_reply=False), tsn=21, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>, *is_reply=False)
2023-02-23 11:24:57.702 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0000] Sending request: Read_Attributes(attribute_ids=[4, 5])
2023-02-23 11:24:57.703 DEBUG (MainThread) [zigpy.device] [0x9441] Extending timeout for 0x15 request
2023-02-23 11:24:57.704 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), dst_ep=1, source_route=None, extended_timeout=True, tsn=21, profile_id=260, cluster_id=0, data=Serialized[b'\x00\x15\x00\x04\x00\x05\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-02-23 11:24:57.705 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (54:ef:44:10:00:71:1d:00, True)
2023-02-23 11:24:57.707 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'26a321a92a2a15af28945a61450193b7f97e'
2023-02-23 11:24:57.720 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'63a3a1a92a2a88947e'
2023-02-23 11:24:57.721 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2023-02-23 11:24:57.725 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setExtendedTimeout: []
2023-02-23 11:24:57.730 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x9441, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=21), 22, b'\x00\x15\x00\x04\x00\x05\x00')
2023-02-23 11:24:57.735 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'37a021a9602a15f3cd904b25aa5493499d4e27befbc9679efdc2638cfca2cb7e'
2023-02-23 11:24:57.744 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'74a0a1a9602a15fdb7217e'
2023-02-23 11:24:57.744 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2023-02-23 11:24:57.746 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 79]
2023-02-23 11:24:58.513 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2023-02-23 11:24:58.516 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'40a121a9a52ae1617e'
2023-02-23 11:24:58.533 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'05a1a1a9a52a14b26194c925ba5593499c4e22abe8ce6c8bfbc66289fd7e3ea7eacddf6f8bffc6dbd4d2698c4623a9ec763ba5ea758241984c2613b1e070381c0e07bbe5ca658a459a4d9e4f9ff7c3d9d46a35a25190482456cf7e'
2023-02-23 11:24:58.533 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2023-02-23 11:24:58.537 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received readCounters: [[1, 56, 131, 16, 1, 0, 5, 5, 11, 6, 1, 1, 1, 1, 1, 4, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]]
2023-02-23 11:24:58.539 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_FREE_BUFFERS: 3>,)
2023-02-23 11:24:58.545 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'51a621a9fe2a16179c7e'
2023-02-23 11:24:58.551 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'16a6a1a9fe2a15b3cfa7f77e'
2023-02-23 11:24:58.551 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2023-02-23 11:24:58.555 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\x96']
2023-02-23 11:24:58.559 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 150
2023-02-23 11:24:58.560 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 1, MAC_TX_BROADCAST = 56, MAC_RX_UNICAST = 131, MAC_TX_UNICAST_SUCCESS = 16, MAC_TX_UNICAST_RETRY = 1, MAC_TX_UNICAST_FAILED = 0, APS_DATA_RX_BROADCAST = 5, APS_DATA_TX_BROADCAST = 5, APS_DATA_RX_UNICAST = 11, APS_DATA_TX_UNICAST_SUCCESS = 6, APS_DATA_TX_UNICAST_RETRY = 1, APS_DATA_TX_UNICAST_FAILED = 1, ROUTE_DISCOVERY_INITIATED = 1, NEIGHBOR_ADDED = 1, NEIGHBOR_REMOVED = 1, NEIGHBOR_STALE = 4, JOIN_INDICATION = 1, CHILD_REMOVED = 1, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 150]
2023-02-23 11:24:58.874 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'26a6b1a96b2a15f3cd904b25aa5493499d4e27e4fbce6763fa7e'
2023-02-23 11:24:58.874 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2023-02-23 11:24:58.877 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=79), 22, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:58.878 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 37953, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=79), 22, <EmberStatus.SUCCESS: 0>, b'']
2023-02-23 11:24:58.888 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'36a6b1a9112a15b658944a24ab1593499c41fb78ac5a9874d5de7688f87e3fe5ef818b22c6fac7db97c505f92b4a879f1355d68507dd32f5234d769f8113562c3d0506c77e'
2023-02-23 11:24:58.888 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2023-02-23 11:24:58.894 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=15), 220, -45, 0x9441, 255, 255, b'\x18\x15\x01\x04\x00\x00B\x04LUMI\x05\x00\x00B\x17lumi.sensor_smoke.acn03']
2023-02-23 11:24:58.895 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=15), 220, -45, 0x9441, 255, 255, b'\x18\x15\x01\x04\x00\x00B\x04LUMI\x05\x00\x00B\x17lumi.sensor_smoke.acn03']
2023-02-23 11:24:58.895 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=15, profile_id=260, cluster_id=0, data=Serialized[b'\x18\x15\x01\x04\x00\x00B\x04LUMI\x05\x00\x00B\x17lumi.sensor_smoke.acn03'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=220, rssi=-45)
2023-02-23 11:24:58.896 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0000] Received ZCL frame: b'\x18\x15\x01\x04\x00\x00B\x04LUMI\x05\x00\x00B\x17lumi.sensor_smoke.acn03'
2023-02-23 11:24:58.897 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0000] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=21, command_id=1, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
2023-02-23 11:24:58.901 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0000] Decoded ZCL frame: Basic:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0004, status=<Status.SUCCESS: 0>, value=TypeValue(type=CharacterString, value='LUMI')), ReadAttributeRecord(attrid=0x0005, status=<Status.SUCCESS: 0>, value=TypeValue(type=CharacterString, value='lumi.sensor_smoke.acn03'))])
2023-02-23 11:24:58.910 INFO (MainThread) [zigpy.device] [0x9441] Read model 'lumi.sensor_smoke.acn03' and manufacturer 'LUMI' from <Endpoint id=1 in=[basic:0x0000, ias_zone:0x0500, identify:0x0003, power:0x0001] out=[ota:0x0019] status=<Status.ZDO_INIT: 1>>
2023-02-23 11:24:58.911 INFO (MainThread) [zigpy.device] [0x9441] Discovered basic device information for <Device model='lumi.sensor_smoke.acn03' manuf='LUMI' nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=True>
2023-02-23 11:24:58.911 DEBUG (MainThread) [zigpy.application] Device is initialized <Device model='lumi.sensor_smoke.acn03' manuf='LUMI' nwk=0x9441 ieee=54:ef:44:10:00:71:1d:00 is_initialized=True>
2023-02-23 11:24:58.914 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.sensor_smoke.acn03 (54:ef:44:10:00:71:1d:00)
2023-02-23 11:24:58.914 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'xiaomi.smoke.LumiSensorSmokeAcn03'>
2023-02-23 11:24:58.916 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 54:ef:44:10:00:71:1d:00: <class 'xiaomi.smoke.LumiSensorSmokeAcn03'>
2023-02-23 11:24:58.927 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'binary_sensor' component -> 'IASZone' using ['ias_zone']
2023-02-23 11:24:58.927 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'button' component -> 'ZHAIdentifyButton' using ['identify']
2023-02-23 11:24:58.928 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'DeviceTemperature' using ['device_temperature']
2023-02-23 11:24:58.928 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'RSSISensor' using ['basic']
2023-02-23 11:24:58.928 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'LQISensor' using ['basic']
2023-02-23 11:24:58.932 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x9441:54:ef:44:10:00:71:1d:00 entering async_device_initialized - is_new_join: True
2023-02-23 11:24:58.933 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] device - 0x9441:54:ef:44:10:00:71:1d:00 has joined the ZHA zigbee network
2023-02-23 11:24:58.935 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9441](lumi.sensor_smoke.acn03): started configuration
2023-02-23 11:24:58.935 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:ZDO](lumi.sensor_smoke.acn03): 'async_configure' stage succeeded
2023-02-23 11:24:58.953 DEBUG (MainThread) [zigpy.appdb] Error handling '_save_attribute' event with (54:ef:44:10:00:71:1d:00, 1, 0, 4, 'LUMI') params: FOREIGN KEY constraint failed
2023-02-23 11:24:58.957 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: Performing cluster binding
2023-02-23 11:24:58.957 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: bound 'device_temperature' cluster: Status.SUCCESS
2023-02-23 11:24:58.958 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: Configuring cluster attribute reporting
2023-02-23 11:24:58.959 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: Successfully configured reporting for '{'current_temperature': (30, 900, 50)}' on 'device_temperature' cluster: [ConfigureReportingResponseRecord(status=<Status.SUCCESS: 0>)]
2023-02-23 11:24:58.962 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0002]: finished channel configuration
2023-02-23 11:24:58.963 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0003]: Configuring cluster attribute reporting
2023-02-23 11:24:58.963 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0003]: finished channel configuration
2023-02-23 11:24:58.963 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0000]: Configuring cluster attribute reporting
2023-02-23 11:24:58.963 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0000]: finished channel configuration
2023-02-23 11:24:58.964 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: started IASZoneChannel configuration
2023-02-23 11:24:58.965 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: bound 'ias_zone' cluster: Status.SUCCESS
2023-02-23 11:24:58.965 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: wrote cie_addr: 38:5c:fb:ff:fe:e3:73:71 to 'ias_zone' cluster: [WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]
2023-02-23 11:24:58.966 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: Sending pro-active IAS enroll response
2023-02-23 11:24:58.966 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0500]: finished IASZoneChannel configuration
2023-02-23 11:24:58.967 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0xfcc0]: Performing cluster binding
2023-02-23 11:24:58.968 DEBUG (MainThread) [zigpy.device] [0x9441] Extending timeout for 0x17 request
2023-02-23 11:24:58.969 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9441), dst_ep=0, source_route=None, extended_timeout=True, tsn=23, profile_id=0, cluster_id=<ZDOCmd.Bind_req: 0x0021>, data=Serialized[b'\x17\x00\x1dq\x00\x10D\xefT\x01\xc0\xfc\x03qs\xe3\xfe\xff\xfb\\8\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-02-23 11:24:58.970 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (54:ef:44:10:00:71:1d:00, True)
2023-02-23 11:24:58.971 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9441:1:0x0019]: finished channel configuration
2023-02-23 11:24:58.973 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'64a721a92a2a15af28945a614501932d8c7e'
2023-02-23 11:24:58.976 DEBUG (MainThread) [zigpy.zcl] [0x9441:1:0x0500] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False, *is_reply=False), tsn=25, command_id=0, *direction=<Direction.Server_to_Client: 0>, *is_reply=False)