aiohomekit icon indicating copy to clipboard operation
aiohomekit copied to clipboard

Configuration characteristics do not seem to update on external changes

Open M10tech opened this issue 10 months ago • 17 comments

[TL;DR this happens after an update of the configuration number of the accessory. Quick fix: disable and enable the device]

Currently I am testing the HK controller and using custom characteristics such as "EE56B186-B0D3-488E-8C79-C21FC9BCF437" //VENDOR_AQARA_E1_GATEWAY_VOLUME

I have defined it to be reporting events and this works when testing with the EVE app. I change the value in HA device view and EVE instantly changes the value in it's screen.

However, the other way around, changing the value in EVE and observing the value in HA, this does not work.

Even after the polling, done every minute, the value does not update.

Am I missing something or is this a bug?

Note that in the same setup, changes in TARGET_HEATING_COOLING_STATE DO get reported in the same kind of test.

But then, TEMPERATURE_DISPLAY_UNITS does also not act as expected. So maybe it has to do with the category of 'configuration'? But then, EVE does know how to act on events for these...

Note that my device is paired to two controllers, HA and Apple, which should not matter for this purpose

M10tech avatar Apr 25 '25 16:04 M10tech

Can you give more details about what you are doing and why.

In particular, how you can use the Eve app and HK controller at the same time. Do you mean the official iOS Eve app for their line of radiator valves, motion sensors, temp sensors, etc? Or something else? It shouldn't be possible to have a HomeKit device in that app and home assistant at the same time. There's no (sane) way to get the encryption keys out of iOS when the device is added there. And there's no sane way to import them into iOS if you add a device to HA first. So there must be something I'm missing.

In general custom characteristics are discouraged. Id push people towards esphome, matter or mqtt before building new HomeKit stuff that doesn't work with the stock iOS characteristics. I'd probably not land new ones for non commercial devices. And they have just been a source of pain for some vendors.

If you look at the "diagnostic download" in HA you should be able to find the uuid and confirm the device is reporting the event, read and write flags for it.

If it has the ev flag, we will subscribe to it. You should be able to confirm that with the debug logs. Then it's up to the device to send unsolicited packets with new values in. You should see raw HTTP response frames in the log if it's sending them.

Category is meaningless in terms of how the connection works, how subscription works etc.

Jc2k avatar Apr 25 '25 17:04 Jc2k

Hi thanks for your swift reply,

I use the MaximKulkin stack to program my own HK devices. It is a simple trick to allow pairing to two controllers, which at the HAP level is nothing special, just multiple IDs allowed to pair with the device and control it in parallel, just like the old architecture.

Custom Characteristics are no big deal, the standard allows it, and EVE and others use it. Personally I see a benefit in it, so please consider it an honest request to make this work. AND I think I argued the problem I reported also occurred with apple chars like TEMPERATURE_DISPLAY_UNITS

I'll create additional logs tomorrow, but from my work in other issues I reported before (you know what I mean) I am positive that event reporting works properly. And the report I have from my device is that HA has subscribed to my events! And I have seen these events being sent to HA. But as promised, I'll make a fresh set of logs tomorrow, to remove all doubt.

So, the only correlation I could see between thing working as expected and not, is the category... We'll dig deeper tomorrow. As always, thanks for your attention and your great work on the HomeKit support.

M10tech avatar Apr 25 '25 20:04 M10tech

I'm not coming out against custom characteristics because I think they are a big deal. They are just different UUID's. At a protocol level they are completely boring. They have caused us a lot of support work because lots of vendors can't implement their own characteristics well. Eve is a bit of an exception here. Heck other vendors can barely manage to implement the core protocol properly. But you are an expert that cares about your firmware, so i'm sure you won't have those problems.

But if what you are saying is you want to create "custom" custom characteristics (and have them built into aiohomekit and homekit_controller) thats a very different ticket for me than just "temperature display units" isn't updating. I don't personally want to get involved in that, thanks for understanding.

Jc2k avatar Apr 25 '25 22:04 Jc2k

