relay continuously switching when mqtt not connected

[xoseperez]

Originally reported by: P.B. (Bitbucket: PieBru, GitHub: PieBru)

---

Hi, I'm using a Sonoff-POW to know when a refrigerator pump is running and, rarely, to remotely power it off.
When returning from a power shortage the relay should start ON, so the "Switch boot mode" is configured "Always on".
When the POW loses the MQTT connection, the relay continuously loops on/off until the MQTT connection is established again, but the pump doesn't like this ;)
I used Espurna 1.6.7 updated to yesterday's github repo.
Any hint or patch to solve this?
Thanks,
PB

[xoseperez]

My guess is that when it reconnects to the MQTT broker it receives retained messages with payload 2 that somehow has not been overwritten... It would be useful to see the debug log to confirm this point (connect it to you programmer and open a terminal session at 115200 bauds).
Question: have you defined a custom MQTT_USE_SETTER value?

[xoseperez]

Original comment by f-fish (Bitbucket: f-fish, GitHub: Unknown):

---

I can confirm the buggy behaviour .. take a working POW - mqtt etc all good - happens to be on 1.6.7. It is configured to switch mode always off. Switch the light on - domoticz or web interface. Now change the mqtt server IP address .. in a few seconds the light switches off. Switch it on while leaving mqqt pointing to the wrong IP and it will switch off and stay off.

Do the same with switch mode always on .. and you get the looping.

Let me see what happens to the basic on the bench.

Later Ferdie

[xoseperez]

Original comment by f-fish (Bitbucket: f-fish, GitHub: Unknown):

---

Nothing on the basic with the DS18b50 - but it is dev and running of USB. Lets try the dual that is on AC. Dual also does not show this behaviour so something is up with the POW's.

Later Ferdie

[xoseperez]

Will try tomorrow with the pow. It's a shame I only have one and it's on duty...

[xoseperez]

Original comment by P.B. (Bitbucket: PieBru, GitHub: PieBru):

---

During these tests I kept the MQTT server down.
When connected via FTDI the POW shows the correct behaviour and the red led light is steady on.
The same POW, when connected to the mains (220V) the red led and the relay continuously loop on/off.
After I start the MQTT server the problem disappears withouth touching the POW.
Obviously I can't look at the console log via FTDI while the POW is attached to 220V.
In these cases and for phisically unreachable devices it would be very handy to have the console log to an UDP socket, i.e. in another project I used:

#!arduino


  #ifdef USE_CONSOLE_UDP
    int udp_printf(const char *format, ...) {
      char strbuff[256];
      zero_mem(strbuff, sizeof(strbuff));
      int strbuff_len = 0;
      va_list arglist;

      va_start(arglist, format);
      if (UDPconsole1.beginPacket(USE_CONSOLE_UDP, CONSOLE_UDP_PORT)) {
        vsnprintf(strbuff, sizeof(strbuff)-1, format, arglist);
        strbuff_len = strlen(strbuff);
        // ##### Fixme: use UDPconsole1.printf() instead of UDPconsole1.write() ???
        UDPconsole1.write(strbuff, strbuff_len);
        UDPconsole1.endPacket();
      }
      va_end(arglist);
      return(strbuff_len);
    }
  #endif  // USE_CONSOLE_UDP

[xoseperez]

Original comment by P.B. (Bitbucket: PieBru, GitHub: PieBru):

---

Xose, I temporarily can dedicate a couple of POW to tests.
I'm quite fluent in C but I never tinkered inside Espurna.
Let me know if I can be useful.
Piero

[xoseperez]

Two things:

1. You are right about the UDP socket for debugging, will do it asap
2. I just had a similar problem but not with a POW. The culprit was that the Domoticz OUT topic was not set (it actually show a placeholder but the field is empty, I'm starting to hate those placeholders). When trying to subscribe to the empty topic the MQTT connection just dropped and tried to connect again. I'm fixing that checking for topic length but you can check if your domoticz topic has a real value. This is not 100% of the solution since we still have to know why it is switching the relay off upon MQTT disconnection.

[xoseperez]

Original comment by P.B. (Bitbucket: PieBru, GitHub: PieBru):

---

I use OpenHAB, so I didn't touch the DomoticZ config section. As you can observe in the json config, DomoticZ IN and OUT topics kept the default value, which is the same value of the placeholder. By emptying these two fields the on/off relay loop problem persists when the MQTT server is down, so it should be related to the MQTT connection failure, not the DomoticZ stuff.

[xoseperez]

Original comment by f-fish (Bitbucket: f-fish, GitHub: Unknown):

---

Hmm from observation - it is not he mqtt disconnection, but rather the failed to connect that is causing the issue.

Yeah my POW is also on duty so that buggering ... ag it is only a screw .. let me get a trace quickly.

[xoseperez]

Original comment by f-fish (Bitbucket: f-fish, GitHub: Unknown):

---

Here you go ...
On usb 3.3 volt - NO AC ;-)

You do not get the relay clicking but the blue - think it is blue - light blinking on every failed connect.

To reproduce on the pow, have a working mqtt, switch relay on, change the mqtt IP address,.

#!arduino

[WEBSOCKET] Requested action: on
[RELAY] 0 => ON
[MQTT] Sending /test/switch/SONOFF_POW_20DA75/relay/0 => 1
[WEBSOCKET] Broadcasting '{"relayStatus":[true]}'
[MQTT] Sending domoticz/in => {"idx": 66, "nvalue": 1, "svalue": ""}
[MQTT] Received /test/switch/SONOFF_POW_20DA75/relay/0 => 1
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[WEBSOCKET] Parsing configuration data
[SETTINGS] Saving
[MQTT] Disconnected!
[WEBSOCKET] Broadcasting '{"mqttStatus": false}'
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[MQTT] Connecting to broker at 192.168.1.51

Could it be the websocket broadcast ?

Later Ferdie

PS if you need more debugging let me know how. The POW is on the bench now ;-)

Later Ferdie

[xoseperez]

Original comment by f-fish (Bitbucket: f-fish, GitHub: Unknown):

---

Ah wait the behaviour is clear when you plug it onto power.
This is a the trace for always on on reboot and with the wrong mqtt

#!arduino

[POW] Enabled
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[NTP] Time: 17:43:48 28/02/2017
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[WEBSOCKET] Broadcasting '{"powVisible":1,"powActivePower":0,"powCurrent":0.00,"powVoltage":0,"powApparentPower":0,"powReactivePower":0,"powPowerFactor":0}'
[MQTT] Connecting to broker at 192.168.1.51

Now - I would assume the same thing on AC ( no the usb is not plugged in)

See https://www.youtube.com/watch?v=-gbBTl6SMXE&feature=youtu.be

The behaviour on dc vs AC is different. Wonder if this is true for a basic on AC ... hmm
no** FTDI is not connected when on AC** !!!!!!

Later Ferdie

[xoseperez]

Original comment by P.B. (Bitbucket: PieBru, GitHub: PieBru):

---

I just tested a Sonoff Basic with the same firmware and settings as the POW, always on at boot, MQTT, etc...
No issue with the Basic, only the POW is affected.

[xoseperez]

Original comment by f-fish (Bitbucket: f-fish, GitHub: Unknown):

---

Both on AC I assume?

[xoseperez]

Original comment by P.B. (Bitbucket: PieBru, GitHub: PieBru):

---

Yes, both on DC and AC no issue with the Basic.

[xoseperez]

Original comment by f-fish (Bitbucket: f-fish, GitHub: Unknown):

---

Hmm looking at the trace of a basic with the same always on and MIA MQTT.

#!arduino

[WEBSOCKET] Parsing configuration data
[SETTINGS] Saving
[MQTT] Disconnected!
[WEBSOCKET] Broadcasting '{"mqttStatus": false}'
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[MQTT] Connecting to broker at 192.168.1.51
[MQTT] Connection failed
[MQTT] Connecting to broker at 192.168.1.51

No websocket update on every failed connection, that said in the video you can clearly see the POW getting confused in a different way nothing to do with the timing of the websocket I would think.

Later Ferdie