Homekit requires manual restart in Karaf to restore communication to iOSapp

I’m Openhabian 2.5.7 build 175 on an RPi4 and have found an issue where when using the iOS Home app, devices will periodically display a “No response” message. This happens a few times a day. I have a script running as an hourly OH cron task with this content:

#!/bin/bash

echo "Restarting  Homekit Bundle"
openhab-cli console -p habopen bundle:restart org.openhab.io.homekit

if the cron task is run when the devices are in the “No Response” state, communication is not restored. But, if I run the script manually from the command line, or execute the command from within Karaf the communication is restored. I’ve also used bundle:refresh in the script, but the results are the same.

I’m at a loss as to how to keep Homekit working as it should. Any ideas?

Initially, my script was written as follows:

#!/bin/bash

echo "Restarting  Homekit Bundle"
openhab-cli console -p habopen bundle:stop org.openhab.io.homekit
sleep 3
openhab-cli console -p habopen bundle:start org.openhab.io.homekit

But as this is bit inefficient, with a little help from the community, I re-wrote the script as the above, but I think my “older” version may have actually worked better, but I’ll try it again and see what happens.
Thanks

1 Like

The cronjob is being executed under the same user that is being used on command line ?
Scripts that are being executed under cron have a limited environment.
You need to make sure that related environment variables that are required are explicitly set.
E.g. I would use an abosolute path to the openhab-cli executable.
You also can make sure that ( if you have not done yet ) STDOUT is redirected to a logfile.
Redirect to STDERR to the same or to another file to have a look at the output in case of an error.
As long as the executable ( openhab-cli ) is not found you will find that in the logfile then.
E.g. you can use

>> /tmp/mylogfile 2>&1

right after the call to your script file in the cron entry to redirect the output to a logfile placed in the temp directory. >> will make sure that output is appended to the end of the file. 2>&1 will redirect STDERR to STDOUT. This makes sure that STDERR is written to the same logfile.

When running the script from the command line, it is being run as the ‘openhabian’ user.

[15:01:54] openhabian@openhabpi4:~$ whoami
openhabian
[15:01:57] openhabian@openhabpi4:~$ 

I’ll try your suggestions and see that makes a difference.
Thanks for the reply.

On the scripts last run, I only got this line:

Session has been closed

Looks as though it was a user rights issue. I’ve removed the OH cron task and set the script up to run under the root user’s cron.

The output I see in the OH log is this:

2020-08-31 16:24:12.870 [INFO ] [mekit.internal.HomekitChangeListener] - Created 37 HomeKit items.

This is what I see when the script executes successfully.
Is it possible to ‘sudo’ this script within OH as a cron task?

Yes, that should work. See e.g.

and there are more examples.
While the above examples use ssh key-pairs for authentication your script uses password.
So the above examples can be used for the OH cron part. Just adapt it to continue to use password instead of keys.

they key question is why you need to restart the binding?
do you see any error or exception in the log for the time of “No Response”?
if you enable TRACE with

log:set TRACE io.github.hapjava

do you see any requests comming from iOS device to openHAB?

I’ll try the trace, but unless I restart the bundle, I can’t control my devices from Home app. They lose communication a few times a day.

the question is why it is loosing connection. maybe there is an exception that makes bundle to stop working. hopefully logging will help

I see lots of lines like this:

2020-09-03 14:11:57.512 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 1005451058
2020-09-03 14:11:57.514 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 1005451058
2020-09-03 14:11:57.516 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 1005451058
2020-09-03 14:11:57.743 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 1005451058
2020-09-03 14:11:57.746 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 1005451058
2020-09-03 14:11:57.748 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 1005451058
2020-09-03 14:11:57.750 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 1005451058
2020-09-03 14:12:06.924 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 566325295
2020-09-03 14:12:06.985 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 1162713894
2020-09-03 14:12:06.992 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 1162713894
2020-09-03 14:12:07.414 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 1637036167
2020-09-03 14:12:12.603 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 342805909
2020-09-03 14:12:21.160 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 342805909
2020-09-03 14:12:45.651 [TRACE] [impl.connections.SubscriptionManager] - Publishing change for 342805909

the log message says an update about item state was sent to subscribed iOS device. typically an iOS device subscribes to all changes

you have several lines for the same item which typically means that there are several iOS devices paired with openHAB (according to log files > 7 device).
do you have more that many iOS devices with home app connected to openHAB?

if you have less than 7 device then one device is subscribed several times. that could lead to the issue with non-responsive items in home app.

do you see something like “Added subscription to …” in the log?
do you see them only after a restart or later?

could it be that your wifi connection is sometimes unstable and devices get disconnected?

I only have 2 iOS devices with the Home app installed. I don’t see an “Added subscription to…” line the log either. My wifi connection is pretty solid.

maybe too many subscription is result of often binding restarts.
can you restart openhab and pay attention how many “Publishing change for” you get for the same number. it must 1 or 2 depending on number of connected devices.

do you have this issue since beginning or only after an upgrade / config change or new homekit device?

I did a

sudo cat /var/log/openhab2/openhab.log | grep -i "publishing"

immediately after a restart, but nothing with “publishing” was in there.

I also have this issue. I need to restart it every day. I can help debug this if you tell me how.

do you need to restart openhab or only homekit ? what happens if you dont do it?

only homekit from karaf. Openhab works, but the items show up in the home app as not responding.

Edit: but this has been happening for a few months, i taught it was a know issue. Maybe since before 2.5.0

ok. let us try to debug it.
i would need following information

  1. which version of homekit binding you have installed?
  2. number of paired homekit devices ? do you have apple tv or ipad paired?
  3. do you see any exception in openhab log file ? just search for exceptions

then i will need more detailed logs for the time you see “not responding” first time on the home app.
for this you would need to enable TRACE log for hap protocol with this command in karaf console

log:set TRACE io.github.hapjava

dont paste the log here but better upload it somewhere like https://pastebin.com/.

  1. 2.5.9
  2. total about 30, openhab ones under 10, all z-wave and 1 orvibo
  3. I’ve enabled them. Where can I find them? Also, where is the openhab log? in /var/log/openhab2/openhab.log, the logfile is empty.

edit: also in karaf, log:display is empty

this is strange. without logs it will be difficult to troubleshoot. it could be anything - starting from wrong configuration, bug in the binding and to out of memory issues.
not sure how to fix logging issue. only the standard things

  • check disk space to ensure the disk/sd card is not full
  • check access rights to /var/log/openhab2/ and /var/log/openhab2/openhab.log. if unsure allow all the full access to them, e.g. chmod o+rw /var/log/openhab2/openhab.log
  • restart openhab