Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[homekit] Binding stops working after a couple of days #9773

Closed
jewesta opened this issue Jan 10, 2021 · 25 comments
Closed

[homekit] Binding stops working after a couple of days #9773

jewesta opened this issue Jan 10, 2021 · 25 comments
Labels
bug An unexpected problem or unintended behavior of an add-on

Comments

@jewesta
Copy link

jewesta commented Jan 10, 2021

Current Behavior

I am using the Homekit binding to make approx. 50 openHAB items available for control via Siri. After a seemingly random amount of time - mostly a couple of days - the binding stops working. The symptoms are that the Home app flags all items with "no response".

We have two HomePods and an Apple TV. All three are listed as Homekit hubs in the Home app settings. We tried to reboot the device shown as "connected" (as opposed to "standby") in the Home app settings when the problem occurred. But that didn't help.

If I check Karaf console, I can see that a ConcurrentModificationException has been logged. The following is an abbreviated copy & paste of my Karaf console output spanning approx two weeks and showing two consecutive incidents. Although I am not 100% sure that the Exception is directly related to the issue it was there every time I checked the server after Homekit stopped working. As can be seen I can correct the issue if I just restart the binding. Seconds later all Homekit items become responsive again.

                           _   _     _     ____  
   ___   ___   ___   ___  | | | |   / \   | __ ) 
  / _ \ / _ \ / _ \ / _ \ | |_| |  / _ \  |  _ \ 
 | (_) | (_) |  __/| | | ||  _  | / ___ \ | |_) )
  \___/|  __/ \___/|_| |_||_| |_|/_/   \_\|____/ 
       |_|       3.1.0-SNAPSHOT - Build #2101

...

openhab> Exception in thread "SocketListener(macmini-2012-fritz-box.local.)" java.util.ConcurrentModificationException
	at java.base/java.util.ArrayList$Itr.checkForComodification(ArrayList.java:1043)
	at java.base/java.util.ArrayList$Itr.next(ArrayList.java:997)
	at javax.jmdns.impl.DNSCache.getDNSEntry(DNSCache.java:142)
	at javax.jmdns.impl.JmDNSImpl.handleRecord(JmDNSImpl.java:1362)
	at javax.jmdns.impl.JmDNSImpl.handleResponse(JmDNSImpl.java:1476)
	at javax.jmdns.impl.SocketListener.run(SocketListener.java:77)
bundle:list
START LEVEL 100 , List Threshold: 50
 ID │ State  │ Lvl │ Version                 │ Name
────┼────────┼─────┼─────────────────────────┼──────────────────────────────────────────────────────────────
...
227 │ Active │  80 │ 3.1.0.202012260419      │ openHAB Add-ons :: Bundles :: IO :: Homekit
...
openhab> bundle:restart 227

... a couple of days later, no additional output logged ...

openhab> Exception in thread "SocketListener(2a02-908-d81-9640-b0b2-4528-a5a5-dd04-en0.local.)" java.util.ConcurrentModificationException
	at java.base/java.util.ArrayList$Itr.checkForComodification(ArrayList.java:1043)
	at java.base/java.util.ArrayList$Itr.next(ArrayList.java:997)
	at javax.jmdns.impl.DNSCache.getDNSEntry(DNSCache.java:142)
	at javax.jmdns.impl.JmDNSImpl.handleRecord(JmDNSImpl.java:1362)
	at javax.jmdns.impl.JmDNSImpl.handleResponse(JmDNSImpl.java:1476)
	at javax.jmdns.impl.SocketListener.run(SocketListener.java:77)
Exception in thread "SocketListener(macmini-2012-fritz-box.local.)" java.lang.NullPointerException
	at javax.jmdns.impl.JmDNSImpl.handleRecord(JmDNSImpl.java:1373)
	at javax.jmdns.impl.JmDNSImpl.handleResponse(JmDNSImpl.java:1476)
	at javax.jmdns.impl.SocketListener.run(SocketListener.java:77)
bundle:restart 227
openhab>

Steps to Reproduce (for Bugs)

Unfortunately this issue seems to happen at random. I do not know of a way to reproduce it at will.

Your Environment

Here is the output of the Karaf "info" command:

Karaf
  Karaf version               4.2.7
  Karaf home                  /Users/administrator/openhab/runtime
  Karaf base                  /Users/administrator/openhab/userdata
  OSGi Framework              org.eclipse.osgi-3.12.100.v20180210-1608

