DeconZ and OpenWeatherMap stops working (together)

kangaxx · February 18, 2021, 8:02am

Hello,
since a while I had the Problem that the OpenWeatherMap-Binding stopped working, so I had to restart the Raspi (3 B+ with openhabian).
Last Autumn I bought a Dresden Elektronik Zigbee Dongle for some lights (originally I used only a Razberry Z-Wave PiHat but Lights with Zwave is really expensive). Now I have the problem that the deconz-binding (working flawlessly after installation) stopped working too after a while (it’s different, sometimes they work for over two weeks and sometimes they stop working after a few days) but always both stop working together. After a hole restart of the Pi they’re working again, restarting only the binding in the cli doesn’t help.
I’m not sure if its really the bindings or somesing else… when openhab is not able to switch the Zigbee lights; with the Hue-app (connected to the deconz-software too) it is still working.
The overview of the things says that its all online.

This week I migrated to OH3 (from OH2.5), everything was working so far, till yesterday with the mentioned above problems. I hoped the problem would be solved with the upgrade but still the same behavior…
So I’m not sure if it is the software or something else but I have no idea where to look.
Could it happen when the Internetconnection is shortly gone? I have a Pihole in the Network and sometimes it quits working too, so I have to restart it. But I still couldn’t get a context of this. So I have no idea where to look further (and surely need some help with my poor linux-skills).

Now it is in the state that it is not working, I didn’t restart the Pi…

Wolfgang_S · February 18, 2021, 6:28pm

first things to check would be the openhab.log, events.log file in folder /var/log/openhab to check if you can find any entry that gives a hint why it does not work any more.
On system level you can have a look to /var/log/syslog.log

kangaxx · February 19, 2021, 6:54am

In the openhab.log was nothing to find… I set the loglevel for the OW-binding to debug and the deconz-binding to trace. I just restartet the machine and take a look when they stop working again.

kangaxx · February 20, 2021, 11:23am

O.K., after the reboot I had too many problems (some rules weren’t working und the bindings stops working within the same day).
So I rolled back the hole system to v2.5.12 and will take a further look to these two bindings. When the system is running stable I will take a new trial for the upgrade to v3.

//Edit: I found the same error like here discribed , but there is no solution.

Here the part from the openhab.log
2021-02-20 13:59:34.664 [DEBUG] [internal.handler.DeconzBridgeHandler] - Get full state failed


java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException: Total timeout 3000 ms elapsed
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) ~[?:?]

at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346) ~[?:?]

at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:632) ~[?:?]

at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) [?:?]

at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) [?:?]

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.HttpReceiver.terminateResponse(HttpReceiver.java:444) [bundleFile:9.4.20.v20190813]

at org.eclipse.jetty.client.HttpReceiver.abort(HttpReceiver.java:527) [bundleFile:9.4.20.v20190813]

at org.eclipse.jetty.client.HttpChannel.abortResponse(HttpChannel.java:156) [bundleFile:9.4.20.v20190813]

at org.eclipse.jetty.client.HttpChannel.abort(HttpChannel.java:149) [bundleFile:9.4.20.v20190813]

at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:257) [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.TimeoutCompleteListener.onTimeoutExpired(TimeoutCompleteListener.java:51) [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:515) [?:?]

at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]

at java.lang.Thread.run(Thread.java:834) [?:?]

Caused by: java.util.concurrent.TimeoutException: Total timeout 3000 ms elapsed
... 8 more

