Strange POWER command happening on MQTT connect

[cdntinker]

PROBLEM DESCRIPTION

A clear and concise description of what the problem is.

REQUESTED INFORMATION

Make sure your have performed every step and checked the applicable boxes before submitting your issue. Thank you!

• Read the Contributing Guide and Policy and the Code of Conduct
• Searched the problem in issues
• Searched the problem in discussions
• Searched the problem in the docs
• Searched the problem in the chat
• Device used (e.g., Sonoff Basic): Sonoff Dual R2
• Tasmota binary firmware version number used: 14.3.0
  • Pre-compiled
  • Self-compiled
• Flashing tools used: OTA upgrade
• Provide the output of command: Backlog Template; Module; GPIO 255:

  Configuration output here:
21:56:48.631 CMD: Backlog Template; Module; GPIO 255
21:56:48.662 MQT: stat/AquariumLights/RESULT = {"NAME":"Generic","GPIO":[1,1,1,1,1,1,1,1,1,1,1,1,1,1],"FLAG":0,"BASE":18}
21:56:48.884 MQT: stat/AquariumLights/RESULT = {"Module":{"39":"Sonoff Dual R2"}}
21:56:49.135 MQT: stat/AquariumLights/RESULT = {"GPIO0":{"0":"None"},"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"0":"None"},"GPIO5":{"225":"Relay2"},"GPIO9":{"0":"None"},"GPIO10":{"32":"Button1"},"GPIO12":{"224":"Relay1"},"GPIO13":{"320":"Led_i1"},"GPIO14":{"0":"None"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"},"GPIO17":{"0":"None"}}

• If using rules, provide the output of this command: Backlog Rule1; Rule2; Rule3:

  Rules output here:

• Provide the output of this command: Status 0:

  STATUS 0 output here:
21:59:37.106 CMD: Status 0
21:59:37.114 RSL: STATUS = {"Status":{"Module":39,"DeviceName":"Aquarium Lights","FriendlyName":["Aquarium_Lights_1","Aquarium_Lights_2"],"Topic":"AquariumLights","ButtonTopic":"0","Power":"01","PowerLock":"00","PowerOnState":3,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0,"InfoRetain":0,"StateRetain":0,"StatusRetain":0}}
21:59:37.119 RSL: STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://ota.tasmota.com/tasmota/release/tasmota.bin.gz","RestartReason":"Software/System restart","Uptime":"0T00:13:59","StartupUTC":"2024-12-18T20:45:38","Sleep":50,"CfgHolder":4617,"BootCount":35,"BCResetTime":"2024-11-10T19:49:10","SaveCount":982,"SaveAddress":"F5000"}}
21:59:37.123 RSL: STATUS2 = {"StatusFWR":{"Version":"14.3.0(release-tasmota)","BuildDateTime":"2024-10-15T08:18:01","Boot":31,"Core":"2_7_7","SDK":"2.2.2-dev(38a443e)","CpuFrequency":80,"Hardware":"ESP8285N08","CR":"413/699"}}
21:59:37.127 RSL: STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["VictoriaDrive2B","VictoriaDrive3"],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008009","2805C80001000600003C5A0A192800000000","00000080","00006000","00004000","00000000"]}}
21:59:37.138 RSL: STATUS4 = {"StatusMEM":{"ProgramSize":649,"Free":352,"Heap":17,"ProgramFlashSize":1024,"FlashSize":1024,"FlashChipId":"144051","FlashFrequency":40,"FlashMode":"DOUT","Features":["0809","8F9AC787","04368001","000000CF","010013C0","C000F981","00004004","00001000","54000020","00000080","00000000"],"Drivers":"1,2,!3,!4,!5,!6,7,!8,9,10,12,!16,!18,!19,!20,!21,!22,!24,26,!27,29,!30,!35,!37,!45,62,!68","Sensors":"1,2,3,4,5,6","I2CDriver":"7"}}
21:59:37.143 RSL: STATUS5 = {"StatusNET":{"Hostname":"AquariumLights-2458","IPAddress":"192.168.9.27","Gateway":"192.168.8.1","Subnetmask":"255.255.252.0","DNSServer1":"192.168.8.1","DNSServer2":"127.0.0.1","Mac":"60:01:94:AC:89:9A","Webserver":2,"HTTP_API":1,"WifiConfig":4,"WifiPower":17.0}}
21:59:37.146 RSL: STATUS6 = {"StatusMQT":{"MqttHost":"mosquitto1","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_AC899A","MqttUser":"DVES_USER","MqttCount":1,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30,"SOCKET_TIMEOUT":4}}
21:59:37.151 RSL: STATUS7 = {"StatusTIM":{"UTC":"2024-12-18T20:59:37Z","Local":"2024-12-18T21:59:37","StartDST":"2024-03-31T02:00:00","EndDST":"2024-10-27T03:00:00","Timezone":"+01:00","Sunrise":"08:39","Sunset":"16:54"}}
21:59:37.156 RSL: STATUS10 = {"StatusSNS":{"Time":"2024-12-18T21:59:37"}}
21:59:37.161 RSL: STATUS11 = {"StatusSTS":{"Time":"2024-12-18T21:59:37","Uptime":"0T00:13:59","UptimeSec":839,"Heap":17,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"POWER1":"ON","POWER2":"OFF","Wifi":{"AP":1,"SSId":"VictoriaDrive2B","BSSId":"94:83:C4:06:74:F9","Channel":5,"Mode":"11n","RSSI":70,"Signal":-65,"LinkCount":1,"Downtime":"0T00:00:05"}}}