JVM
  Java Virtual Machine        OpenJDK 64-Bit Server VM version 11.0.9+11
  Version                     11.0.9
  Vendor                      AdoptOpenJDK
  Pid                         29796
  Uptime                      14 days 23 hours
  Process CPU time            11 hours 23 minutes
  Process CPU load            0.00
  System CPU load             0.00
  Open file descriptors       323
  Max file descriptors        10,240
  Total compile time          13 minutes
Threads
  Live threads                312
  Daemon threads              126
  Peak                        356
  Total started               485947
Memory
  Current heap size           371,764 kbytes
  Maximum heap size           4,194,304 kbytes
  Committed heap size         576,512 kbytes
  Pending objects             0
  Garbage collector           Name = 'G1 Young Generation', Collections = 9834, Time = 58.410 seconds
  Garbage collector           Name = 'G1 Old Generation', Collections = 0, Time = 0.000 seconds
Classes
  Current classes loaded      21,664
  Total classes loaded        32,984
  Total classes unloaded      11,320
Operating system
  Name                        Mac OS X version 10.15.7
  Architecture                x86_64
  Processors                  4

I am currently running the 3.1.0-SNAPSHOT of openHAB, but I had this issue with the milestones (and I believe the 3.0 release) as well. It is hard to tell as the milestones sometimes got released faster than the issue usually appears.

As can be seen on the Karaf output the system I am running openHAB on is a mac Mini 2012 running macOS Catalina. The system is used exclusively for openHAB.

@jewesta jewesta added the bug An unexpected problem or unintended behavior of an add-on label Jan 10, 2021
@SniperGER
Copy link

I have the very same issue using a Raspberry Pi 3 Model B. Around 20 HomeKit devices (most of them DIY thermometers and Sonoff switches) and an Apple TV 4 ("HD").

Here's the output from systemctl status openhab:

Jan 03 14:17:13 raspberrypi systemd[1]: Started openHAB - empowering the smart home.
Jan 12 04:46:48 raspberrypi karaf[545]: Exception in thread "SocketListener(192-168-178-104.local.)" java.util.ConcurrentModificationException
Jan 12 04:46:48 raspberrypi karaf[545]:         at java.base/java.util.ArrayList$Itr.checkForComodification(ArrayList.java:1043)
Jan 12 04:46:48 raspberrypi karaf[545]:         at java.base/java.util.ArrayList$Itr.next(ArrayList.java:997)
Jan 12 04:46:48 raspberrypi karaf[545]:         at javax.jmdns.impl.DNSCache.getDNSEntry(DNSCache.java:142)
Jan 12 04:46:48 raspberrypi karaf[545]:         at javax.jmdns.impl.JmDNSImpl.handleRecord(JmDNSImpl.java:1362)
Jan 12 04:46:48 raspberrypi karaf[545]:         at javax.jmdns.impl.JmDNSImpl.handleResponse(JmDNSImpl.java:1476)
Jan 12 04:46:48 raspberrypi karaf[545]:         at javax.jmdns.impl.SocketListener.run(SocketListener.java:77)

Also, some general system info:

pi@raspberry:~ $ neofetch
pi@raspberrypi
--------------
OS: Raspbian GNU/Linux 10 (buster) armv7l
Host: Raspberry Pi 3 Model B Rev 1.2
Kernel: 5.4.79-v7+
Uptime: 8 days, 20 hours, 6 mins
Packages: 558 (dpkg)
Shell: bash 5.0.3
Terminal: /dev/pts/0
CPU: BCM2835 (4) @ 1.200GHz
Memory: 331MiB / 924MiB
openhab> info
Karaf
  Karaf version               4.2.7
  Karaf home                  /usr/share/openhab/runtime
  Karaf base                  /var/lib/openhab
  OSGi Framework              org.eclipse.osgi-3.12.100.v20180210-1608

JVM
  Java Virtual Machine        OpenJDK Server VM version 11.0.9.1+1-post-Raspbian-1deb10u2
  Version                     11.0.9.1
  Vendor                      Raspbian
  Pid                         32765
  Uptime                      3 minutes
  Process CPU time            3 minutes
  Process CPU load            0.00
  System CPU load             0.25
  Open file descriptors       273
  Max file descriptors        102,642
  Total compile time          1 minute