2021-02-20 13:59:48.155 [TRACE] [nternal.netutils.WebSocketConnection] - Raw data received by websocket ESH-httpClient-conz-deconz-b5f7dc6c$3209424: {“attr”:{“id”:“2”,“lastannounced”:null,“lastseen”:“2021-02-20T12:59Z”,“manufacturername”:“dresden elektronik”,“modelid”:“ConBee II”,“name”:“Configuration tool 2”,“swversion”:“0x00000000”,“type”:“Configuration tool”,“uniqueid”:“00:21:2e:ff:ff:06:15:be-01”},“e”:“changed”,“id”:“2”,“r”:“lights”,“t”:“event”,“uniqueid”:“00:21:2e:ff:ff:06:15:be-01”}
2021-02-20 13:59:48.158 [TRACE] [nternal.netutils.WebSocketConnection] - Couldn’t find light listener for id 2
2021-02-20 13:59:55.396 [TRACE] [nternal.netutils.WebSocketConnection] - Raw data received by websocket ESH-httpClient-conz-deconz-b5f7dc6c$3209424: {“attr”:{“colorcapabilities”:31,“ctmax”:1000,“ctmin”:100,“id”:“1”,“lastannounced”:“2021-01-10T17:22:13Z”,“lastseen”:“2021-02-20T12:59Z”,“manufacturername”:“innr”,“modelid”:“FL 140 C”,“name”:“Terrassenlicht”,“swversion”:“0x27202162”,“type”:“Extended color light”,“uniqueid”:“00:15:8d:00:05:01:8a:58-01”},“e”:“changed”,“id”:“1”,“r”:“lights”,“t”:“event”,“uniqueid”:“00:15:8d:00:05:01:8a:58-01”}
2021-02-20 13:59:55.400 [TRACE] [z.internal.handler.LightThingHandler] - deconz:extendedcolorlight:b5f7dc6c:00158d0005018a5801 received LightMessage{hascolor=null, ctmax=null, ctmin=null, type=null, state=null, e=‘changed’, r=‘lights’, t=‘event’, id=‘1’, manufacturername=’’, modelid=’’, name=’’, swversion=’’, ep=’’, uniqueid=‘00:15:8d:00:05:01:8a:58-01’}
2021-02-20 14:00:05.023 [TRACE] [nternal.netutils.WebSocketConnection] - Raw data received by websocket ESH-httpClient-conz-deconz-b5f7dc6c$3209424: {“attr”:{“id”:“3”,“lastannounced”:“2021-02-12T07:39:25Z”,“lastseen”:“2021-02-20T13:00Z”,“manufacturername”:“IKEA of Sweden”,“modelid”:“TRADFRI Driver 10W”,“name”:“Vitrine_WZ”,“swversion”:“1.2.245”,“type”:“Dimmable light”,“uniqueid”:“84:2e:14:ff:fe:79:cc:1d-01”},“e”:“changed”,“id”:“3”,“r”:“lights”,“t”:“event”,“uniqueid”:“84:2e:14:ff:fe:79:cc:1d-01”}

2021-02-20 14:00:05.027 [TRACE] [z.internal.handler.LightThingHandler] - deconz:dimmablelight:b5f7dc6c:842e14fffe79cc1d01 received LightMessage{hascolor=null, ctmax=null, ctmin=null, type=null, state=null, e=‘changed’, r=‘lights’, t=‘event’, id=‘3’, manufacturername=’’, modelid=’’, name=’’, swversion=’’, ep=’’, uniqueid=‘84:2e:14:ff:fe:79:cc:1d-01’}

kangaxx · February 20, 2021, 6:08pm

They stopped working again.
In the /var/log/syslog I found the following:
Feb 20 08:28:08 openHABianDevice 08:28:08 deCONZ-WIFI2.sh[408]: command failed: Network is down (-100) Feb 20 17:38:21 openHABianDevice deCONZ-update2.sh[328]: Error: database is locked Feb 20 17:38:22 openHABianDevice deCONZ-WIFI2.sh[408]: Error: database is locked Feb 20 19:45:08 openHABianDevice deCONZ-WIFI2.sh[408]: command failed: Network is down (-100)
nearly 3 minutes the same entry over and over again and at many point since I restartet the Raspi at 07:55…

