Homekit behaving differently from control panel favorites than from app

viktor_Sc · March 9, 2020, 7:44pm

Hi,

I use the latest OH stable with homekit integration.
Now, the last two times after simply updating all components (with sudo apt-get and with the openhabian-config tool) and a reboot I get the following issue:
When opening the control panel > home, I see the items as offline (‘no answer’).

When I open the home app without changing anything, they are functional:

The last time I simply removed them from the favorites within the home app and re-added them again. That made them working again from the control panel. But this time I’m tired

Any ideas what this might be? Reboot of OH and the iPhone didn’t help.

Thanks,
Viktor

yfre · March 9, 2020, 9:11pm

hi Viktor

it looks like an IoS bug. i dont think it is related to OH.
do you have apple tv / ipad acting as homekit bridge?

for troubleshooting you could enable additional logging with
log:set TRACE io.github.hapjava

and check whether OH get any requests while you are opening the favorites

viktor_Sc · March 9, 2020, 9:29pm

Hi,

Thanks for your answer. No apple tv or ipad in place. Just OH with the homekit binding.

I tried what you said and whenever I open the favorites, there’s a lot in the logs. Whats’s the original log level, ‘error’?

I hope there’s no secret information in the logs

2020-03-09 22:23:17.096 [TRACE] [pl.http.impl.NettyHomekitHttpService] - READ PooledUnsafeDirectByteBuf(ridx: 0, widx: 195, cap: 368) [/192.168.84.67:54975]:
B1006521DDE093948FD0317E2F2E7C7AF0D7BA18551EBBB42D65FA408941DDA5532EC6C62431D11B4B7FF01A3E882225B43612E8A16288888970E675EF3BD8A9F62F735D6EF57E4CFC0FB22E99FBF5F8F2553DA8FAC30F9ACAE39EB313DEF2E940BA721343BB81ABA44EA1041E75A549FE9D355974BD44D5909793082EA561D404B5F17EAB28062BAF60D295C264838CE86526FD8307DB63F9264394E4B355B82968FDC92D55B5FDE4434E22888FC93D322DB305958E7F9FE7A6E1F6088BC533F61642

2020-03-09 22:23:17.099 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Received message of length 195. Existing buffer is 0
2020-03-09 22:23:17.101 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Attempting to read message of length 195
2020-03-09 22:23:17.104 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Read complete message
2020-03-09 22:23:17.106 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Returning 1 results
2020-03-09 22:23:17.109 [TRACE] [ub.hapjava.impl.crypto.ChachaDecoder] - calculated '[5, -107, -114, 127, -97, -25, -90, -31, -10, 8, -117, -59, 51, -10, 22, 66]', received '[5, -107, -114, 127, -97, -25, -90, -31, -10, 8, -117, -59, 51, -10, 22, 66]'
2020-03-09 22:23:17.112 [DEBUG] [hapjava.impl.http.impl.BinaryHandler] - Received data [/192.168.84.67:54975]:
PUT /characteristics HTTP/1.1
Host: openHAB._hap._tcp.local
Content-Length: 57
Content-Type: application/hap+json

{"characteristics":[{"aid":318978463,"iid":9,"ev":true}]}
2020-03-09 22:23:17.115 [TRACE] [http.impl.FullRequestHttpRequestImpl] - received [123, 34, 99, 104, 97, 114, 97, 99, 116, 101, 114, 105, 115, 116, 105, 99, 115, 34, 58, 91, 123, 34, 97, 105, 100, 34, 58, 51, 49, 56, 57, 55, 56, 52, 54, 51, 44, 34, 105, 105, 100, 34, 58, 57, 44, 34, 101, 118, 34, 58, 116, 114, 117, 101, 125, 93, 125]
2020-03-09 22:23:17.122 [INFO ] [impl.connections.SubscriptionManager] - Added subscription to class io.github.hapjava.impl.characteristics.common.PowerStateCharacteristic for 30470843
2020-03-09 22:23:17.125 [INFO ] [va.impl.http.HomekitClientConnection] - 204 /characteristics
2020-03-09 22:23:17.129 [DEBUG] [hapjava.impl.http.impl.BinaryHandler] - Sending data [/192.168.84.67:54975]:
HTTP/1.1 204 No Content
Content-type: application/hap+json
Connection: keep-alive


