Shelly binding 2.5 giving repeated WARN in logs

Hello, tried searching for this but didn’t find any solutions.

Running OpenHab2.5 on Armbian (on an Olinuxino Micro).

Installed Shelly binding as I have one Shelly device in my home, wanting to add more but wanted to see if it played well with OpenHab first before committing to more.

The device itself is a Shelly 1, and I’ve got it working so far (I can turn on and off the light from the control panel/ui, and the panel/ui correctly reports the state of the device if I turn it on/off manually at the actual physical switch).
However, my logs are full of this warning, which repeats every 15 seconds:

22:03:27.051 [WARN ] [e.californium.core.network.UdpMatcher] - error receiving response ACK- 
2.05   MID=23371, Token=, OptionSet={"Unknown (3332)":0x534853572d31233737324234432331}, 
"{"blk":[{"I":0,"D":"Rela".. 201 bytes for Exchange[L7228, complete]
com.google.gson.JsonSyntaxException: com.google.gson.stream.MalformedJsonException: 
Unterminated array at line 1 column 30 path $.blk[1]
    at com.google.gson.Gson.fromJson(Gson.java:942) ~[?:?]
    at com.google.gson.Gson.fromJson(Gson.java:892) ~[?:?]
    at com.google.gson.Gson.fromJson(Gson.java:841) ~[?:?]
    at com.google.gson.Gson.fromJson(Gson.java:813) ~[?:?]
    at org.openhab.binding.shelly.internal.coap.ShellyCoapHandler.handleDeviceDescription(ShellyCoapHandler.java:252) ~[?:?]
    at org.openhab.binding.shelly.internal.coap.ShellyCoapHandler.processResponse(ShellyCoapHandler.java:216) ~[?:?]
    at org.openhab.binding.shelly.internal.coap.ShellyCoapHandler$1.onResponse(ShellyCoapHandler.java:883) ~[?:?]
    at org.eclipse.californium.core.coap.Request.setResponse(Request.java:711) ~[bundleFile:?]
    at org.eclipse.californium.core.network.EndpointManager$ClientMessageDeliverer.deliverResponse(EndpointManager.java:272) ~[bundleFile:?]
    at org.eclipse.californium.core.network.stack.BaseCoapStack$StackTopAdapter.receiveResponse(BaseCoapStack.java:210) ~[bundleFile:?]
    at org.eclipse.californium.core.network.stack.AbstractLayer.receiveResponse(AbstractLayer.java:89) ~[bundleFile:?]
    at org.eclipse.californium.core.network.stack.ExchangeCleanupLayer.receiveResponse(ExchangeCleanupLayer.java:93) ~[bundleFile:?]
    at org.eclipse.californium.core.network.stack.ObserveLayer.receiveResponse(ObserveLayer.java:150) ~[bundleFile:?]
    at org.eclipse.californium.core.network.stack.BlockwiseLayer.receiveResponse(BlockwiseLayer.java:676) ~[bundleFile:?]
    at org.eclipse.californium.core.network.stack.ReliabilityLayer.receiveResponse(ReliabilityLayer.java:305) ~[bundleFile:?]
    at org.eclipse.californium.core.network.stack.AbstractLayer.receiveResponse(AbstractLayer.java:89) ~[bundleFile:?]
    at org.eclipse.californium.core.network.stack.BaseCoapStack.receiveResponse(BaseCoapStack.java:139) ~[bundleFile:?]
    at org.eclipse.californium.core.network.CoapEndpoint$1.receiveResponse(CoapEndpoint.java:277) ~[bundleFile:?]
    at org.eclipse.californium.core.network.UdpMatcher$4.run(UdpMatcher.java:399) [bundleFile:?]
    at org.eclipse.californium.elements.util.SerialExecutor$1.run(SerialExecutor.java:276) [bundleFile:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_131]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_131]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_131]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_131]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_131]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_131]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]
Caused by: com.google.gson.stream.MalformedJsonException: Unterminated array at line 1 column 30 path $.blk[1]
    at com.google.gson.stream.JsonReader.syntaxError(JsonReader.java:1568) ~[?:?]
    at com.google.gson.stream.JsonReader.doPeek(JsonReader.java:476) ~[?:?]
    at com.google.gson.stream.JsonReader.hasNext(JsonReader.java:414) ~[?:?]
    at com.google.gson.internal.bind.CollectionTypeAdapterFactory$Adapter.read(CollectionTypeAdapterFactory.java:81) ~[?:?]
    at com.google.gson.internal.bind.CollectionTypeAdapterFactory$Adapter.read(CollectionTypeAdapterFactory.java:61) ~[?:?]
    at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$1.read(ReflectiveTypeAdapterFactory.java:131) ~[?:?]
    at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$Adapter.read(ReflectiveTypeAdapterFactory.java:222) ~[?:?]
    at com.google.gson.Gson.fromJson(Gson.java:927) ~[?:?]
    ... 26 more

(Sorry for the long log file, not sure where the useful info ends in this bit of stuff).

The two questions I guess I have, are:

  1. Is this something that I should be trying to fix, and how would I go about fixing it?

  2. If it’s not important enough to worry about (since my Shelly seems to be working), how can I silence it so that it doesn’t fill up my disk space with the log file? (I’m guessing I could set the ROOT log level to ERROR instead of WARN, and that might prevent it from being logged, but I really don’t want to miss other WARNs as I am still trying out other bindings, etc and I don’t want to hide any potentially useful info that they might give me,)

Thanks in advance for any advice anyone might have to offer

