Environment: Latest HA and Zigbee. End device is an ESP32-H2 (my code but based on the Espressif HA_on_off_light example).
The end device is registering withe ZHA and the two ‘devices’ - an on-off switch that the coordinator uses to turn on and off the LED on the ESP32-H2, and an ‘temperature sensor’ which is currently just an counter that increments every 2 seconds with the bounds set up by the temperature sensor cluster.
The HA can turn the light on and off correctly and I appear to be receiving the temperature sensor updates but the UI never changes.
The debug log showing the incoming temperature sensor updates is:
2023-12-26 15:59:27.504 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingSenderEui64Handler: [48:31:b7:ff:fe:c0:71:27]
2023-12-26 15:59:27.505 DEBUG (MainThread) [bellows.zigbee.application] Received incomingSenderEui64Handler frame with [48:31:b7:ff:fe:c0:71:27]
2023-12-26 15:59:27.509 DEBUG (MainThread) [bellows.uart] Data frame: b'2373b1a9112a15b658964e27a8159f499c63e366b5719874f5c61b8bfc7e16d5e8cf97197e'
2023-12-26 15:59:27.510 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2023-12-26 15:59:27.512 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1026, sourceEndpoint=2, destinationEndpoint=2, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_SOURCE_EUI64|APS_OPTION_DESTINATION_EUI64: 3392>, groupId=0, sequence=45), 196, -51, 0xbf58, 255, 255, b'\x00x\x02\x00\x00)r\x03']
2023-12-26 15:59:27.513 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1026, sourceEndpoint=2, destinationEndpoint=2, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_SOURCE_EUI64|APS_OPTION_DESTINATION_EUI64: 3392>, groupId=0, sequence=45), 196, -51, 0xbf58, 255, 255, b'\x00x\x02\x00\x00)r\x03']
2023-12-26 15:59:27.513 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 26, 4, 59, 27, 513519, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBF58), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=2, source_route=None, extended_timeout=False, tsn=45, profile_id=260, cluster_id=1026, data=Serialized[b'\x00x\x02\x00\x00)r\x03'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-51)
2023-12-26 15:59:27.515 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Received ZCL frame: b'\x00x\x02\x00\x00)r\x03'
2023-12-26 15:59:27.517 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=120, command_id=2, *direction=<Direction.Server_to_Client: 0>)
2023-12-26 15:59:27.519 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Decoded ZCL frame: TemperatureMeasurement:Write_Attributes(attributes=[Attribute(attrid=0x0000, value=TypeValue(type=int16s, value=882))])
2023-12-26 15:59:27.519 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Received command 0x02 (TSN 120): Write_Attributes(attributes=[Attribute(attrid=0x0000, value=TypeValue(type=int16s, value=882))])
2023-12-26 15:59:27.521 DEBUG (Thread-4) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f708b0e50>, 'UPDATE devices_v12\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1703566767.513519, 'ieee': 48:31:b7:ff:fe:c0:71:27, 'min_update_delta': 30.0})
2023-12-26 15:59:27.522 DEBUG (Thread-4) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f708b0e50>, 'UPDATE devices_v12\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1703566767.513519, 'ieee': 48:31:b7:ff:fe:c0:71:27, 'min_update_delta': 30.0}) completed
2023-12-26 15:59:27.523 DEBUG (Thread-4) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f708b0e50>)
2023-12-26 15:59:27.524 DEBUG (Thread-4) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f708b0e50>) completed
2023-12-26 15:59:29.481 DEBUG (MainThread) [zigpy.application] Feeding watchdog
2023-12-26 15:59:29.482 DEBUG (MainThread) [bellows.ezsp.protocol] Send command readCounters: ()
2023-12-26 15:59:29.482 DEBUG (MainThread) [bellows.uart] Sending: b'337021a9a52af7ae7e'
2023-12-26 15:59:29.499 DEBUG (MainThread) [bellows.uart] Data frame: b'3470a1a9a52a15b25494ec250c5593499c4e27abedce038bfdc66389fc7e3fa7ebcdde6f8fffc7dbd5d2698c4623a9ec763ba5ea758241984c2613b1e070381c0e07bbe5ca658a459a4d9e4f9ff7c3d9d46a35a2519048246b837e'
2023-12-26 15:59:29.500 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2023-12-26 15:59:29.501 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received readCounters: [[0, 13, 166, 166, 1, 0, 0, 0, 100, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]]
2023-12-26 15:59:29.502 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_FREE_BUFFERS: 3>,)
2023-12-26 15:59:29.506 DEBUG (MainThread) [bellows.uart] Sending: b'447121a9fe2a1635b57e'
2023-12-26 15:59:29.506 DEBUG (MainThread) [bellows.uart] Data frame: b'4470b5a9362a32c3996ab5929b1dce427e'
2023-12-26 15:59:29.507 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2023-12-26 15:59:29.508 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingSenderEui64Handler: [48:31:b7:ff:fe:c0:71:27]
2023-12-26 15:59:29.509 DEBUG (MainThread) [bellows.zigbee.application] Received incomingSenderEui64Handler frame with [48:31:b7:ff:fe:c0:71:27]
2023-12-26 15:59:29.511 DEBUG (MainThread) [bellows.uart] Data frame: b'5470b1a9112a15b658964e27a8159f499c60e366b5719874f5c61a8bfc7e16d4e8cf1c4f7e'
2023-12-26 15:59:29.511 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2023-12-26 15:59:29.512 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1026, sourceEndpoint=2, destinationEndpoint=2, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_SOURCE_EUI64|APS_OPTION_DESTINATION_EUI64: 3392>, groupId=0, sequence=46), 196, -51, 0xbf58, 255, 255, b'\x00y\x02\x00\x00)s\x03']
2023-12-26 15:59:29.513 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1026, sourceEndpoint=2, destinationEndpoint=2, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_SOURCE_EUI64|APS_OPTION_DESTINATION_EUI64: 3392>, groupId=0, sequence=46), 196, -51, 0xbf58, 255, 255, b'\x00y\x02\x00\x00)s\x03']
2023-12-26 15:59:29.513 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 26, 4, 59, 29, 513341, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBF58), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=2, source_route=None, extended_timeout=False, tsn=46, profile_id=260, cluster_id=1026, data=Serialized[b'\x00y\x02\x00\x00)s\x03'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-51)
2023-12-26 15:59:29.514 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Received ZCL frame: b'\x00y\x02\x00\x00)s\x03'
2023-12-26 15:59:29.515 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=121, command_id=2, *direction=<Direction.Server_to_Client: 0>)
2023-12-26 15:59:29.516 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Decoded ZCL frame: TemperatureMeasurement:Write_Attributes(attributes=[Attribute(attrid=0x0000, value=TypeValue(type=int16s, value=883))])
2023-12-26 15:59:29.516 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Received command 0x02 (TSN 121): Write_Attributes(attributes=[Attribute(attrid=0x0000, value=TypeValue(type=int16s, value=883))])
2023-12-26 15:59:29.517 DEBUG (Thread-4) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f708b0e50>, 'UPDATE devices_v12\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1703566769.513341, 'ieee': 48:31:b7:ff:fe:c0:71:27, 'min_update_delta': 30.0})
2023-12-26 15:59:29.518 DEBUG (MainThread) [bellows.uart] Data frame: b'6571a1a9fe2a15b3a37dbf7e'
2023-12-26 15:59:29.518 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2023-12-26 15:59:29.519 DEBUG (Thread-4) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f708b0e50>, 'UPDATE devices_v12\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1703566769.513341, 'ieee': 48:31:b7:ff:fe:c0:71:27, 'min_update_delta': 30.0}) completed
2023-12-26 15:59:29.519 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b'\xfa']
2023-12-26 15:59:29.520 DEBUG (MainThread) [bellows.zigbee.application] Free buffers status EzspStatus.SUCCESS, value: 250
2023-12-26 15:59:29.520 DEBUG (MainThread) [bellows.zigbee.application] ezsp_counters: [MAC_RX_BROADCAST = 75, MAC_TX_BROADCAST = 137, MAC_RX_UNICAST = 1515, MAC_TX_UNICAST_SUCCESS = 1588, MAC_TX_UNICAST_RETRY = 510, MAC_TX_UNICAST_FAILED = 151, APS_DATA_RX_BROADCAST = 5, APS_DATA_TX_BROADCAST = 5, APS_DATA_RX_UNICAST = 908, APS_DATA_TX_UNICAST_SUCCESS = 22, APS_DATA_TX_UNICAST_RETRY = 0, APS_DATA_TX_UNICAST_FAILED = 9, ROUTE_DISCOVERY_INITIATED = 0, NEIGHBOR_ADDED = 0, NEIGHBOR_REMOVED = 0, NEIGHBOR_STALE = 0, JOIN_INDICATION = 1, CHILD_REMOVED = 0, ASH_OVERFLOW_ERROR = 0, ASH_FRAMING_ERROR = 0, ASH_OVERRUN_ERROR = 0, NWK_FRAME_COUNTER_FAILURE = 0, APS_FRAME_COUNTER_FAILURE = 0, UTILITY = 0, APS_LINK_KEY_NOT_AUTHORIZED = 0, NWK_DECRYPTION_FAILURE = 0, APS_DECRYPTION_FAILURE = 0, ALLOCATE_PACKET_BUFFER_FAILURE = 0, RELAYED_UNICAST = 0, PHY_TO_MAC_QUEUE_LIMIT_REACHED = 0, PACKET_VALIDATE_LIBRARY_DROPPED_COUNT = 0, TYPE_NWK_RETRY_OVERFLOW = 0, PHY_CCA_FAIL_COUNT = 0, BROADCAST_TABLE_FULL = 0, PTA_LO_PRI_REQUESTED = 0, PTA_HI_PRI_REQUESTED = 0, PTA_LO_PRI_DENIED = 0, PTA_HI_PRI_DENIED = 0, PTA_LO_PRI_TX_ABORTED = 0, PTA_HI_PRI_TX_ABORTED = 0, ADDRESS_CONFLICT_SENT = 0, EZSP_FREE_BUFFERS = 250]
2023-12-26 15:59:29.521 DEBUG (Thread-4) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f708b0e50>)
2023-12-26 15:59:29.522 DEBUG (Thread-4) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f708b0e50>) completed
2023-12-26 15:59:31.503 DEBUG (MainThread) [bellows.uart] Data frame: b'7571b5a9362a32c3996ab5929b1dab787e'
2023-12-26 15:59:31.504 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2023-12-26 15:59:31.506 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingSenderEui64Handler: [48:31:b7:ff:fe:c0:71:27]
2023-12-26 15:59:31.507 DEBUG (MainThread) [bellows.zigbee.application] Received incomingSenderEui64Handler frame with [48:31:b7:ff:fe:c0:71:27]
2023-12-26 15:59:31.509 DEBUG (MainThread) [bellows.uart] Data frame: b'0571b1a9112a15b658964e27a8159f499c61e366b5719874f5c6198bfc7e16d3e8cf5e0d7e'
2023-12-26 15:59:31.509 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2023-12-26 15:59:31.511 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1026, sourceEndpoint=2, destinationEndpoint=2, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_SOURCE_EUI64|APS_OPTION_DESTINATION_EUI64: 3392>, groupId=0, sequence=47), 196, -51, 0xbf58, 255, 255, b'\x00z\x02\x00\x00)t\x03']
2023-12-26 15:59:31.511 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=1026, sourceEndpoint=2, destinationEndpoint=2, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_SOURCE_EUI64|APS_OPTION_DESTINATION_EUI64: 3392>, groupId=0, sequence=47), 196, -51, 0xbf58, 255, 255, b'\x00z\x02\x00\x00)t\x03']
2023-12-26 15:59:31.512 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 26, 4, 59, 31, 512562, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xBF58), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=2, source_route=None, extended_timeout=False, tsn=47, profile_id=260, cluster_id=1026, data=Serialized[b'\x00z\x02\x00\x00)t\x03'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-51)
2023-12-26 15:59:31.514 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Received ZCL frame: b'\x00z\x02\x00\x00)t\x03'
2023-12-26 15:59:31.515 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=122, command_id=2, *direction=<Direction.Server_to_Client: 0>)
2023-12-26 15:59:31.517 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Decoded ZCL frame: TemperatureMeasurement:Write_Attributes(attributes=[Attribute(attrid=0x0000, value=TypeValue(type=int16s, value=884))])
2023-12-26 15:59:31.518 DEBUG (MainThread) [zigpy.zcl] [0xBF58:2:0x0402] Received command 0x02 (TSN 122): Write_Attributes(attributes=[Attribute(attrid=0x0000, value=TypeValue(type=int16s, value=884))])
2023-12-26 15:59:31.520 DEBUG (Thread-4) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f708b0e50>, 'UPDATE devices_v12\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1703566771.512562, 'ieee': 48:31:b7:ff:fe:c0:71:27, 'min_update_delta': 30.0})
2023-12-26 15:59:31.521 DEBUG (Thread-4) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f708b0e50>, 'UPDATE devices_v12\n SET last_seen=:ts\n WHERE ieee=:ieee AND :ts - last_seen > :min_update_delta', {'ts': 1703566771.512562, 'ieee': 48:31:b7:ff:fe:c0:71:27, 'min_update_delta': 30.0}) completed
2023-12-26 15:59:31.524 DEBUG (Thread-4) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f708b0e50>)
2023-12-26 15:59:31.524 DEBUG (Thread-4) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f708b0e50>) completed
The way I read that is the update is being received and is triggering some SQL update (and looking at the database I can see the record being updated every 30 seconds) but the UI does not update at all, even after 20+ minutes.
Any suggestions as to what I’m doing incorrectly to not have the UI updated?
Susan