Threads
  Live threads                148
  Daemon threads              81
  Peak                        148
  Total started               205
Memory
  Current heap size           69,448 kbytes
  Maximum heap size           229,760 kbytes
  Committed heap size         116,312 kbytes
  Pending objects             0
  Garbage collector           Name = 'Copy', Collections = 74, Time = 1.908 seconds
  Garbage collector           Name = 'MarkSweepCompact', Collections = 6, Time = 2.016 seconds
Classes
  Current classes loaded      17,897
  Total classes loaded        17,912
  Total classes unloaded      15
Operating system
  Name                        Linux version 5.4.79-v7+
  Architecture                arm
  Processors                  4

openhab> bundle:list
[...]
224 │ Active │  80 │ 3.0.0                   │ openHAB Add-ons :: Bundles :: MQTT Broker Binding
225 │ Active │  81 │ 3.0.0                   │ openHAB Add-ons :: Bundles :: MQTT Things and Channels
226 │ Active │  82 │ 3.0.0                   │ openHAB Add-ons :: Bundles :: MQTT HomeAssistant Convention
227 │ Active │  82 │ 3.0.0                   │ openHAB Add-ons :: Bundles :: MQTT Homie Convention
228 │ Active │  80 │ 3.0.0                   │ openHAB Add-ons :: Bundles :: WiFiLED Binding
229 │ Active │  80 │ 3.0.0                   │ openHAB Core :: Bundles :: MQTT Transport
230 │ Active │  80 │ 3.0.0                   │ openHAB Add-ons :: Bundles :: IO :: Homekit
231 │ Active │  80 │ 3.0.0                   │ openHAB Add-ons :: Bundles :: Persistence Service :: RRD4j
232 │ Active │  80 │ 3.0.0                   │ openHAB UI :: Bundles :: Basic UI
233 │ Active │  80 │ 3.0.0                   │ openHAB UI :: Bundles :: Icon Set :: Classic
[...]

@jewesta
Copy link
Author

jewesta commented Jan 15, 2021

It happened again yesterday. So approx. four days since my original posting. Same stack trace as shown above.

@jewesta
Copy link
Author

jewesta commented Jan 17, 2021

Not going to post every time this happens (I promise this will be the last time). But this morning it happened again, and there were some loosely time related warnings immediately preceeding the stack trace. I believe they are not related because those warnings have been reported in another issue. But I wanted to share the info anyway.

WARNING: An illegal reflective access operation has occurred                                                                              
WARNING: Illegal reflective access by com.google.gson.internal.bind.ReflectiveTypeAdapterFactory (file:/Users/administrator/openhab/userdata/cache/org.eclipse.osgi/27/0/bundleFile) to field java.time.LocalDateTime.date
WARNING: Please consider reporting this to the maintainers of com.google.gson.internal.bind.ReflectiveTypeAdapterFactory
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
Exception in thread "SocketListener(macmini-2012-fritz-box.local.)" java.util.ConcurrentModificationException
	at java.base/java.util.ArrayList$Itr.checkForComodification(ArrayList.java:1043)
	at java.base/java.util.ArrayList$Itr.next(ArrayList.java:997)
	at javax.jmdns.impl.DNSCache.getDNSEntry(DNSCache.java:142)
	at javax.jmdns.impl.JmDNSImpl.handleRecord(JmDNSImpl.java:1362)
	at javax.jmdns.impl.JmDNSImpl.handleResponse(JmDNSImpl.java:1476)
	at javax.jmdns.impl.SocketListener.run(SocketListener.java:77)

As usual, a restart of the homekit binding fixed the Home App / Siri.

@SniperGER
Copy link

Happened again today. I'm going to work around this by restarting OpenHAB at a fixed time (every day at 3:00 AM for now) until this issue is actually fixed.

@ossiflocke
Copy link

I have the same problem. ConcurrentModificationException as well as the HomeKit stopping to work issue. I'm using the official 3.0.0 release.

I think the problem startet somewhere around 3.0.0M4 or M5.

@fermentfan
Copy link

Same problem here!

@fermentfan
Copy link

jmdns/jmdns#211

There is an open issue at the jmDNS repository

@openhab-bot
Copy link
Collaborator

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/homekit-jmdns-concurrent-modification-exception/115410/1

@fermentfan
Copy link

fermentfan commented Jan 25, 2021