2020-03-09 22:23:17.132 [TRACE] [pl.http.impl.NettyHomekitHttpService] - WRITE PooledUnsafeDirectByteBuf(ridx: 0, widx: 105, cap: 256) [/192.168.84.67:54975]:
57000F7A7F4236F312D274884D0E9D363E202AC746AC00CF0435E45BFD8A9C3D1309C4A8383C1BFC1F44E79D6C448C1C1DA9FBDD013201931743C827ABA9F6E89A215CCBBB1B38928470DC2B75055158881165E7548FFF5258F0E00D8844DE9FAA168B27C3D0D133A8

2020-03-09 22:23:17.281 [TRACE] [pl.http.impl.NettyHomekitHttpService] - READ PooledUnsafeDirectByteBuf(ridx: 0, widx: 196, cap: 352) [/192.168.84.67:54975]:
B200BAED9A02AB19126B0359AFCDFD0B0E5DBF35A5F221A5E2AEAD586394EF17E0FF6B372EB1B52566F207BEC88FB4270525AF4E5264BD6CC28541847BF5C883960362C9A6E46743A4B22E3EBBB4442AB52484330EF5C3195F1A26B18FAAC6CE6DDE7747562CE3763501C89A8676B348CD1E41404A7484B34CF38B17B9A36DA2DC1860616844926A9EFC1FA7152919BE4445D04B28F6704D5BB17374F38F6C883A54470E9AAE06A2ACCDD5CB571C03B60CE077C8A0AFFA73C2D926628C8664D2A564A952

2020-03-09 22:23:17.283 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Received message of length 196. Existing buffer is 0
2020-03-09 22:23:17.285 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Attempting to read message of length 196
2020-03-09 22:23:17.287 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Read complete message
2020-03-09 22:23:17.289 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Returning 1 results
2020-03-09 22:23:17.292 [TRACE] [ub.hapjava.impl.crypto.ChachaDecoder] - calculated '[-96, -81, -6, 115, -62, -39, 38, 98, -116, -122, 100, -46, -91, 100, -87, 82]', received '[-96, -81, -6, 115, -62, -39, 38, 98, -116, -122, 100, -46, -91, 100, -87, 82]'
2020-03-09 22:23:17.294 [DEBUG] [hapjava.impl.http.impl.BinaryHandler] - Received data [/192.168.84.67:54975]:
PUT /characteristics HTTP/1.1
Host: openHAB._hap._tcp.local
Content-Length: 58
Content-Type: application/hap+json

{"characteristics":[{"aid":1286627947,"iid":9,"ev":true}]}
2020-03-09 22:23:17.298 [TRACE] [http.impl.FullRequestHttpRequestImpl] - received [123, 34, 99, 104, 97, 114, 97, 99, 116, 101, 114, 105, 115, 116, 105, 99, 115, 34, 58, 91, 123, 34, 97, 105, 100, 34, 58, 49, 50, 56, 54, 54, 50, 55, 57, 52, 55, 44, 34, 105, 105, 100, 34, 58, 57, 44, 34, 101, 118, 34, 58, 116, 114, 117, 101, 125, 93, 125]
2020-03-09 22:23:17.301 [INFO ] [impl.connections.SubscriptionManager] - Added subscription to class io.github.hapjava.impl.characteristics.common.PowerStateCharacteristic for 30470843
2020-03-09 22:23:17.304 [INFO ] [va.impl.http.HomekitClientConnection] - 204 /characteristics
2020-03-09 22:23:17.307 [DEBUG] [hapjava.impl.http.impl.BinaryHandler] - Sending data [/192.168.84.67:54975]:
HTTP/1.1 204 No Content
Content-type: application/hap+json
Connection: keep-alive