And this is the point in the openhab.log:
2021-02-20 17:37:53.419 [TRACE] [nternal.netutils.WebSocketConnection] - Raw data received by websocket ESH-httpClient-conz-deconz-b5f7dc6c$3209424: {“attr”:{“id”:“3”,$ 2021-02-20 17:37:53.422 [TRACE] [z.internal.handler.LightThingHandler] - deconz:dimmablelight:b5f7dc6c:842e14fffe79cc1d01 received LightMessage{hascolor=null, ctmax=nu$ 2021-02-20 17:37:55.754 [TRACE] [nternal.netutils.WebSocketConnection] - Raw data received by websocket ESH-httpClient-conz-deconz-b5f7dc6c$3209424: {“attr”:{“id”:“2”,$ 2021-02-20 17:37:55.759 [TRACE] [nternal.netutils.WebSocketConnection] - Couldn’t find light listener for id 2 2021-02-20 17:38:00.101 [TRACE] [z.internal.handler.LightThingHandler] - Sending {“on”:true,“bri”:190,“hue”:3458,“sat”:243} to light 1 via http://localhost:80/api/7493$ 2021-02-20 17:38:03.105 [DEBUG] [z.internal.handler.LightThingHandler] - Sending command 19,96,75 to channel deconz:extendedcolorlight:b5f7dc6c:00158d0005018a5801:colo$ java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException: Total timeout 3000 ms elapsed at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) ~[?:?] at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346) ~[?:?] at java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:704) ~[?:?] at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) [?:?] at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) [?:?] 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:515) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?] at java.lang.Thread.run(Thread.java:834) [?:?] Caused by: java.util.concurrent.TimeoutException: Total timeout 3000 ms elapsed … 8 more 2021-02-20 17:38:14.089 [TRACE] [nternal.netutils.WebSocketConnection] - Raw data received by websocket ESH-httpClient-conz-deconz-b5f7dc6c$3209424: {“attr”:{"colorcap$ 2021-02-20 17:38:14.092 [TRACE] [z.internal.handler.LightThingHandler] - deconz:extendedcolorlight:b5f7dc6c:00158d0005018a5801 received LightMessage{hascolor=null, ctm$ 2021-02-20 17:38:58.527 [TRACE] [nternal.netutils.WebSocketConnection] - Raw data received by websocket ESH-httpClient-conz-deconz-b5f7dc6c$3209424: {“attr”:{“id”:“3”,$ 2021-02-20 17:38:58.532 [TRACE] [z.internal.handler.LightThingHandler] - deconz:dimmablelight:b5f7dc6c:842e14fffe79cc1d01 received LightMessage{hascolor=null, ctmax=nu$ 2021-02-20 17:39:00.858 [TRACE] [nternal.netutils.WebSocketConnection] - Raw data received by websocket ESH-httpClient-conz-deconz-b5f7dc6c$3209424: {“attr”:{“id”:“2”,$ 2021-02-20 17:39:00.862 [TRACE] [nternal.netutils.WebSocketConnection] - Couldn’t find light listener for id 2

RGroll · February 20, 2021, 6:11pm

Did you changed the owner of some of your files?

kangaxx · February 20, 2021, 6:39pm

Yes, after this I copied back the files and changed the owner and permissions. But I think I got the problems with these bindings before but I’m not really sure.

After booting the Raspi all is working so far and at some point of the day (not really sure when) they stopped working. Everything else (Zwave, Astro, MQTT, Telegram, Network, Onky, Samsung and WiFi-LED) is working like before.

I took a look in the events.log…
The light at the terrace (a zigbee lightstripe) had to switch on, when the sun sets.
In the events.log is nothing to find at this point, the part of the openhab.log (mentioned above) it is the point at 17:38:03.

Now the deCONZ-bridge says “online” but when I will restart the binding at openhab-cli it says always “initialising”, with the openweathermap-binding the same.

Wolfgang_S · February 21, 2021, 9:16am

firmware of DeconZ is up-to-date ?
I don’t expect that pihole is the root cause for DeconZ to fail nevertheless could you define an exception so that all network traffic of the OH host bipasses the pihole filter ?
what if you temporarily disable the OpenWeatherMap binding ?

kangaxx · February 21, 2021, 9:23am

Yes, deconz-FW is up-to-date (v2.09.03).
Here (last post) I found a problem with the permissions of deconz.service and deconz-update.service. Probably thats the solution for the “Database is locked”-error, so I inserted the “User=1000” at deconz-update.service too.
I also disabled the deconz-wifi service because I’m not using it (sudo systemctl stop deconz-wifi; sudo systemctl disable deconz-wifi).
Now I restarted the machine, disabled the OW-binding and take a look how long the deconz-binding is working now.

kangaxx · February 27, 2021, 7:19pm

This week it stops working again (I can’t say when because within the week I’m not at home).
I stopped the openhab2-service, cleaned the cache and rebooted the Raspi.
The loglevel for deconz I set back to debug, with Trace the logfiles ran full rapidly and I didn’t found something helpfull in there.
After rebooting and waiting nearly 10 minutes I recognized that 19% of the RAM is free (Raspi 3B+ with 1GB). Before rebooting it were only 4%…
I will observe this, probably the machine runs out of RAM?

kangaxx · February 28, 2021, 5:29pm

The OWM-Binding throws out the following error:
2021-02-28 17:21:42.870 [DEBUG] [nWeatherMapWeatherAndForecastHandler] - Update weather and forecast data of thing ‘openweathermap:weather-and-orecast:826570ce:local’. 2021-02-28 17:21:43.599 [DEBUG] [ap.internal.utils.ByteArrayFileCache] - Reading file ‘479a332fb40d867790aa8107dfead30b.png’ from cache 2021-02-28 17:21:43.604 [DEBUG] [nWeatherMapWeatherAndForecastHandler] - Update channel ‘icon’ of group ‘current’ with new state ‘raw type (image/png): 2773 bytes’. 2021-02-28 17:21:43.611 [DEBUG] [nWeatherMapWeatherAndForecastHandler] - Update channel ‘temperature’ of group ‘current’ with new state ‘5.83 °C’. 2021-02-28 17:21:43.623 [DEBUG] [nWeatherMapWeatherAndForecastHandler] - Update channel ‘pressure’ of group ‘current’ with new state ‘1035.0 hPa’. 2021-02-28 17:21:43.650 [DEBUG] [nWeatherMapWeatherAndForecastHandler] - Update channel ‘humidity’ of group ‘current’ with new state ‘93 %’. 2021-02-28 17:21:43.659 [DEBUG] [nWeatherMapWeatherAndForecastHandler] - Update channel ‘wind-speed’ of group ‘current’ with new state ‘4.63 m/s’. 2021-02-28 17:21:43.676 [DEBUG] [nWeatherMapWeatherAndForecastHandler] - Update channel ‘wind-direction’ of group ‘current’ with new state ‘320.0 °’. 2021-02-28 17:21:43.690 [DEBUG] [handler.OpenWeatherMapUVIndexHandler] - Update UV Index data of thing ‘openweathermap:uvindex:826570ce:local’. 2021-02-28 17:21:43.830 [DEBUG] [handler.OpenWeatherMapUVIndexHandler] - JsonSyntaxException occurred during execution: java.lang.IllegalStateException: Expected BEGIN_ARRAY but was BEGIN_OBJECT at line 1 column 2 path $ com.google.gson.JsonSyntaxException: java.lang.IllegalStateException: Expected BEGIN_ARRAY but was BEGIN_OBJECT at line 1 column 2 path $ at com.google.gson.Gson.fromJson(Gson.java:900) ~[bundleFile:?] at com.google.gson.Gson.fromJson(Gson.java:853) ~[bundleFile:?] at com.google.gson.Gson.fromJson(Gson.java:802) ~[bundleFile:?] at com.google.gson.Gson.fromJson(Gson.java:774) ~[bundleFile:?] at org.openhab.binding.openweathermap.internal.connection.OpenWeatherMapConnection.getUVIndexForecastData(OpenWeatherMapConnection.java:207) ~[bundleFile:?] at org.openhab.binding.openweathermap.internal.handler.OpenWeatherMapUVIndexHandler.requestData(OpenWeatherMapUVIndexHandler.java:123) [bundleFile:?] at org.openhab.binding.openweathermap.internal.handler.AbstractOpenWeatherMapHandler.updateData(AbstractOpenWeatherMapHandler.java:138) [bundleFile:?] at org.openhab.binding.openweathermap.internal.handler.OpenWeatherMapAPIHandler.updateThing(OpenWeatherMapAPIHandler.java:176) [bundleFile:?] at org.openhab.binding.openweathermap.internal.handler.OpenWeatherMapAPIHandler.updateThings(OpenWeatherMapAPIHandler.java:167) [bundleFile:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?] at java.lang.Thread.run(Thread.java:834) [?:?] Caused by: java.lang.IllegalStateException: Expected BEGIN_ARRAY but was BEGIN_OBJECT at line 1 column 2 path $ at com.google.gson.stream.JsonReader.beginArray(JsonReader.java:350) ~[bundleFile:?] at com.google.gson.internal.bind.ArrayTypeAdapter.read(ArrayTypeAdapter.java:70) ~[bundleFile:?] at com.google.gson.Gson.fromJson(Gson.java:888) ~[bundleFile:?] … 14 more

kangaxx · March 1, 2021, 1:52pm

Stops working again…
But now I can conclose it to a period of nearly half an hour.
When I went to bed yesterday I could switch off the showcase normally, half an hour later the terrace should switch off, what it didn’t.
Now I’m browsing the logs…
The last change from Openweathermap was at 23:42, at 00:22 the OW-Bridge went offline.

I think there is no immediate connection betwen these two bindings, it has to be somewhere else.

rossko57 · March 1, 2021, 2:00pm

OWM are changing the data they supply here.

kangaxx · March 1, 2021, 2:21pm

O.K., I removed the UV-index (I don’t really need it, it’s only nice to know).

But in the logs I didn’t found something helpfull.

In the syslog I found many entries like this:
Feb 28 22:30:15 openHABianDevice influxd[796]: [httpd] 127.0.0.1 - openhab [28/Feb/2021:22:30:15 +0100] “POST /write?consistency=one&db=openhab_db&p=%5BREDACTED%5D&precision=n&rp=autogen&u=openhab HTTP/1.1” 204 0 “-” “okhttp/2.4.0” 25a66340-7a0c-11eb-81ba-b827eb0c5468 7914 Feb 28 22:31:15 openHABianDevice influxd[796]: [httpd] 127.0.0.1 - openhab [28/Feb/2021:22:31:15 +0100] “POST /write?consistency=one&db=openhab_db&p=%5BREDACTED%5D&precision=n&rp=autogen&u=openhab HTTP/1.1” 204 0 “-” “okhttp/2.4.0” 4969a422-7a0c-11eb-81bb-b827eb0c5468 9609 Feb 28 22:32:15 openHABianDevice influxd[796]: [httpd] 127.0.0.1 - openhab [28/Feb/2021:22:32:15 +0100] “POST /write?consistency=one&db=openhab_db&p=%5BREDACTED%5D&precision=n&rp=autogen&u=openhab HTTP/1.1” 204 0 “-” “okhttp/2.4.0” 6d2cf03a-7a0c-11eb-81bc-b827eb0c5468 175133 Feb 28 22:33:15 openHABianDevice influxd[796]: [httpd] 127.0.0.1 - openhab [28/Feb/2021:22:33:15 +0100] “POST /write?consistency=one&db=openhab_db&p=%5BREDACTED%5D&precision=n&rp=autogen&u=openhab HTTP/1.1” 204 0 “-” “okhttp/2.4.0” 90f0465e-7a0c-11eb-81bd-b827eb0c5468 122753 Feb 28 22:34:15 openHABianDevice influxd[796]: [httpd] 127.0.0.1 - openhab [28/Feb/2021:22:34:15 +0100] “POST /write?consistency=one&db=openhab_db&p=%5BREDACTED%5D&precision=n&rp=autogen&u=openhab HTTP/1.1” 204 0 “-” “okhttp/2.4.0” b4b378f8-7a0c-11eb-81be-b827eb0c5468 22794 Feb 28 22:35:15 openHABianDevice influxd[796]: [httpd] 127.0.0.1 - openhab [28/Feb/2021:22:35:15 +0100] “POST /write?consistency=one&db=openhab_db&p=%5BREDACTED%5D&precision=n&rp=autogen&u=openhab HTTP/1.1” 204 0 “-” “okhttp/2.4.0” d876fa38-7a0c-11eb-81bf-b827eb0c5468 358070 Feb 28 22:36:15 openHABianDevice influxd[796]: [httpd] 127.0.0.1 - openhab [28/Feb/2021:22:36:15 +0100] “POST /write?consistency=one&db=openhab_db&p=%5BREDACTED%5D&precision=n&rp=autogen&u=openhab HTTP/1.1” 204 0 “-” “okhttp/2.4.0” fc3a39cb-7a0c-11eb-81c0-b827eb0c5468 10588 Feb 28 22:37:15 openHABianDevice influxd[796]: [httpd] 127.0.0.1 - openhab [28/Feb/2021:22:37:15 +0100] “POST /write?consistency=one&db=openhab_db&p=%5BREDACTED%5D&precision=n&rp=autogen&u=openhab HTTP/1.1” 204 0 “-” “okhttp/2.4.0” 1ffd5002-7a0d-11eb-81c1-b827eb0c5468 10339

and this:
Feb 28 22:23:15 openHABianDevice dhcpcd[793]: eth0: Router Advertisement from fe80::9ec7:a6ff:fe14:4da1 Feb 28 22:23:15 openHABianDevice systemd[1]: Stopping Network Time Synchronization… Feb 28 22:23:15 openHABianDevice systemd[1]: systemd-timesyncd.service: Succeeded. Feb 28 22:23:15 openHABianDevice systemd[1]: Stopped Network Time Synchronization. Feb 28 22:23:16 openHABianDevice systemd[1]: Starting Network Time Synchronization… Feb 28 22:23:16 openHABianDevice systemd[1]: Started Network Time Synchronization. Feb 28 22:23:16 openHABianDevice systemd[1]: Stopping Network Time Synchronization… Feb 28 22:23:17 openHABianDevice systemd[1]: systemd-timesyncd.service: Succeeded. Feb 28 22:23:17 openHABianDevice systemd[1]: Stopped Network Time Synchronization. Feb 28 22:23:17 openHABianDevice systemd[1]: Starting Network Time Synchronization… Feb 28 22:23:17 openHABianDevice systemd[1]: Started Network Time Synchronization. Feb 28 22:23:49 openHABianDevice dhcpcd[793]: eth0: Router Advertisement from fe80::9ec7:a6ff:fe14:4da1 Feb 28 22:23:49 openHABianDevice systemd[1]: Stopping Network Time Synchronization… Feb 28 22:23:49 openHABianDevice systemd[1]: systemd-timesyncd.service: Succeeded. Feb 28 22:23:49 openHABianDevice systemd[1]: Stopped Network Time Synchronization. Feb 28 22:23:49 openHABianDevice systemd[1]: Starting Network Time Synchronization… Feb 28 22:23:49 openHABianDevice systemd[1]: Started Network Time Synchronization. Feb 28 22:23:50 openHABianDevice systemd[1]: Stopping Network Time Synchronization… Feb 28 22:23:50 openHABianDevice systemd[1]: systemd-timesyncd.service: Succeeded. Feb 28 22:23:50 openHABianDevice systemd[1]: Stopped Network Time Synchronization. Feb 28 22:23:50 openHABianDevice systemd[1]: Starting Network Time Synchronization… Feb 28 22:23:50 openHABianDevice systemd[1]: Started Network Time Synchronization.

What could this be?

stepi · March 24, 2021, 9:33pm

I have the same problem… It works fine for the last 3month and now openhab works only for some hours…Then openweathermaps and deconz stops working.

The only solution for me is to reboot …any ideas?

OH 3.01
DECONZ 2.09.03

log:

2021-03-24 22:28:38.958 [DEBUG] [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:331) ~[?:?]

	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346) ~[?:?]

	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:632) ~[?:?]

	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) [?:?]

	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) [?:?]

	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:515) [?:?]

	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]

	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]

	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]

	at java.lang.Thread.run(Thread.java:834) [?:?]

