EMS-ESP32 icon indicating copy to clipboard operation
EMS-ESP32 copied to clipboard

No automatic MQTT reconnect after software restart in 3.4.2b2

Open gaszu opened this issue 2 years ago • 20 comments

After software restart doesn't start automatic mqtt connection - I must to go to mqtt settings tab, click save, than mqtt connects to my ha server. On previous versions - no problem - only in 3.4.2b2. No hardware changes beetween present and previous version. No errors in log.

gaszu avatar Jun 06 '22 07:06 gaszu

This is Ethernet correct? And you can confirm this happens all the time, so from the EMS-ESP web page click on 'Restart' it will not connect to the MQTT server and you'll see these errors in the Console log?

proddy avatar Jun 06 '22 07:06 proddy

All the time. In console no errors.

gaszu avatar Jun 06 '22 09:06 gaszu

No errors on ethernet. The same situation when i'm connected via wifi. This time only ethernet. faster and more stable, and more bandwith :)

gaszu avatar Jun 06 '22 09:06 gaszu

I can't reproduce. You will need to compile the code yourself and use the debug flags (see pio_local.ini_example) and watch the MQTT client logs in the serial console.

proddy avatar Jun 11 '22 07:06 proddy

I installed ha some days ago (next to my ioBroker installation) for test. I observed MQTT problems as well.

My ems-esp system still reboots after a while (some 3 to 5 days in the moment). Last time this night. After this reboot due to software crash ems-esp stays connected to MQTT but no data is send anymore. HA does not show any data anymore. Changing MQTT settings manually off/on will restart MQTT sending data.

When restarting from web-ui everything works fine. I will further observe the MQTT stability ...

tp1de avatar Jul 04 '22 09:07 tp1de

Same issue here, MQTT stops working after some time and can only be enabled by switching on/off the MQTT.

mtc716 avatar Jul 19 '22 08:07 mtc716

@mtc716 anything happen up to this point? i.e. wifi reconnected, MQTT broker restarted etc...

proddy avatar Jul 19 '22 10:07 proddy

@mtc716 anything happen up to this point? i.e. wifi reconnected, MQTT broker restarted etc...

Nothing at all. It happens just randomly during normal operation. Sometimes after 1 day, sometimes after 2-4 days.

mtc716 avatar Jul 19 '22 11:07 mtc716

@mtc716 anything happen up to this point? i.e. wifi reconnected, MQTT broker restarted etc...

Nothing at all. It happens just randomly during normal operation. Sometimes after 1 day, sometimes after 2-4 days.

if the MQTT disconnects there should be an INFO log message. Do you see this in the system log? If it happens after a few days its easier to use a SysLog server to capture the logs. In the next build I'll change it to Warning to make it easier to spot.

proddy avatar Jul 19 '22 12:07 proddy

@mtc716 anything happen up to this point? i.e. wifi reconnected, MQTT broker restarted etc...

Nothing at all. It happens just randomly during normal operation. Sometimes after 1 day, sometimes after 2-4 days.

if the MQTT disconnects there should be an INFO log message. Do you see this in the system log? If it happens after a few days its easier to use a SysLog server to capture the logs. In the next build I'll change it to Warning to make it easier to spot.

Will check for it and I guess it should reoccure latest tomorrow....

mtc716 avatar Jul 19 '22 12:07 mtc716

@mtc716 anything happen up to this point? i.e. wifi reconnected, MQTT broker restarted etc...

Nothing at all. It happens just randomly during normal operation. Sometimes after 1 day, sometimes after 2-4 days.

if the MQTT disconnects there should be an INFO log message. Do you see this in the system log? If it happens after a few days its easier to use a SysLog server to capture the logs. In the next build I'll change it to Warning to make it easier to spot.

Will check for it and I guess it should reoccure latest tomorrow....

It happened again and just before the disconnect, the WiFi was disconnected according to the logs....

2022-07-20 09:26:38.109 INFO 18305: [emsesp] WiFi connection dropped, stopping NTP 2022-07-20 09:26:38.109 INFO 18306: [system] NTP disconnected 2022-07-20 09:26:38.109 INFO 18307: [emsesp] WiFi disconnected. Reason code=3 2022-07-20 09:26:38.109 INFO 18308: [mqtt] MQTT disconnected: TCP 2022-07-20 09:26:42.975 INFO 18309: [emsesp] Starting NTP 2022-07-20 09:26:42.978 INFO 18310: [emsesp] WiFi connected with IP=192.168.178.36, hostname=ems-esp-new 2022-07-20 09:26:43.019 INFO 18311: [emsesp] mDNS responder service started 2022-07-20 09:26:45.655 INFO 18312: [system] NTP connected

mtc716 avatar Jul 20 '22 09:07 mtc716

thanks for checking. The reason for the wifi says "WIFI_REASON_AUTH_LEAVE" which doesn't tell us much. Your wifi is down for about 4 minutes. I'll run some tests here again to see if the MQTT reconnects when the wifi is off for a long period.

proddy avatar Jul 20 '22 09:07 proddy

I can't reproduce. I used connected the EMS-ESP to a Wifi AP, then switched off the AP and back on after a few minutes. As soon as the WiFi reconnected so did MQTT. @mtc716 could you share your MQTT settings in EMS-ESP? Are you using authentication, clean session....

proddy avatar Jul 20 '22 18:07 proddy

I can't reproduce. I used connected the EMS-ESP to a Wifi AP, then switched off the AP and back on after a few minutes. As soon as the WiFi reconnected so did MQTT. @mtc716 could you share your MQTT settings in EMS-ESP? Are you using authentication, clean session....

I even had it a second time today. Settings for MQTT are below: Screenshot_20220720_210741

mtc716 avatar Jul 20 '22 19:07 mtc716

Can you try the latest beta? Looks like you're using an older firmware. Not sure it'll make a difference but worth trying. The problem we need to fix is why EMS-ESP loses the WiFi connectivity. The system information we need you can download from the Help page.

proddy avatar Jul 20 '22 19:07 proddy

The problem occured with the latest Beta 3.4.2b3. I switched today back to 3.4.1 to check If it happens as well...

Do you need the debug information?

mtc716 avatar Jul 20 '22 19:07 mtc716

ah ok. The emsesp_info.txt file which you can download from the Help page (latest beta) would be useful as it shows the settings and also your WiFi strength (called RSSI). If the WiFi is unstable you can try playing with the settings like using a lower bandwidth or turning on nosleep.

proddy avatar Jul 20 '22 20:07 proddy

could the instability come from the mqtt broker? Since I installed a new mqtt broker within homeassistant as add in it seem to be stable now and reconnect works

tp1de avatar Jul 20 '22 21:07 tp1de

ah ok. The emsesp_info.txt file which you can download from the Help page (latest beta) would be useful as it shows the settings and also your WiFi strength (called RSSI). If the WiFi is unstable you can try playing with the settings like using a lower bandwidth or turning on nosleep.

the file can be found below. As you will see the RSSI is good and by the way, it worked since month at the same location. The difference is just the sw-version. If I can be of any further help, let me know.

emsesp_info.txt

mtc716 avatar Jul 21 '22 05:07 mtc716

could the instability come from the mqtt broker? Since I installed a new mqtt broker within homeassistant as add in it seem to be stable now and reconnect works

I am using already the internal mqtt broker of homeassistant and there has been no change since month.

mtc716 avatar Jul 21 '22 05:07 mtc716