I can confirm this behavior on my OH2 installation.
I’m running OH 2.5.6 as well as OH 2.5.7 (build #180).
Both versions report this exception periodically, but OH seem to be operational.
OH is hosted on Mac OSX with Java version “1.8.0_221”

Shall we report this as an issue on github?

I can also confirm this behavior. Did you find any solution or were you able to identify a root cause?
Freshly installed Shelly Binding on Openhabian 2.5.7 Release Build with only one Shelly 2.5 UL.

Shelly is on latest firmware:

Current version: 20200812-091015/v1.8.0@8acf41b0
You have latest version of your device!

My Log is flooded with the following Error Message:

Log-Output
2020-08-25 19:17:15.945 [WARN ] [.californium.core.network.UdpMatcher] - error receiving response ACK-2.05   MID= 1902, Token=, OptionSet={"Unknown (3332)":0x534853572d3235233638433633414642304545442332}, "{"blk":[{"I":1,"D":"rela".. 1118 bytes for Exchange[L200, complete]

com.google.gson.JsonSyntaxException: java.lang.IllegalStateException: Expected a string but was BEGIN_ARRAY at line 1 column 320 path $.sen[4].R

	at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$Adapter.read(ReflectiveTypeAdapterFactory.java:224) ~[?:?]

	at com.google.gson.internal.bind.TypeAdapterRuntimeTypeWrapper.read(TypeAdapterRuntimeTypeWrapper.java:41) ~[?:?]

	at com.google.gson.internal.bind.CollectionTypeAdapterFactory$Adapter.read(CollectionTypeAdapterFactory.java:82) ~[?:?]

	at com.google.gson.internal.bind.CollectionTypeAdapterFactory$Adapter.read(CollectionTypeAdapterFactory.java:61) ~[?:?]

	at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$1.read(ReflectiveTypeAdapterFactory.java:129) ~[?:?]

	at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$Adapter.read(ReflectiveTypeAdapterFactory.java:220) ~[?:?]

	at com.google.gson.Gson.fromJson(Gson.java:888) ~[?:?]

	at com.google.gson.Gson.fromJson(Gson.java:853) ~[?:?]

	at com.google.gson.Gson.fromJson(Gson.java:802) ~[?:?]

	at com.google.gson.Gson.fromJson(Gson.java:774) ~[?:?]

	at org.openhab.binding.shelly.internal.coap.ShellyCoapHandler.handleDeviceDescription(ShellyCoapHandler.java:252) ~[?:?]

	at org.openhab.binding.shelly.internal.coap.ShellyCoapHandler.processResponse(ShellyCoapHandler.java:216) ~[?:?]

	at org.openhab.binding.shelly.internal.coap.ShellyCoapHandler$1.onResponse(ShellyCoapHandler.java:884) ~[?:?]

	at org.eclipse.californium.core.coap.Request.setResponse(Request.java:711) ~[bundleFile:?]

	at org.eclipse.californium.core.network.EndpointManager$ClientMessageDeliverer.deliverResponse(EndpointManager.java:272) ~[bundleFile:?]

	at org.eclipse.californium.core.network.stack.BaseCoapStack$StackTopAdapter.receiveResponse(BaseCoapStack.java:210) ~[bundleFile:?]

	at org.eclipse.californium.core.network.stack.AbstractLayer.receiveResponse(AbstractLayer.java:89) ~[bundleFile:?]

	at org.eclipse.californium.core.network.stack.ExchangeCleanupLayer.receiveResponse(ExchangeCleanupLayer.java:93) ~[bundleFile:?]

	at org.eclipse.californium.core.network.stack.ObserveLayer.receiveResponse(ObserveLayer.java:150) ~[bundleFile:?]

	at org.eclipse.californium.core.network.stack.BlockwiseLayer.receiveResponse(BlockwiseLayer.java:676) ~[bundleFile:?]

	at org.eclipse.californium.core.network.stack.ReliabilityLayer.receiveResponse(ReliabilityLayer.java:305) ~[bundleFile:?]

	at org.eclipse.californium.core.network.stack.AbstractLayer.receiveResponse(AbstractLayer.java:89) ~[bundleFile:?]

	at org.eclipse.californium.core.network.stack.BaseCoapStack.receiveResponse(BaseCoapStack.java:139) ~[bundleFile:?]

	at org.eclipse.californium.core.network.CoapEndpoint$1.receiveResponse(CoapEndpoint.java:277) ~[bundleFile:?]

	at org.eclipse.californium.core.network.UdpMatcher$4.run(UdpMatcher.java:399) [bundleFile:?]

	at org.eclipse.californium.elements.util.SerialExecutor$1.run(SerialExecutor.java:276) [bundleFile:?]

	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222]

	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_222]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_222]

	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]

	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]

	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]

Caused by: java.lang.IllegalStateException: Expected a string but was BEGIN_ARRAY at line 1 column 320 path $.sen[4].R

	at com.google.gson.stream.JsonReader.nextString(JsonReader.java:825) ~[?:?]

	at com.google.gson.internal.bind.TypeAdapters$16.read(TypeAdapters.java:401) ~[?:?]

	at com.google.gson.internal.bind.TypeAdapters$16.read(TypeAdapters.java:389) ~[?:?]

	at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$1.read(ReflectiveTypeAdapterFactory.java:129) ~[?:?]

	at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$Adapter.read(ReflectiveTypeAdapterFactory.java:220) ~[?:?]

Regards

Boxon

Problem seems to be with latest Firmware Version 1.8 and later. Downgrading Shelly to older Firmware (1.7) fixed warning. How to downgrade is described here: http://archive.shelly-faq.de/