MQTT switch does not update item

Hello everyone,
my items file has a switch

Switch sHallway_en <dimmablelight> (gHallway, gLights) { mqtt=">[mosquitto:/sonoff_hallway/gpio/12:command:ON:1], >[mosquitto:/sonoff_hallway/gpio/12:command:OFF:0], <[mosquitto:/sonoff_hallway/button/state:state:MAP(onoff.map)]", channel="hue:0210:0017884d7c57:5:color" }

As you can see, the switch is linked to different “channels”, to an MQTT broker and to a Phillips Hue.

The sitemap also displays that switch

Switch item=sHallway_en

The MQTT broker (Mosquitto) talks to a Sonoff touch flashed with ESPeasy.
Here comes the complicated part I don´t understand.

When I toggle the switch through Basic UI or a phone app, I hear the relay clicking in the switch and the Phillips hue turns ON or OFF. However, when I touch the switch, the relay clicks as well as does the switch move in the Basic UI or the phone app, but it does not turn ON/OFF the light.

Switching the Sonoff touch from OFF to ON and back gives me the following log entry

2017-07-28 13:41:44.790 [ItemStateChangedEvent     ] - sHallway_en changed from OFF to ON
2017-07-28 13:41:46.792 [ItemStateChangedEvent     ] - sHallway_en changed from ON to OFF

Using the “virtual” switch on the sitemap displays the following log entries

2017-07-28 13:41:50.231 [ItemStateChangedEvent     ] - sHallway_en changed from OFF to ON
2017-07-28 13:41:50.241 [ItemCommandEvent          ] - Item 'sHallway_en' received command ON
2017-07-28 13:41:51.941 [ItemStateChangedEvent     ] - sHallway_en changed from ON to OFF
2017-07-28 13:41:51.945 [ItemCommandEvent          ] - Item 'sHallway_en' received command OFF

What am I missing, why does toggling the Sonoff touch does toggle the switch on the sitemap but does not turn ON/OFF the Phillips hue, while using the switch on the sitemap turns ON/OFF the switch AND the Hue?

EDIT:
Maybe I should add my onoff.map

1=ON
0=OFF
ON=1
OFF=0

So I find trying to mix bindings on the same Item is challenging to get right and almost impossible to debug when it doesn’t work. Therefore I almost never use them. Instead, I’ll use a Proxy Item and a simple rule or two to synchronize between the two. It takes more Items and code but the advantage is you actually can get feedback and add debugging logging to help pinpoint the source of the problem.

I don’t know if it makes a difference but i do my channel definition before mqtt.

If you turn on mqtt and hue debug in your logs you can see how the messages and commands are moving back and forth. My guess is that it’s in the transforms that things are getting mixed up.

I have tried your suggestion with the same result. When I click the switch on the sitemap or phone app, the lights go ON or OFF and the relay in the Sonoff touch clicks. As soon as I use the Sonoff touch, the relay clicks and moves the switch on the sitemap/phone app but does not turn on/off the light.

Changed the order of the channels with no help.

I figured it wouldn’t make a difference, but you never know.

Did you setup debug logs to verify communication / commands to see if it might be a transformation issue?

I only know how to use openhab.log and event.log. Furthermore I have an MQTT “Spy” running which confirms that MQTT is working properly. Do you have a link for debug logs where I can dig in?

Use the karaf console to change from warn to debug logs and you’ll be able to see the specific commands back and forth.

http://docs.openhab.org/administration/logging.html

Edit: Rereading your original post it sounds to me like an issue with the hue binding not being able to respond to the switch change when it’s triggered by an mqtt message, since you are able to get the virtual switch and physical switch to stay in sync. I’d test @rlkoshak suggestion of separating the hue item from the mqtt item and syncing them with a rule to verify at least that works.

I have set the log:level to debug. There is zillions of messages flying by. When I press the button on the switch, this pops up immediately so I assume it is associated to the error. However, this is like Chinese to me.

