Shelly Binding

@markus7017
In some rare situations I still get timeout messages in the openHAB log. I can reproduce this with a command to the “control” channel.

I have sent you a tcpdump via private message. hope this helps.

Here is the logged message:

11:29:38.478 [WARN ] [ly.internal.handler.ShellyBaseHandler] - shellyswitch25-f36f94 ERROR: Unable to process command for channel shelly:shelly25-roller:f36f94:roller#control: Shelly API call failed: connect timed out, uri=/roller/0?go=stop (class java.io.IOException)
Stack Trace: [org.openhab.binding.shelly.internal.api.ShellyHttpApi.request(ShellyHttpApi.java:482), org.openhab.binding.shelly.internal.api.ShellyHttpApi.setRollerTurn(ShellyHttpApi.java:160), org.openhab.binding.shelly.internal.handler.ShellyRelayHandler.handleRoller(ShellyRelayHandler.java:259), org.openhab.binding.shelly.internal.handler.ShellyRelayHandler.handleDeviceCommand(ShellyRelayHandler.java:120), org.openhab.binding.shelly.internal.handler.ShellyBaseHandler.handleCommand(ShellyBaseHandler.java:296), sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method), sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62), sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43), java.lang.reflect.Method.invoke(Method.java:498), org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152), org.eclipse.smarthome.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59), com.sun.proxy.$Proxy1710.handleCommand(Unknown Source), org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:74), org.eclipse.smarthome.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48), sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method), sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62), sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43), java.lang.reflect.Method.invoke(Method.java:498), org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152), org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52), java.util.concurrent.FutureTask.run(FutureTask.java:266), java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149), java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624), java.lang.Thread.run(Thread.java:748)]

I did some testing with the DEV build in combination with the Shelly RGBW2.
I still can get the shelly to perform a reboot (to crash) if I do very quick changes in color, brightness, etc. The only difference I saw is that there is no more timeout log message (and password protected devices are not working, but I think you already mentioned that).

2020-01-24 13:51:42.423 [hingStatusInfoChangedEvent] - 'shelly:shellyrgbw2-color:fenster' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Es trat ein unerwartetes Problem beim API-Zugriff auf. Überprüfen Sie die Logdatei für genauere Informationen.
2020-01-24 13:51:43.312 [WARN ] [y.internal.handler.ShellyBaseHandler] - shellyrgbw2-color ERROR: 
Unable to process command for channel shelly:shellyrgbw2-color:fenster:color#hsb: Shelly API call failed: connect timed out, uri=/color/0?red=123&green=0&blue=255&white=255&turn=on (class java.io.IOException)
Stack Trace: [org.openhab.binding.shelly.internal.api.ShellyHttpApi.request(ShellyHttpApi.java:482), 
org.openhab.binding.shelly.internal.api.ShellyHttpApi.setLightParms(ShellyHttpApi.java:269), 
org.openhab.binding.shelly.internal.handler.ShellyLightHandler.sendColors(ShellyLightHandler.java:484), 
org.openhab.binding.shelly.internal.handler.ShellyLightHandler.handleDeviceCommand(ShellyLightHandler.java:211), 
org.openhab.binding.shelly.internal.handler.ShellyBaseHandler.handleCommand(ShellyBaseHandler.java:296), 
sun.reflect.GeneratedMethodAccessor115.invoke(Unknown Source), 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43), 
java.lang.reflect.Method.invoke(Method.java:498), 
org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152), 
org.eclipse.smarthome.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59), 
com.sun.proxy.$Proxy1352.handleCommand(Unknown Source), 
org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:74), 
org.eclipse.smarthome.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48),
 sun.reflect.GeneratedMethodAccessor114.invoke(Unknown Source), 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43), 
java.lang.reflect.Method.invoke(Method.java:498), 
org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152), 
org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52), 
java.util.concurrent.FutureTask.run(FutureTask.java:266), 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149), 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624), 
java.lang.Thread.run(Thread.java:748)]

