Hi Jochen,
this should not be the case anymore…
which version of homekit binding you have? do you see any exception in the log file? how you reboot OH2?
regards
Eugen
Hi Eugen,
homekit is really weird - I couldn’t see any device because my iPad had one home and my iPhone created a second home. Took me hours to find out what happened - also Siri didn’t work any more.
I think I’m good for now but its also good to know for everyone that this re-pairing problem should not exist anymore.
regards,
Jochen
1 Like
Hi Eugen,
after adding things to homekit in the config file which didn’t show up in homekit and after reboot (sudo /bin/systemctl restart openhab2.service) I received:
java.lang.Exception: Unknown user: 6CF1021E-19A2-493A-A6B9-24B207F64174 at io.github.hapjava.server.impl.pairing.PairVerificationManager.stage2(PairVerificationManager.java:113) ~[bundleFile:?] at io.github.hapjava.server.impl.pairing.PairVerificationManager.handle(PairVerificationManager.java:51) ~[bundleFile:?] at io.github.hapjava.server.impl.connections.HttpSession.handlePairVerify(HttpSession.java:127) [bundleFile:?] at io.github.hapjava.server.impl.connections.HttpSession.handleRequest(HttpSession.java:56) [bundleFile:?] at io.github.hapjava.server.impl.connections.ConnectionImpl.doHandleRequest(ConnectionImpl.java:56) [bundleFile:?] at io.github.hapjava.server.impl.connections.ConnectionImpl.handleRequest(ConnectionImpl.java:49) [bundleFile:?] at io.github.hapjava.server.impl.http.impl.AccessoryHandler.channelRead0(AccessoryHandler.java:52) [bundleFile:?] at io.github.hapjava.server.impl.http.impl.AccessoryHandler.channelRead0(AccessoryHandler.java:17) [bundleFile:?] at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105) [bundleFile:4.1.42.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) [bundleFile:4.1.42.Final] at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:56) [bundleFile:4.1.42.Final] at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:365) [bundleFile:4.1.42.Final] at io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:66) [bundleFile:4.1.42.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1044) [bundleFile:4.1.42.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [bundleFile:4.1.42.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [bundleFile:4.1.42.Final]
Any ideas?
Latest openHABian 2.5.7-1
RaspberryPi 3b+
iPad Air iOS 12.4.8
iPhone iOs 13.4
argh. that one again.
this is known issue. it happens very seldom and is not producible.
we have no explanation yet.
but maybe you can help us to finally find the root cause.
background:
homekit binding stores IDs of paired devices in $OPENHAB_USERDATA/jsondb/homekit.json in the record called user. sometimes the user, i.e. paired device, disappears from homekit.json.
from the code it can happen only in following cases:
- command “clearPairings” was executed in karaf console
- device has trigged unpairing, e.g. you have removed home from home app. in which other cases device would trigger this, is unclear
i assume you have not done none from the 2 things above.
the last option - file homekit.json got corrupted, e.g. openhab was stopped during the writing of this file or users were only cached and never written to the file. this option is supported by the fact that it is usually happens only on restart. but it is strange that only users are effected and never other setting from homekit.json
it would be great help if you could answer following questions:
- have pairing survived restart before?
- what you get if you execute the command in ssh/command line
sudo grep user /var/lib/openhab2/jsondb/backup/*
- is it reproducable - if you pair and restart, do you get this issue again?
- was debug logging enabled?
The only mistake I did (I can remember) I had a wrong thing configured
ex:
Switch | SwitchSchalter | “Küche Spots” | {channel=“zwave:device:node33:switch_dimmer1”}
Dimmer | SwitchSchalter | “Küche Spots” | {homekit=“Lighting,Lighting.Brightness”,channel=“zwave:device:node33:switch_dimmer1”}
and I saved the config - error was shown in fontail log of course
Yes I think so - maybe I also did clearing OH cache?!
Nothing to see here
Will find that out in some days/weeks - for now I cleared pairings and added it again
No - I enabled it just in case. I keep working on my config for sure because I need to add support for venetian blinds and RGBW stips
For now: thanks for your help
regards,
Jochen
edit:
got kicked after reboot ( sudo /bin/systemctl restart openhab2.service )
maybe there is a difference to a full reboot (sudo reboot)
the debug log is too big for here (2,60 MB) – https://pastebin.pl/view/6522bc9e
Jochen, thank you for the input.
strange that you have nothing in the /backup/* directory. it means either the device id (from pairing) was never saved to the file or backup files were removed.
can you please check, once your openHAB is up and running and homekit is paired and working, whether you have “user” entry in the /var/lib/openhab2/jsondb/homekit.json, i.e.
cat /var/lib/openhab2/jsondb/homekit.json | grep user
btw, you can store homekit.json somewhere and restore it if you get the issue with unknown user again.
from the log file i can only see the the user is not there anymore but not why it was removed or never stored. it would interesting to see the log before restart/shutdown. what im looking for is the statement
“Remove user …”
in the log file.
best regards
Eugen
Comment, which may be totally irrelevant here!
Openhabian users may now find zram implemented by default (file storage in memory), which needs tidy shutdowns to write data away to permanent storage.
Symptoms of some part of that process going wrong would obviously include vanishing or regressing files.
I’ve no idea which files might be zrammed by default.
Hi Eugen,
thanks for your support - I just backuped homekit.json to my pc’s local drive.
I have paired homekit after the last failture - now
sudo grep user /var/lib/openhab2/jsondb/backup/*
returns three entries - I guess thats three devices that have access to homekit
cat /var/lib/openhab2/jsondb/homekit.json | grep user
returns two entries - I guess thas two different Apple-IDs
So I’m good for now but I was not able during the days to test openhab/homekit and add features.
I guess I will also do a full reboot and not cut openhab with
sudo /bin/systemctl restart openhab2.service
I will keep you updated if there are some more issues.
kind regards,
Jochen
1 Like
I was having the same issue. When I would restart opanhab2.service, I would have to add a new bridge to HomeKit and set it all up again, and remove the old bridge. It was very consistent. I tried a stop, start rather than restart, homekit connected on startup this time. I have not restarted again, so I don’t yet know if this is a coincidence or fix, but it worked once. I know that there shouldn’t be a difference, but maybe there is.
sudo systemctl stop openhab2.service
sudo systemctl start openhab2.service
Hi David,
if you still have the issue, could you please enable log with this command in karaf
log:set TRACE org.openhab.io.homekit.internal
keep openhab running for a while (few hours) and use homekit as usual
then restart openhab and check whether homekit is still working. if not, i would love to see the log files BEFORE the restart.
what i want to see, whether something tiggers deletion of the pair device before restart
Eugen,
I have enabled the log trace. I have not restarted OH yet. I am in the middle of a marathon learn OH and switch from SmartThings.
I will update you once I restart the software.
Eugen,
Well, I tried.
I did a stop/start, HomeKit worked.
Then I did a restart, HomeKit worked.
Finally I did a stop and a RasPi shutdown, HomeKit worked on startup.
1 Like
David,
thank for the report. happy to hear that homekit works for you now.
this is why i hate this issue - it is difficult to re-produce and to catch… it appears suddenly and disappears again without any changes on the configuration.
Eugen,
I enabled logging according to your recommendation and caught the error. Are you interested in the logs?
Hi Florian,
sure, please share, maybe we will finally find the root cause and fix it.
Hi Eugen,
i have the same issue. After every re-boot i need to re-pair again. here is a trace log, i hope this sheds some light.
Homekit trace log.txt (101.5 KB)
I am on 3.1.0 M3
thanks. very interesting.
one question already: can you double check that you have only one homekit addon running? either via karaf
“list | grep -i homekit”
or UI
can you try to deactivate the usage of openHAB in mDNS service.
i see these lines and it looks very strange… like multiple instance starting and stopping again and again. maybe it crashing for another reason, e.g. memory, space on sd card, access rights to directories
2021-04-16 13:42:37.098 .. Suitable mDNS client for IP /192.168.178.90 found and will be used for HomeKit
2021-04-16 13:48:35.073 ... stop debouncer
2021-04-16 13:48:37.206 .. - Suitable mDNS client for IP /192.168.178.90 found and will be used for HomeKit
2021-04-16 13:48:42.895 .. - stop debouncer
2021-04-16 13:48:45.015 .. - Suitable mDNS client for IP /192.168.178.90 found and will be used for HomeKit
2021-04-16 13:49:49.931 ... - stop debouncer
2021-04-16 13:49:52.149 ... - Create HomeKit server with dedicated mDNS server
2021-04-16 13:51:32.409 ... - stop debouncer
2021-04-16 13:51:34.575 .. - Suitable mDNS client for IP /192.168.178.90 found and will be used for HomeKit
it should be actually only one line, without “stop debouncer”.
e.g. on my side
021-04-16T15:25:48+00:00 oh openhab[17917] Create HomeKit server with dedicated mDNS server
2021-04-16T15:25:48+00:00 oh openhab[17917] Registering _hap._tcp.local. on port 9124
Hi Eugen,
here is the complete trace, Terminated at 12:31
Please let me know if you need more.Trace.txt (244.3 KB)