2017-07-28 22:50:35.727 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1751b53[PROCESSING][i=null,cb=Blocker@1413856{null}] generate: DONE (null,[p=150,l=150,c=32768,r=0],false)@COMMITTED
2017-07-28 22:50:35.732 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1751b53[PROCESSING][i=null,cb=Blocker@1413856{null}] generate: FLUSH (null,[p=0,l=206,c=32768,r=206],false)@COMMITTED
2017-07-28 22:50:35.736 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 212 SelectChannelEndPoint@e37b94{/192.168.1.145:52332<->8080,Open,in,out,-,W,10/30000,HttpConnection}{io=0,kio=0,kro=4}
2017-07-28 22:50:35.741 [ERROR] [.script.engine.ScriptExecutionThread] - Rule 'BoundSwitchUpdates received update': An error occurred during the script execution: The name '<XFeatureCallImplCustom>.PostUpdate(<XNumberLiteralImpl>)' cannot be resolved to an item or type.
2017-07-28 22:50:35.744 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1751b53[PROCESSING][i=null,cb=Blocker@1413856{null}] generate: DONE (null,[p=206,l=206,c=32768,r=0],false)@COMMITTED
2017-07-28 22:50:35.754 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1751b53[PROCESSING][i=null,cb=Blocker@1413856{null}] generate: FLUSH (null,[p=0,l=143,c=32768,r=143],false)@COMMITTED
2017-07-28 22:50:35.757 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 149 SelectChannelEndPoint@e37b94{/192.168.1.145:52332<->8080,Open,in,out,-,W,14/30000,HttpConnection}{io=0,kio=0,kro=4}
2017-07-28 22:50:35.760 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1751b53[PROCESSING][i=null,cb=Blocker@1413856{null}] generate: DONE (null,[p=143,l=143,c=32768,r=0],false)@COMMITTED
2017-07-28 22:50:35.765 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1751b53[PROCESSING][i=null,cb=Blocker@1413856{null}] generate: FLUSH (null,[p=0,l=199,c=32768,r=199],false)@COMMITTED
2017-07-28 22:50:35.768 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 205 SelectChannelEndPoint@e37b94{/192.168.1.145:52332<->8080,Open,in,out,-,W,8/30000,HttpConnection}{io=0,kio=0,kro=4}
2017-07-28 22:50:35.771 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1751b53[PROCESSING][i=null,cb=Blocker@1413856{null}] generate: DONE (null,[p=199,l=199,c=32768,r=0],false)@COMMITTED
2017-07-28 22:50:37.535 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@6245916 pairs: {GET /api/tXcuYy2Dkk-v-a7N0chTwYhN82mUsN7422KXs1my/ HTTP/1.1: null}{Content-Type: application/json}{User-Agent: Java/1.8.0_121}{Host: 192.168.1.116}{Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2}{Connection: keep-alive}
2017-07-28 22:50:37.556 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@131f75411 pairs: {null: HTTP/1.1 200 OK}{Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0}{Pragma: no-cache}{Expires: Mon, 1 Aug 2011 09:00:00 GMT}{Connection: close}{Access-Control-Max-Age: 3600}{Access-Control-Allow-Origin: *}{Access-Control-Allow-Credentials: true}{Access-Control-Allow-Methods: POST, GET, OPTIONS, PUT, DELETE, HEAD}{Access-Control-Allow-Headers: Content-Type}{Content-type: application/json}

Pat your rule that you used with the proxy item.

Just set debug for mqtt and hue not your whole system. That will help narrow it down.

I modified your solution and now it works.
I have replaced

    Item ProxySwitch received command

in my rules with

    Item ProxySwitch changed from OFF to ON

and vice versa

and all of a sudden it worked. I have no, absolutely no, idea why but hey… it works.
Thank you @rlkoshak and @rgerrans for your support!

1 Like

Glad the proxy switch worked. Don’t forget to turn off debug or you’ll have a mess of log files

Loool, that was the very first thing after the light came on…

1 Like