For the moment I am using a simple cron to detect the corrupted state of the bundle to restart it periodically. Not a beauty, but it minimizes the impact... Adjust to your likings. OpenHab is my only homekit bridge at home so I can detect the faulty state by detecting the missing _hap._tcp MDNS entry.

/usr/bin/avahi-browse -t -r _hap._tcp > /root/checkhap/lookup.txt
actualsize=$(/usr/bin/wc -c <"/root/checkhap/lookup.txt")
if [ $actualsize -ge 1 ]; then
    echo size is over $minimumsize bytes. Homekit seems healthy. Aborting...
else
    echo size is under $minimumsize bytes. Restarting bundle...
    echo bundle:restart 241 | /usr/bin/openhab-cli console -p habopen  
fi
rm /root/checkhap/lookup.txt

@sebiJo
Copy link

sebiJo commented Feb 4, 2021

Same issue here! Thanks for posting your cron job as workaround

@fermentfan
Copy link

@sebiJo No problem! FYI I changed the script as the interactive cli didn't work in a cron job. Now it does.

@openhab-bot
Copy link
Collaborator

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/homekit-no-response-error-on-all-openhab-items/118200/2

@openhab-bot
Copy link
Collaborator

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/homekit-no-response-error-on-all-openhab-items/118200/4

@openhab-bot
Copy link
Collaborator

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/homekit-integration-repeatedly-falling-offline-since-oh3-upgrade/119327/5

@sebiJo
Copy link

sebiJo commented Mar 22, 2021

Deactivating IPv6 for my entire Raspberry Pi helped!

@jewesta
Copy link
Author

jewesta commented Apr 7, 2021

Unfortunately the issue still exists in 3.1.0-SNAPSHOT Build 2294 (to which I updated on 2021-03-30). The stack trace appeared approx. 1 week after the update and the Homekit-Binding stopped working.

Following the advice of @sebiJo I have now disabled IPv6 on the Mac mini's ethernet interface & Wifi (although Wifi is off anyway) and will see how that goes.

@openhab-bot
Copy link
Collaborator

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/need-to-reset-homekit-pairing-at-every-launch/13542/72

@jewesta
Copy link
Author

jewesta commented Apr 22, 2021

Disabling IPv6 does not seem to help on my Mac. It took two weeks but the binding stopped working again yesterday.

@OlafSc
Copy link

OlafSc commented Apr 27, 2021

Same issue on 3.1M3, rasPi, IPv6 disabled, both on using its own and using OpenHABs mDNS - still, after some hours, all homekit items are flagged as non responding.

openhab-cli console -p XXXXX bundle:restart org.openhab.io.homekit helps. logs:

Last login: Sun Apr 25 13:18:36 on ttys000

The default interactive shell is now zsh.
To update your account to use zsh, please run chsh -s /bin/zsh.
For more details, please visit https://support.apple.com/kb/HT208050.
schnapauff-macbookpro:~ schnapauff$ ssh openhabian@192.168.2.12
openhabian@192.168.2.12's password:
Linux OpenHabian 5.10.17-v7l+ #1403 SMP Mon Feb 22 11:33:35 GMT 2021 armv7l

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
Last login: Sun Apr 25 13:18:45 2021 from 192.168.2.121

###############################################################################
############### openHABianDevice ############################################
###############################################################################

Ip = 192.168.2.12

Release = Raspbian GNU/Linux 10 (buster)

Kernel = Linux 5.10.17-v7l+

Platform = Raspberry Pi 4 Model B Rev 1.2

Uptime = 2 day(s). 1:24:56

CPU Usage = 0% avg over 4 cpu(s) (4 core(s) x 1 socket(s))

CPU Load = 1m: 0.00, 5m: 0.00, 15m: 0.00

Memory = Free: 2.60GB (69%), Used: 1.18GB (31%), Total: 3.78GB

Swap = Free: 2.58GB (100%), Used: 0.00GB (0%), Total: 2.58GB

Root = Free: 21.50GB (77%), Used: 6.25GB (23%), Total: 28.98GB

Updates = 7 apt updates available.

Sessions = 1 session(s)

Processes = 125 running processes of 32768 maximum processes

###############################################################################

                      _   _     _     ____   _               

