Deconz binding Communication_Error UpgradeException: 0 null

HansMeier · September 18, 2020, 1:23pm

Hi Community,

i have problems with the deconz server since 2 weeks and I didn´t find the fault.
Does any one have an Idea for the problem?
I search in this forum but I don´t find the problem

If I restart the stystem all binding are in function.
After about 3-6 hours the deconz binding have a communication error.
With the communication error I can controll the lights, but I get a bad response.
So all rules are out of function.

On the deconz binding i have some window- and motionsensors and 5 hue lights.

In the eventlog I get these output:

2020-09-18 11:16:13.233 [hingStatusInfoChangedEvent] - ‘deconz:deconz:5fd26ce2’ changed from OFFLINE (COMMUNICATION_ERROR): org.eclipse.jetty.websocket.api.UpgradeException: 0 null to OFFLINE (COMMUNICATION_ERROR): 0 null

2020-09-18 11:16:13.244 [hingStatusInfoChangedEvent] - ‘deconz:deconz:5fd26ce2’ changed from OFFLINE (COMMUNICATION_ERROR): 0 null to OFFLINE (COMMUNICATION_ERROR): org.eclipse.jetty.websocket.api.UpgradeException: 0 null

And in the openhab.log I don´t have any output at this time

System
Raspberry Pi 4 with Openhab, Deconz (Port 80) and pvCCU3

J-N-K · September 19, 2020, 6:48pm

Please set org.openhab.binding.deconz to DEBUG logging and show the last messages before the failure occurs.

The exception indicates that there is some websocket connection problem. Which version of the deconz software is installed?

Snupru · October 17, 2020, 10:00am

I have the same problem…

openhab.log:

    2020-10-15 16:59:06.235 [DEBUG] [ernal.handler.DeconzBaseThingHandler] - Get new 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_262]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_262]
	at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607) ~[?:1.8.0_262]
	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591) ~[?:1.8.0_262]
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) [?:1.8.0_262]
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) [?:1.8.0_262]
	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:511) [?:1.8.0_262]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_262]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_262]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_262]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_262]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_262]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_262]
Caused by: java.util.concurrent.TimeoutException: Total timeout 2000 ms elapsed
	... 9 more
2020-10-15 16:59:06.248 [DEBUG] [ernal.handler.DeconzBaseThingHandler] - Get new 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_262]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_262]
	at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607) ~[?:1.8.0_262]
	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591) ~[?:1.8.0_262]
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) [?:1.8.0_262]
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) [?:1.8.0_262]
	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:511) [?:1.8.0_262]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_262]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_262]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_262]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_262]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_262]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_262]
Caused by: java.util.concurrent.TimeoutException: Total timeout 2000 ms elapsed
	... 9 more

events.log:

2020-10-15 16:59:07.063 [hingStatusInfoChangedEvent] - 'deconz:deconz:xxxxxxxx' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Value must be between 0 and 100
2020-10-15 16:59:07.074 [hingStatusInfoChangedEvent] - 'deconz:colortemperaturelight:xxxxxxxx:00118d0008870cc0000' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)

HansMeier · November 2, 2020, 5:34pm

I´m sorry. In the last time i haven´t time for my smarthome.
I have the same error.
The Deconz and Openhab-Server are running on the same raspberry.
Sometimes the Deconz-Server goes offline after I turn the light off.

Blockquote
Switch item=gHue_AllOffice_On label=“Bürolampen [%d]” icon=“light” mappings=[ON=“Ein”,OFF=“Aus”]

Deconz with port 80
Openhab with port 8080

openhab.log

