I recently upgraded my raspberry OpenHAB installation from 2.5.0 to 2.5.5.
After upgrade, the switches were not always online. Sometimes a restart of openHAB was enough, some other times a reboot of the box was necessary. I even tried to restart the bundle with the karaf console.
Activating the DEBUG log of the binding through the karaf console I noticed that for some reason the avmfritz binding tries to connect to the fritz!box router using the generic address fritz.box
instead of the proper ip address set in the things file. For some reasons that I do not know (probably related to my non-standard network settings and configuration) sometimes the raspberry cannot resolve the ip address of fritz.box
.
As a workaround, I simply edited the /etc/hosts
file by adding the fritz.box ip address (in my case 192.168.27.1).
The binding works reliably through openHAB restarts now, but I wonder whether this situation may give wrong results if there are multiple bridges in the network (for example, a permanent VPN connection with a fritzbox in another location).
Let me add more details in the following that may be helpful to some other user having similar random errors or to the binding developer. Is this an issue to be opened on the openhab addons github?
Thank you for your attention,
Lionello
I am using the avmfritz binding for controlling several DECT!200 smart switches through a fritzbox 7590 with fritzOS 7.19 . I am also using the old FritzboxTr064 binding as it works well for presence detection with android phones (much better than the network binding, but this is another story).
I use text file configuration for things and items.
Bridge avmfritz:fritzbox:1 "Fritz!Padova" @ "Soggiorno" [ipaddress="192.168.27.1",user="openhab2",password="YYYYYY"] {
Thing FRITZ_DECT_200 zzzzzzz "Fz_Asciugatrice" @ "Mansarda" [ain="zzzzz"]
}
I am using two different users for the FritzboxTr064 (configured through the fritzboxtr064.cfg ) and AVMFritz bindings. I thought that using the same users may lead to inconsistent behavior, but I reached this conclusion before realizing the problem of the hardcoded fritz.box address in the binding.
When the problem occurs, nothing appears in openhab.log, while the events.log file contains the following lines repeting every 15 seconds
2020-05-16 20:44:09.623 [hingStatusInfoChangedEvent] - 'avmfritz:fritzbox:1' changed from OFFLINE (COMMUNICATION_ERROR): Request is invalid to OFFLINE (COMMUNICATION_ERROR): FRITZ!Box does not respond
2020-05-16 20:44:11.302 [hingStatusInfoChangedEvent] - 'avmfritz:fritzbox:1' changed from OFFLINE (COMMUNICATION_ERROR): FRITZ!Box does not respond to OFFLINE (COMMUNICATION_ERROR): Request is invalid
2020-05-16 20:44:24.608 [hingStatusInfoChangedEvent] - 'avmfritz:fritzbox:1' changed from OFFLINE (COMMUNICATION_ERROR): Request is invalid to OFFLINE (COMMUNICATION_ERROR): FRITZ!Box does not respond
I activated the DEBUG level for the avmfritz binding and the log is as follows
2020-05-25 18:38:16.593 [DEBUG] [ery.AVMFritzUpnpDiscoveryParticipant] - discovered on /192.168.27.2
2020-05-25 18:38:16.599 [DEBUG] [ery.AVMFritzUpnpDiscoveryParticipant] - discovered: AVM Berlin FRITZ!Box 7590 avme (FRITZ!Box 7590) at 192.168.27.1
2020-05-25 18:38:16.833 [DEBUG] [l.discovery.AVMFritzDiscoveryService] - initialize discovery service
2020-05-25 18:38:16.841 [DEBUG] [l.discovery.AVMFritzDiscoveryService] - start background scanning job at interval 180s
2020-05-25 18:38:16.873 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - About to initialize FRITZ!Box fritzbox
2020-05-25 18:38:16.903 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - Discovered FRITZ!Box initialized: org.openhab.binding.avmfritz.internal.config.AVMFritzConfiguration@58127f[IP=fritz.box,port=<null>,proto=http,user=openhab2,pollingInterval=15,asyncTimeout=10000,syncTimeout=2000]
2020-05-25 18:38:16.914 [DEBUG] [ternal.hardware.FritzAhaWebInterface] - Failed to GET url 'http://fritz.box/login_sid.lua': java.net.UnknownHostException: fritz.box: Name or service not known
java.util.concurrent.ExecutionException: java.net.UnknownHostException: fritz.box: Name or service not known
at org.eclipse.jetty.client.util.FutureResponseListener.getResult(FutureResponseListener.java:118) ~[bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.client.util.FutureResponseListener.get(FutureResponseListener.java:101) ~[bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:685) ~[bundleFile:9.4.20.v20190813]
at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.syncGet(FritzAhaWebInterface.java:252) [bundleFile:?]
at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.authenticate(FritzAhaWebInterface.java:100) [bundleFile:?]
at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.<init>(FritzAhaWebInterface.java:208) [bundleFile:?]
at org.openhab.binding.avmfritz.internal.handler.AVMFritzBaseBridgeHandler.initialize(AVMFritzBaseBridgeHandler.java:141) [bundleFile:?]
at sun.reflect.GeneratedMethodAccessor93.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
Caused by: java.net.UnknownHostException: fritz.box: Name or service not known
at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method) ~[?:1.8.0_252]
at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:929) ~[?:1.8.0_252]
at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1324) ~[?:1.8.0_252]
at java.net.InetAddress.getAllByName0(InetAddress.java:1277) ~[?:1.8.0_252]
at java.net.InetAddress.getAllByName(InetAddress.java:1193) ~[?:1.8.0_252]
at java.net.InetAddress.getAllByName(InetAddress.java:1127) ~[?:1.8.0_252]
at org.eclipse.jetty.util.SocketAddressResolver$Async.lambda$resolve$1(SocketAddressResolver.java:170) ~[?:?]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) ~[?:?]
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) ~[?:?]
... 1 more
I tried to ping fritz.box from the raspberry and it did not respond. I then modified the /etc/host file by adding the fritz.box address and that address was reachable and the binding correctly connected to the router again.