___ ___ ___ ___ | | | | / \ | __ ) () ____ ___
/ _ \ / _ \ / _ \ / _ \ | |
| | / _ \ | _ \ | | / _ \ / _ \
| () | () | /| | | || _ | / ___ \ | |) )| || () || | | |
_
/| / _/|| |||| ||// _|/ || _|||| | |
|
| 3.1.0.M3 - Milestone Build

Looking for a place to get started? Check out 'sudo openhabian-config' and the
documentation at https://www.openhab.org/docs/installation/openhabian.html
The openHAB dashboard can be reached at http://OpenHabian:8080
To interact with openHAB on the command line, execute: 'openhab-cli --help'

openhabian@OpenHabian:~ $ openhab-cli showlods

Unrecognised command: showlods
Usage: openhab-cli command [options]

Possible commands:
backup [--full] [filename] -- Stores the current configuration of openHAB.
clean-cache -- Cleans the openHAB temporary folders.
console -- Opens the openHAB console.
info -- Displays distribution information.
reset-ownership -- Gives openHAB control of its own directories.
restore filename -- Restores the openHAB configuration from a backup.
showlogs -- Displays the log messages of openHAB.
start [--debug] -- Starts openHAB in the terminal.
status -- Checks to see if openHAB is running.
stop -- Stops any running instance of openHAB.

openhabian@OpenHabian:~ $ openhab-cli showlogs

==> /var/log/openhab/audit.log <==

==> /var/log/openhab/events.log <==
2021-04-27 14:38:06.498 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'SchlafzimmerRaumtempreglerSchaltaktor1fach2041ABB700DCDEE0_Roomtemperature' changed from 20.76 to 20.78
2021-04-27 14:42:50.554 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'daikin:ac_unit:192_168_2_115' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Daikin HTTP error
2021-04-27 14:43:50.675 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'daikin:ac_unit:192_168_2_115' changed from OFFLINE (COMMUNICATION_ERROR): Daikin HTTP error to ONLINE
2021-04-27 14:44:03.832 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HauptIndoorModulZuhauseWetterstation_CO2Gehalt' changed from 425 to 396
2021-04-27 14:44:03.841 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WindmesserZuhauseWetterstation_Windrichtung' changed from 227 to 221
2021-04-27 14:44:03.842 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WindmesserZuhauseWetterstation_Windgeschwindigkeit' changed from 12 to 13
2021-04-27 14:44:03.844 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WindmesserZuhauseWetterstation_BoenRichtung' changed from 232 to 230
2021-04-27 14:44:03.845 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WindmesserZuhauseWetterstation_BoenGeschwindigkeit' changed from 18 to 20
2021-04-27 14:44:03.846 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'DraussenZuhauseWetterstation_Temperatur' changed from 14.80000019073486328125 to 14.8999996185302734375
2021-04-27 14:44:08.334 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'SchlafzimmerRaumtempreglerSchaltaktor1fach2041ABB700DCDEE0_Roomtemperature' changed from 20.78 to 20.8

==> /var/log/openhab/openhab.log <==
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:700) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:635) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:552) [bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:514) [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]
at java.lang.Thread.run(Thread.java:834) [?:?]
2021-04-27 14:28:35.764 [TRACE] [rver.impl.http.impl.AccessoryHandler] - Terminated HomeKit connection from /192.168.2.143:55780
q^C
openhabian@OpenHabian:
$ less /var/log/openhab/openhab.log
openhabian@OpenHabian:
$ openhab-cli showlogs

==> /var/log/openhab/audit.log <==

==> /var/log/openhab/events.log <==
2021-04-27 14:38:06.498 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'SchlafzimmerRaumtempreglerSchaltaktor1fach2041ABB700DCDEE0_Roomtemperature' changed from 20.76 to 20.78
2021-04-27 14:42:50.554 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'daikin:ac_unit:192_168_2_115' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Daikin HTTP error
2021-04-27 14:43:50.675 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'daikin:ac_unit:192_168_2_115' changed from OFFLINE (COMMUNICATION_ERROR): Daikin HTTP error to ONLINE
2021-04-27 14:44:03.832 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HauptIndoorModulZuhauseWetterstation_CO2Gehalt' changed from 425 to 396
2021-04-27 14:44:03.841 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WindmesserZuhauseWetterstation_Windrichtung' changed from 227 to 221
2021-04-27 14:44:03.842 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WindmesserZuhauseWetterstation_Windgeschwindigkeit' changed from 12 to 13
2021-04-27 14:44:03.844 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WindmesserZuhauseWetterstation_BoenRichtung' changed from 232 to 230
2021-04-27 14:44:03.845 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WindmesserZuhauseWetterstation_BoenGeschwindigkeit' changed from 18 to 20
2021-04-27 14:44:03.846 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'DraussenZuhauseWetterstation_Temperatur' changed from 14.80000019073486328125 to 14.8999996185302734375
2021-04-27 14:44:08.334 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'SchlafzimmerRaumtempreglerSchaltaktor1fach2041ABB700DCDEE0_Roomtemperature' changed from 20.78 to 20.8

