home-assistant[bot]
commented
1 week ago Hey there @dmulcahey, @adminiuga, @puddly, @thejulianjes, mind taking a look at this issue as it has been labeled with an integration (zha) you are listed as a code owner for? Thanks!
Code owner commands
Code owners of `zha` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign zha` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.(message by CodeOwnersMention)
zha documentation zha source (message by IssueLinks)
The problem
Moved my network over to a PoE TubesZB EFR32 MGM24 PoE Coordinator 2024 and moved my Home Assistant install from a Raspberry Pi to a VM in ESXi. Network runs great for about a week but then it gets into a funny state where 10 devices or so fall offline and then I hit max concurrency and the messages start piling up. It occurred today and I started at ~500 messages queued and now I am well over 5,000. I have a log but it is close to 2GB. I put an excerpt below.
What version of Home Assistant Core has the issue?
core-2024.9.2
What was the last working version of Home Assistant Core?
No response
What type of installation are you running?
Home Assistant OS
Integration causing the issue
zha
Link to integration documentation on our website
https://www.home-assistant.io/integrations/zha/
Diagnostics information
Unable to download diagnostics.
Example YAML snippet
No response
Anything in the logs that might be useful for us?
No response
Additional information
Logs (click to open)
```python 2024-09-23 13:04:17.520 DEBUG (MainThread) [bellows.ash] Received data 3363b1a97d312a15b658964d24ab1592499cb1af15f7799874fade6683fc7c27a7e9e2d77e 2024-09-23 13:04:17.520 DEBUG (MainThread) [bellows.ash] Received frame DataFrame(frm_num=3, re_tx=0, ack_num=3, ezsp_frame=b'!\x90\x01E\x00\x00\x04\x01\x02\x07\x01\x01@\x00\x00\x00\xff\x88\xbe\x1a\xb7\xff\xff\x07\x18\x05\n\x00\x02\x18\x00\x02') 2024-09-23 13:04:17.520 DEBUG (MainThread) [bellows.ash] Sending frame AckFrame(res=0, ncp_ready=0, ack_num=4) + FLAG 2024-09-23 13:04:17.520 DEBUG (MainThread) [bellows.ash] Sending data 8430fc7e 2024-09-23 13:04:17.521 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type':, 'apsFrame': EmberApsFrame(profileId=260, clusterId=1794, sourceEndpoint=1, destinationEndpoint=1, options=, groupId=0, sequence=255), 'lastHopLqi': 136, 'lastHopRssi': -66, 'sender': 0xB71A, 'bindingIndex': 255, 'addressIndex': 255, 'messageContents': b'\x18\x05\n\x00\x02\x18\x00'}
2024-09-23 13:04:17.522 DEBUG (MainThread) [bellows.ezsp.protocol] Frame contains trailing data: b'\x02'
2024-09-23 13:04:17.522 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [, EmberApsFrame(profileId=260, clusterId=1794, sourceEndpoint=1, destinationEndpoint=1, options=, groupId=0, sequence=255), 136, -66, 0xB71A, 255, 255, b'\x18\x05\n\x00\x02\x18\x00']
2024-09-23 13:04:17.522 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 17, 522567, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0xB71A), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=255, profile_id=260, cluster_id=1794, data=Serialized[b'\x18\x05\n\x00\x02\x18\x00'], tx_options=, radius=0, non_member_radius=0, lqi=136, rssi=-66)
2024-09-23 13:04:17.523 DEBUG (MainThread) [zigpy.zcl] [0xB71A:1:0x0702] Received ZCL frame: b'\x18\x05\n\x00\x02\x18\x00'
2024-09-23 13:04:17.524 DEBUG (MainThread) [zigpy.zcl] [0xB71A:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x18>(frame_type=, is_manufacturer_specific=0, direction=, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=5, command_id=10, *direction=)
2024-09-23 13:04:17.525 DEBUG (MainThread) [zigpy.zcl] [0xB71A:1:0x0702] Decoded ZCL frame: Metering:Report_Attributes(attribute_reports=[Attribute(attrid=0x0200, value=TypeValue(type=bitmap8, value=))])
2024-09-23 13:04:17.526 DEBUG (MainThread) [zigpy.zcl] [0xB71A:1:0x0702] Received command 0x0A (TSN 5): Report_Attributes(attribute_reports=[Attribute(attrid=0x0200, value=TypeValue(type=bitmap8, value=))])
2024-09-23 13:04:17.527 DEBUG (MainThread) [zigpy.zcl] [0xB71A:1:0x0702] Attribute report received: status=
2024-09-23 13:04:17.527 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0xB71A:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[Metering] attr[status] value[0]
2024-09-23 13:04:17.528 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=512, attribute_name='status', attribute_value=, cluster_handler_unique_id='94:de:b8:ff:fe:45:91:dc:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-23 13:04:17.528 DEBUG (Thread-6) [aiosqlite] executing functools.partial(, 'UPDATE devices_v13\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1727111057.522567, 'ieee': 94:de:b8:ff:fe:45:91:dc, 'min_update_delta': 30.0})
2024-09-23 13:04:17.531 DEBUG (Thread-6) [aiosqlite] operation functools.partial(, 'UPDATE devices_v13\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1727111057.522567, 'ieee': 94:de:b8:ff:fe:45:91:dc, 'min_update_delta': 30.0}) completed
2024-09-23 13:04:17.532 DEBUG (Thread-6) [aiosqlite] executing functools.partial()
2024-09-23 13:04:17.532 DEBUG (Thread-6) [aiosqlite] operation functools.partial() completed
2024-09-23 13:04:17.533 DEBUG (Thread-6) [aiosqlite] executing functools.partial(, '\n INSERT INTO attributes_cache_v13\n VALUES (:ieee, :endpoint_id, :cluster_type, :cluster_id, :attr_id, :value, :timestamp)\n ON CONFLICT (ieee, endpoint_id, cluster_type, cluster_id, attr_id) DO UPDATE\n SET value=excluded.value, last_updated=excluded.last_updated\n WHERE\n value != excluded.value\n OR :timestamp - last_updated > :min_update_delta\n ', {'ieee': 94:de:b8:ff:fe:45:91:dc, 'endpoint_id': 1, 'cluster_type': , 'cluster_id': 1794, 'attr_id': 512, 'value': , 'timestamp': 1727111057.527632, 'min_update_delta': 30.0})
2024-09-23 13:04:17.537 DEBUG (Thread-6) [aiosqlite] operation functools.partial(, '\n INSERT INTO attributes_cache_v13\n VALUES (:ieee, :endpoint_id, :cluster_type, :cluster_id, :attr_id, :value, :timestamp)\n ON CONFLICT (ieee, endpoint_id, cluster_type, cluster_id, attr_id) DO UPDATE\n SET value=excluded.value, last_updated=excluded.last_updated\n WHERE\n value != excluded.value\n OR :timestamp - last_updated > :min_update_delta\n ', {'ieee': 94:de:b8:ff:fe:45:91:dc, 'endpoint_id': 1, 'cluster_type': , 'cluster_id': 1794, 'attr_id': 512, 'value': , 'timestamp': 1727111057.527632, 'min_update_delta': 30.0}) completed
2024-09-23 13:04:17.538 DEBUG (Thread-6) [aiosqlite] executing functools.partial()
2024-09-23 13:04:17.539 DEBUG (Thread-6) [aiosqlite] operation functools.partial() completed
2024-09-23 13:04:17.585 DEBUG (MainThread) [bellows.ash] Received data 4363b1a97d312a15b658904124ab1592499c59577d33c3c59874f5de4083f77b16d1ebcf1f7f7e
2024-09-23 13:04:17.585 DEBUG (MainThread) [bellows.ash] Received frame DataFrame(frm_num=4, re_tx=0, ack_num=3, ezsp_frame=b'!\x90\x01E\x00\x00\x04\x01\x04\x0b\x01\x01@\x00\x00\x00\x17p\xb8.\x0b\xff\xff\x08\x18#\n\x0b\x05)v\x00\x02')
2024-09-23 13:04:17.585 DEBUG (MainThread) [bellows.ash] Sending frame AckFrame(res=0, ncp_ready=0, ack_num=5) + FLAG
2024-09-23 13:04:17.585 DEBUG (MainThread) [bellows.ash] Sending data 8520dd7e
2024-09-23 13:04:17.586 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': , 'apsFrame': EmberApsFrame(profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=1, options=, groupId=0, sequence=23), 'lastHopLqi': 112, 'lastHopRssi': -72, 'sender': 0x0B2E, 'bindingIndex': 255, 'addressIndex': 255, 'messageContents': b'\x18#\n\x0b\x05)v\x00'}
2024-09-23 13:04:17.586 DEBUG (MainThread) [bellows.ezsp.protocol] Frame contains trailing data: b'\x02'
2024-09-23 13:04:17.586 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [, EmberApsFrame(profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=1, options=, groupId=0, sequence=23), 112, -72, 0x0B2E, 255, 255, b'\x18#\n\x0b\x05)v\x00']
2024-09-23 13:04:17.587 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 17, 587211, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0x0B2E), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=23, profile_id=260, cluster_id=2820, data=Serialized[b'\x18#\n\x0b\x05)v\x00'], tx_options=, radius=0, non_member_radius=0, lqi=112, rssi=-72)
2024-09-23 13:04:17.588 DEBUG (MainThread) [zigpy.zcl] [0x0B2E:1:0x0b04] Received ZCL frame: b'\x18#\n\x0b\x05)v\x00'
2024-09-23 13:04:17.588 DEBUG (MainThread) [zigpy.zcl] [0x0B2E:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x18>(frame_type=, is_manufacturer_specific=0, direction=, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=35, command_id=10, *direction=)
2024-09-23 13:04:17.590 DEBUG (MainThread) [zigpy.zcl] [0x0B2E:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Report_Attributes(attribute_reports=[Attribute(attrid=0x050B, value=TypeValue(type=int16s, value=118))])
2024-09-23 13:04:17.590 DEBUG (MainThread) [zigpy.zcl] [0x0B2E:1:0x0b04] Received command 0x0A (TSN 35): Report_Attributes(attribute_reports=[Attribute(attrid=0x050B, value=TypeValue(type=int16s, value=118))])
2024-09-23 13:04:17.591 DEBUG (MainThread) [zigpy.zcl] [0x0B2E:1:0x0b04] Attribute report received: active_power=118
2024-09-23 13:04:17.592 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x0B2E:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[active_power] value[118]
2024-09-23 13:04:17.592 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1291, attribute_name='active_power', attribute_value=118, cluster_handler_unique_id='70:ac:08:ff:fe:70:d5:2f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-23 13:04:17.592 DEBUG (MainThread) [zha] Emitting event state_changed with data EntityStateChangedEvent(event_type='entity', event='state_changed', platform=, unique_id='70:ac:08:ff:fe:70:d5:2f-1-2820', device_ieee=70:ac:08:ff:fe:70:d5:2f, endpoint_id=1, group_id=None) (1 listeners)
2024-09-23 13:04:17.593 DEBUG (MainThread) [homeassistant.components.zha.entity] sensor.inovelli_vzm31_sn_active_power_8: Handling event from entity: EntityStateChangedEvent(event_type='entity', event='state_changed', platform=, unique_id='70:ac:08:ff:fe:70:d5:2f-1-2820', device_ieee=70:ac:08:ff:fe:70:d5:2f, endpoint_id=1, group_id=None)
2024-09-23 13:04:17.595 DEBUG (Thread-6) [aiosqlite] executing functools.partial(, 'UPDATE devices_v13\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1727111057.587211, 'ieee': 70:ac:08:ff:fe:70:d5:2f, 'min_update_delta': 30.0})
2024-09-23 13:04:17.597 DEBUG (Thread-6) [aiosqlite] operation functools.partial(, 'UPDATE devices_v13\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1727111057.587211, 'ieee': 70:ac:08:ff:fe:70:d5:2f, 'min_update_delta': 30.0}) completed
2024-09-23 13:04:17.599 DEBUG (Thread-6) [aiosqlite] executing functools.partial()
2024-09-23 13:04:17.600 DEBUG (Thread-6) [aiosqlite] operation functools.partial() completed
2024-09-23 13:04:17.602 DEBUG (Thread-6) [aiosqlite] executing functools.partial(, '\n INSERT INTO attributes_cache_v13\n VALUES (:ieee, :endpoint_id, :cluster_type, :cluster_id, :attr_id, :value, :timestamp)\n ON CONFLICT (ieee, endpoint_id, cluster_type, cluster_id, attr_id) DO UPDATE\n SET value=excluded.value, last_updated=excluded.last_updated\n WHERE\n value != excluded.value\n OR :timestamp - last_updated > :min_update_delta\n ', {'ieee': 70:ac:08:ff:fe:70:d5:2f, 'endpoint_id': 1, 'cluster_type': , 'cluster_id': 2820, 'attr_id': 1291, 'value': 118, 'timestamp': 1727111057.592089, 'min_update_delta': 30.0})
2024-09-23 13:04:17.603 DEBUG (Thread-6) [aiosqlite] operation functools.partial(, '\n INSERT INTO attributes_cache_v13\n VALUES (:ieee, :endpoint_id, :cluster_type, :cluster_id, :attr_id, :value, :timestamp)\n ON CONFLICT (ieee, endpoint_id, cluster_type, cluster_id, attr_id) DO UPDATE\n SET value=excluded.value, last_updated=excluded.last_updated\n WHERE\n value != excluded.value\n OR :timestamp - last_updated > :min_update_delta\n ', {'ieee': 70:ac:08:ff:fe:70:d5:2f, 'endpoint_id': 1, 'cluster_type': , 'cluster_id': 2820, 'attr_id': 1291, 'value': 118, 'timestamp': 1727111057.592089, 'min_update_delta': 30.0}) completed
2024-09-23 13:04:17.604 DEBUG (Thread-6) [aiosqlite] executing functools.partial()
2024-09-23 13:04:17.604 DEBUG (Thread-6) [aiosqlite] operation functools.partial() completed
2024-09-23 13:04:17.938 DEBUG (MainThread) [bellows.ash] Received data 5363b1a96b2a7d334fa6944a25aa559249984e272812ce67dcd07e
2024-09-23 13:04:17.938 DEBUG (MainThread) [bellows.ash] Received frame DataFrame(frm_num=5, re_tx=0, ack_num=3, ezsp_frame=b'!\x90\x01?\x00\x06\xfd\xff\x00\x00\x00\x00\x00\x00\x00\x04\x00\x00\x83\xff\x00\x00')
2024-09-23 13:04:17.938 DEBUG (MainThread) [bellows.ash] Sending frame AckFrame(res=0, ncp_ready=0, ack_num=6) + FLAG
2024-09-23 13:04:17.938 DEBUG (MainThread) [bellows.ash] Sending data 8610be7e
2024-09-23 13:04:17.939 DEBUG (MainThread) [bellows.ezsp.protocol] Received command messageSentHandler: {'type': , 'indexOrDestination': 65533, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=, groupId=0, sequence=131), 'messageTag': 255, 'status': , 'messageContents': b''}
2024-09-23 13:04:17.939 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [, 65533, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=, groupId=0, sequence=131), 255, , b'']
2024-09-23 13:04:17.939 DEBUG (MainThread) [bellows.zigbee.application] Unexpected message send notification tag: (65533, 255)
2024-09-23 13:04:18.211 DEBUG (MainThread) [bellows.ash] Received data 6363b1a97d312a15b658904124ab1592499c4ea717f7799874f5de6583f77b16b8ebcfbfed7e
2024-09-23 13:04:18.211 DEBUG (MainThread) [bellows.ash] Received frame DataFrame(frm_num=6, re_tx=0, ack_num=3, ezsp_frame=b'!\x90\x01E\x00\x00\x04\x01\x04\x0b\x01\x01@\x00\x00\x00\x00\x80\xbc\x1a\xb7\xff\xff\x08\x18\x06\n\x0b\x05)\x1f\x00\x02')
2024-09-23 13:04:18.211 DEBUG (MainThread) [bellows.ash] Sending frame AckFrame(res=0, ncp_ready=0, ack_num=7) + FLAG
2024-09-23 13:04:18.211 DEBUG (MainThread) [bellows.ash] Sending data 87009f7e
2024-09-23 13:04:18.212 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': , 'apsFrame': EmberApsFrame(profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=1, options=, groupId=0, sequence=0), 'lastHopLqi': 128, 'lastHopRssi': -68, 'sender': 0xB71A, 'bindingIndex': 255, 'addressIndex': 255, 'messageContents': b'\x18\x06\n\x0b\x05)\x1f\x00'}
2024-09-23 13:04:18.213 DEBUG (MainThread) [bellows.ezsp.protocol] Frame contains trailing data: b'\x02'
2024-09-23 13:04:18.213 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [, EmberApsFrame(profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=1, options=, groupId=0, sequence=0), 128, -68, 0xB71A, 255, 255, b'\x18\x06\n\x0b\x05)\x1f\x00']
2024-09-23 13:04:18.213 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 18, 213556, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0xB71A), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=2820, data=Serialized[b'\x18\x06\n\x0b\x05)\x1f\x00'], tx_options=, radius=0, non_member_radius=0, lqi=128, rssi=-68)
2024-09-23 13:04:18.214 DEBUG (MainThread) [zigpy.zcl] [0xB71A:1:0x0b04] Received ZCL frame: b'\x18\x06\n\x0b\x05)\x1f\x00'
2024-09-23 13:04:18.215 DEBUG (MainThread) [zigpy.zcl] [0xB71A:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x18>(frame_type=, is_manufacturer_specific=0, direction=, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=6, command_id=10, *direction=)
2024-09-23 13:04:18.216 DEBUG (MainThread) [zigpy.zcl] [0xB71A:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Report_Attributes(attribute_reports=[Attribute(attrid=0x050B, value=TypeValue(type=int16s, value=31))])
2024-09-23 13:04:18.217 DEBUG (MainThread) [zigpy.zcl] [0xB71A:1:0x0b04] Received command 0x0A (TSN 6): Report_Attributes(attribute_reports=[Attribute(attrid=0x050B, value=TypeValue(type=int16s, value=31))])
2024-09-23 13:04:18.218 DEBUG (MainThread) [zigpy.zcl] [0xB71A:1:0x0b04] Attribute report received: active_power=31
2024-09-23 13:04:18.218 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0xB71A:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[active_power] value[31]
2024-09-23 13:04:18.218 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1291, attribute_name='active_power', attribute_value=31, cluster_handler_unique_id='94:de:b8:ff:fe:45:91:dc:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-23 13:04:18.220 DEBUG (Thread-6) [aiosqlite] executing functools.partial(, 'UPDATE devices_v13\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1727111058.213556, 'ieee': 94:de:b8:ff:fe:45:91:dc, 'min_update_delta': 30.0})
2024-09-23 13:04:18.221 DEBUG (Thread-6) [aiosqlite] operation functools.partial(, 'UPDATE devices_v13\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1727111058.213556, 'ieee': 94:de:b8:ff:fe:45:91:dc, 'min_update_delta': 30.0}) completed
2024-09-23 13:04:18.223 DEBUG (Thread-6) [aiosqlite] executing functools.partial()
2024-09-23 13:04:18.224 DEBUG (Thread-6) [aiosqlite] operation functools.partial() completed
2024-09-23 13:04:18.225 DEBUG (Thread-6) [aiosqlite] executing functools.partial(, '\n INSERT INTO attributes_cache_v13\n VALUES (:ieee, :endpoint_id, :cluster_type, :cluster_id, :attr_id, :value, :timestamp)\n ON CONFLICT (ieee, endpoint_id, cluster_type, cluster_id, attr_id) DO UPDATE\n SET value=excluded.value, last_updated=excluded.last_updated\n WHERE\n value != excluded.value\n OR :timestamp - last_updated > :min_update_delta\n ', {'ieee': 94:de:b8:ff:fe:45:91:dc, 'endpoint_id': 1, 'cluster_type': , 'cluster_id': 2820, 'attr_id': 1291, 'value': 31, 'timestamp': 1727111058.218455, 'min_update_delta': 30.0})
2024-09-23 13:04:18.225 DEBUG (Thread-6) [aiosqlite] operation functools.partial(, '\n INSERT INTO attributes_cache_v13\n VALUES (:ieee, :endpoint_id, :cluster_type, :cluster_id, :attr_id, :value, :timestamp)\n ON CONFLICT (ieee, endpoint_id, cluster_type, cluster_id, attr_id) DO UPDATE\n SET value=excluded.value, last_updated=excluded.last_updated\n WHERE\n value != excluded.value\n OR :timestamp - last_updated > :min_update_delta\n ', {'ieee': 94:de:b8:ff:fe:45:91:dc, 'endpoint_id': 1, 'cluster_type': , 'cluster_id': 2820, 'attr_id': 1291, 'value': 31, 'timestamp': 1727111058.218455, 'min_update_delta': 30.0}) completed
2024-09-23 13:04:18.226 DEBUG (Thread-6) [aiosqlite] executing functools.partial()
2024-09-23 13:04:18.226 DEBUG (Thread-6) [aiosqlite] operation functools.partial() completed
2024-09-23 13:04:18.260 DEBUG (MainThread) [zha.application.platforms] b0:ce:18:14:03:53:69:4e-1: setting transitioning flag to True
2024-09-23 13:04:18.261 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2024-09-23 13:04:18.261 DEBUG (MainThread) [zigpy.zcl] [0x9F0F:1:0x0008] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=77, command_id=4, *direction=)
2024-09-23 13:04:18.262 DEBUG (MainThread) [zigpy.zcl] [0x9F0F:1:0x0008] Sending request: move_to_level_with_on_off(level=254, transition_time=100)
2024-09-23 13:04:18.263 DEBUG (MainThread) [zigpy.device] [0x9f0f] Extending timeout for 0x4d request
2024-09-23 13:04:18.263 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 18, 263816, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0x9F0F), dst_ep=1, source_route=[0xF691], extended_timeout=True, tsn=77, profile_id=260, cluster_id=8, data=Serialized[b'\x01M\x04\xfed\x00'], tx_options=, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-23 13:04:18.264 DEBUG (MainThread) [zigpy.application] Max concurrency (8) reached, delaying request (3664 enqueued)
2024-09-23 13:04:18.267 DEBUG (MainThread) [zha.application.platforms] b0:ce:18:14:03:52:f2:d9-1: setting transitioning flag to True
2024-09-23 13:04:18.267 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2024-09-23 13:04:18.268 DEBUG (MainThread) [zigpy.zcl] [0x6E49:1:0x0008] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=67, command_id=4, *direction=)
2024-09-23 13:04:18.269 DEBUG (MainThread) [zigpy.zcl] [0x6E49:1:0x0008] Sending request: move_to_level_with_on_off(level=254, transition_time=100)
2024-09-23 13:04:18.270 DEBUG (MainThread) [zigpy.device] [0x6e49] Extending timeout for 0x43 request
2024-09-23 13:04:18.270 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 18, 270383, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0x6E49), dst_ep=1, source_route=[0xF691], extended_timeout=True, tsn=67, profile_id=260, cluster_id=8, data=Serialized[b'\x01C\x04\xfed\x00'], tx_options=, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-23 13:04:18.271 DEBUG (MainThread) [zigpy.application] Max concurrency (8) reached, delaying request (3665 enqueued)
2024-09-23 13:04:18.452 DEBUG (MainThread) [bellows.ash] Received data 7363b1a97d312a15b658964d24ab1593499cca577d3357d39874f4ce4e83fc7a156feacdda41977e
2024-09-23 13:04:18.452 DEBUG (MainThread) [bellows.ash] Received frame DataFrame(frm_num=7, re_tx=0, ack_num=3, ezsp_frame=b'!\x90\x01E\x00\x00\x04\x01\x02\x07\x01\x01@\x01\x00\x00\x84p\xb8\xba\x1d\xff\xff\t\x08-\n\x00\x04*\xc8\x01\x00\x04')
2024-09-23 13:04:18.452 DEBUG (MainThread) [bellows.ash] Sending frame AckFrame(res=0, ncp_ready=0, ack_num=0) + FLAG
2024-09-23 13:04:18.452 DEBUG (MainThread) [bellows.ash] Sending data 8070787e
2024-09-23 13:04:18.453 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': , 'apsFrame': EmberApsFrame(profileId=260, clusterId=1794, sourceEndpoint=1, destinationEndpoint=1, options=, groupId=0, sequence=132), 'lastHopLqi': 112, 'lastHopRssi': -72, 'sender': 0x1DBA, 'bindingIndex': 255, 'addressIndex': 255, 'messageContents': b'\x08-\n\x00\x04*\xc8\x01\x00'}
2024-09-23 13:04:18.453 DEBUG (MainThread) [bellows.ezsp.protocol] Frame contains trailing data: b'\x04'
2024-09-23 13:04:18.453 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [, EmberApsFrame(profileId=260, clusterId=1794, sourceEndpoint=1, destinationEndpoint=1, options=, groupId=0, sequence=132), 112, -72, 0x1DBA, 255, 255, b'\x08-\n\x00\x04*\xc8\x01\x00']
2024-09-23 13:04:18.453 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 18, 453961, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0x1DBA), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=132, profile_id=260, cluster_id=1794, data=Serialized[b'\x08-\n\x00\x04*\xc8\x01\x00'], tx_options=, radius=0, non_member_radius=0, lqi=112, rssi=-72)
2024-09-23 13:04:18.455 DEBUG (MainThread) [zigpy.zcl] [0x1DBA:1:0x0702] Received ZCL frame: b'\x08-\n\x00\x04*\xc8\x01\x00'
2024-09-23 13:04:18.455 DEBUG (MainThread) [zigpy.zcl] [0x1DBA:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x08>(frame_type=, is_manufacturer_specific=0, direction=, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=45, command_id=10, *direction=)
2024-09-23 13:04:18.457 DEBUG (MainThread) [zigpy.zcl] [0x1DBA:1:0x0702] Decoded ZCL frame: Metering:Report_Attributes(attribute_reports=[Attribute(attrid=0x0400, value=TypeValue(type=int24s, value=456))])
2024-09-23 13:04:18.457 DEBUG (MainThread) [zigpy.zcl] [0x1DBA:1:0x0702] Received command 0x0A (TSN 45): Report_Attributes(attribute_reports=[Attribute(attrid=0x0400, value=TypeValue(type=int24s, value=456))])
2024-09-23 13:04:18.459 DEBUG (MainThread) [zigpy.zcl] [0x1DBA:1:0x0702] Attribute report received: instantaneous_demand=456
2024-09-23 13:04:18.459 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1DBA:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[Metering] attr[instantaneous_demand] value[456]
2024-09-23 13:04:18.459 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1024, attribute_name='instantaneous_demand', attribute_value=456, cluster_handler_unique_id='b0:ce:18:14:03:6b:93:c0:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (2 listeners)
2024-09-23 13:04:18.460 DEBUG (MainThread) [zha] Emitting event state_changed with data EntityStateChangedEvent(event_type='entity', event='state_changed', platform=, unique_id='b0:ce:18:14:03:6b:93:c0-1-1794', device_ieee=b0:ce:18:14:03:6b:93:c0, endpoint_id=1, group_id=None) (1 listeners)
2024-09-23 13:04:18.460 DEBUG (MainThread) [homeassistant.components.zha.entity] sensor.theater_equipment_instantaneous_demand_2: Handling event from entity: EntityStateChangedEvent(event_type='entity', event='state_changed', platform=, unique_id='b0:ce:18:14:03:6b:93:c0-1-1794', device_ieee=b0:ce:18:14:03:6b:93:c0, endpoint_id=1, group_id=None)
2024-09-23 13:04:18.461 DEBUG (MainThread) [zigpy.zcl] [0x1DBA:1:0x0702] Sending reply header: ZCLHeader(frame_control=FrameControl<0x10>(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=45, command_id=, *direction=)
2024-09-23 13:04:18.462 DEBUG (MainThread) [zigpy.zcl] [0x1DBA:1:0x0702] Sending reply: Default_Response(command_id=10, status=)
2024-09-23 13:04:18.463 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 18, 463618, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0x1DBA), dst_ep=1, source_route=[0x0B2E], extended_timeout=False, tsn=45, profile_id=260, cluster_id=1794, data=Serialized[b'\x10-\x0b\n\x00'], tx_options=, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-23 13:04:18.464 DEBUG (MainThread) [zigpy.application] Max concurrency (8) reached, delaying request (3666 enqueued)
2024-09-23 13:04:18.464 DEBUG (Thread-6) [aiosqlite] executing functools.partial(, 'UPDATE devices_v13\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1727111058.453961, 'ieee': b0:ce:18:14:03:6b:93:c0, 'min_update_delta': 30.0})
2024-09-23 13:04:18.465 DEBUG (Thread-6) [aiosqlite] operation functools.partial(, 'UPDATE devices_v13\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1727111058.453961, 'ieee': b0:ce:18:14:03:6b:93:c0, 'min_update_delta': 30.0}) completed
2024-09-23 13:04:18.466 DEBUG (Thread-6) [aiosqlite] executing functools.partial()
2024-09-23 13:04:18.466 DEBUG (Thread-6) [aiosqlite] operation functools.partial() completed
2024-09-23 13:04:18.468 DEBUG (Thread-6) [aiosqlite] executing functools.partial(, '\n INSERT INTO attributes_cache_v13\n VALUES (:ieee, :endpoint_id, :cluster_type, :cluster_id, :attr_id, :value, :timestamp)\n ON CONFLICT (ieee, endpoint_id, cluster_type, cluster_id, attr_id) DO UPDATE\n SET value=excluded.value, last_updated=excluded.last_updated\n WHERE\n value != excluded.value\n OR :timestamp - last_updated > :min_update_delta\n ', {'ieee': b0:ce:18:14:03:6b:93:c0, 'endpoint_id': 1, 'cluster_type': , 'cluster_id': 1794, 'attr_id': 1024, 'value': 456, 'timestamp': 1727111058.459408, 'min_update_delta': 30.0})
2024-09-23 13:04:18.469 DEBUG (Thread-6) [aiosqlite] operation functools.partial(, '\n INSERT INTO attributes_cache_v13\n VALUES (:ieee, :endpoint_id, :cluster_type, :cluster_id, :attr_id, :value, :timestamp)\n ON CONFLICT (ieee, endpoint_id, cluster_type, cluster_id, attr_id) DO UPDATE\n SET value=excluded.value, last_updated=excluded.last_updated\n WHERE\n value != excluded.value\n OR :timestamp - last_updated > :min_update_delta\n ', {'ieee': b0:ce:18:14:03:6b:93:c0, 'endpoint_id': 1, 'cluster_type': , 'cluster_id': 1794, 'attr_id': 1024, 'value': 456, 'timestamp': 1727111058.459408, 'min_update_delta': 30.0}) completed
2024-09-23 13:04:18.471 DEBUG (Thread-6) [aiosqlite] executing functools.partial()
2024-09-23 13:04:18.472 DEBUG (Thread-6) [aiosqlite] operation functools.partial() completed
2024-09-23 13:04:18.581 DEBUG (MainThread) [bellows.ash] Received data 0363b5a9902a1e0de969b47e7d3363b1a9d42abc0de9b01e7e
2024-09-23 13:04:18.581 DEBUG (MainThread) [bellows.ash] Received frame DataFrame(frm_num=0, re_tx=0, ack_num=3, ezsp_frame=b'!\x94\x01\xc4\x00\x0b\xbf\xb0')
2024-09-23 13:04:18.581 DEBUG (MainThread) [bellows.ash] Sending frame AckFrame(res=0, ncp_ready=0, ack_num=1) + FLAG
2024-09-23 13:04:18.581 DEBUG (MainThread) [bellows.ash] Sending data 8160597e
2024-09-23 13:04:18.582 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingNetworkStatusHandler: {'errorCode': , 'target': 0xB0BF}
2024-09-23 13:04:18.582 DEBUG (MainThread) [bellows.zigbee.application] Received incomingNetworkStatusHandler frame with [, 0xB0BF]
2024-09-23 13:04:18.582 DEBUG (MainThread) [bellows.ash] Received frame DataFrame(frm_num=1, re_tx=0, ack_num=3, ezsp_frame=b'!\x90\x01\x80\x00\xa9\xbf\xb0')
2024-09-23 13:04:18.582 DEBUG (MainThread) [bellows.ash] Sending frame AckFrame(res=0, ncp_ready=0, ack_num=2) + FLAG
2024-09-23 13:04:18.582 DEBUG (MainThread) [bellows.ash] Sending data 82503a7e
2024-09-23 13:04:18.583 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingRouteErrorHandler: {'status': , 'target': 0xB0BF}
2024-09-23 13:04:18.583 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteErrorHandler frame with [, 0xB0BF]
2024-09-23 13:04:18.583 DEBUG (MainThread) [bellows.zigbee.application] Processing route error: status=sl_Status.ZIGBEE_SOURCE_ROUTE_FAILURE, nwk=0xB0BF
2024-09-23 13:04:18.758 DEBUG (MainThread) [bellows.ash] Received data 2363b1a97d312a15b658964d24ab1593499cada7172e7d389889f1de0c83fc7d5e7d3a3f92cede6f8ff989167e
2024-09-23 13:04:18.758 DEBUG (MainThread) [bellows.ash] Received frame DataFrame(frm_num=2, re_tx=0, ack_num=3, ezsp_frame=b'!\x90\x01E\x00\x00\x04\x01\x02\x07\x01\x01@\x01\x00\x00\xe3\x80\xbc\xc3\xd6\xff\x02\x0c\x18o\n\x00\x00%\x98y\x03\x00\x00\x00\x06')
2024-09-23 13:04:18.758 DEBUG (MainThread) [bellows.ash] Sending frame AckFrame(res=0, ncp_ready=0, ack_num=3) + FLAG
2024-09-23 13:04:18.758 DEBUG (MainThread) [bellows.ash] Sending data 83401b7e
2024-09-23 13:04:18.759 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': , 'apsFrame': EmberApsFrame(profileId=260, clusterId=1794, sourceEndpoint=1, destinationEndpoint=1, options=, groupId=0, sequence=227), 'lastHopLqi': 128, 'lastHopRssi': -68, 'sender': 0xD6C3, 'bindingIndex': 255, 'addressIndex': 2, 'messageContents': b'\x18o\n\x00\x00%\x98y\x03\x00\x00\x00'}
2024-09-23 13:04:18.759 DEBUG (MainThread) [bellows.ezsp.protocol] Frame contains trailing data: b'\x06'
2024-09-23 13:04:18.759 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [, EmberApsFrame(profileId=260, clusterId=1794, sourceEndpoint=1, destinationEndpoint=1, options=, groupId=0, sequence=227), 128, -68, 0xD6C3, 255, 2, b'\x18o\n\x00\x00%\x98y\x03\x00\x00\x00']
2024-09-23 13:04:18.760 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 18, 759973, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0xD6C3), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=227, profile_id=260, cluster_id=1794, data=Serialized[b'\x18o\n\x00\x00%\x98y\x03\x00\x00\x00'], tx_options=, radius=0, non_member_radius=0, lqi=128, rssi=-68)
2024-09-23 13:04:18.761 DEBUG (MainThread) [zigpy.zcl] [0xD6C3:1:0x0702] Received ZCL frame: b'\x18o\n\x00\x00%\x98y\x03\x00\x00\x00'
2024-09-23 13:04:18.761 DEBUG (MainThread) [zigpy.zcl] [0xD6C3:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x18>(frame_type=, is_manufacturer_specific=0, direction=, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=111, command_id=10, *direction=)
2024-09-23 13:04:18.762 DEBUG (MainThread) [zigpy.zcl] [0xD6C3:1:0x0702] Decoded ZCL frame: Metering:Report_Attributes(attribute_reports=[Attribute(attrid=0x0000, value=TypeValue(type=uint48_t, value=227736))])
2024-09-23 13:04:18.763 DEBUG (MainThread) [zigpy.zcl] [0xD6C3:1:0x0702] Received command 0x0A (TSN 111): Report_Attributes(attribute_reports=[Attribute(attrid=0x0000, value=TypeValue(type=uint48_t, value=227736))])
2024-09-23 13:04:18.764 DEBUG (MainThread) [zigpy.zcl] [0xD6C3:1:0x0702] Attribute report received: current_summ_delivered=227736
2024-09-23 13:04:18.765 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0xD6C3:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[Metering] attr[current_summ_delivered] value[227736]
2024-09-23 13:04:18.765 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=0, attribute_name='current_summ_delivered', attribute_value=227736, cluster_handler_unique_id='b0:ce:18:14:03:52:ee:05:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (2 listeners)
2024-09-23 13:04:18.765 DEBUG (MainThread) [zha] Emitting event state_changed with data EntityStateChangedEvent(event_type='entity', event='state_changed', platform=, unique_id='b0:ce:18:14:03:52:ee:05-1-1794-summation_delivered', device_ieee=b0:ce:18:14:03:52:ee:05, endpoint_id=1, group_id=None) (1 listeners)
2024-09-23 13:04:18.765 DEBUG (MainThread) [homeassistant.components.zha.entity] sensor.sengled_e12_n1e_summation_delivered_12: Handling event from entity: EntityStateChangedEvent(event_type='entity', event='state_changed', platform=, unique_id='b0:ce:18:14:03:52:ee:05-1-1794-summation_delivered', device_ieee=b0:ce:18:14:03:52:ee:05, endpoint_id=1, group_id=None)
2024-09-23 13:04:18.767 DEBUG (Thread-6) [aiosqlite] executing functools.partial(, 'UPDATE devices_v13\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1727111058.759973, 'ieee': b0:ce:18:14:03:52:ee:05, 'min_update_delta': 30.0})
2024-09-23 13:04:18.768 DEBUG (Thread-6) [aiosqlite] operation functools.partial(, 'UPDATE devices_v13\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1727111058.759973, 'ieee': b0:ce:18:14:03:52:ee:05, 'min_update_delta': 30.0}) completed
2024-09-23 13:04:18.769 DEBUG (Thread-6) [aiosqlite] executing functools.partial()
2024-09-23 13:04:18.771 DEBUG (Thread-6) [aiosqlite] operation functools.partial() completed
2024-09-23 13:04:18.773 DEBUG (Thread-6) [aiosqlite] executing functools.partial(, '\n INSERT INTO attributes_cache_v13\n VALUES (:ieee, :endpoint_id, :cluster_type, :cluster_id, :attr_id, :value, :timestamp)\n ON CONFLICT (ieee, endpoint_id, cluster_type, cluster_id, attr_id) DO UPDATE\n SET value=excluded.value, last_updated=excluded.last_updated\n WHERE\n value != excluded.value\n OR :timestamp - last_updated > :min_update_delta\n ', {'ieee': b0:ce:18:14:03:52:ee:05, 'endpoint_id': 1, 'cluster_type': , 'cluster_id': 1794, 'attr_id': 0, 'value': 227736, 'timestamp': 1727111058.764964, 'min_update_delta': 30.0})
2024-09-23 13:04:18.773 DEBUG (Thread-6) [aiosqlite] operation functools.partial(, '\n INSERT INTO attributes_cache_v13\n VALUES (:ieee, :endpoint_id, :cluster_type, :cluster_id, :attr_id, :value, :timestamp)\n ON CONFLICT (ieee, endpoint_id, cluster_type, cluster_id, attr_id) DO UPDATE\n SET value=excluded.value, last_updated=excluded.last_updated\n WHERE\n value != excluded.value\n OR :timestamp - last_updated > :min_update_delta\n ', {'ieee': b0:ce:18:14:03:52:ee:05, 'endpoint_id': 1, 'cluster_type': , 'cluster_id': 1794, 'attr_id': 0, 'value': 227736, 'timestamp': 1727111058.764964, 'min_update_delta': 30.0}) completed
2024-09-23 13:04:18.775 DEBUG (Thread-6) [aiosqlite] executing functools.partial()
2024-09-23 13:04:18.776 DEBUG (Thread-6) [aiosqlite] operation functools.partial() completed
2024-09-23 13:04:18.809 DEBUG (MainThread) [zha.application.platforms] b0:ce:18:14:00:17:b6:14-1: setting transitioning flag to True
2024-09-23 13:04:18.810 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2024-09-23 13:04:18.810 DEBUG (MainThread) [zigpy.zcl] [0xE928:1:0x0008] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=43, command_id=4, *direction=)
2024-09-23 13:04:18.812 DEBUG (MainThread) [zigpy.zcl] [0xE928:1:0x0008] Sending request: move_to_level_with_on_off(level=254, transition_time=100)
2024-09-23 13:04:18.812 DEBUG (MainThread) [zigpy.device] [0xe928] Extending timeout for 0x2b request
2024-09-23 13:04:18.813 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 18, 812984, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0xE928), dst_ep=1, source_route=[0x1D27, 0xF27B], extended_timeout=True, tsn=43, profile_id=260, cluster_id=8, data=Serialized[b'\x01+\x04\xfed\x00'], tx_options=, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-23 13:04:18.813 DEBUG (MainThread) [zigpy.application] Max concurrency (8) reached, delaying request (3667 enqueued)
2024-09-23 13:04:18.814 DEBUG (MainThread) [zha.application.platforms] b0:ce:18:14:00:17:fc:38-1: setting transitioning flag to True
2024-09-23 13:04:18.817 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2024-09-23 13:04:18.818 DEBUG (MainThread) [zigpy.zcl] [0x1FF7:1:0x0008] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=65, command_id=4, *direction=)
2024-09-23 13:04:18.819 DEBUG (MainThread) [zigpy.zcl] [0x1FF7:1:0x0008] Sending request: move_to_level_with_on_off(level=254, transition_time=100)
2024-09-23 13:04:18.819 DEBUG (MainThread) [zigpy.device] [0x1ff7] Extending timeout for 0x41 request
2024-09-23 13:04:18.820 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 18, 820064, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0x1FF7), dst_ep=1, source_route=[0x405B, 0x4C7C], extended_timeout=True, tsn=65, profile_id=260, cluster_id=8, data=Serialized[b'\x01A\x04\xfed\x00'], tx_options=, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-23 13:04:18.820 DEBUG (MainThread) [zigpy.application] Max concurrency (8) reached, delaying request (3668 enqueued)
2024-09-23 13:04:18.821 DEBUG (MainThread) [zha.application.platforms] b0:ce:18:14:00:17:db:9e-1: setting transitioning flag to True
2024-09-23 13:04:18.821 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2024-09-23 13:04:18.822 DEBUG (MainThread) [zigpy.zcl] [0xC002:1:0x0008] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=58, command_id=4, *direction=)
2024-09-23 13:04:18.823 DEBUG (MainThread) [zigpy.zcl] [0xC002:1:0x0008] Sending request: move_to_level_with_on_off(level=254, transition_time=100)
2024-09-23 13:04:18.824 DEBUG (MainThread) [zigpy.device] [0xc002] Extending timeout for 0x3a request
2024-09-23 13:04:18.824 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 18, 824849, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0xC002), dst_ep=1, source_route=[0x1D27, 0xF27B], extended_timeout=True, tsn=58, profile_id=260, cluster_id=8, data=Serialized[b'\x01:\x04\xfed\x00'], tx_options=, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-23 13:04:18.825 DEBUG (MainThread) [zigpy.application] Max concurrency (8) reached, delaying request (3669 enqueued)
2024-09-23 13:04:18.826 DEBUG (MainThread) [zha.application.platforms] b0:ce:18:14:00:17:f4:fd-1: setting transitioning flag to True
2024-09-23 13:04:18.827 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2024-09-23 13:04:18.828 DEBUG (MainThread) [zigpy.zcl] [0x0BC5:1:0x0008] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=, is_manufacturer_specific=False, direction=, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=46, command_id=4, *direction=)
2024-09-23 13:04:18.829 DEBUG (MainThread) [zigpy.zcl] [0x0BC5:1:0x0008] Sending request: move_to_level_with_on_off(level=254, transition_time=100)
2024-09-23 13:04:18.829 DEBUG (MainThread) [zigpy.device] [0x0bc5] Extending timeout for 0x2e request
2024-09-23 13:04:18.830 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 23, 17, 4, 18, 830015, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=, address=0x0BC5), dst_ep=1, source_route=[0xA4E0], extended_timeout=True, tsn=46, profile_id=260, cluster_id=8, data=Serialized[b'\x01.\x04\xfed\x00'], tx_options=, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-23 13:04:18.830 DEBUG (MainThread) [zigpy.application] Max concurrency (8) reached, delaying request (3670 enqueued)
```