2020-03-09 22:23:17.310 [TRACE] [pl.http.impl.NettyHomekitHttpService] - WRITE PooledUnsafeDirectByteBuf(ridx: 0, widx: 105, cap: 256) [/192.168.84.67:54975]:
5700C196FA00E97C2121215D059DA9EBA4D80D78782527BEF3A77C5218DDB9194E95C2DF7EF4F3B9E869479EC84725604FDE9077DFCF3F4E3EFA36E716A9BDC5B418F5886E6853638C6FA4ABDB58BCF8D0080BBA9D8F477B8997CF203B36CC3787E60A49CBEAEC5F8B

2020-03-09 22:23:17.433 [TRACE] [pl.http.impl.NettyHomekitHttpService] - READ PooledUnsafeDirectByteBuf(ridx: 0, widx: 344, cap: 352) [/192.168.84.67:54975]:
4601076480A8F935965B3466D0D92D2261A363CA8B54A968F1194E14B04F1ACCBBCCA334896A3004148779BA8715208E8F12CF6F05C93DB69648F86CBC2A454F57CD711A893F50F039EECC5A8699B7D6304E5C5A7117D3587484CD13ED9E5262C02AEC4632230B472C01141844ED0C9FFC4BDE2BA914BB3C0999500045032CD83593159B57841B9F835D0D00DD20749DC97B98E117D04010B0F548FB840A6F8107462A25867E2FF63C9ECCF8FB31812DB69D30F0BCFF814BE3580593BA550B07E076396C204336F19207FA1E54A338CBA52A317ED7455C79635603C0FACB3AA3214B02D0B635652A4F7E8639DFA169332A0A129FF0C0B9DAA3C5A1E1042BF57E88D8F9837760709716084460C8C90AFF2213C1ED413BE22E0644E9D31E89956AEB32A895363F8E87CDD39776D666E0D40211CECFEE27BB37398617A0C7E5F4F9B10E83EE1DD36DF3AC41BED762EC2D3E09BEA56CB838C79F

2020-03-09 22:23:17.435 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Received message of length 344. Existing buffer is 0
2020-03-09 22:23:17.436 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Attempting to read message of length 344
2020-03-09 22:23:17.438 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Read complete message
2020-03-09 22:23:17.441 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Returning 1 results
2020-03-09 22:23:17.444 [TRACE] [ub.hapjava.impl.crypto.ChachaDecoder] - calculated '[-84, 65, -66, -41, 98, -20, 45, 62, 9, -66, -91, 108, -72, 56, -57, -97]', received '[-84, 65, -66, -41, 98, -20, 45, 62, 9, -66, -91, 108, -72, 56, -57, -97]'
2020-03-09 22:23:17.447 [DEBUG] [hapjava.impl.http.impl.BinaryHandler] - Received data [/192.168.84.67:54975]:
PUT /characteristics HTTP/1.1
Host: openHAB._hap._tcp.local
Content-Length: 205
Content-Type: application/hap+json

