[deconz] Values are not updated

[eric1905]

My values from deconz stop to be updated after some time. In the phoscon app from my conbee II stick are correct, also the values in the rest api http://deconzip/api// But when I check the values in Visual Studio Code they are not updated and remain. In this case the presence remains as ON in openhab, even if there was no movement. Deconz says no presence. And as it is not changing no rule is working

After a restart of openhab service they resume working but after some time they stop again sudo systemctl restart openhab2

Expected Behavior

Values in Openhab are updated correctly

Current Behavior

Values in openhab are not updated

Steps to Reproduce (for Bugs)

Unfortunately I cannot reproduce this issue

Your Environment

"Debian GNU/Linux 10 (buster)" openHAB 2.5.6 Release Build openjdk version "1.8.0_252" OpenJDK Runtime Environment (Zulu 8.46.0.19-CA-linux64) (build 1.8.0_252-b14) OpenJDK 64-Bit Server VM (Zulu 8.46.0.19-CA-linux64) (build 25.252-b14, mixed mode)

My phoscon app has version 2.05.78 / 22.05.2020 Firmware 26580700

[J-N-K]

Please show the openHAB log when this happens.

[eric1905]

I just recognized that it is not working again. But how should I show the log file. Do I need a specific log level? For which class? It is hard to find the moment when it stops working, I just can see when it is not working anymore.

[eric1905]

@J-N-K Ok, I created a logfile for org.openhab.binding.deconz

It stopped working during today and now I find a lot of the following errors in the logfile:

2020-09-27 18:24:50.145 [DEBUG] [onz.internal.handler.DeconzBridgeHandler] - Get full state failed java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException: Total timeout 2000 ms elapsed at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) [?:1.8.0_252] at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) [?:1.8.0_252] at org.openhab.binding.deconz.internal.netutils.AsyncHttpClient$1.onComplete(AsyncHttpClient.java:109) [bundleFile:?] at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:198) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:190) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpExchange.notifyFailureComplete(HttpExchange.java:269) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:240) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpConversation.abort(HttpConversation.java:149) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpRequest.abort(HttpRequest.java:768) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpDestination$TimeoutTask.onTimeoutExpired(HttpDestination.java:529) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:282) [bundleFile:9.4.20.v20190813] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_252] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_252] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?: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.util.concurrent.TimeoutException: Total timeout 2000 ms elapsed ... 9 more 2020-09-27 18:34:50.146 [DEBUG] [onz.internal.handler.DeconzBridgeHandler] - Get full state failed java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException: Total timeout 2000 ms elapsed at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) [?:1.8.0_252] at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) [?:1.8.0_252] at org.openhab.binding.deconz.internal.netutils.AsyncHttpClient$1.onComplete(AsyncHttpClient.java:109) [bundleFile:?] at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:198) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:190) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpExchange.notifyFailureComplete(HttpExchange.java:269) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:240) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpConversation.abort(HttpConversation.java:149) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpRequest.abort(HttpRequest.java:768) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpDestination$TimeoutTask.onTimeoutExpired(HttpDestination.java:529) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:282) [bundleFile:9.4.20.v20190813] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_252] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_252] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?: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.util.concurrent.TimeoutException: Total timeout 2000 ms elapsed ... 9 more 2020-09-27 18:39:50.146 [DEBUG] [onz.internal.handler.DeconzBridgeHandler] - Get full state failed java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException: Total timeout 2000 ms elapsed at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) [?:1.8.0_252] at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) [?:1.8.0_252] at org.openhab.binding.deconz.internal.netutils.AsyncHttpClient$1.onComplete(AsyncHttpClient.java:109) [bundleFile:?] at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:198) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:190) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpExchange.notifyFailureComplete(HttpExchange.java:269) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:240) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpConversation.abort(HttpConversation.java:149) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpRequest.abort(HttpRequest.java:768) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpDestination$TimeoutTask.onTimeoutExpired(HttpDestination.java:529) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:282) [bundleFile:9.4.20.v20190813] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_252] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_252] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?: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.util.concurrent.TimeoutException: Total timeout 2000 ms elapsed ... 9 more

Between a lot of those messages I found one other error message, but maybe this is only temporary