OK, understood, so we will focus on temperature display unit (TDU) as an official apple characteristic. Here it is char2.14

Not sure how to convey this properly, since the experiments hinge around me pressing bits and pieces in various GUIs and observing updates. I'll send a log nevertheless with all lines that had to do with 2.14. My summary is that the HA device view TDU has a lot of issues such as -not updating when events are received, nor when received in a GET, -sending the 2.14 PUT when going from 0 to 1, but not sending it when going from 1 to 0 The latter might be caused by thinking it is still in 0 after having sent a 1 but not getting confirmation of it actually being 1

If you feel to give me a hint in which area of the source to look, I can do some code inspection. And note that updating the setpoint temperature DOES update the HA device view through the event 2025-04-26 14:16:13.820 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 12): {'value': 20}}

Below, various experiments where 2.14 was involved from both controllers. Note that after HA sets TDU to 1, the accessory confirms the value with an event, saying it is now 1.

2025-04-26 13:35:59.087 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":14,"value":1}]}'
2025-04-26 13:35:59.225 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:35:59.228 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:36:35.534 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:36:36.079 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":0}]}')
2025-04-26 13:37:35.534 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:37:35.689 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":0}]}')
2025-04-26 13:37:57.989 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":14,"value":1}]}'
2025-04-26 13:37:58.404 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:37:58.409 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:38:35.535 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:38:35.884 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":0}]}')
2025-04-26 13:39:00.865 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":14,"value":1}]}'
2025-04-26 13:39:00.994 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:39:01.005 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:39:35.536 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:39:36.604 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":0}]}')
2025-04-26 13:39:49.549 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 0}, (3, 11): {'value': 2}}
2025-04-26 13:39:58.827 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:40:02.605 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 0}}
2025-04-26 13:40:35.538 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:40:35.703 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":0},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')
2025-04-26 13:40:52.305 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":14,"value":1}]}'
2025-04-26 13:40:52.834 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:40:52.842 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:41:22.177 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":14,"value":1}]}'
2025-04-26 13:41:22.320 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:41:22.365 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:41:31.565 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 0}}
2025-04-26 13:41:35.538 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:41:35.914 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":0},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')
2025-04-26 13:42:01.097 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":14,"value":1}]}'
2025-04-26 13:42:01.681 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:42:01.688 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:42:35.539 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:42:36.714 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')
2025-04-26 13:43:35.539 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:43:36.210 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')
2025-04-26 13:44:19.945 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":14,"value":1}]}'
2025-04-26 13:44:20.466 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:44:20.474 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:44:35.540 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:44:35.934 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')
2025-04-26 13:45:19.470 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 0}}
2025-04-26 13:45:35.540 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:45:36.636 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":0},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')
2025-04-26 13:45:47.111 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:46:35.541 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:46:36.350 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')
2025-04-26 13:47:35.542 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:47:36.531 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')
2025-04-26 13:48:35.542 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:48:36.658 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')
2025-04-26 13:49:35.543 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:49:35.766 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')
2025-04-26 13:49:49.703 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":14,"value":1}]}'
2025-04-26 13:49:49.794 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:49:49.800 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{(2, 14): {'value': 1}}
2025-04-26 13:50:35.545 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-26 13:50:36.521 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":1},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20.5},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":1}]}')

M10tech avatar Apr 26 '25 12:04 M10tech

And the config as seen by HA

              {
                "type": "00000036-0000-1000-8000-0026BB765291",
                "iid": 14,
                "perms": [
                  "pr",
                  "pw",
                  "ev"
                ],
                "format": "uint8",
                "value": 0,
                "description": "Temperature Display Units",
                "minValue": 0,
                "maxValue": 1,
                "minStep": 1,
                "valid-values": [
                  0,
                  1
                ]
              }

M10tech avatar Apr 26 '25 12:04 M10tech

Hmm, I was experimenting more and decided to DISABLE the HK device and reenable it. Now it all seems to work as expected, also the custom attributes.