==> /var/log/openhab/openhab.log <==
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:700) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:635) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:552) [bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:514) [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]
at java.lang.Thread.run(Thread.java:834) [?:?]
2021-04-27 14:28:35.764 [TRACE] [rver.impl.http.impl.AccessoryHandler] - Terminated HomeKit connection from /192.168.2.143:55780
q^C
openhabian@OpenHabian:
$ less /var/log/openhab/openhab.log
openhabian@OpenHabian:
$ openhab-cli console -p habopen bundle:restart org.openhab.io.homekit

Logging in as openhab
openhabian@OpenHabian:~ $ less /var/log/openhab/openhab.log
openhabian@OpenHabian:~ $ less /var/log/openhab/openhab.log

    at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39) ~[?:?]
    at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:276) ~[?:?]
    at sun.nio.ch.IOUtil.read(IOUtil.java:233) ~[?:?]
    at sun.nio.ch.IOUtil.read(IOUtil.java:223) ~[?:?]
    at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:358) ~[?:?]
    at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:247) ~[bundleFile:4.1.42.Final]
    at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1147) ~[bundleFile:4.1.42.Final]
    at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:347) ~[bundleFile:4.1.42.Final]
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148) [bundleFile:4.1.42.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:700) [bundleFile:4.1.42.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:635) [bundleFile:4.1.42.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:552) [bundleFile:4.1.42.Final]
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:514) [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]
    at java.lang.Thread.run(Thread.java:834) [?:?]

2021-04-27 14:28:35.758 [DEBUG] [rver.impl.http.impl.AccessoryHandler] - Exception caught in web handler
java.io.IOException: Connection timed out
at sun.nio.ch.FileDispatcherImpl.read0(Native Method) ~[?:?]
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39) ~[?:?]
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:276) ~[?:?]
at sun.nio.ch.IOUtil.read(IOUtil.java:233) ~[?:?]
at sun.nio.ch.IOUtil.read(IOUtil.java:223) ~[?:?]
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:358) ~[?:?]
at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:247) ~[bundleFile:4.1.42.Final]
at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1147) ~[bundleFile:4.1.42.Final]
at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:347) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:700) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:635) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:552) ~[bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:514) ~[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]
at java.lang.Thread.run(Thread.java:834) [?:?]
2021-04-27 14:28:35.764 [TRACE] [rver.impl.http.impl.AccessoryHandler] - Terminated HomeKit connection from /192.168.2.143:55780

@openhab-bot
Copy link
Collaborator

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/homekit-no-response-error-on-all-openhab-items/118200/104

@piejanssens
Copy link

@kaikreuzer Did OH 3.1 ship with jmdns 3.5.7? Where can we see this info?

@kaikreuzer
Copy link
Member

Yes, you can check on the openHAB console like this:

openhab> list -s | grep jmdns
 56 │ Active │  80 │ 3.5.7                 │ javax.jmdns

markuslindenberg added a commit to markuslindenberg/habfw that referenced this issue Oct 19, 2021
@openhab-bot
Copy link
Collaborator

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/homekit-no-response-error-on-all-openhab-items/118200/153

@yfre
Copy link
Contributor

yfre commented Nov 14, 2022

@jewesta this bug report is almost 2 years old and there were several improvements in the homekit binding
do you still have this issue or can we close this bug report?

@jewesta
Copy link
Author

jewesta commented Nov 14, 2022

@yfre I've been using 3.3.0 Release for quite a while now and the problem is gone. Yes, I am confident that we can close this issue. Thanks a lot for keeping track! 👍

@jewesta jewesta closed this as completed Nov 14, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug An unexpected problem or unintended behavior of an add-on
Projects
None yet
Development

No branches or pull requests

10 participants