search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
71.85k stars 30.1k forks source link

RBSH-TRV0-ZB-EU pairing/connection unreliable #126280

Open jclsn opened 1 week ago

jclsn commented 1 week ago

The problem

I have owned this thermostat since beginning of the year and have only trouble with it using ZHA. In Z2M it seemed to be supported well, although I haven't run a long-term test.

These issues have been persisting since I got the device:

Now sending the ZHA permit doesn't even work anymore, not does the device pair. This used to work before. I have already returned the old device and Bosch sent me a new one, which exhibited the same behaviour. I have also bought another coordinator as I have a cheap CC2652 and bought a Sonoff ZBDongle-E, which is based on the same chipset, but I was hoping for better quality. It had the same issues, even after upgrading the Z-Stack firmware.

I have no issue with any other Zigbee device and afaik this is the only Zigbee 3.0 device that requires an install code, so I am assuming that the problem lies here somewhere.

What version of Home Assistant Core has the issue?

2024.9.2

What was the last working version of Home Assistant Core?

-

What type of installation are you running?

Home Assistant OS

Integration causing the issue

zha

Link to integration documentation on our website

No response

Diagnostics information

zha-2c83e557aa0cb39a5cd61efffc93193b-BOSCH RBSH-TRV0-ZB-EU-fe80d1ea03c48bd82887d783ad4337d7.json

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2024-09-18 21:50:27.640 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[active_power] value[0]
2024-09-18 21:50:27.640 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1291, attribute_name='active_power', attribute_value=0, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.641 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_current] value[0]
2024-09-18 21:50:27.642 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1288, attribute_name='rms_current', attribute_value=0, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.642 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_voltage] value[234]
2024-09-18 21:50:27.642 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1285, attribute_name='rms_voltage', attribute_value=234, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.643 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[active_power] value[active_power]
2024-09-18 21:50:27.643 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1291, attribute_name='active_power', attribute_value='active_power', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_current] value[rms_current]
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1288, attribute_name='rms_current', attribute_value='rms_current', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_voltage] value[rms_voltage]
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1285, attribute_name='rms_voltage', attribute_value='rms_voltage', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.645 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689027.633513, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0})
2024-09-18 21:50:27.647 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689027.633513, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.649 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.650 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:27.651 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1291, 'value': 0, 'timestamp': 1726689027.640479, 'min_update_delta': 30.0})
2024-09-18 21:50:27.653 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1291, 'value': 0, 'timestamp': 1726689027.640479, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.656 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.657 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:27.658 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1288, 'value': 0, 'timestamp': 1726689027.641681, 'min_update_delta': 30.0})
2024-09-18 21:50:27.660 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1288, 'value': 0, 'timestamp': 1726689027.641681, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.662 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.663 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:27.664 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1285, 'value': 234, 'timestamp': 1726689027.642516, 'min_update_delta': 30.0})
2024-09-18 21:50:27.665 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1285, 'value': 234, 'timestamp': 1726689027.642516, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.666 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.667 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:30.422 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2024-09-18 21:50:30.422 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x45C8:1:0x000d]: cluster_handler[analog_output] attribute_updated - cluster[TuyaTemperatureOffset] attr[present_value] value[0.6000000000000001]
2024-09-18 21:50:30.423 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=85, attribute_name='present_value', attribute_value=0.6000000000000001, cluster_handler_unique_id='cc:86:ec:ff:fe:c1:f8:a9:1:0x000d', cluster_id=13, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:30.423 DEBUG (MainThread) [zha] Emitting event state_changed with data EntityStateChangedEvent(event_type='entity', event='state_changed', platform=<Platform.NUMBER: 'number'>, unique_id='cc:86:ec:ff:fe:c1:f8:a9-1-13', device_ieee=cc:86:ec:ff:fe:c1:f8:a9, endpoint_id=1, group_id=None) (1 listeners)
2024-09-18 21:50:30.423 DEBUG (MainThread) [homeassistant.components.zha.entity] number.thermostat_schlafzimmer_number_temperature_offset: Handling event from entity: EntityStateChangedEvent(event_type='entity', event='state_changed', platform=<Platform.NUMBER: 'number'>, unique_id='cc:86:ec:ff:fe:c1:f8:a9-1-13', device_ieee=cc:86:ec:ff:fe:c1:f8:a9, endpoint_id=1, group_id=None)
2024-09-18 21:50:30.424 DEBUG (MainThread) [zigpy.zcl] [0x45C8:1:0xef00] Sending request header: ZCLHeader(frame_control=FrameControl<0x05>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=True, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), manufacturer=4098, tsn=21, command_id=0, *direction=<Direction.Client_to_Server: 0>)
2024-09-18 21:50:30.425 DEBUG (MainThread) [zigpy.zcl] [0x45C8:1:0xef00] Sending request: set_data(param=Command(status=0, tsn=21, command_id=539, function=0, data=0))
2024-09-18 21:50:30.426 DEBUG (MainThread) [zigpy_znp.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 18, 19, 50, 30, 426296, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x45C8), dst_ep=1, source_route=None, extended_timeout=False, tsn=21, profile_id=260, cluster_id=61184, data=Serialized[b'\x05\x02\x10\x15\x00\x00\x15\x1b\x02\x00\x04\x00\x00\x00\x00'], tx_options=<TransmitOptions.ACK: 1>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-18 21:50:30.429 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x45C8), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=61184, TSN=21, Options=<TransmitOptions.ACK_REQUEST|SUPPRESS_ROUTE_DISC_NETWORK: 48>, Radius=0, Data=b'\x05\x02\x10\x15\x00\x00\x15\x1B\x02\x00\x04\x00\x00\x00\x00')
2024-09-18 21:50:30.430 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': cc:86:ec:ff:fe:c1:f8:a9, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 13, 'attr_id': 85, 'value': 0.6000000000000001, 'timestamp': 1726689030.422702, 'min_update_delta': 30.0})
2024-09-18 21:50:30.431 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': cc:86:ec:ff:fe:c1:f8:a9, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 13, 'attr_id': 85, 'value': 0.6000000000000001, 'timestamp': 1726689030.422702, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:30.432 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:30.433 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:30.450 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2024-09-18 21:50:31.560 DEBUG (MainThread) [zha.decorators] [<Task pending name='sensor_state_poller_a4:c1:38:ca:0a:c0:de:4f-1-1794-summation_delivered_PolledSmartEnergySummation' coro=<periodic.<locals>.scheduler.<locals>.wrapper() running at /usr/local/lib/python3.12/site-packages/zha/decorators.py:78> cb=[set.remove()]>] executing periodic task [zha.application.platforms.sensor::PollableSensor._refresh]
2024-09-18 21:50:31.561 DEBUG (MainThread) [zha.application.platforms] a4:c1:38:ca:0a:c0:de:4f-1-1794-summation_delivered: polling for updated state
2024-09-18 21:50:31.561 DEBUG (MainThread) [zha.application.platforms] a4:c1:38:ca:0a:c0:de:4f-1-1794-summation_delivered: polling current state
2024-09-18 21:50:31.562 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: async_update
2024-09-18 21:50:31.562 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: Reading attributes in chunks: ['current_summ_delivered', 'status']
2024-09-18 21:50:31.564 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl<0x00>(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=82, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Client_to_Server: 0>)
2024-09-18 21:50:31.566 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Sending request: Read_Attributes(attribute_ids=[0, 512])
2024-09-18 21:50:31.568 DEBUG (MainThread) [zigpy_znp.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 18, 19, 50, 31, 568794, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x1FEE), dst_ep=1, source_route=None, extended_timeout=False, tsn=82, profile_id=260, cluster_id=1794, data=Serialized[b'\x00R\x00\x00\x00\x00\x02'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-18 21:50:31.571 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x1FEE), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=1794, TSN=82, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=0, Data=b'\x00\x52\x00\x00\x00\x00\x02')
2024-09-18 21:50:31.592 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2024-09-18 21:50:31.595 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.SUCCESS: 0>, Endpoint=1, TSN=82)
2024-09-18 21:50:31.633 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=1794, SrcAddr=0x1FEE, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=116, SecurityUse=<Bool.false: 0>, TimeStamp=12664075, TSN=0, Data=b'\x18\x52\x01\x00\x00\x00\x25\xA9\x15\x00\x00\x00\x00\x00\x02\x00\x18\x00', MacSrcAddr=0x1FEE, MsgResultRadius=29)
2024-09-18 21:50:31.634 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 9, 18, 19, 50, 31, 634852, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x1FEE), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=1794, data=Serialized[b'\x18R\x01\x00\x00\x00%\xa9\x15\x00\x00\x00\x00\x00\x02\x00\x18\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=116, rssi=None)
2024-09-18 21:50:31.637 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Received ZCL frame: b'\x18R\x01\x00\x00\x00%\xa9\x15\x00\x00\x00\x00\x00\x02\x00\x18\x00'
2024-09-18 21:50:31.638 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x18>(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=82, command_id=1, *direction=<Direction.Server_to_Client: 1>)
2024-09-18 21:50:31.642 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Decoded ZCL frame: TuyaZBMeteringCluster:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0, status=<Status.SUCCESS: 0>, value=TypeValue(type=uint48_t, value=5545)), ReadAttributeRecord(attrid=512, status=<Status.SUCCESS: 0>, value=TypeValue(type=bitmap8, value=<bitmap8: 0>))])
2024-09-18 21:50:31.644 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[current_summ_delivered] value[5545]
2024-09-18 21:50:31.644 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=0, attribute_name='current_summ_delivered', attribute_value=5545, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[status] value[0]
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=512, attribute_name='status', attribute_value=<bitmap8: 0>, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[current_summ_delivered] value[current_summ_delivered]
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=0, attribute_name='current_summ_delivered', attribute_value='current_summ_delivered', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[status] value[status]
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=512, attribute_name='status', attribute_value='status', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.650 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689031.634852, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0})
2024-09-18 21:50:31.653 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689031.634852, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:31.655 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:31.655 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:31.657 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 0, 'value': 5545, 'timestamp': 1726689031.643816, 'min_update_delta': 30.0})
2024-09-18 21:50:31.658 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 0, 'value': 5545, 'timestamp': 1726689031.643816, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:31.660 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:31.662 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:31.663 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 512, 'value': <bitmap8: 0>, 'timestamp': 1726689031.644957, 'min_update_delta': 30.0})
2024-09-18 21:50:31.665 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 512, 'value': <bitmap8: 0>, 'timestamp': 1726689031.644957, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:31.666 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:31.666 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed2024-09-18 21:50:27.640 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[active_power] value[0]
2024-09-18 21:50:27.640 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1291, attribute_name='active_power', attribute_value=0, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.641 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_current] value[0]
2024-09-18 21:50:27.642 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1288, attribute_name='rms_current', attribute_value=0, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.642 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_voltage] value[234]
2024-09-18 21:50:27.642 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1285, attribute_name='rms_voltage', attribute_value=234, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.643 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[active_power] value[active_power]
2024-09-18 21:50:27.643 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1291, attribute_name='active_power', attribute_value='active_power', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_current] value[rms_current]
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1288, attribute_name='rms_current', attribute_value='rms_current', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_voltage] value[rms_voltage]
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1285, attribute_name='rms_voltage', attribute_value='rms_voltage', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.645 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689027.633513, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0})
2024-09-18 21:50:27.647 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689027.633513, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.649 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.650 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:27.651 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1291, 'value': 0, 'timestamp': 1726689027.640479, 'min_update_delta': 30.0})
2024-09-18 21:50:27.653 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1291, 'value': 0, 'timestamp': 1726689027.640479, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.656 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.657 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:27.658 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1288, 'value': 0, 'timestamp': 1726689027.641681, 'min_update_delta': 30.0})
2024-09-18 21:50:27.660 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1288, 'value': 0, 'timestamp': 1726689027.641681, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.662 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.663 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:27.664 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1285, 'value': 234, 'timestamp': 1726689027.642516, 'min_update_delta': 30.0})
2024-09-18 21:50:27.665 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1285, 'value': 234, 'timestamp': 1726689027.642516, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.666 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.667 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:30.422 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2024-09-18 21:50:30.422 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x45C8:1:0x000d]: cluster_handler[analog_output] attribute_updated - cluster[TuyaTemperatureOffset] attr[present_value] value[0.6000000000000001]
2024-09-18 21:50:30.423 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=85, attribute_name='present_value', attribute_value=0.6000000000000001, cluster_handler_unique_id='cc:86:ec:ff:fe:c1:f8:a9:1:0x000d', cluster_id=13, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:30.423 DEBUG (MainThread) [zha] Emitting event state_changed with data EntityStateChangedEvent(event_type='entity', event='state_changed', platform=<Platform.NUMBER: 'number'>, unique_id='cc:86:ec:ff:fe:c1:f8:a9-1-13', device_ieee=cc:86:ec:ff:fe:c1:f8:a9, endpoint_id=1, group_id=None) (1 listeners)
2024-09-18 21:50:30.423 DEBUG (MainThread) [homeassistant.components.zha.entity] number.thermostat_schlafzimmer_number_temperature_offset: Handling event from entity: EntityStateChangedEvent(event_type='entity', event='state_changed', platform=<Platform.NUMBER: 'number'>, unique_id='cc:86:ec:ff:fe:c1:f8:a9-1-13', device_ieee=cc:86:ec:ff:fe:c1:f8:a9, endpoint_id=1, group_id=None)
2024-09-18 21:50:30.424 DEBUG (MainThread) [zigpy.zcl] [0x45C8:1:0xef00] Sending request header: ZCLHeader(frame_control=FrameControl<0x05>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=True, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), manufacturer=4098, tsn=21, command_id=0, *direction=<Direction.Client_to_Server: 0>)
2024-09-18 21:50:30.425 DEBUG (MainThread) [zigpy.zcl] [0x45C8:1:0xef00] Sending request: set_data(param=Command(status=0, tsn=21, command_id=539, function=0, data=0))
2024-09-18 21:50:30.426 DEBUG (MainThread) [zigpy_znp.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 18, 19, 50, 30, 426296, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x45C8), dst_ep=1, source_route=None, extended_timeout=False, tsn=21, profile_id=260, cluster_id=61184, data=Serialized[b'\x05\x02\x10\x15\x00\x00\x15\x1b\x02\x00\x04\x00\x00\x00\x00'], tx_options=<TransmitOptions.ACK: 1>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-18 21:50:30.429 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x45C8), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=61184, TSN=21, Options=<TransmitOptions.ACK_REQUEST|SUPPRESS_ROUTE_DISC_NETWORK: 48>, Radius=0, Data=b'\x05\x02\x10\x15\x00\x00\x15\x1B\x02\x00\x04\x00\x00\x00\x00')
2024-09-18 21:50:30.430 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': cc:86:ec:ff:fe:c1:f8:a9, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 13, 'attr_id': 85, 'value': 0.6000000000000001, 'timestamp': 1726689030.422702, 'min_update_delta': 30.0})
2024-09-18 21:50:30.431 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': cc:86:ec:ff:fe:c1:f8:a9, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 13, 'attr_id': 85, 'value': 0.6000000000000001, 'timestamp': 1726689030.422702, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:30.432 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:30.433 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:30.450 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2024-09-18 21:50:31.560 DEBUG (MainThread) [zha.decorators] [<Task pending name='sensor_state_poller_a4:c1:38:ca:0a:c0:de:4f-1-1794-summation_delivered_PolledSmartEnergySummation' coro=<periodic.<locals>.scheduler.<locals>.wrapper() running at /usr/local/lib/python3.12/site-packages/zha/decorators.py:78> cb=[set.remove()]>] executing periodic task [zha.application.platforms.sensor::PollableSensor._refresh]
2024-09-18 21:50:31.561 DEBUG (MainThread) [zha.application.platforms] a4:c1:38:ca:0a:c0:de:4f-1-1794-summation_delivered: polling for updated state
2024-09-18 21:50:31.561 DEBUG (MainThread) [zha.application.platforms] a4:c1:38:ca:0a:c0:de:4f-1-1794-summation_delivered: polling current state
2024-09-18 21:50:31.562 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: async_update
2024-09-18 21:50:31.562 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: Reading attributes in chunks: ['current_summ_delivered', 'status']
2024-09-18 21:50:31.564 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl<0x00>(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=82, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Client_to_Server: 0>)
2024-09-18 21:50:31.566 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Sending request: Read_Attributes(attribute_ids=[0, 512])
2024-09-18 21:50:31.568 DEBUG (MainThread) [zigpy_znp.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 18, 19, 50, 31, 568794, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x1FEE), dst_ep=1, source_route=None, extended_timeout=False, tsn=82, profile_id=260, cluster_id=1794, data=Serialized[b'\x00R\x00\x00\x00\x00\x02'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-18 21:50:31.571 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x1FEE), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=1794, TSN=82, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=0, Data=b'\x00\x52\x00\x00\x00\x00\x02')
2024-09-18 21:50:31.592 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2024-09-18 21:50:31.595 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.SUCCESS: 0>, Endpoint=1, TSN=82)
2024-09-18 21:50:31.633 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=1794, SrcAddr=0x1FEE, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=116, SecurityUse=<Bool.false: 0>, TimeStamp=12664075, TSN=0, Data=b'\x18\x52\x01\x00\x00\x00\x25\xA9\x15\x00\x00\x00\x00\x00\x02\x00\x18\x00', MacSrcAddr=0x1FEE, MsgResultRadius=29)
2024-09-18 21:50:31.634 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 9, 18, 19, 50, 31, 634852, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x1FEE), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=1794, data=Serialized[b'\x18R\x01\x00\x00\x00%\xa9\x15\x00\x00\x00\x00\x00\x02\x00\x18\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=116, rssi=None)
2024-09-18 21:50:31.637 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Received ZCL frame: b'\x18R\x01\x00\x00\x00%\xa9\x15\x00\x00\x00\x00\x00\x02\x00\x18\x00'
2024-09-18 21:50:31.638 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x18>(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=82, command_id=1, *direction=<Direction.Server_to_Client: 1>)
2024-09-18 21:50:31.642 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Decoded ZCL frame: TuyaZBMeteringCluster:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0, status=<Status.SUCCESS: 0>, value=TypeValue(type=uint48_t, value=5545)), ReadAttributeRecord(attrid=512, status=<Status.SUCCESS: 0>, value=TypeValue(type=bitmap8, value=<bitmap8: 0>))])
2024-09-18 21:50:31.644 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[current_summ_delivered] value[5545]
2024-09-18 21:50:31.644 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=0, attribute_name='current_summ_delivered', attribute_value=5545, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[status] value[0]
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=512, attribute_name='status', attribute_value=<bitmap8: 0>, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[current_summ_delivered] value[current_summ_delivered]
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=0, attribute_name='current_summ_delivered', attribute_value='current_summ_delivered', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[status] value[status]
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=512, attribute_name='status', attribute_value='status', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.650 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689031.634852, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0})
2024-09-18 21:50:31.653 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689031.634852, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:31.655 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:31.655 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:31.657 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 0, 'value': 5545, 'timestamp': 1726689031.643816, 'min_update_delta': 30.0})
2024-09-18 21:50:31.658 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 0, 'value': 5545, 'timestamp': 1726689031.643816, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:31.660 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:31.662 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:31.663 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 512, 'value': <bitmap8: 0>, 'timestamp': 1726689031.644957, 'min_update_delta': 30.0})
2024-09-18 21:50:31.665 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 512, 'value': <bitmap8: 0>, 'timestamp': 1726689031.644957, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:31.666 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:31.666 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed2024-09-18 21:50:27.640 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[active_power] value[0]
2024-09-18 21:50:27.640 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1291, attribute_name='active_power', attribute_value=0, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.641 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_current] value[0]
2024-09-18 21:50:27.642 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1288, attribute_name='rms_current', attribute_value=0, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.642 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_voltage] value[234]
2024-09-18 21:50:27.642 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1285, attribute_name='rms_voltage', attribute_value=234, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.643 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[active_power] value[active_power]
2024-09-18 21:50:27.643 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1291, attribute_name='active_power', attribute_value='active_power', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_current] value[rms_current]
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1288, attribute_name='rms_current', attribute_value='rms_current', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0b04]: cluster_handler[electrical_measurement] attribute_updated - cluster[Electrical Measurement] attr[rms_voltage] value[rms_voltage]
2024-09-18 21:50:27.644 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=1285, attribute_name='rms_voltage', attribute_value='rms_voltage', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0b04', cluster_id=2820, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (3 listeners)
2024-09-18 21:50:27.645 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689027.633513, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0})
2024-09-18 21:50:27.647 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689027.633513, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.649 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.650 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:27.651 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1291, 'value': 0, 'timestamp': 1726689027.640479, 'min_update_delta': 30.0})
2024-09-18 21:50:27.653 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1291, 'value': 0, 'timestamp': 1726689027.640479, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.656 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.657 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:27.658 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1288, 'value': 0, 'timestamp': 1726689027.641681, 'min_update_delta': 30.0})
2024-09-18 21:50:27.660 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1288, 'value': 0, 'timestamp': 1726689027.641681, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.662 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.663 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:27.664 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1285, 'value': 234, 'timestamp': 1726689027.642516, 'min_update_delta': 30.0})
2024-09-18 21:50:27.665 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 2820, 'attr_id': 1285, 'value': 234, 'timestamp': 1726689027.642516, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:27.666 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:27.667 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:30.422 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2024-09-18 21:50:30.422 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x45C8:1:0x000d]: cluster_handler[analog_output] attribute_updated - cluster[TuyaTemperatureOffset] attr[present_value] value[0.6000000000000001]
2024-09-18 21:50:30.423 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=85, attribute_name='present_value', attribute_value=0.6000000000000001, cluster_handler_unique_id='cc:86:ec:ff:fe:c1:f8:a9:1:0x000d', cluster_id=13, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:30.423 DEBUG (MainThread) [zha] Emitting event state_changed with data EntityStateChangedEvent(event_type='entity', event='state_changed', platform=<Platform.NUMBER: 'number'>, unique_id='cc:86:ec:ff:fe:c1:f8:a9-1-13', device_ieee=cc:86:ec:ff:fe:c1:f8:a9, endpoint_id=1, group_id=None) (1 listeners)
2024-09-18 21:50:30.423 DEBUG (MainThread) [homeassistant.components.zha.entity] number.thermostat_schlafzimmer_number_temperature_offset: Handling event from entity: EntityStateChangedEvent(event_type='entity', event='state_changed', platform=<Platform.NUMBER: 'number'>, unique_id='cc:86:ec:ff:fe:c1:f8:a9-1-13', device_ieee=cc:86:ec:ff:fe:c1:f8:a9, endpoint_id=1, group_id=None)
2024-09-18 21:50:30.424 DEBUG (MainThread) [zigpy.zcl] [0x45C8:1:0xef00] Sending request header: ZCLHeader(frame_control=FrameControl<0x05>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=True, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), manufacturer=4098, tsn=21, command_id=0, *direction=<Direction.Client_to_Server: 0>)
2024-09-18 21:50:30.425 DEBUG (MainThread) [zigpy.zcl] [0x45C8:1:0xef00] Sending request: set_data(param=Command(status=0, tsn=21, command_id=539, function=0, data=0))
2024-09-18 21:50:30.426 DEBUG (MainThread) [zigpy_znp.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 18, 19, 50, 30, 426296, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x45C8), dst_ep=1, source_route=None, extended_timeout=False, tsn=21, profile_id=260, cluster_id=61184, data=Serialized[b'\x05\x02\x10\x15\x00\x00\x15\x1b\x02\x00\x04\x00\x00\x00\x00'], tx_options=<TransmitOptions.ACK: 1>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-18 21:50:30.429 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x45C8), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=61184, TSN=21, Options=<TransmitOptions.ACK_REQUEST|SUPPRESS_ROUTE_DISC_NETWORK: 48>, Radius=0, Data=b'\x05\x02\x10\x15\x00\x00\x15\x1B\x02\x00\x04\x00\x00\x00\x00')
2024-09-18 21:50:30.430 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': cc:86:ec:ff:fe:c1:f8:a9, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 13, 'attr_id': 85, 'value': 0.6000000000000001, 'timestamp': 1726689030.422702, 'min_update_delta': 30.0})
2024-09-18 21:50:30.431 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': cc:86:ec:ff:fe:c1:f8:a9, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 13, 'attr_id': 85, 'value': 0.6000000000000001, 'timestamp': 1726689030.422702, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:30.432 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:30.433 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:30.450 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2024-09-18 21:50:31.560 DEBUG (MainThread) [zha.decorators] [<Task pending name='sensor_state_poller_a4:c1:38:ca:0a:c0:de:4f-1-1794-summation_delivered_PolledSmartEnergySummation' coro=<periodic.<locals>.scheduler.<locals>.wrapper() running at /usr/local/lib/python3.12/site-packages/zha/decorators.py:78> cb=[set.remove()]>] executing periodic task [zha.application.platforms.sensor::PollableSensor._refresh]
2024-09-18 21:50:31.561 DEBUG (MainThread) [zha.application.platforms] a4:c1:38:ca:0a:c0:de:4f-1-1794-summation_delivered: polling for updated state
2024-09-18 21:50:31.561 DEBUG (MainThread) [zha.application.platforms] a4:c1:38:ca:0a:c0:de:4f-1-1794-summation_delivered: polling current state
2024-09-18 21:50:31.562 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: async_update
2024-09-18 21:50:31.562 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: Reading attributes in chunks: ['current_summ_delivered', 'status']
2024-09-18 21:50:31.564 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl<0x00>(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=82, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Client_to_Server: 0>)
2024-09-18 21:50:31.566 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Sending request: Read_Attributes(attribute_ids=[0, 512])
2024-09-18 21:50:31.568 DEBUG (MainThread) [zigpy_znp.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 9, 18, 19, 50, 31, 568794, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x1FEE), dst_ep=1, source_route=None, extended_timeout=False, tsn=82, profile_id=260, cluster_id=1794, data=Serialized[b'\x00R\x00\x00\x00\x00\x02'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-09-18 21:50:31.571 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x1FEE), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=1794, TSN=82, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=0, Data=b'\x00\x52\x00\x00\x00\x00\x02')
2024-09-18 21:50:31.592 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2024-09-18 21:50:31.595 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.SUCCESS: 0>, Endpoint=1, TSN=82)
2024-09-18 21:50:31.633 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=1794, SrcAddr=0x1FEE, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=116, SecurityUse=<Bool.false: 0>, TimeStamp=12664075, TSN=0, Data=b'\x18\x52\x01\x00\x00\x00\x25\xA9\x15\x00\x00\x00\x00\x00\x02\x00\x18\x00', MacSrcAddr=0x1FEE, MsgResultRadius=29)
2024-09-18 21:50:31.634 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 9, 18, 19, 50, 31, 634852, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x1FEE), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=1794, data=Serialized[b'\x18R\x01\x00\x00\x00%\xa9\x15\x00\x00\x00\x00\x00\x02\x00\x18\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=116, rssi=None)
2024-09-18 21:50:31.637 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Received ZCL frame: b'\x18R\x01\x00\x00\x00%\xa9\x15\x00\x00\x00\x00\x00\x02\x00\x18\x00'
2024-09-18 21:50:31.638 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x18>(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=82, command_id=1, *direction=<Direction.Server_to_Client: 1>)
2024-09-18 21:50:31.642 DEBUG (MainThread) [zigpy.zcl] [0x1FEE:1:0x0702] Decoded ZCL frame: TuyaZBMeteringCluster:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0, status=<Status.SUCCESS: 0>, value=TypeValue(type=uint48_t, value=5545)), ReadAttributeRecord(attrid=512, status=<Status.SUCCESS: 0>, value=TypeValue(type=bitmap8, value=<bitmap8: 0>))])
2024-09-18 21:50:31.644 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[current_summ_delivered] value[5545]
2024-09-18 21:50:31.644 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=0, attribute_name='current_summ_delivered', attribute_value=5545, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[status] value[0]
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=512, attribute_name='status', attribute_value=<bitmap8: 0>, cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[current_summ_delivered] value[current_summ_delivered]
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=0, attribute_name='current_summ_delivered', attribute_value='current_summ_delivered', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha.zigbee.cluster_handlers] [0x1FEE:1:0x0702]: cluster_handler[smartenergy_metering] attribute_updated - cluster[TuyaZBMeteringCluster] attr[status] value[status]
2024-09-18 21:50:31.645 DEBUG (MainThread) [zha] Emitting event cluster_handler_attribute_updated with data ClusterAttributeUpdatedEvent(attribute_id=512, attribute_name='status', attribute_value='status', cluster_handler_unique_id='a4:c1:38:ca:0a:c0:de:4f:1:0x0702', cluster_id=1794, event_type='cluster_handler_event', event='cluster_handler_attribute_updated') (1 listeners)
2024-09-18 21:50:31.650 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689031.634852, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0})
2024-09-18 21:50:31.653 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, 'UPDATE devices_v13\n                    SET last_seen=:ts\n                    WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1726689031.634852, 'ieee': a4:c1:38:ca:0a:c0:de:4f, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:31.655 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:31.655 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:31.657 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 0, 'value': 5545, 'timestamp': 1726689031.643816, 'min_update_delta': 30.0})
2024-09-18 21:50:31.658 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 0, 'value': 5545, 'timestamp': 1726689031.643816, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:31.660 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:31.662 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed
2024-09-18 21:50:31.663 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 512, 'value': <bitmap8: 0>, 'timestamp': 1726689031.644957, 'min_update_delta': 30.0})
2024-09-18 21:50:31.665 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f64ab35b0>, '\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': a4:c1:38:ca:0a:c0:de:4f, 'endpoint_id': 1, 'cluster_type': <ClusterType.Server: 0>, 'cluster_id': 1794, 'attr_id': 512, 'value': <bitmap8: 0>, 'timestamp': 1726689031.644957, 'min_update_delta': 30.0}) completed
2024-09-18 21:50:31.666 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>)
2024-09-18 21:50:31.666 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f64ab35b0>) completed

Additional information

No response

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)

puddly commented 1 week ago

The Sonoff E dongle uses a different firmware than the the CC2562. Have you tried the Sonoff E? Or just the Sonoff P, which has the same chip?

jclsn commented 1 week ago

Just looked, it is the Sonoff E. I just upgraded its firmware yesterday and migrated to it from the CC2652P. It took like 10 tries to pair and today it is not reacting anymore. Will try to upgrade the fimrware of the TRV as well with Z2M.

jclsn commented 1 week ago

Here is one log from a failed pairing/interview try

https://0x0.st/X3Re.log

jclsn commented 1 week ago

I now switched to channel 20 and it paired better. So far no issues for two days.

Another thing I have noticed: Pairing only works if I have completely deleted the device before. Overwriting an old configuration doesn't work.

jclsn commented 2 days ago

So it lasted a week and now the thermostat is again not responding anymore. I can set the temperature, but it is not sent to the thermostat. It also shows as idle although it should be active. The temperature reading is for some reason updated correctly.

image

I set the heating setpoint manually on the thermostat's interface and it is currently heating, but still showing as idle in HA.

I have written the debug log to a file, which has grown to 170MB meanwhile. Should I upload this file somewhere?