arendst / Tasmota

Alternative firmware for ESP8266 and ESP32 based devices with easy configuration using webUI, OTA updates, automation using timers or rules, expandability and entirely local control over MQTT, HTTP, Serial or KNX. Full documentation at
https://tasmota.github.io/docs
GNU General Public License v3.0
22.18k stars 4.8k forks source link

Periodically can't connect to MQTT broker after upgrade to 12.x #17281

Closed SteveDinn closed 1 year ago

SteveDinn commented 1 year ago

PROBLEM DESCRIPTION

Upgraded most of my devices to v12.2.0, and strangely only in a few cases, devices have become "unavailable" in Home Assistant for a few minutes at a time before coming back. I can tell that these devices are able to reconnect to wi-fi immediately because I can still connect to the web console right after they become "unavailable". The problem is that they can't seem to reconnect to the MQTT broker. Nothing has happened to the MQTT broker because the plethora of other devices (TASMOTA included) in my home network are still using it the whole time.

The one thing I am doing that others may not be is using a DNS name instead of an IP address for my MQTT broker. It is provided by my local DNS server (Pi-Hole), which is up the entire time as well. I've verified that I can lookup the DNS name of the MQTT broker while TASMOTA is having this problem.

Here's what TASMOTA's console messages look like when I connect to the web console (I have redacted personal information):