2020-09-27 12:39:48.997 [DEBUG] [onz.internal.handler.DeconzBridgeHandler] - Get full state failed java.util.concurrent.CompletionException: java.net.NoRouteToHostException: Keine Route zum Zielrechner at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591) ~[?:1.8.0_252] at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) [?:1.8.0_252] at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) [?:1.8.0_252] at org.openhab.binding.deconz.internal.netutils.AsyncHttpClient$1.onComplete(AsyncHttpClient.java:109) [bundleFile:?] at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:198) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:190) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpExchange.notifyFailureComplete(HttpExchange.java:269) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:240) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpConversation.abort(HttpConversation.java:149) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpRequest.abort(HttpRequest.java:768) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpDestination.abort(HttpDestination.java:453) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpDestination.failed(HttpDestination.java:234) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.AbstractConnectionPool$1.failed(AbstractConnectionPool.java:140) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.util.Promise$Wrapper.failed(Promise.java:136) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.HttpClient$1$1.failed(HttpClient.java:612) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.AbstractConnectorHttpClientTransport.connectFailed(AbstractConnectorHttpClientTransport.java:138) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.client.AbstractConnectorHttpClientTransport$ClientSelectorManager.connectionFailed(AbstractConnectorHttpClientTransport.java:188) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.io.ManagedSelector$Connect.failed(ManagedSelector.java:812) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.io.ManagedSelector.processConnect(ManagedSelector.java:245) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.io.ManagedSelector.access$1500(ManagedSelector.java:61) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.processSelected(ManagedSelector.java:533) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:395) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:360) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:184) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813] at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252] Caused by: java.net.NoRouteToHostException: Keine Route zum Zielrechner at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) ~[?:1.8.0_252] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:714) ~[?:1.8.0_252] at org.eclipse.jetty.io.SelectorManager.doFinishConnect(SelectorManager.java:355) ~[?:?] at org.eclipse.jetty.io.ManagedSelector.processConnect(ManagedSelector.java:223) ~[?:?] ... 11 more

Is this helpful? Is there a class which I should add to my logger so I can get a more detailed log?

[J-N-K]

Especially the last message states that you have Network issue (no route to host). The others are timeouts, so the binding is Not receiving an answer from the gateway.

[eric1905]

Yes I know, that the last message is related to an network issue. But this one occured just one time, and the oter ones multiple times before and after the network issue. Is there the possibility to try to call the gateway after SSH to the openhab console or from another computer in the network so I can figure out if the problem is related to openhab? Because I already installed my deconz software on another raspberry pi and the error still occurs, so it should not be related to the phoscon gateway.

[eric1905]

@J-N-K I am also not sure when this happens, It happened today again and I thought it happend during the time I rebooted my router. So I had the guess that it happens as soon the deconz service is not reachable anymore. So I did it again and also tried to take my raspberry with phoscon offline but then I saw the following in the log: 2020-10-03 18:36:25.967 [DEBUG] [nz.internal.netutils.WebSocketConnection] - Connecting to: ws://192.168.0.219:443 2020-10-03 18:36:35.985 [DEBUG] [nz.internal.netutils.WebSocketConnection] - Connecting to: ws://192.168.0.219:443 2020-10-03 18:36:49.255 [DEBUG] [nz.internal.netutils.WebSocketConnection] - Connecting to: ws://192.168.0.219:443 2020-10-03 18:37:00.989 [DEBUG] [nz.internal.netutils.WebSocketConnection] - Connecting to: ws://192.168.0.219:443 2020-10-03 18:37:11.001 [DEBUG] [nz.internal.netutils.WebSocketConnection] - Connecting to: ws://192.168.0.219:443 2020-10-03 18:37:11.016 [DEBUG] [nz.internal.netutils.WebSocketConnection] - Connect: /192.168.0.219

Until i it was reachable again. But when the error happens it is not trying to reconnect. So why is openhab not able to connect to deconz in this special case and returns another errormessage compared to the case where I remove deconz from the netwrok

[J-N-K]

Found. Will be fixed in next version. The reason is that no retry is scheduled if the initial request fails (no web socket connection at all ist started). If the connection fails later, the websocket is restarted.

[eric1905]

Thank you for your support. Looking forward to the next release