Caused by: java.util.concurrent.TimeoutException: Total timeout 2000 ms elapsed

	... 8 more

kangaxx · March 27, 2021, 10:19am

I probably found the solution for myself.
Following:
I also had installed the AVM-Fritz!-Binding. Sometimes I recognized that the Fritzbox (I had only the device, no items linked to it) went offline too but I never got a context of that.
This and deconz both communicates via port 80 by default. I changed deconz to port 84 (in /lib/systemd/system/deconz.service and paperUI) and Fritz to port 85 (but it came never online at that port). After rebooting it was running over a week without issues. After this week I deinstalled the Fritz-Binding because it is mainly for the smart-devices from AVM and I don’t own one of them (I originally installed it for communicating with the Fritzbox itself, but for that the TR064-Binding is the right one).
Now it runs for over two weeks without a full reboot (accept the restart of openhab when deinstalling the binding).
The TR064-Binding is a Openhab v1 Version so I will probably install it after upgrading to openhab v3 (I think there is a v3-version available).

Now I will change Openweathermap to the OneCallAPI, look how it runs and then I will give an update to v3 another try.

Wolfgang_S · March 27, 2021, 10:29am

I would say this can’t be the reason for the problem - at least I do not understand how this could be the reason. The Fritz Box and deconz ( hardware ! ) are not both hosted on your OH host.
Both may use port 80. OH is the client and opens different ports ( > 1024 ) on the client side. It would be a problem if deconz hardware uses port 80 on your OH host and another service also tries to start on port 80 like nginx or apache. But this conflict will be show at startup of the services ( e.g. deconz vs. nginx ) for the second service to be started on the same port.