I'll monitor this for a few days to see if it breaks down again, or else close this ticket...

M10tech avatar Apr 26 '25 13:04 M10tech

Like you say this way of presenting your experiments is kinda impossible.

You are a HAP expert, I think I don't actually really need to see your logs. I need you to answer some questions. Again, on phone so please do be brief.

Your original complaint:

However, the other way around, changing the value in EVE and observing the value in HA, this does not work.

Even after the polling, done every minute, the value does not update.

(1) With both Eve and HA paired, please confirm you see the subscribe request for the characteristic. There shouldn't be any errors near this. You should see a request per iid to match iOS behaviour.

(2) Change the target display units to both settings. Do that twice. Do you see any log activity when you do that? In particular, there should be "callback ev" events for that characteristic with the value change on/off/on/off.

(3) If not, after a minute have you seen a poll for the characteristic. Did it generate a "callback ev". Is the Ha view now correct?

Ideally you would start a new testing session and test these 3 things in isolation from any testing you have done and without thought to any theories you have.

Thank you.

Jc2k avatar Apr 26 '25 14:04 Jc2k

Oh that's great news. If the problem resurfaces I'd be interested in whether restarting HA changes things. Maybe a race etc.

Jc2k avatar Apr 26 '25 14:04 Jc2k

Just to make sure, I updated that after a disable/enable cycle on the HA end, things started working as expected.(you saw that 3 seconds ago) My answers are in the OLD context

  1. I see the subscribe requests, for each and all chars with the ev permission PUT {"characteristics":[{"aid":2,"iid":14,"ev":true}]}
  2. I see those events in the log when TDU is changing between C and F as triggered from EVE/Apple
  3. I also see the poll and the TDU is also requested and returned

M10tech avatar Apr 26 '25 14:04 M10tech

And the HA UI doesn't update in any of those cases, even though you see a "callback ev" line with the correct value?

Then, you might not be able to answer this, but if you change something on the HA side does it keep the new value or does it snap back to the old value within a few seconds (if it even changes at all), despite it changing the value on the eve side?

Jc2k avatar Apr 26 '25 14:04 Jc2k

Correct, initially, before the dis/enable the HA UI side would not update.

And changing it on the HA side would sometimes revert to Celsius when I went out and into the view. But staying inside the view, I did not see it snap back on its own.

But since now it works, it is hard to give verified data... just memory of a few days ago.

M10tech avatar Apr 26 '25 14:04 M10tech

Some JS widgets assume that an action worked. They snap back when the state machine corrects them. For some simple elements this can be within a few seconds, but from what you describe that's not uniform. That's a core HA behaviour, not a HomeKit thing.

HomeKit doesn't send an event to a connection if the connection is the source of that change. So the "callback ev" logs for those are synthetic.

So, together that means that the synthetic callback is seemingly not affecting the state machine.

The fact that all 3 of these mechanisms are failing, but not all of the time, and it's consistent which characteristics seem to be affected, really culls where the problem might be.

Well, let's see if it happens again. Maybe we'll get lucky after your next HA restart.

Jc2k avatar Apr 26 '25 15:04 Jc2k

Intermediate update, I've managed to get it in stuck state again. This happened after I updated my device (so c# went from 6 to 7) In the 19 hours before I have tested every once in a while and it continued to work. In the test following 30 minutes after that update, it did not work anymore. I'll test this in a more structured way when I have a new device update... 2Bcontinued...

a bit of log that might suggest that the 'migration' and the re-registration of the events might be relevant??