ohh, I did not check if my Shelly is rebooting during the timeouts, too. How do I check for a reboot of the Shelly device?

I thing the connect timeout is the phase while the device is rebooting. This usually takes between 5-15sec.

Do you see “xxx: Alarm condition: RESTARTED” in the log. You could also link the channel uptime. If the device restarts this values gets resetted and starts over (that is the condition checked by the binding).

@markus7017
I do not see RESTARTED messages and uptime is not reset. So in my setup the Shelly 2.5 seems not to restart.

Have you got my tcpdump file and does this help?

yep I got it, saw a lot of retransmit at those times and forwarded it to the manufacturer
now: sit and wait…

1 Like

Yes, the RESTARTED log message appears once openHAB starts talking to the shelly again.

which firmware are you using?
please provide a bug description incl strps to reproduce and I‘ll forward iit to Shelly

  • device type / production batch (check thing properties)
  • firmware version
  • signal strength
  • sequence to reproduce

did you tried a different firmware?

  • device type
    – Shelly RGBW2
  • production batch
    – 1
  • firmware version
    – 1.5.7
  • signal strength
    – 2 / -72
  • sequence to reproduce
    – Change color/brightness very often in a short period of time

No, since I got the RGBW2s they are on firmware version 1.5.7 (latest firmware available).

ok, has been reported to the Shelly QA team
what options do you have enabled on the device? coap, mqtt?

Coap and mqtt are disabled. The only things I changed are the wifi settings, the NTP server and I set a login password. I don’t use the shelly app / shelly cloud.

Is Cloud enabled? Could you try to disable the Cloud function and repeat the test?
It seems that the device is not able to handle http requests (REST) while the device sends data to the cloud.

I uploaded a DEV buld to myfiles with increased timeouts (connect 30s, read 6s).
@Nightman @Chris_si Could you please verify this build.

On device no MQTT enabled. Coapp enable/disable is no more possible on Shelly 2.5 device with current firmware.

No.

I will try this new build of the binding, but maybe not before weekend.

@markus7017
I have just done another test with the current (not updated) dev build of your binding.

Reproducable timeouts happen, if I use the Shelly 2.5 as it was configured from the binding (http:// entries in the Actions section of the Shelly enabled and set).

As soon as I disable all Actions in the Shelly (using the webinterface of the Shelly 2.5) I do not see any timeouts in the openHAB log any more, regardless how much and how quickly I switch.

My conclusion: Timeouts are happening due to the actions ‘callback’ of the Shelly (bug in binding or openHAB or openHAB-system OS?) or during the Shelly doing the actions ‘callback’ (bug in Shelly firmware?).

Hope that helps narrow down this problem.

Cloud is disabled. It’s just openHAB communicating via the binding with the Shelly RGBW2 in the local network.

I’ll give it a try in the next few days.

@Nightman @Chris_si
That’s good info, I forward to the Shelly guys. That’s a clear pointer to the http events (action urls)
please perform another test (if you have time)

  • disable button & relay events in the thing config, enable CoIoT
  • clear action urls using the Web App
  • run the test
    In this case to http events should be echoed, but Coap, which is UDP-based

@markus7017 did the test. No timeout messages in the openHAB logs.

btw: Why is the binding saving action http://… values in the Shelly if I in openHAB save the Thing settings with nothing switched on? Bug?

Keep in mind: all my reporting about logs are based on INFO log (no debug log etc.)

sounds good, that means CoIoT would fix it. However, I don’t all status values by Coap. I already reported the missing ones to Shelly and they are checking to implement those for firmware 1.6.0 (not yet confirmed)

Currently the binding sets the urls when this is enabled in the thing config, but it doesn’t deregister when you switch it off. That’s on my list.

Could yo switch to DEBUG (for a while) even exception should be displayed on INFO level. Just to make sure the log is clean. OH console: “log:set DEBUG org.openhab.binding.shelly”

Quick question… on the RGBW2 device, there isn’t a channel shown for the ‘input’ like you see on other devices. Is that expected behaviour? Is there a way to activate that function somehow?