Trying to understand inconsistent values between HA history and InfluxDB recorded values

I’m seeing some odd behavior from HA that I don’t understand. I have five HVAC thermostats connected into HA via the homekit-controller integration. Furthermore, I have the InfluxDB integration configured to log all state changes to an InfluxDB instance that I monitor via a few Grafana dashboards.

My confusion comes from the Homekit entities receiving updated values in InfluxDB, but not in HA.

Here is an example from the last 24 hours… because I’m a new user, I can only post one photo, which I’ve put at the end.

Looking at the “current temperature” state history for one of the thermostats in HA shows a constant value from about 2AM onward (this is inaccurate). This can be seen on the top half of my attached image.

I assumed this was due to some sort of communication issue with the thermostat, but if I look at the same value in InfluxDB with a query of:

from(bucket: "home_assistant")
  |> range(start: v.timeRangeStart, stop: v.timeRangeStop)
  |> filter(fn: (r) => r["_measurement"] == "climate.mysa_xxxxxx_thermostat")
  |> filter(fn: (r) => r["_field"] == "current_temperature")

I get the a display like in the bottom half of the attached image, with many more updated values over the last 24 hours.

I take this to mean that HA is in fact seeing the updated values, because they’re making it into my InfluxDB, but for some reason the values shown in HA are not updated…

Any idea what’s going on here, or how I could debug further? TIA!

Just to clarify, the InfluxDB state logging is coming from Home Assistant?

Yes, that’s correct. HA is sending the values to InfluxDB, where I can then chart them and they look as expected. That’s why I’m a bit flummoxed, since the values look wrong inside HA itself, but it must be getting the correct values since it’s sending them to influx…

Yeah that is weird. Try clearing your web browser cache and reloading the history graph. Or try in a private browsing tab.

Unfortunately, no. I just tried, and still see the same behavior (HA History on top in Incognito, and Grafana pulling from InfluxDB on the bottom – for the same climate device looking at the current_temperature entity):

It does not look like the history for that entity is being recorded at all now.

Did you exclude it from the recorder?

Do you have database or recorder errors in Settings → System → Logs?

Did you exclude it from the recorder?

If so, I certainly didn’t mean to or remember how/if I did that

Do you have database or recorder errors in Settings → System → Logs?

I don’t see any database or recorder issues. I see a couple lines related to homekit, but I’m not sure if they’re relevant:

Logger: homeassistant.components.homekit_controller.connection
Source: components/homekit_controller/connection.py:744
Integration: HomeKit Device (documentation, issues)
First occurred: 1:01:10 AM (2 occurrences)
Last logged: 1:38:10 AM

HomeKit device update skipped as previous poll still in flight: 93:A8:5B:FF:F0:23
Logger: aiohomekit.utils
Source: /usr/local/lib/python3.11/site-packages/aiohomekit/utils.py:45
First occurred: October 16, 2023 at 1:17:54 AM (10 occurrences)
Last logged: 1:20:01 AM

Failure running background task: Task-83372
Failure running background task: Task-85144
Failure running background task: Task-259741
Failure running background task: Task-260523
Failure running background task: Task-260860
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
Logger: aiohomekit.utils
Source: /usr/local/lib/python3.11/site-packages/aiohomekit/utils.py:45
First occurred: October 16, 2023 at 1:12:50 AM (22 occurrences)
Last logged: 1:19:42 AM

Failure running background task: Task-85932
Failure running background task: Task-259743
Failure running background task: Task-260525
Failure running background task: Task-260558
Failure running background task: Task-260864
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 192.168.xxx.xxx:57959

A little bit more info… I opened up the HA database directly, and found the entity in question:

SELECT * from states_meta where metadata_id = 203;
metadata_id entity_id
203 sensor.mysa_xxxxxx_current_temperature

If I probe the states table directly, I only see intermittent values in there:

SELECT datetime(last_updated_ts,'unixepoch') as 'last_updated_ts', state_id, state, metadata_id
FROM states where metadata_id = 203 
ORDER BY last_updated_ts DESC 
LIMIT 5;
last_updated_ts state_id state metadata_id
2023-10-16 07:02:24 1958758 65.1 203
2023-10-16 05:56:49 1958299 65.3 203
2023-10-16 03:37:19 1957245 65.5 203
2023-10-16 01:47:43 1956446 65.3 203
2023-10-16 01:00:33 1956172 65.1 203

Compare that to an Influx query:

from(bucket: "home_assistant")
  |> range(start: v.timeRangeStart, stop: v.timeRangeStop)
  |> filter(fn: (r) => r["_measurement"] == "climate.mysa_xxxxxx_thermostat")
  |> filter(fn: (r) => r["_field"] == "current_temperature")
  |> aggregateWindow(every: 5s, fn: last, createEmpty: false)
  |> yield(name: "last")

Which returns tons of values:

_time _value _field _measurement domain entity_id
2023-10-17T15:31:25Z 65 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T15:27:50Z 65 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T15:16:50Z 65 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T15:15:25Z 65 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T15:02:55Z 65 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T14:34:20Z 65 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T14:23:40Z 65 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T14:18:00Z 65 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T14:15:45Z 66 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T14:10:15Z 66 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T14:06:40Z 66 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T12:38:10Z 67 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T12:35:20Z 67 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T11:33:10Z 66 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T09:00:50Z 67 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T07:38:15Z 68 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T06:31:05Z 68 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat
2023-10-17T04:34:55Z 68 current_temperature climate.mysa_xxxxxx_thermostat climate mysa_xxxxxx_thermostat

I guess this isn’t much more info than I already knew from the plots, but shows that the data is not getting logged into the DB correctly, I think?

I’m surprised it’s getting to influxdb if this is your thermostat:

Timeout while waiting for connection to device 192.168.xxx.xxx:57959

It appears to be a different thermostat, but it could be related (I have five of these devices total).

I enabled Debug logging for the homekit integration and reloaded it, so I’ll keep watching it and see what happens.

It’s still very strange to me thought that HA would “see” these data points enough to send them out to Influx, but not to write them to it’s local DB

Are you sure you have the correct entity id then?

Yes, this issue is happening for all of them

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:

image

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

FYI, reported this bug here: Homekit device fails to update after connection times out · Issue #102258 · home-assistant/core · GitHub

1 Like

Good. That was my next suggestion. Your last post about the attributes explains the discrepancy between HA aand InfluxDB.

FYI: don’t use custom card charts to support your case. Only core cards. The team might blame it on the custom card and close the issue as outside their responsibility. You have core history charts there as well so it should be ok.

Thanks for the tip. It took a while, but I eventually realized that the state vs. attribute thing was the issue, and that happens regardless of the custom card, so hopefully they can work out why the sensors are not being updated after a disconnect.

1 Like