2025-04-27 13:49:48.283 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Secure connection to 192.168.178.236:5556 established
2025-04-27 13:49:48.283 DEBUG (MainThread) [aiohomekit.controller.abstract] callback ev:{}
2025-04-27 13:49:48.283 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for FF:9F:F9:4C:AE:AC
2025-04-27 13:49:48.283 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":11,"ev":true}]}'
2025-04-27 13:49:48.297 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.298 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":10,"ev":true}]}'
2025-04-27 13:49:48.313 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.313 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":14,"ev":true}]}'
2025-04-27 13:49:48.328 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.328 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":3,"iid":10,"ev":true}]}'
2025-04-27 13:49:48.351 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.351 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":13,"ev":true}]}'
2025-04-27 13:49:48.366 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.366 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":3,"iid":13,"ev":true}]}'
2025-04-27 13:49:48.382 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.382 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":11,"ev":true}]}'
2025-04-27 13:49:48.408 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.408 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":3,"iid":11,"ev":true}]}'
2025-04-27 13:49:48.425 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.425 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":14,"ev":true}]}'
2025-04-27 13:49:48.445 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.445 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":3,"iid":14,"ev":true}]}'
2025-04-27 13:49:48.624 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.624 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":13,"ev":true}]}'
2025-04-27 13:49:48.647 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.647 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":12,"ev":true}]}'
2025-04-27 13:49:48.665 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.665 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":10,"ev":true}]}'
2025-04-27 13:49:48.680 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.680 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":3,"iid":12,"ev":true}]}'
2025-04-27 13:49:48.774 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:48.794 DEBUG (MainThread) [aiohomekit.zeroconf] ff:9f:f9:4c:ae:ac: Notifying pairing of description update: HomeKitService(name='OutdoorT2', id='ff:9f:f9:4c:ae:ac', model='lcm-demo', feature_flags=<FeatureFlags: 0>, status_flags=<StatusFlags: 0>, config_num=7, state_num=1, category=<Categories.THERMOSTAT: 9>, protocol_version='1.0', type='_hap._tcp.local.', address='192.168.178.236', addresses=['192.168.178.236'], port=5556)
2025-04-27 13:49:48.794 DEBUG (MainThread) [aiohomekit.controller.abstract] OutdoorT2 [192.168.178.236:5556] (id=FF:9F:F9:4C:AE:AC): Description updated: old=HomeKitService(name='OutdoorT2', id='ff:9f:f9:4c:ae:ac', model='lcm-demo', feature_flags=<FeatureFlags: 0>, status_flags=<StatusFlags: 0>, config_num=6, state_num=1, category=<Categories.THERMOSTAT: 9>, protocol_version='1.0', type='_hap._tcp.local.', address='192.168.178.236', addresses=['192.168.178.236'], port=5556) new=HomeKitService(name='OutdoorT2', id='ff:9f:f9:4c:ae:ac', model='lcm-demo', feature_flags=<FeatureFlags: 0>, status_flags=<StatusFlags: 0>, config_num=7, state_num=1, category=<Categories.THERMOSTAT: 9>, protocol_version='1.0', type='_hap._tcp.local.', address='192.168.178.236', addresses=['192.168.178.236'], port=5556)
2025-04-27 13:49:48.794 DEBUG (MainThread) [aiohomekit.controller.abstract] OutdoorT2 [192.168.178.236:5556] (id=FF:9F:F9:4C:AE:AC): Config number has changed from 6 to 7; char cache invalid
2025-04-27 13:49:48.794 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /accessories HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-27 13:49:48.888 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"accessories":[{"aid":1,"services":[{"iid":1,"type":"0000003E-0000-1000-8000-0026BB765291","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":2,"type":"00000023-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Name","format":"string","value":"OutdoorT2"},{"aid":3,"iid":3,"type":"00000020-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Manufacturer","format":"string","value":"HomeACcessorykid"},{"aid":3,"iid":4,"type":"00000030-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Serial Number","format":"string","value":"C8:F0:9E:4F:E2:DC"},{"aid":1,"iid":5,"type":"00000021-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Model","format":"string","value":"lcm-demo"},{"aid":1,"iid":6,"type":"00000052-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Firmware Revision","format":"string","value":"0.0.7"},{"aid":1,"iid":7,"type":"00000014-0000-1000-8000-0026BB765291","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"0000008A-0000-1000-8000-0026BB765291","hidden":false,"primary":true,"characteristics":[{"aid":1,"iid":9,"type":"00000023-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Name","format":"string","value":"OutdoorT2"},{"aid":1,"iid":10,"type":"00000011-0000-1000-8000-0026BB765291","perms":["pr","ev"],"ev":true,"description":"Current Temperature","format":"float","unit":"celsius","minValue":0,"maxValue":100,"minStep":0.100000001490116,"value":3},{"aid":1,"iid":11,"type":"B1C09E4C-E202-4827-B343-B0F32F727CFF","perms":["pr","pw","ev"],"ev":true,"description":"}FirmwareUpdate","format":"bool","value":false},{"aid":1,"iid":12,"type":"F0000020-0e36-4a42-ad11-745a73b84f2b","perms":["pr","pw","ev"],"ev":false,"description":"}PairAgain","format":"bool","value":false},{"aid":1,"iid":13,"type":"EE56B186-B0D3-528E-8C79-C21FC9BCF437","perms":["pr","pw","ev"],"ev":true,"description":"HeaterFactor","format":"int","minValue":-100,"maxValue":105,"minStep":5,"value":105},{"aid":1,"iid":14,"type":"EE56B186-B0D3-488E-8C79-C21FC9BCF437","perms":["pr","pw","ev"],"ev":true,"description":"CHsetpoint","format":"int","minValue":20,"maxValue":50,"minStep":1,"value":30}]}]},{"aid":2,"services":[{"iid":1,"type":"0000003E-0000-1000-8000-0026BB765291","hidden":false,"primary":false,"characteristics":[{"aid":2,"iid":2,"type":"00000023-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Name","format":"string","value":"Thermostat2"},{"aid":3,"iid":3,"type":"00000020-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Manufacturer","format":"string","value":"HomeACcessorykid"},{"aid":3,"iid":4,"type":"00000030-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Serial Number","format":"string","value":"C8:F0:9E:4F:E2:DC"},{"aid":1,"iid":5,"type":"00000021-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Model","format":"string","value":"lcm-demo"},{"aid":1,"iid":6,"type":"00000052-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Firmware Revision","format":"string","value":"0.0.7"},{"aid":2,"iid":7,"type":"00000014-0000-1000-8000-0026BB765291","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"0000004A-0000-1000-8000-0026BB765291","hidden":false,"primary":true,"characteristics":[{"aid":2,"iid":9,"type":"00000023-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Name","format":"string","value":"Thermostat2"},{"aid":2,"iid":10,"type":"00000033-0000-1000-8000-0026BB765291","perms":["pr","pw","ev"],"ev":true,"description":"Target Heating Cooling State","format":"uint8","minValue":0,"maxValue":3,"minStep":1,"valid-values":[0,1,2,3],"value":3},{"aid":2,"iid":11,"type":"0000000F-0000-1000-8000-0026BB765291","perms":["pr","ev"],"ev":true,"description":"Current Heating Cooling State","format":"uint8","minValue":0,"maxValue":2,"minStep":1,"valid-values":[0,1,2],"value":0},{"aid":2,"iid":12,"type":"00000035-0000-1000-8000-0026BB765291","perms":["pr","pw","ev"],"ev":true,"description":"Target Temperature","format":"float","unit":"celsius","minValue":10,"maxValue":25,"minStep":0.100000001490116,"value":20},{"aid":2,"iid":13,"type":"00000011-0000-1000-8000-0026BB765291","perms":["pr","ev"],"ev":true,"description":"Current Temperature","format":"float","unit":"celsius","minValue":0,"maxValue":100,"minStep":0.100000001490116,"value":1},{"aid":2,"iid":14,"type":"00000036-0000-1000-8000-0026BB765291","perms":["pr","pw","ev"],"ev":true,"description":"Temperature Display Units","format":"uint8","minValue":0,"maxValue":1,"minStep":1,"valid-values":[0,1],"value":0}]}]},{"aid":3,"services":[{"iid":1,"type":"0000003E-0000-1000-8000-0026BB765291","hidden":false,"primary":false,"characteristics":[{"aid":3,"iid":2,"type":"00000023-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Name","format":"string","value":"Thermo22"},{"aid":3,"iid":3,"type":"00000020-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Manufacturer","format":"string","value":"HomeACcessorykid"},{"aid":3,"iid":4,"type":"00000030-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Serial Number","format":"string","value":"C8:F0:9E:4F:E2:DC"},{"aid":1,"iid":5,"type":"00000021-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Model","format":"string","value":"lcm-demo"},{"aid":1,"iid":6,"type":"00000052-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Firmware Revision","format":"string","value":"0.0.7"},{"aid":3,"iid":7,"type":"00000014-0000-1000-8000-0026BB765291","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"0000004A-0000-1000-8000-0026BB765291","hidden":false,"primary":true,"characteristics":[{"aid":3,"iid":9,"type":"00000023-0000-1000-8000-0026BB765291","perms":["pr"],"description":"Name","format":"string","value":"Thermo22"},{"aid":3,"iid":10,"type":"00000033-0000-1000-8000-0026BB765291","perms":["pr","pw","ev"],"ev":true,"description":"Target Heating Cooling State","format":"uint8","minValue":0,"maxValue":3,"minStep":1,"valid-values":[0,1,2,3],"value":1},{"aid":3,"iid":11,"type":"0000000F-0000-1000-8000-0026BB765291","perms":["pr","ev"],"ev":true,"description":"Current Heating Cooling State","format":"uint8","minValue":0,"maxValue":2,"minStep":1,"valid-values":[0,1,2],"value":0},{"aid":3,"iid":12,"type":"00000035-0000-1000-8000-0026BB765291","perms":["pr","pw","ev"],"ev":true,"description":"Target Temperature","format":"float","unit":"celsius","minValue":10,"maxValue":25,"minStep":0.100000001490116,"value":20},{"aid":3,"iid":13,"type":"00000011-0000-1000-8000-0026BB765291","perms":["pr","ev"],"ev":true,"description":"Current Temperature","format":"float","unit":"celsius","minValue":0,"maxValue":100,"minStep":0.100000001490116,"value":2},{"aid":3,"iid":14,"type":"00000036-0000-1000-8000-0026BB765291","perms":["pr","pw","ev"],"ev":true,"description":"Temperature Display Units","format":"uint8","minValue":0,"maxValue":1,"minStep":1,"valid-values":[0,1],"value":0}]}]}]}')
2025-04-27 13:49:48.889 DEBUG (MainThread) [homeassistant.components.homekit_controller.storage] Creating or updating entity map for FF:9F:F9:4C:AE:AC
2025-04-27 13:49:48.889 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Serial number 'C8:F0:9E:4F:E2:DC' is duplicated within this pairing, it cannot be used as a unique identifier
2025-04-27 13:49:48.889 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Serial number 'C8:F0:9E:4F:E2:DC' is duplicated within this pairing, it cannot be used as a unique identifier
2025-04-27 13:49:48.889 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Migrating device registry entries for pairing FF:9F:F9:4C:AE:AC
2025-04-27 13:49:48.889 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Removing legacy serial numbers from device registry entries for pairing FF:9F:F9:4C:AE:AC
2025-04-27 13:49:48.889 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Removing stale entity registry entries for pairing FF:9F:F9:4C:AE:AC
2025-04-27 13:49:48.890 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Starting HomeKit device update: FF:9F:F9:4C:AE:AC
2025-04-27 13:49:48.890 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-27 13:49:48.891 DEBUG (MainThread) [homeassistant.components.homekit_controller.storage] Creating or updating entity map for FF:9F:F9:4C:AE:AC
2025-04-27 13:49:49.013 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":0},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":0}]}')
2025-04-27 13:49:49.013 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for FF:9F:F9:4C:AE:AC
2025-04-27 13:49:49.013 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Finished HomeKit device update: FF:9F:F9:4C:AE:AC
2025-04-27 13:49:49.140 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":14,"ev":true}]}'
2025-04-27 13:49:49.448 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.448 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":3,"iid":14,"ev":true}]}'
2025-04-27 13:49:49.467 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.467 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":11,"ev":true}]}'
2025-04-27 13:49:49.481 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.481 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":10,"ev":true}]}'
2025-04-27 13:49:49.500 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.500 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":14,"ev":true}]}'
2025-04-27 13:49:49.513 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.513 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":3,"iid":10,"ev":true}]}'
2025-04-27 13:49:49.525 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.525 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":13,"ev":true}]}'
2025-04-27 13:49:49.544 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.544 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":3,"iid":13,"ev":true}]}'
2025-04-27 13:49:49.564 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.564 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":13,"ev":true}]}'
2025-04-27 13:49:49.579 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.579 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":12,"ev":true}]}'
2025-04-27 13:49:49.594 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.594 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":10,"ev":true}]}'
2025-04-27 13:49:49.610 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.610 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":3,"iid":12,"ev":true}]}'
2025-04-27 13:49:49.626 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.627 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":11,"ev":true}]}'
2025-04-27 13:49:49.637 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:49:49.637 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.178.236\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":3,"iid":11,"ev":true}]}'
2025-04-27 13:49:49.657 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'')
2025-04-27 13:50:26.700 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Starting HomeKit device update: FF:9F:F9:4C:AE:AC
2025-04-27 13:50:26.700 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw request: b'GET /characteristics?id=2.14,3.14,1.11,2.10,1.14,3.10,2.13,3.13,1.13,2.12,1.10,3.12,2.11,3.11 HTTP/1.1\r\nHost: 192.168.178.236\r\n\r\n'
2025-04-27 13:50:27.622 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.178.236: raw response: bytearray(b'{"characteristics":[{"aid":2,"iid":14,"value":0},{"aid":3,"iid":14,"value":0},{"aid":1,"iid":11,"value":false},{"aid":2,"iid":10,"value":3},{"aid":1,"iid":14,"value":30},{"aid":3,"iid":10,"value":1},{"aid":2,"iid":13,"value":1},{"aid":3,"iid":13,"value":2},{"aid":1,"iid":13,"value":105},{"aid":2,"iid":12,"value":20},{"aid":1,"iid":10,"value":3},{"aid":3,"iid":12,"value":20},{"aid":2,"iid":11,"value":0},{"aid":3,"iid":11,"value":0}]}')
2025-04-27 13:50:27.623 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for FF:9F:F9:4C:AE:AC
2025-04-27 13:50:27.623 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Finished HomeKit device update: FF:9F:F9:4C:AE:AC

M10tech avatar Apr 27 '25 13:04 M10tech

OK, executed a controlled test and this must be the driving factor. upgrading c# blocks the updates, dis- and enable fixes it again.

I have put some [note: ...]s in the log

The only thing that surprises me is that HA starts polling for a connection once it is lost, without having seen a mdns update. This has the effect of creating a session without being aware of the change in c# I'm not claiming this is incorrect behaviour, just that it might trigger the situation that we are facing.

There are some extra observations below the log, about some not relevant (IMO) weirdness...

HKcontroller-ignore-events-log1.txt

The log by chance started with a reset of the connection, but from a HKdevice point of view, the original connection continued to do the work. This is why we do not see subscriptions from this new connection, yet the original connection is still subscribed and gets the updates... this could be a new issue ticket, but not right now.

There are a lot of updates of 3.11 so I removed many which would not add to the story... Note that these were being detected ALL the time in the HA device view

M10tech avatar Apr 27 '25 15:04 M10tech

So just to be clear, in the "broken" state do you still see the "callback ev" log events, with all the right values and none missed?

Jc2k avatar Apr 27 '25 16:04 Jc2k

Correct, they are shown, but not pushed to the GUI

M10tech avatar Apr 27 '25 16:04 M10tech

I've just updated the issue starter with this text: [TL;DR this happens after an update of the configuration number of the accessory. Quick fix: disable and enable the device]

M10tech avatar Apr 28 '25 16:04 M10tech