15:13:51.914 WIF: Connecting to AP1 WiFi_SSID Channel 4 BSSId [WiFi_BSSID] in mode 11n as MonitorLight...
15:13:51.919 MQT: Attempting connection...
15:13:52.065 MQT: Connect failed to mqtt.example.com:1883, rc -5. Retry in 10 sec
15:14:05.832 MQT: Attempting connection...
15:14:06.046 MQT: Connect failed to mqtt.example.com:1883, rc -2. Retry in 20 sec
15:14:26.833 MQT: Attempting connection...
15:14:26.847 MQT: Connect failed to mqtt.example.com:1883, rc -2. Retry in 30 sec
15:14:57.822 MQT: Attempting connection...
15:14:57.839 MQT: Connect failed to mqtt.example.com:1883, rc -2. Retry in 40 sec
15:15:01.184 RSL: STATE = {"Time":"2022-12-02T15:15:01","Uptime":"31T01:05:55","UptimeSec":2682355,"Heap":26,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":44,"POWER":"OFF","Wifi":{"AP":1,"SSId":"WiFi_SSID","BSSId":"[WiFi_BSSID]","Channel":4,"Mode":"11n","RSSI":70,"Signal":-65,"LinkCount":39,"Downtime":"0T00:02:22"}}
15:15:38.839 MQT: Attempting connection...
15:15:38.850 MQT: Connect failed to mqtt.example.com:1883, rc -2. Retry in 50 sec
15:16:30.113 MQT: Attempting connection...
15:16:30.228 MQT: Connected
15:16:30.232 MQT: tele/MonitorLight/LWT = Online (retained)
15:16:30.235 MQT: cmnd/MonitorLight/POWER = 

And as shown, it eventually does reconnect, but it takes a few minutes.

REQUESTED INFORMATION

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

- [x] Provide the output of this command: `Status 0`:
```lua
15:30:36.503 MQT: stat/MonitorLight/STATUS = {"Status":{"Module":1,"DeviceName":"Monitor Light","FriendlyName":["Monitor Light"],"Topic":"MonitorLight","ButtonTopic":"0","Power":0,"PowerOnState":0,"LedState":0,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":1,"InfoRetain":0,"StateRetain":0,"StatusRetain":0}}
15:30:36.511 MQT: stat/MonitorLight/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://tasmota.example.com/release/tasmota.bin.gz","RestartReason":"Software/System restart","Uptime":"31T01:21:30","StartupUTC":"2022-11-01T13:09:06","Sleep":50,"CfgHolder":4617,"BootCount":2949,"BCResetTime":"2020-04-17T18:36:47","SaveCount":4550,"SaveAddress":"F6000"}}
15:30:36.515 MQT: stat/MonitorLight/STATUS2 = {"StatusFWR":{"Version":"12.2.0(tasmota)","BuildDateTime":"2022-10-17T08:39:23","Boot":31,"Core":"2_7_4_9","SDK":"2.2.2-dev(38a443e)","CpuFrequency":80,"Hardware":"ESP8266EX","CR":"424/699"}}
15:30:36.521 MQT: stat/MonitorLight/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["WiFi_SSID",""],"TelePeriod":300,"Resolution":"558180C0","SetOption":["40008029","0405C80001000600003C5A0A002800000000","000080C0","00006000","00004000","00000000"]}}
15:30:36.533 MQT: stat/MonitorLight/STATUS4 = {"StatusMEM":{"ProgramSize":626,"Free":376,"Heap":22,"ProgramFlashSize":1024,"FlashSize":1024,"FlashChipId":"14405E","FlashFrequency":40,"FlashMode":"DOUT","Features":["00000809","8F9AC787","04368001","000000CF","010013C0","C000F981","00004004","00001000","54000020","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","Sensors":"1,2,3,4,5,6"}}
15:30:36.538 MQT: stat/MonitorLight/STATUS5 = {"StatusNET":{"Hostname":"MonitorLight","IPAddress":"10.1.1.168","Gateway":"10.1.1.1","Subnetmask":"255.255.255.0","DNSServer1":"10.1.1.4","DNSServer2":"1.1.1.1","Mac":"60:01:94:66:B2:52","Webserver":2,"HTTP_API":1,"WifiConfig":2,"WifiPower":17.0}}
15:30:36.542 MQT: stat/MonitorLight/STATUS6 = {"StatusMQT":{"MqttHost":"mqtt.example.com","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_66B252","MqttUser":"homeassistant","MqttCount":45,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30,"SOCKET_TIMEOUT":4}}
15:30:36.548 MQT: stat/MonitorLight/STATUS7 = {"StatusTIM":{"UTC":"2022-12-02T14:30:36","Local":"2022-12-02T15:30:36","StartDST":"2022-03-27T02:00:00","EndDST":"2022-10-30T03:00:00","Timezone":"+01:00","Sunrise":"08:23","Sunset":"16:55"}}
15:30:36.553 MQT: stat/MonitorLight/STATUS10 = {"StatusSNS":{"Time":"2022-12-02T15:30:36"}}
15:30:36.559 MQT: stat/MonitorLight/STATUS11 = {"StatusSTS":{"Time":"2022-12-02T15:30:36","Uptime":"31T01:21:30","UptimeSec":2683290,"Heap":21,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":45,"POWER":"OFF","Wifi":{"AP":1,"SSId":"WiFi_SSID","BSSId":"[WiFi_BSSID]","Channel":4,"Mode":"11n","RSSI":58,"Signal":-71,"LinkCount":39,"Downtime":"0T00:02:22"}}}

TO REPRODUCE

There are no steps to reproduce this other than to have a device with v12.2.0 and have a MQTT broker configured via its DNS name.

EXPECTED BEHAVIOUR

Wi-fi drops happen, but TASMOTA should be able to resolve the name of, and reconnect to, the MQTT broker.

ADDITIONAL CONTEXT

n/a

barbudor commented 1 year ago

"MqttHost":"mqtt.example.com"

Are you using a broker on the Internet ? Or is that a local one with some DNS trickery ?

Scrambling the requested information is not helping us to understand your setup

Everything starts by a DNS problem:

14:41:58.622 DNS: Unable to resolve 'mqtt.example.com' 14:41:58.624 MQT: Connect failed to mqtt.example.com:1883, rc -5. Retry in 10 sec 14:42:09.668 MQT: Attempting connection... 14:42:10.672 DNS: Unable to resolve 'mqtt.example.com' 14:42:10.674 MQT: Connect failed to mqtt.example.com:1883, rc -5. Retry in 20 sec

So I would assume something is wrong there. Your MQTT broker may be up but not the DNS

SteveDinn commented 1 year ago

Should have been explicitly clear before:

And like I said, I can hit the pi-hole instance and successfully look up the name at the same time as tasmota is having these issues. and not ALL my tasmota devices have this problem, despite them all being the same version and many of them being Sonoff Basics.

MaceMoneta commented 1 year ago

DNS2 is set to Cloudflare (1.1.1.1). If you remove that, does the problem still occur?