Tasmota: Device disconnecting from mqtt every 60 seconds, even after reflashing.

[cbullo]

BUG DESCRIPTION

I have accidentally (sic!) flashed a perfectly working sonoff device with the newest firmware. Before it worked perfectly and the connection was super stable. Now after flashing the latest firmware it disconnects from mqtt server exactly every 60 seconds. I have followed the steps from the FAQ MQTT troubleshooting without any change.

FAILURE TO COMPLETE THE REQUESTED INFORMATION WILL RESULT IN YOUR ISSUE BEING CLOSED

• [x] Read the Contributing Guide and Policy and the Code of Conduct
• [x] Searched the problem in issues
• [x] Searched the problem in the wiki
• [x] Searched the problem in the forum
• [x] Searched the problem in the chat
• [x] Device used (e.g., Sonoff Basic): Sonoff wall plug
• [ ] Tasmota binary firmware version number used: 6.7.1
  
  
  
  • [x] Pre-compiled
  
  
  • [ ] Self-compiled
  
  
  • [ ] IDE / Compiler used: _____
  
  
• [x] Flashing tools used: NodeMCU, esptool for erasing

• [ ] Provide the output of command: Backlog Template; Module; GPIO:

  14:21:31 MQT: myhome/livingroom/sonoff/RESULT = {"NAME":"Generic","GPIO":[255,255,255,255,255,255,255,255,255,255,255,255,255],"FLAG":15,"BASE":18}
  14:21:31 MQT: myhome/livingroom/sonoff/RESULT = {"Module":{"1":"Sonoff Basic"}}
  14:21:31 MQT: myhome/livingroom/sonoff/RESULT = {"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"0":"None"},"GPIO14":{"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:
  14:22:16 MQT: myhome/livingroom/sonoff/STATUS = {"Status":{"Module":1,"FriendlyName":["Sonoff"],"Topic":"myhome/livingroom/sonoff","ButtonTopic":"0","Power":0,"PowerOnState":3,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0}}
  14:22:16 MQT: myhome/livingroom/sonoff/STATUS1 = {"StatusPRM":{"Baudrate":115200,"GroupTopic":"sonoffs","OtaUrl":"http://thehackbox.org/tasmota/release/sonoff.bin","RestartReason":"Power on","Uptime":"0T00:08:15","StartupUTC":"2019-11-02T13:14:01","Sleep":50,"CfgHolder":4617,"BootCount":4,"SaveCount":11,"SaveAddress":"F9000"}}
  14:22:16 MQT: myhome/livingroom/sonoff/STATUS2 = {"StatusFWR":{"Version":"6.7.1(basic)","BuildDateTime":"2019-10-26T13:20:09","Boot":31,"Core":"STAGE","SDK":"2.2.2-dev(38a443e)"}}
  14:22:16 MQT: myhome/livingroom/sonoff/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["localnet",""],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008009","2805C8000100060000005A00000000000000","00000000"]}}
  14:22:16 MQT: myhome/livingroom/sonoff/STATUS4 = {"StatusMEM":{"ProgramSize":456,"Free":544,"Heap":29,"ProgramFlashSize":1024,"FlashSize":1024,"FlashChipId":"144051","FlashMode":3,"Features":["00000809","8F082383","041083A0","20021706","010001C0","00000000"],"Drivers":"1,2,3,4,9,10,16,20,21","Sensors":"3"}}
  14:22:16 MQT: myhome/livingroom/sonoff/STATUS5 = {"StatusNET":{"Hostname":"myhome/livingroom/sonoff-5933","IPAddress":"192.168.0.36","Gateway":"192.168.0.1","Subnetmask":"255.255.255.0","DNSServer":"192.168.0.1","Mac":"60:01:94:8D:97:2D","Webserver":2,"WifiConfig":4}}
  14:22:16 MQT: myhome/livingroom/sonoff/STATUS6 = {"StatusMQT":{"MqttHost":"192.168.0.10","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_8D972D","MqttUser":"openhabian","MqttCount":9,"MAX_PACKET_SIZE":1000,"KEEPALIVE":30}}
  14:22:16 MQT: myhome/livingroom/sonoff/STATUS7 = {"StatusTIM":{"UTC":"Sat Nov 02 13:22:16 2019","Local":"Sat Nov 02 14:22:16 2019","StartDST":"Sun Mar 31 02:00:00 2019","EndDST":"Sun Oct 27 03:00:00 2019","Timezone":"+01:00","Sunrise":"07:38","Sunset":"17:29"}}
  14:22:16 MQT: myhome/livingroom/sonoff/STATUS10 = {"StatusSNS":{"Time":"2019-11-02T14:22:16"}}
  14:22:16 MQT: myhome/livingroom/sonoff/STATUS11 = {"StatusSTS":{"Time":"2019-11-02T14:22:16","Uptime":"0T00:08:15","UptimeSec":495,"Vcc":3.426,"Heap":29,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":9,"POWER":"OFF","Wifi":{"AP":1,"SSId":"localnet","BSSId":"D8:D7:75:78:00:45","Channel":8,"RSSI":100,"LinkCount":9,"Downtime":"0T00:00:32"}}}

- [ ] Provide the output of the Console log output when you experience your issue; if applicable:
  _(Please use_ ``weblog 4`` _for more debug information)_
  ```

Console output here:
14:21:14 MQT: Attempting connection...
14:21:14 MQT: Connected
14:21:14 MQT: myhome/livingroom/sonoff/LWT = Online (retained)
14:21:14 MQT: myhome/livingroom/sonoff/cmnd/POWER =
14:21:14 MQT: myhome/livingroom/sonoff/RESULT = {"POWER":"OFF"}
14:21:14 MQT: myhome/livingroom/sonoff/POWER = OFF
14:21:31 CMD: Backlog Template; Module; GPIO
14:21:31 MQT: myhome/livingroom/sonoff/RESULT = {"NAME":"Generic","GPIO":[255,255,255,255,255,255,255,255,255,255,255,255,255],"FLAG":15,"BASE":18}
14:21:31 MQT: myhome/livingroom/sonoff/RESULT = {"Module":{"1":"Sonoff Basic"}}
14:21:31 MQT: myhome/livingroom/sonoff/RESULT = {"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"0":"None"},"GPIO14":{"0":"None"}}
14:22:02 MQT: Attempting connection...
14:22:02 MQT: Connect failed to 192.168.0.10:1883, rc -2. Retry in 10 sec
14:22:14 MQT: Attempting connection...
14:22:14 MQT: Connected
14:22:14 MQT: myhome/livingroom/sonoff/LWT = Online (retained)
14:22:14 MQT: myhome/livingroom/sonoff/cmnd/POWER =
14:22:14 MQT: myhome/livingroom/sonoff/RESULT = {"POWER":"OFF"}
14:22:14 MQT: myhome/livingroom/sonoff/POWER = OFF

```

TO REPRODUCE

Connect to Mosquitto MQTT server on my raspberry pi.

EXPECTED BEHAVIOUR

_A clear and concise description of what you expected to happen._
Not disconnecting from MQTT server

SCREENSHOTS

_If applicable, add screenshots to help explain your problem._

ADDITIONAL CONTEXT

The same is happening with my generic esp 01 module that I flashed with the same firmware.

And these are messages received on my MQTT:

myhome/livingroom/sonoff/LWT Offline
myhome/livingroom/sonoff/LWT Online
myhome/livingroom/sonoff/cmnd/POWER (null)
myhome/livingroom/sonoff/RESULT {"POWER":"OFF"}
myhome/livingroom/sonoff/POWER OFF
myhome/livingroom/sonoff/LWT Offline
myhome/livingroom/sonoff/LWT Online
myhome/livingroom/sonoff/cmnd/POWER (null)
myhome/livingroom/sonoff/RESULT {"POWER":"OFF"}                                                                        myhome/livingroom/sonoff/POWER OFF
myhome/livingroom/sonoff/LWT Offline
myhome/livingroom/sonoff/LWT Online
myhome/livingroom/sonoff/cmnd/POWER (null)
myhome/livingroom/sonoff/RESULT {"POWER":"OFF"}
myhome/livingroom/sonoff/POWER OFF

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

[Jason2866]

You have to search in your setup
-2: MQTT_CONNECT_FAILED - the network connection failed
Could be this https://github.com/arendst/Tasmota/wiki/FAQ#Frequent-MQTT-reconnects

[cbullo]

@Jason2866 Which setup?
I followed the steps from FAQ, no change.

[Jason2866]

Every device needs a specific topic. Read the mqtt part in wiki

[cbullo]

@Jason2866 I have only one device connected right now.

[cbullo]

Also this is repeating in my mosquitto log:

1572703634: Received PUBLISH from DVES_8D972D (d0, q0, r0, m0, 'myhome/livingroom/sonoff/RESULT', ... (15 bytes))
1572703635: Received PUBLISH from DVES_8D972D (d0, q0, r0, m0, 'myhome/livingroom/sonoff/POWER', ... (3 bytes))
1572703635: Sending PUBLISH to paho791735919053177 (d0, q0, r0, m0, 'myhome/livingroom/sonoff/POWER', ... (3 bytes))
1572703642: Received PINGREQ from mqtt_df1e806b.bd9f8
1572703642: Sending PINGRESP to mqtt_df1e806b.bd9f8
1572703664: Received PINGREQ from DVES_8D972D
1572703664: Sending PINGRESP to DVES_8D972D
1572703682: Socket error on client DVES_8D972D, disconnecting.

[Jason2866]

As i said you have a config error somewhere 1572703682: Socket error on client DVES_8D972D, disconnecting.

[cbullo]

@Jason2866 But what kind of error? And as I wrote, it worked correctly before I flashed sonoff with newer firmware.

[Jason2866]

Sorry, i dont know what error. You have to do research. Start from scratch
First erase ESP8266 with esptool.py. Download Tasmota again. Flash this fresh copy.
It is possible that you had a bad flash

[cbullo]

I did erase ESP and flashed a fresh copy of tasmota, as I described in bug report. That didn't change anything.

I have now captured network traffic between sonoff (192.168.0.36) and MQTT server (192.168.0.10). I'm not an expert, but it's sonoff that's sending TCP RST flag, which means it closed its socket.

And it's happening exactly every 60 seconds.

[Jason2866]

Do you have WMM enabled in your AP / Router?
Search for "special" settings in your wifi.
Have you tried to restart the Pi? I had sometime ago a weird issue with mosquitto...

[cbullo]

No WMM or any other special settings in router. Restarting doesn't help.

[edgarveersel]

Same issues. No changes made, but updating Tasmota from 6.5.0 to 6.7.1

[Jason2866]

Which router do you have?
Have you rebooted mqtt broker and updated to latest version?

[cbullo]

@edgarveersel Thanks for the tip. Downgrading Tasmota on sonoff to 6.5.0 solved the issue for me :)

[lhaperen]

Same issue here after updating to 6.7.1 before every thing workt perfect. After downgrade to 6.5.0 it was stable again.

[arendst]

Keepalive was changed in 6.6.0 from 10 to 30 seconds. As mosquitto will drop connection if keepalive is missed within 60 seconds a bad tcp connection will likely miss a keepalive ping resulting in exceeding mosquitto's window.

• Not many users have this issue
• Try with sleep set to zero.
• set teleperiod to 20
• Change keepalive in pubsubclient AND tasmota to 29 hoping the third ping will arrive within the 60 second window.

[cbullo]

@arendst there are a few clues suggesting this is not due to poor WiFi signal. In the Wireshark log I posted above you can see that sonoff had received ping response around time 110.9 and then disconnection happened around time 138.0. Also my sonoff stands 10cm from the router and I have no trouble with any other wifi devices on the network.

[Jason2866]

@cbullo Mhh, your setup has to differ from 100.000 other installations.
There are very very very few issues with latest v.6.7.1.
All of this few issues arrived in Discord where at the end:

• Bad flashes
• Bad hardware (power supply)
• Bad wifi
• Setup errors in wifi
• Setup errors mqtt

btw. There are Sonoff Basic which are known to have bad power supply and bad flash chips.
If i where you i would just replace the Sonoff Basics behaving weird.
A Sonoff Basic is a cheap device in every aspect. Do not expect high reliability from every bought one

[cbullo]

@Jason2866 I have reflashed multiple times, my wifi and mqtt settings are very simple (basically default), I have provided multiple logs with reasoning.
I have tried on one sonoff device and two different esp 01 modules, all exposing the same behavior. I have downgraded firmware and verified that this solves issue without any other changes to my setup. There are two other people in this thread with the same behavior.

I'm not arguing, just stating the facts.

And I'm pretty sure it's something in esp core >= 2.4.0 that's causing trouble, as I wrote a custom firmware (so, not using Tasmota) using pubsubclient and esp core 2.4.0 for my other ESP 01 module and saw similar disconnections.

[Jason2866]

@cbullo IF the error is coming from core nothing can be done from Tasmota side.
Open a issue on https://github.com/esp8266/Arduino with a sample sketch producing the error.
Core 2.4.0 is known to have many bugs/issues
There are many fixes since core 2.4.2 for wifi reliability.

[arendst]

You might want to try the below option:

Add #define MQTT_CLEAN_SESSION 0 to file my_user_config.h around line 267 and recompile.

[jj-uk]

Is this a valid hostname?

{"StatusNET":{"Hostname":"myhome/livingroom/sonoff-5933","IPAddress":"192.168.0.36",

[cbullo]

@jj-uk I left it at default %s-%04d. Works correctly in 6.5. didn't have chance to try changing it in 6.7.1

[jj-uk]

@jj-uk I left it at default %s-%04d. Works correctly in 6.5. didn't have chance to try changing it in 6.7.1

'myhome/livingroom/sonoff-5933' is not the default. Forward slashes are not valid in host names.

[cbullo]

@jj-uk, No, but %s-%04d is default. And that's what I left it at.

[localhost61]

@cbullo nevertheless it seems to be your issue, fix it in the WebUI WiFi config and you'll be done.

[localhost61]

I understand your error now.
Tested with latest 7.0.0.3, that's right that in the WebUI WiFi config if you clear the Hostname field and validate, it will be replaced with the string %s-%04d but by default, it should be the evaluated result of that string, that is sonoff-5933.
%s-%04d in the field will result with the Topic value to be appended in leading position to the default hostname. Hence the result.

[Jason2866]

So it is a case of https://github.com/arendst/Tasmota/issues/6816#issuecomment-549295528

[jj-uk]

@cbullo Set the hostname to "sonoff-%04x" and try again. As a test. See if that fixes your issue.

[localhost61]

When I did it myself the MQTT connection remained stable, then it's not the only reason of the disturbance.
@Jason2866 Nevertheless it remains a bug in Tasmota. Clearing the field shouldn't result in such an unexpected result.

[jj-uk]

Should the 'invalid hostname' bug be reported as a separate issue? I don't think tasmota has enough memory to do full validation of input.

[localhost61]

@jj-uk no, IMHO it's clearly a bug, the user clear a field and a new value appears which is wrong, it's a deliberate behavior of Tasmota which is erroneous and should be corrected (but an empty field is wrong too ;-) ) .

[jj-uk]

I guess tasmota doesn't expect the topic to be anything other than a single word, like "my_topic".
Are you going to open a new issue, since you can reproduce it?

@cbullo - Does this change the behaviour when the hostname is valid, e.g. "my_hostname" ?

[cbullo]

I won't be able to test it until the weekend, likely. Sorry.

[Jason2866]

Tasmota has not the resources to check for valid entrys. A empty field check could be done
But checking for a valid topic would increase code... ESP is a very resource limited device.
Dont expect logic checks.

[Jason2866]

Your problem is solved. Inputs for mqtt topics needs to be valid
Please close. Thx!

[localhost61]

@Jason2866 it's not necessary the origin of the disturbance, locally I got this weird hostname and it as no effect on the MQTT connection. Some hours ago I even issued a restart 1 command and no MQTT disconnection at all since then.
So don't consider it as solved.

[localhost61]

Honestly I don't know how I could achieve this behavior and I can't reproduce, because for the field change to be recorded one need to save the configuration and it triggers a restart. In accordance with the (wiki) documentation, when a '%' is found in the field this one is replaced by the default value which is properly evaluated. When I did it the device didn't restart but now it does...
:-/

[cbullo]

I have now corrected hostname and mqtt topics. It didn't change anything for me, still same reconnections.
My router is Sagemcom FAST3890V2.

[Jason2866]

You can try this version. Uses a different (newer) sdk 2.2.2 version
Has a command to change TX wifi transmit power wifipower <x> x from 0 to 20.5
Higher value higher output. Try value 16
firmware.zip

[ascillato2]

@cbullo

Hi, any news on this?

[cbullo]

@ascillato2 not yet, I haven't had time to try it.

[cbullo]

No change with the new version and increased wifipower.

[Jason2866]

So it is not a wifi power core issue.
I am still thinking it is a sort of config issue -> EXACTLY 60 seconds!
Can you try with a different router or accesspoint?

[thedexboy]

I had a similar problem some time ago. I had to ditch whole Mosquitto broker and reinstall and reconfigure it.
I have no idea what went wrong but I lost a couple of days before trying this.
I'm using hass.io so it was quite easy for me to do that at the time :)

[cbullo]

@Jason2866 Unfortunately, I don't have any to try. I'm fine using version 6.5.0 which works great. If I ever need to upgrade for some reason, I'll try to debug it more with some extra logging in the source. But for now I really don't have more time to do it. So feel free to close this ticket, unless you have any other idea what might be going on.
And I want to say that I think this is really a great project.

[ascillato2]

for now I really don't have more time to do it.

No problem. Ask to reopen if you want to continue this, or address this to the Tasmota Support Chat. Thanks.