• Set weblog to 4 and then, when you experience your issue, provide the output of the Console log:

  Console output here:

TO REPRODUCE

Steps to reproduce the behavior:

EXPECTED BEHAVIOUR

A clear and concise description of what you expected to happen.

I expect the device to NOT toggle its own states without being told to do so.

SCREENSHOTS

If applicable, add screenshots to help explain your problem.

ADDITIONAL CONTEXT

Add any other context about the problem here.

(Please, remember to close the issue when the problem has been addressed)

This is a weird one...

I have a Sonoff Dual R2 running lights on an aquarium. Lately, there has been a lot of WiFi interferance and now, every time it reconnects to my MQTT broker, it seems to be sending out a null message on "cmnd/AquariumLights/POWER".

When this happens, if the lights are in night mode (POWER1 = off, POWER2 = on), it toggles to day mode (POWER1 = on, POWER2 = off). Even stranger, this has no effect if the device is already in day mode.

I have been completely unable, through MANY hours of research, to find any sort of reference to this behaviour.

Is this in any way normal?

Is there any way to make it stop?

[sfromis]

You "forgot" to provide the log for when you see what surprised you. That's one of the most important parts of the form to fil in.

Anyway, the the empty "cmnd/AquariumLights/POWER" is not actually a command it is processing, instead (for backwards compatibility) a message originally allowing other subscribers to see it being available.

Whatever you see with toggling is unrelated to that, but might depend on other details from the detailed log you did not provide.

[cdntinker]

That would definitely be a pain. Apparently, Sonoff has discontinued the Dual R2...

[sfromis]

They have the Sonoff Dual R3 instead, and -lite without energy monitoring.

Recently, I replaced an old Sonoff Pow R2, due to "bad behavior", suddenly started to click the relay without me doing anything.

[cdntinker]

Which requires a redesign of the control box setup & awkwardly flashing the device. (Why on earth has Sonoff gone away from properly laying out those pads???)

[cdntinker]

So...
In preparation for replacement of the Dual R2 with a Dual R3...
I dug out a Dual R3 that I had completely forgotten buying.
Yay! I had already flashed it.
Updated it to 14.4.1...
Took the R2 offline while setting up the R3 to confirm it would act properly as a replacement...
Gave the R3 the WiFi & MQTT configuration of the R2...
Powered it up...

And...

SAME DAMN ISSUE!

Which told me that the problem was NOT the device itself.

But!!!

Now for the good news.

Re started mosquitto_sub sessions in 2 terminals & noticed something odd.

Renamed the R3 & put the R2 back online.

I have NO idea how it happened, but somehow, (& this is the weird part...)

When I started the mosquitto_sub for AquariumLights:

cmnd/AquariumLights/Power1 on
and
cmnd/AquariumLights/Power2 off

showed immediately...

Apparently, those had somehow been retained on both the regular broker and my test broker.

Clearing those 2 retained messages from the brokers seems to have fixed it.

[sfromis]

Such things are why I suggested you to look at relevant and detailed logs, at the relevant point in time. Very important to debugging.

[cdntinker]

And yet, the logs didn't point out anything when the issue did occur.
The only thing that showed up the problem was a chance viewing of MQTT traffic side-by-side with a non-broken equivalent.

[sfromis]

You never posted the detailed logs requested (even after two reminders), which is where clues would've been, including that commands arrived via MQTT.

[cdntinker]

Not sure which detailed logs I missed. I did eventually find the output during the issue from weblog 4 & post it.