{"characteristics":[{"aid":271602942,"iid":9,"ev":true},{"aid":271602942,"iid":10,"ev":true},{"aid":271602942,"iid":11,"ev":true},{"aid":271602942,"iid":12,"ev":true},{"aid":271602942,"iid":13,"ev":true}]}
2020-03-09 22:23:17.450 [TRACE] [http.impl.FullRequestHttpRequestImpl] - received [123, 34, 99, 104, 97, 114, 97, 99, 116, 101, 114, 105, 115, 116, 105, 99, 115, 34, 58, 91, 123, 34, 97, 105, 100, 34, 58, 50, 55, 49, 54, 48, 50, 57, 52, 50, 44, 34, 105, 105, 100, 34, 58, 57, 44, 34, 101, 118, 34, 58, 116, 114, 117, 101, 125, 44, 123, 34, 97, 105, 100, 34, 58, 50, 55, 49, 54, 48, 50, 57, 52, 50, 44, 34, 105, 105, 100, 34, 58, 49, 48, 44, 34, 101, 118, 34, 58, 116, 114, 117, 101, 125, 44, 123, 34, 97, 105, 100, 34, 58, 50, 55, 49, 54, 48, 50, 57, 52, 50, 44, 34, 105, 105, 100, 34, 58, 49, 49, 44, 34, 101, 118, 34, 58, 116, 114, 117, 101, 125, 44, 123, 34, 97, 105, 100, 34, 58, 50, 55, 49, 54, 48, 50, 57, 52, 50, 44, 34, 105, 105, 100, 34, 58, 49, 50, 44, 34, 101, 118, 34, 58, 116, 114, 117, 101, 125, 44, 123, 34, 97, 105, 100, 34, 58, 50, 55, 49, 54, 48, 50, 57, 52, 50, 44, 34, 105, 105, 100, 34, 58, 49, 51, 44, 34, 101, 118, 34, 58, 116, 114, 117, 101, 125, 93, 125]
2020-03-09 22:23:17.453 [INFO ] [impl.connections.SubscriptionManager] - Added subscription to class io.github.hapjava.impl.characteristics.thermostat.CurrentHeatingCoolingModeCharacteristic for 30470843
2020-03-09 22:23:17.455 [INFO ] [impl.connections.SubscriptionManager] - Added subscription to class io.github.hapjava.impl.characteristics.thermostat.CurrentTemperatureCharacteristic for 30470843
2020-03-09 22:23:17.456 [INFO ] [impl.connections.SubscriptionManager] - Added subscription to class io.github.hapjava.impl.characteristics.thermostat.TargetHeatingCoolingModeCharacteristic for 30470843
2020-03-09 22:23:17.459 [INFO ] [impl.connections.SubscriptionManager] - Added subscription to class io.github.hapjava.impl.characteristics.thermostat.TargetTemperatureCharacteristic for 30470843
2020-03-09 22:23:17.460 [INFO ] [impl.connections.SubscriptionManager] - Added subscription to class io.github.hapjava.impl.characteristics.thermostat.TemperatureUnitsCharacteristic for 30470843
2020-03-09 22:23:17.462 [INFO ] [va.impl.http.HomekitClientConnection] - 204 /characteristics
2020-03-09 22:23:17.464 [DEBUG] [hapjava.impl.http.impl.BinaryHandler] - Sending data [/192.168.84.67:54975]:
HTTP/1.1 204 No Content
Content-type: application/hap+json
Connection: keep-alive


2020-03-09 22:23:17.470 [TRACE] [pl.http.impl.NettyHomekitHttpService] - WRITE PooledUnsafeDirectByteBuf(ridx: 0, widx: 105, cap: 256) [/192.168.84.67:54975]:
570008AE8BF198131FB57D34355B02F3622136FB9CC097819208153587F966A081A832591EB4675D70205B32D508EE50295EEB7076801946FC0768A073365D25B278954B25F63162236453ECFA92E1256B28D94B798D4FCB3C1858B19CBA97AE9A019B232865C5D17A

2020-03-09 22:23:17.620 [TRACE] [pl.http.impl.NettyHomekitHttpService] - READ PooledUnsafeDirectByteBuf(ridx: 0, widx: 196, cap: 352) [/192.168.84.67:54975]:
B2005A95A1D0582EFDD3587086DC508113A5CFCABEEAA412EA61453540C7B9E465173758880467E13E6CF7760F89B9948D0D7F7AF524BAC7B74B9030EF5C7F5841758C7F66B1BE301A29CAD84BAC85774915A4A8AAD0023719F595D71BB347FE38D959994E92DB80073A6A226A61A99E8432AA85CD92E94969D0F59D2D253E2C79143785879CA5E5B43CAFCDC7C114A5E7BD687DBB1F48559CAB21189CD30FBCE02C0C5BD93ADE729B9050C997A8679DBE181EECF280A5C371501B0EC8552D3F4CBFB564

2020-03-09 22:23:17.622 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Received message of length 196. Existing buffer is 0
2020-03-09 22:23:17.624 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Attempting to read message of length 196
2020-03-09 22:23:17.626 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Read complete message
2020-03-09 22:23:17.628 [TRACE] [ons.LengthPrefixedByteArrayProcessor] - Returning 1 results
2020-03-09 22:23:17.630 [TRACE] [ub.hapjava.impl.crypto.ChachaDecoder] - calculated '[-14, -128, -91, -61, 113, 80, 27, 14, -56, 85, 45, 63, 76, -65, -75, 100]', received '[-14, -128, -91, -61, 113, 80, 27, 14, -56, 85, 45, 63, 76, -65, -75, 100]'
2020-03-09 22:23:17.634 [DEBUG] [hapjava.impl.http.impl.BinaryHandler] - Received data [/192.168.84.67:54975]:
PUT /characteristics HTTP/1.1
Host: openHAB._hap._tcp.local
Content-Length: 58
Content-Type: application/hap+json

