So after reloading the homekit integration for one of the thermostat devices, and turning on DEBUG logging, I think I might be onto a root cause, maybe… Overnight, it appears the thermostat stopped logging in HA, as the last temperature value recorded is at 11:33 PM, and the last humidity value at 12:59AM:

Meanwhile, if I look in the logs, the homekit integration continues to receive data from the thermostat after that time. Here are some logs extracted from when I opened the window this morning and the temperature fell from 21C (69.8F) to 20.8C (69.4F), as encoded in the values "iid":261
in the response:
...
2023-10-18 07:26:51.442 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":272,"value":36},{"aid":1,"iid":262,"value":25.5},{"aid":1,"iid":1027,"value":0},{"aid":1,"iid":259,"value":0},{"aid":1,"iid":261,"value":21},{"aid":1,"iid":1026,"value":0},{"aid":1,"iid":260,"value":0},{"aid":1,"iid":263,"value":1}]}')
2023-10-18 07:27:51.423 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":272,"value":36},{"aid":1,"iid":262,"value":25.5},{"aid":1,"iid":1027,"value":0},{"aid":1,"iid":259,"value":0},{"aid":1,"iid":261,"value":20.9},{"aid":1,"iid":1026,"value":0},{"aid":1,"iid":260,"value":0},{"aid":1,"iid":263,"value":1}]}')
2023-10-18 07:28:51.379 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":272,"value":36},{"aid":1,"iid":262,"value":25.5},{"aid":1,"iid":1027,"value":0},{"aid":1,"iid":259,"value":0},{"aid":1,"iid":261,"value":20.9},{"aid":1,"iid":1026,"value":0},{"aid":1,"iid":260,"value":0},{"aid":1,"iid":263,"value":1}]}')
2023-10-18 07:29:51.450 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":272,"value":36},{"aid":1,"iid":262,"value":25.5},{"aid":1,"iid":1027,"value":0},{"aid":1,"iid":259,"value":0},{"aid":1,"iid":261,"value":20.9},{"aid":1,"iid":1026,"value":0},{"aid":1,"iid":260,"value":0},{"aid":1,"iid":263,"value":1}]}')
2023-10-18 07:30:51.424 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":272,"value":36},{"aid":1,"iid":262,"value":25.5},{"aid":1,"iid":1027,"value":0},{"aid":1,"iid":259,"value":0},{"aid":1,"iid":261,"value":20.9},{"aid":1,"iid":1026,"value":0},{"aid":1,"iid":260,"value":0},{"aid":1,"iid":263,"value":1}]}')
2023-10-18 07:31:51.385 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":272,"value":36},{"aid":1,"iid":262,"value":25.5},{"aid":1,"iid":1027,"value":0},{"aid":1,"iid":259,"value":0},{"aid":1,"iid":261,"value":20.8},{"aid":1,"iid":1026,"value":0},{"aid":1,"iid":260,"value":0},{"aid":1,"iid":263,"value":1}]}')
2023-10-18 07:32:51.455 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":272,"value":36},{"aid":1,"iid":262,"value":25.5},{"aid":1,"iid":1027,"value":0},{"aid":1,"iid":259,"value":0},{"aid":1,"iid":261,"value":20.8},{"aid":1,"iid":1026,"value":0},{"aid":1,"iid":260,"value":0},{"aid":1,"iid":263,"value":1}]}')
2023-10-18 07:33:51.427 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":272,"value":36},{"aid":1,"iid":262,"value":25.5},{"aid":1,"iid":1027,"value":0},{"aid":1,"iid":259,"value":0},{"aid":1,"iid":261,"value":20.8},{"aid":1,"iid":1026,"value":0},{"aid":1,"iid":260,"value":0},{"aid":1,"iid":263,"value":1}]}')
...
So this perhaps partially explains why the values could still end up in Influx. The homekit integration is still properly reading values from the thermostat, even if they’re not being logged as state changes in HA.
With that observation, my next inquiry is to see what happens around 11:33PM or 12:59AM in the logs. At 11:33, there’s nothing of note. HA keeps reading thermostat values that are constant 71.4F (21.9C). Since the value isn’t changed, HA does not log a value (it seems to only log when the value changes). 12:59AM also doesn’t have anything interesting; it is just the last time the humidity value changes before an ERROR event at 1:02 AM. The below is the logs filtered for this thermostat’s IP (xxx.xxx.30.113
) and/or its identifier (93:A8:5B:xx:xx:xx
). It appears that at 01:02:46, HA lost connection to the thermostat, but it then regained connection since it received data at 01:03:51.059. So something about this “hiccup” causes it to stop logging entirely, even though it’s still receiving information. Is this a bug I should file somewhere?
2023-10-18 01:02:46.790 ERROR (MainThread) [aiohomekit.utils] Failure running background task: Task-375786
Traceback (most recent call last):
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/pairing.py", line 138, in _ensure_connected
await connection.ensure_connection()
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 293, in ensure_connection
await asyncio.shield(self._connector)
asyncio.exceptions.CancelledError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/pairing.py", line 137, in _ensure_connected
async with asyncio_timeout(10):
File "/usr/local/lib/python3.11/asyncio/timeouts.py", line 111, in __aexit__
raise TimeoutError from exc_val
TimeoutError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.11/site-packages/aiohomekit/utils.py", line 40, in _handle_task_result
task.result()
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/pairing.py", line 415, in _process_config_changed
await self.list_accessories_and_characteristics()
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/pairing.py", line 176, in list_accessories_and_characteristics
await self._ensure_connected()
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/pairing.py", line 144, in _ensure_connected
raise AccessoryDisconnectedError(
aiohomekit.exceptions.AccessoryDisconnectedError: Timeout while waiting for connection to device xxx.xxx.30.113:57959
2023-10-18 01:03:00.378 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
6 (State): (1 bytes/<class 'bytearray'>) 0x01
3 (PublicKey): (32 bytes/<class 'bytes'>) b'1e\xf47V \x1aH4\x84^\x8c0\xd2\r\x8c\xf4\t\x0b\xdcy\xd6\xcb#\x90k\xad\x8e\xa7\x05\x13q'
]
2023-10-18 01:03:05.771 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw request: b'POST /pair-verify HTTP/1.1\r\nHost: xxx.xxx.30.113\r\nContent-Length: 37\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x03 \xdc\xcc\xa0\xbex\xfb?(\x1f\xb8\xa2\xcc2\xf1\x1c \x10AOI\x8c\x04\xef\xf1\xf6\xa1T\xf5\xe7\xbe\x9bX'
2023-10-18 01:03:05.772 ERROR (MainThread) [aiohomekit.utils] Failure running background task: Task-375784
Traceback (most recent call last):
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 91, in send_bytes
return await result
^^^^^^^^^^^^
asyncio.exceptions.CancelledError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 90, in send_bytes
async with asyncio_timeout(30):
File "/usr/local/lib/python3.11/asyncio/timeouts.py", line 111, in __aexit__
raise TimeoutError from exc_val
TimeoutError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.11/site-packages/aiohomekit/utils.py", line 40, in _handle_task_result
task.result()
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/pairing.py", line 415, in _process_config_changed
await self.list_accessories_and_characteristics()
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/pairing.py", line 178, in list_accessories_and_characteristics
response = await self.connection.get_json("/accessories")
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 327, in get_json
response = await self.get(target)
^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 321, in get
return await self.request(
^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 476, in request
resp = await self.protocol.send_bytes(request_bytes)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 158, in send_bytes
return await super().send_bytes(b"".join(buffer))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 95, in send_bytes
raise AccessoryDisconnectedError("Timeout while waiting for response")
aiohomekit.exceptions.AccessoryDisconnectedError: Timeout while waiting for response
2023-10-18 01:03:06.274 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'\x06\x01\x02\x03 \xc6\xe6\xc5\xb03\xfb\x88 \x01P\\"\x98\xec\x9e\x14\xa0\xd3\xeb\x01\x1bC\x7f\x9f2Y\x878\x0e^*\x02\x05e\xa3\x13\xb2\x14q\xe3SC\x82\xd7\x1bH\x81\xe1|\x92EG\xbbP\xf7U\xebC\x99\x13\ra\x0e\xb0x\x85[\xa4\xb7\xa7\x071N_\xd6R\x1d\xa1/\x85x\xbe_\xeb\x88\x9dy\x94B/\x9a\n~9\xf1\x9c\x803\x9f\x96\x12\x92\xdf\x1d\x00t$\xe8\xc0^\xb8\x81ZfK\xe9\x10Pb\xb5g\xd2\x05\xef\xdc\x8b\xcca\xe1x\x1e\xb8\xafj\xc4')
2023-10-18 01:03:06.275 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
6 (State): (1 bytes/<class 'bytearray'>) 0x02
3 (PublicKey): (32 bytes/<class 'bytearray'>) 0xc6e6c5b033fb882001505c2298ec9e14a0d3eb011b437f9f325987380e5e2a02
5 (EncryptedData): (101 bytes/<class 'bytearray'>) 0xa313b21471e3534382d71b4881e17c924547bb50f755eb4399130d610eb078855ba4b7a707314e5fd6521da12f8578be5feb889d7994422f9a0a7e39f19c80339f961292df1d007424e8c05eb8815a664be9105062b567d205efdc8bcc61e1781eb8af6ac4
]
2023-10-18 01:03:06.322 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
1 (Identifier): (17 bytes/<class 'bytearray'>) 0x39333a41383a35423a46463a46303a3233
10 (Signature): (64 bytes/<class 'bytearray'>) 0xca6910c84530a784983ba5e7bd24e72b62344ad55a8ebfd295f9a6fbdd2c94c7f0b499276b0db97d52aaeb6ee206b4a7decbf1e67f3e1e49be0c29fa120ac709
]
2023-10-18 01:03:06.323 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
1 (Identifier): (36 bytes/<class 'bytes'>) b'a8699a5b-c0f3-4e78-9671-67a69b5550c8'
10 (Signature): (64 bytes/<class 'bytes'>) b'\x13z\xebZ|d\xc8G\xce8\xf5y\x03\xee\xcf$\x06Z9\xf1\'\x07\x86\x0e\x0e\nK\xd077:o\xe5\\\xe7\x16\xbeV.\xce\xde%"\x98\xa5C\xc0\xe7\xde\x7f\x9f.\xad\x8e\xc3B:\xab5\xbf\x9e~=\x08'
]
2023-10-18 01:03:06.325 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
6 (State): (1 bytes/<class 'bytearray'>) 0x03
5 (EncryptedData): (120 bytes/<class 'bytes'>) b'\n}\x92\r\x12\x1a\xa7\xb3m\x08\x0eL\x9b\xc94\xf1\x8b\x987`\xbarC\xa3\xb9\x1b\x8e\xcf\x85b\xc9\xbdqw\x10o\xff[\x84\x10\x06\x18\x12\x19\x1c\x11\xf4\xe7\xdb\xd1m[\x0c\x0b\x17\x9b\xc2\x93\x87\x80\x81\xddlYSF\xe3\xb0\xb9\x84\x1e\r\xfc\xecX\x8e=\xe8\xeaeo\x10ug?\xbd\xa4\xe0-\x1fC\x0f5\x8a\xac\xe2\x81\xe7\xb4~\xb2P\xec\x9a\xfc\xa81"\xe35\x15.b~^\xda\xed2ob'
]
2023-10-18 01:03:06.325 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw request: b'POST /pair-verify HTTP/1.1\r\nHost: xxx.xxx.30.113\r\nContent-Length: 125\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x03\x05x\n}\x92\r\x12\x1a\xa7\xb3m\x08\x0eL\x9b\xc94\xf1\x8b\x987`\xbarC\xa3\xb9\x1b\x8e\xcf\x85b\xc9\xbdqw\x10o\xff[\x84\x10\x06\x18\x12\x19\x1c\x11\xf4\xe7\xdb\xd1m[\x0c\x0b\x17\x9b\xc2\x93\x87\x80\x81\xddlYSF\xe3\xb0\xb9\x84\x1e\r\xfc\xecX\x8e=\xe8\xeaeo\x10ug?\xbd\xa4\xe0-\x1fC\x0f5\x8a\xac\xe2\x81\xe7\xb4~\xb2P\xec\x9a\xfc\xa81"\xe35\x15.b~^\xda\xed2ob'
2023-10-18 01:03:06.514 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'\x06\x01\x04')
2023-10-18 01:03:06.514 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
6 (State): (1 bytes/<class 'bytearray'>) 0x04
]
2023-10-18 01:03:06.515 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Secure connection to xxx.xxx.30.113:57959 established
2023-10-18 01:03:06.515 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{}
2023-10-18 01:03:06.515 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for 93:A8:5B:xx:xx:xx
2023-10-18 01:03:06.515 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for 93:A8:5B:xx:xx:xx
2023-10-18 01:03:06.516 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: xxx.xxx.30.113\r\nContent-Length: 263\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":272,"ev":true},{"aid":1,"iid":1027,"ev":true},{"aid":1,"iid":261,"ev":true},{"aid":1,"iid":262,"ev":true},{"aid":1,"iid":259,"ev":true},{"aid":1,"iid":1026,"ev":true},{"aid":1,"iid":260,"ev":true},{"aid":1,"iid":263,"ev":true}]}'
2023-10-18 01:03:06.549 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'')
2023-10-18 01:03:50.927 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for 93:A8:5B:xx:xx:xx
2023-10-18 01:03:50.927 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw request: b'GET /characteristics?id=1.272,1.262,1.1027,1.259,1.261,1.1026,1.260,1.263 HTTP/1.1\r\nHost: xxx.xxx.30.113\r\n\r\n'
2023-10-18 01:03:51.059 DEBUG (MainThread) [aiohomekit.controller.ip.connection] xxx.xxx.30.113: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":272,"value":35},{"aid":1,"iid":262,"value":25.5},{"aid":1,"iid":1027,"value":0},{"aid":1,"iid":259,"value":0},{"aid":1,"iid":261,"value":21.9},{"aid":1,"iid":1026,"value":0},{"aid":1,"iid":260,"value":0},{"aid":1,"iid":263,"value":1}]}')
2023-10-18 01:03:51.059 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for 93:A8:5B:xx:xx:xx
2023-10-18 01:03:51.060 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Finished HomeKit device update: 93:A8:5B:xx:xx:xx