Blockquote
2020-11-02 18:18:08.663 [DEBUG] [nternal.netutils.WebSocketConnection] - Connect: /192.168.178.57
2020-11-02 18:18:08.653 [DEBUG] [nternal.netutils.WebSocketConnection] - Connecting to: ws://192.168.178.57:443
2020-11-02 18:18:08.669 [DEBUG] [nternal.netutils.WebSocketConnection] - Connecting to: ws://192.168.178.57:443
2020-11-02 18:18:08.674 [DEBUG] [nternal.netutils.WebSocketConnection] - Connecting to: ws://192.168.178.57:443
2020-11-02 18:18:08.674 [DEBUG] [nternal.netutils.WebSocketConnection] - Connect: /192.168.178.57
2020-11-02 18:18:08.683 [DEBUG] [nternal.netutils.WebSocketConnection] - Connect: /192.168.178.57
2020-11-02 18:18:08.690 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘236’, scaledValue = ‘93’
2020-11-02 18:18:08.691 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘254’, scaledValue = ‘100’
2020-11-02 18:18:08.696 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘236’, scaledValue = ‘93’
2020-11-02 18:18:08.698 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘254’, scaledValue = ‘100’
2020-11-02 18:18:08.708 [DEBUG] [nternal.netutils.WebSocketConnection] - Connect: /192.168.178.57
2020-11-02 18:18:08.717 [DEBUG] [nternal.netutils.WebSocketConnection] - Connecting to: ws://192.168.178.57:443
2020-11-02 18:18:08.725 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘140’, scaledValue = ‘56’
2020-11-02 18:18:08.724 [DEBUG] [nternal.netutils.WebSocketConnection] - Connect: /192.168.178.57
2020-11-02 18:18:08.726 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘11’, scaledValue = ‘5’
2020-11-02 18:18:09.326 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘254’, scaledValue = ‘100’
2020-11-02 18:18:09.940 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘236’, scaledValue = ‘93’
2020-11-02 18:18:09.941 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘254’, scaledValue = ‘100’
2020-11-02 18:18:09.946 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘236’, scaledValue = ‘93’
2020-11-02 18:18:09.947 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘254’, scaledValue = ‘100’
2020-11-02 18:18:10.034 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘140’, scaledValue = ‘56’
2020-11-02 18:18:10.035 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘11’, scaledValue = ‘5’
2020-11-02 18:18:10.140 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘254’, scaledValue = ‘100’
2020-11-02 18:18:10.693 [DEBUG] [ernal.handler.DeconzBaseThingHandler] - Get new 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_212]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:593) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) [?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) [?:1.8.0_212]
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:511) [?:1.8.0_212]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_212]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_212]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_212]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_212]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_212]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_212]
Caused by: java.util.concurrent.TimeoutException: Total timeout 2000 ms elapsed
… 9 more

event.log

Blockquote
2020-11-02 18:18:08.872 [hingStatusInfoChangedEvent] - ‘deconz:deconz:5fd26ce2’ changed from OFFLINE (COMMUNICATION_ERROR): Disconnected to OFFLINE (COMMUNICATION_ERROR): Value must be between 0 and 100
2020-11-02 18:18:08.874 [hingStatusInfoChangedEvent] - ‘deconz:colortemperaturelight:5fd26ce2:001788010204ef830b’ changed from OFFLINE (GONE): Not reachable to OFFLINE (BRIDGE_OFFLINE)
2020-11-02 18:18:08.875 [hingStatusInfoChangedEvent] - ‘deconz:extendedcolorlight:5fd26ce2:0017880104d968bc0b’ changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2020-11-02 18:18:08.888 [hingStatusInfoChangedEvent] - ‘deconz:batterysensor:5fd26ce2:680ae2fffeec4616010001’ changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)

J-N-K · November 2, 2020, 5:56pm

Which version are you using?

Snupru · November 12, 2020, 10:09am

Deconz 2.05.84
OpenHAB: 02.05.10

J-N-K · November 12, 2020, 11:42am

The binding ran into a timeout. This can have several reasons. If it recovers, this is not a problem. Does it stay there or does it re-connect?

Snupru · November 12, 2020, 12:00pm

It doesn’t reconnect.
I have to restart the deconz-bundle

J-N-K · November 12, 2020, 12:26pm

Unfortunately all of these message don’t put a complete picture of what is happening and why the re-connect does not happen. Please set binding to TRACE logging.

And check if you selected the correct item-type for each channel (escpecially the color-temperature channel). The Value must be between 0-100 message indicates that there might be a problem.

eric1905 · November 13, 2020, 1:58pm

@Snupru @J-N-K Where can I get this version? I have the 2.5.10 and some errors, so before I open a git issue i would like to check it with the newest version

eric1905 · November 13, 2020, 1:59pm

Ok i realized that you are talking about the deconz version in the phoscon gateway
I was searching for the newest addon version

Snupru · November 20, 2020, 11:50am

Now it works

The item-type was wrong for two items (color-temperature)

kangaxx · March 1, 2021, 2:57pm

Which item-type do you choosed for colortemperature and color-values? I have a similar problem…
Colortempetature is Number and Color is Color?
2021-02-28 19:01:07.776 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘243’, scaledValue = ‘96’ 2021-02-28 19:01:07.780 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘254’, scaledValue = ‘100’ 2021-02-28 19:01:08.836 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘243’, scaledValue = ‘96’ 2021-02-28 19:01:08.838 [DEBUG] [z.internal.handler.LightThingHandler] - val = ‘254’, scaledValue = ‘100’ 2021-02-28 19:01:10.771 [DEBUG] [z.internal.handler.LightThingHandler] - Sending command 19,96,100 to channel deconz:extendedcolorlight:b5f7dc6c:00158d0005018a5801:color 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$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.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

Snupru · March 1, 2021, 6:02pm

For colortemperature -> Number