{"characteristics":[{"aid":1931562690,"iid":9,"ev":true}]}
2020-03-09 22:23:17.639 [TRACE] [http.impl.FullRequestHttpRequestImpl] - received [123, 34, 99, 104, 97, 114, 97, 99, 116, 101, 114, 105, 115, 116, 105, 99, 115, 34, 58, 91, 123, 34, 97, 105, 100, 34, 58, 49, 57, 51, 49, 53, 54, 50, 54, 57, 48, 44, 34, 105, 105, 100, 34, 58, 57, 44, 34, 101, 118, 34, 58, 116, 114, 117, 101, 125, 93, 125]
2020-03-09 22:23:17.641 [INFO ] [impl.connections.SubscriptionManager] - Added subscription to class io.github.hapjava.impl.characteristics.common.PowerStateCharacteristic for 30470843
2020-03-09 22:23:17.643 [INFO ] [va.impl.http.HomekitClientConnection] - 204 /characteristics
2020-03-09 22:23:17.647 [DEBUG] [hapjava.impl.http.impl.BinaryHandler] - Sending data [/192.168.84.67:54975]:
HTTP/1.1 204 No Content
Content-type: application/hap+json
Connection: keep-alive

And a lot more… I hope there’s something useful in this. I had to cut it as the limit of the community would be exceeded.

The binding has the version: binding-homematic - 2.5.2.

yfre · March 9, 2020, 9:45pm

yeah, default level it ERROR.

logs looks ok. ios subscribe to changes of devices.
are there any errors /exception in the log?

viktor_Sc · March 9, 2020, 9:49pm

I set the log level to WARN and there are no errors when I open the favorites or the home app.
There are errors of course, but not related to this binding and not at the time of opening or switching something.

So, an ios issue?

viktor_Sc · March 9, 2020, 10:01pm

Just figured out a kind of workaround:
In the iPhone settings under control panel > customize controls, I removed the home app. Reopened the settings again, added it again and et voila - it works again.

So yes, looks like an issue of ios.

Thanks!

weakfl · March 9, 2020, 10:03pm

FWIW: I had similar problems with the homekit add-on. Never had it since switching to homebridge-openhab2-complete…

viktor_Sc · March 9, 2020, 10:05pm

Hi, can you provide more details? Is it a special binding? Or the homebridge with a binding to it?

yfre · March 9, 2020, 10:11pm

hmm. difficult to say. i dont see any issues in your log and if removing and re-adding items to favorites fixes this, then it looks like ios issue to me.

viktor_Sc · March 9, 2020, 10:12pm

I agree.

Thanks for your help! I think this can be considered as closed as the workaround with re-adding the app to the control panel works and is not a lot of effort.

viktor_Sc · March 9, 2020, 10:45pm

Anyway, one more thing I just realized. All the switches were set back to the default room after the update and reboot. In the favorites they were still assigned to the correct rooms.
I assume some kind of internal IDs or something similar might have changed. So that they appear as new devices.
But I don‘t know…

weakfl · March 10, 2020, 5:25am

Take a look here.

yfre · March 10, 2020, 9:27am

does it work now (after re-adding items for favorite)?

viktor_Sc · March 10, 2020, 9:31am

Yes, after re-adding the home app to the control panel, it works again.

fex · March 10, 2020, 11:40am

There is also a nice post about this in our forum: HomeKit holy grail: homebridge-openhab2-complete

I switched two months ago to homebridge + homebridge-openhab2-complete plugin for homekit stuff and I’m quite happy with it - it’s much more reliable than my experiences with the openHAB homkit binding.
To avoid misunderstandings - openHAB ist still the center of my Smart Home setup - homebridge + homebridge-openhab2-complete is only used to expose my openHAB items to homekit.

viktor_Sc · March 10, 2020, 11:53am

Right, thanks guys. I’m going to have a look at it. Sounds good so far!