openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.86k stars 3.58k forks source link

[network] NPE in PresenceDetection.enableDHCPListen() while disposing ThingHandler #3494

Closed cweitkamp closed 5 years ago

cweitkamp commented 6 years ago

You will see this NPE whenever a hostname cannot be resolved to an IP address (e.g. if you configure an unknown hostname).

2018-04-17 21:05:10.229 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.dispose()' on 'org.openhab.binding.network.handler.NetworkHandler@1bc4277': null
java.lang.NullPointerException: null
    at org.openhab.binding.network.internal.PresenceDetection.enableDHCPListen(PresenceDetection.java:524) [224:org.openhab.binding.network:2.3.0.201804141026]
    at org.openhab.binding.network.internal.PresenceDetection.stopAutomaticRefresh(PresenceDetection.java:500) [224:org.openhab.binding.network:2.3.0.201804141026]
    at org.openhab.binding.network.handler.NetworkHandler.dispose(NetworkHandler.java:143) [224:org.openhab.binding.network:2.3.0.201804141026]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
    at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [103:org.eclipse.smarthome.core:0.10.0.201804131043]
    at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [103:org.eclipse.smarthome.core:0.10.0.201804131043]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
    at java.lang.Thread.run(Thread.java:748) [?:?]
2018-04-17 21:05:10.235 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occurred while disposing handler of thing 'network:pingdevice:myphone': null
java.lang.NullPointerException: null
    at org.openhab.binding.network.internal.PresenceDetection.enableDHCPListen(PresenceDetection.java:524) [224:org.openhab.binding.network:2.3.0.201804141026]
    at org.openhab.binding.network.internal.PresenceDetection.stopAutomaticRefresh(PresenceDetection.java:500) [224:org.openhab.binding.network:2.3.0.201804141026]
    at org.openhab.binding.network.handler.NetworkHandler.dispose(NetworkHandler.java:143) [224:org.openhab.binding.network:2.3.0.201804141026]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
    at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [103:org.eclipse.smarthome.core:0.10.0.201804131043]
    at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [103:org.eclipse.smarthome.core:0.10.0.201804131043]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
    at java.lang.Thread.run(Thread.java:748) [?:?]

On initialization of the ThingHandler we see an ERROR log which should be reduced to DEBUG level:

2018-04-17 20:53:35.526 [ERROR] [nding.network.handler.NetworkHandler] - Configuration for hostname is faulty
java.net.UnknownHostException: myphone: Der Name oder der Dienst ist nicht bekannt
        at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method) ~[?:?]
        at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:928) [?:?]
        at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1323) [?:?]
        at java.net.InetAddress.getAllByName0(InetAddress.java:1276) [?:?]
        at java.net.InetAddress.getAllByName(InetAddress.java:1192) [?:?]
        at java.net.InetAddress.getAllByName(InetAddress.java:1126) [?:?]
        at java.net.InetAddress.getByName(InetAddress.java:1076) [?:?]
        at org.openhab.binding.network.internal.PresenceDetection.setHostname(PresenceDetection.java:96) [224:org.openhab.binding.network:2.3.0.201804141026]
        at org.openhab.binding.network.handler.NetworkHandler.initialize(NetworkHandler.java:156) [224:org.openhab.binding.network:2.3.0.201804141026]
        at org.openhab.binding.network.handler.NetworkHandler.initialize(NetworkHandler.java:202) [224:org.openhab.binding.network:2.3.0.201804141026]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [103:org.eclipse.smarthome.core:0.10.0.201804131043]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [103:org.eclipse.smarthome.core:0.10.0.201804131043]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
cweitkamp commented 6 years ago

As a side note: I didn't find time to replace the ExpiringCacheAsync with the ESH implementation (see https://github.com/openhab/openhab2-addons/pull/2765#pullrequestreview-75794884). Maybe someone can give me a hand on that.

cweitkamp commented 6 years ago

Another one:

2018-04-19 08:51:34.243 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception
java.lang.NullPointerException: null
    at java.util.LinkedList$ListItr.next(LinkedList.java:893) ~[?:?]
    at org.openhab.binding.network.internal.toberemoved.cache.ExpiringCacheAsync.setValue(ExpiringCacheAsync.java:90) ~[?:?]
    at org.openhab.binding.network.internal.PresenceDetection.submitFinalResult(PresenceDetection.java:321) ~[?:?]
    at org.openhab.binding.network.internal.PresenceDetection.waitForPresenceDetection(PresenceDetection.java:350) ~[?:?]
    at org.openhab.binding.network.internal.PresenceDetection.performPresenceDetection(PresenceDetection.java:288) ~[?:?]
    at org.openhab.binding.network.internal.PresenceDetection.lambda$4(PresenceDetection.java:479) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
    at java.lang.Thread.run(Thread.java:748) [?:?]
davidgraeff commented 5 years ago

The OP NPE is fixed in the lasted code base. Closing this now. If the second NPE still (which might be related) still occurs, please reopen.

cweitkamp commented 5 years ago

@davidgraeff Agreed. They never occurred again.

Do you think we can at least take care of the replacement for the "toberemoved" class (ExpiringCacheAsync)?

davidgraeff commented 5 years ago

My next round of fixing will be MQTT related, the network binding is like super low on my priority list atm. But yeah at some point that class should go.