kangaxx · March 27, 2021, 10:37am

Sounds plausible…
But these where the only Probably I have another sudo netstat -tulpn doesn’t say so: tcp 0 0 127.0.0.1:8088 tcp 0 0 0.0.0.0:8443 tcp 0 0 0.0.0.0:443 tcp 0 0 0.0.0.0:1883 tcp 0 0 0.0.0.0:445 tcp 0 0 127.0.0.1:8101 tcp 0 0 0.0.0.0:9001 tcp 0 0 0.0.0.0:139 tcp 0 0 0.0.0.0:5007 tcp 0 0 0.0.0.0:8080 tcp 0 0 0.0.0.0:84 tcp 0 0 127.0.0.1:44565 tcp 0 0 127.0.0.1:8086 tcp 0 0 0.0.0.0:22 tcp6 0 0 :::3000 tcp6 0 0 :::1883 tcp6 0 0 :::445 tcp6 0 0 :::139 tcp6 0 0 :::22 things I changed in my configuration. service on port 80 running on my raspi but | grep LISTEN 0.0.0.0:* LISTEN 708/influxd 0.0.0.0:* LISTEN 1059/java 0.0.0.0:* LISTEN 346/deCONZ 0.0.0.0:* LISTEN 709/mosquitto 0.0.0.0:* LISTEN 1073/smbd 0.0.0.0:* LISTEN 1059/java 0.0.0.0:* LISTEN 2565/node 0.0.0.0:* LISTEN 1073/smbd 0.0.0.0:* LISTEN 1059/java 0.0.0.0:* LISTEN 1059/java 0.0.0.0:* LISTEN 346/deCONZ 0.0.0.0:* LISTEN 1059/java 0.0.0.0:* LISTEN 708/influxd 0.0.0.0:* LISTEN 717/sshd :::* LISTEN 707/grafana-server :::* LISTEN 709/mosquitto :::* LISTEN 1073/smbd :::* LISTEN 1073/smbd :::* LISTEN 717/sshd

//Edit (2021-04-11): Its running for 4 weeks now, without any issues.