[Bug] Present omitted if initial mqtt connection fails

[jkandasa]

Original issue reported by @cimba007 on mycontroller-org/mycontroller-v1-legacy#425

If I upload a new sketch the mqtt-client does not logoff from the mqtt-server (buildin mycontroller).
On next sketch run presentation is skipped:

MC[I]: Booting ESP8266 device...<\n>
MC[I]: WIFI not connected, trying connection...<\n>
MC[D]: Searching BSSID for ssid:[FRITZ!Box Fon WLAN 7390]<\n>
MC[D]: Found BSSID[] for ssid:[FRITZ!Box Fon WLAN 7390], RSSI:[-62 -dBm, 76 %]<\n>
MC[D]: Selected bssid:[]<\n>
MC[I]: Connecting to WiFi with ssid[FRITZ!Box Fon WLAN 7390] and with password.....OK<\n>
MC[I]: WiFi BSSID:[], RSSI:[-68 dBm, 64 %], IP:[], StatusCode:[3]<\n>
MC[D]: WiFi connection status: Connected<\n>
MC[I]: Configuration(NodeEUI:[], Mqtt{mDNS-status:[0], Server:[], Port:[], FeedId:[esp], User:[]})<\n>
MC[D]: Attempting MQTT connection...<\n>
MC[I]: MQTT settings(Broker:[], Port:[])<\n>
MC[I]: MQTT authenticating as user:[]<\n>
MC[I]: MQTT connection failed, rc=-4<\n>
MC[D]: Try again in 3 seconds<\n>
MC[I]: Initialization done...<\n>
MC[I]: MQTT failed! Retryting to connect...<\n>
MC[D]: WiFi connection status: Connected<\n>
MC[D]: Attempting MQTT connection...<\n>
MC[I]: MQTT settings(Broker:[], Port:[])<\n>
MC[I]: MQTT authenticating as user:[]<\n>
MC[I]: MQTT connected :)<\n>
MC[I]: MQTT topic subscribed:[in_esp/ESP_C0DE98/#]<\n>

@cimba007 Could you please elaborate this issue?

I will try .. assume I upload my sketch to the esp8266 and everything is working as expected.

Now I want to upload a new sketch .. the upload process resets the esp8266 and leaves an open mqtt-connection on the broker (the client just vanished and did no proper logoff). Now the new sketch is uploaded .. and tries to connect again to the broker.

MC[D]: Attempting MQTT connection...<\n>
MC[I]: MQTT settings(Broker:[], Port:[])<\n>
MC[I]: MQTT authenticating as user:[]<\n>
MC[I]: MQTT connection failed, rc=-4<\n>
MC[D]: Try again in 3 seconds<\n>

The connection fails .. but succeeds after 3 seconds on the next retry.

MyControllerDevice/MyController.cpp

Line 121 in 95ea3ea

if(mqttClient.connected()){

The code presented here will be skipped ...

  if(mqttClient.connected()){
    before();
    sendRSSI();
    sendStatistics();
    mcPresentation();
  }

When the yellow part is called

The only check and chance to run

  if(mqttClient.connected()){
    before();
    sendRSSI();
    sendStatistics();
    mcPresentation();
  }

is gone.

I hope this made it a little bit more clear.

[jkandasa]

Updated by @cimba007

I am not good with github and pull requests but I suggest to change this:

   mqttClient.connect(WiFi.hostname().c_str(), _mqttUser, _mqttPwd)

to

	  int limit = 0;
	  while(!mqttClient.connect(WiFi.hostname().c_str(), _mqttUser, _mqttPwd) && limit++ < 5)
	  {
		  MC_SERIAL.printf("MC[I]: MQTT retry .. %d\n",limit);
		  mcDelay(500);
	  }

in void MyController::checkMqtt() {

[jkandasa]

@cimba007 thank you for the tips and code. I will update. I hope we can delay 3 seconds to retry. What do you think?

To create this document might help you. https://gist.github.com/Chaser324/ce0505fbed06b947d962

[jkandasa]

@cimba007 can you check this fix? merged into master.

[cimba007]

MC[I]: Booting ESP8266 device...
MC[I]: WIFI not connected, trying connection...
MC[D]: Searching BSSID for ssid:[FRITZ_BOX]
MC[D]: Found BSSID[MAC] for ssid:[FRITZ_BOX], RSSI:[-62 -dBm, 76 %]
MC[D]: Selected bssid:[MAC]
MC[I]: Connecting to WiFi with ssid[FRITZ_BOX] and with password......OK
MC[I]: WiFi BSSID:[MAC], RSSI:[-66 dBm, 68 %], IP:[192.168.178.72], StatusCode:[3]
MC[D]: WiFi connection status: Connected
MC[I]: Configuration(NodeEUI:[ESP_C0DE98], Mqtt{mDNS-status:[0], Server:[HOST], Port:[1883], FeedId:[esp], User:[MQTT_USER]})
MC[D]: Attempting MQTT connection...
MC[I]: MQTT settings(Broker:[HOST], Port:[1883])
MC[I]: MQTT authenticating as user:[MQTT_USER]
MC[I]: MQTT connection failed, rc=-4
MC[D]: Try again in 3 seconds
MC[I]: Initialization done...
MC[I]: MQTT failed! Retryting to connect...
MC[D]: WiFi connection status: Connected
MC[D]: Attempting MQTT connection...
MC[I]: MQTT settings(Broker:[HOST], Port:[1883])
MC[I]: MQTT authenticating as user:[MQTT_USER]
MC[I]: MQTT connected :)
MC[I]: MQTT topic subscribed:[in_esp/ESP_C0DE98/#]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/SENSOR_BC/C_INTERNAL/I_RSSI/0], Payload:[-66 dBm]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/SENSOR_BC/C_INTERNAL/I_PROPERTIES/0], Payload:[freeHeap=29968;chipId=12639896;flashChipSize=524288;flashChipRealSize=4194304;flashChipSpeed=40000000;cycleCount=1989731509;localIP=192.168.178.72;vcc=2780 mV]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/SENSOR_BC/C_INTERNAL/I_PROPERTIES/0], Payload:[subnetMask=255.255.255.0;gatewayIP=192.168.178.1;macAddress=MAC;ssid=FRITZ_BOX;hostname=ESP_C0DE98;bssid=MAC;rssi=-66 dBm;rssiAsQuality=68]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/SENSOR_BC/C_PRESENTATION/S_ARDUINO_NODE/0], Payload:[1.0.0]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/SENSOR_BC/C_INTERNAL/I_SKETCH_NAME/0], Payload:[433MHz to Mycontroller GW]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/SENSOR_BC/C_INTERNAL/I_SKETCH_VERSION/0], Payload:[1.0.0]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/00/C_PRESENTATION/S_DOOR/0], Payload:[433b Haustuer vorne]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/01/C_PRESENTATION/S_DOOR/0], Payload:[433b Terrassentuer (Tuer)]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/02/C_PRESENTATION/S_MOTION/0], Payload:[433b Terrassentuer (Aussen)]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/03/C_PRESENTATION/S_MOTION/0], Payload:[433b Bewegungsmelder vorne]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/04/C_PRESENTATION/S_MOTION/0], Payload:[433b Bewegungsmelder Garten (1)]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/05/C_PRESENTATION/S_DOOR/0], Payload:[433b Bewegungsmelder Keller (2)]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/06/C_PRESENTATION/S_DOOR/0], Payload:[433b D-On Test]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/07/C_PRESENTATION/S_DOOR/0], Payload:[433b Reed (2)]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/08/C_PRESENTATION/S_DOOR/0], Payload:[433b Reed (3)]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/09/C_PRESENTATION/S_DOOR/0], Payload:[433b Reed (4)]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/10/C_PRESENTATION/S_DOOR/0], Payload:[433b Keller (Tuer)]
MC[D]: About to publish a topic:[out_esp/ESP_C0DE98/11/C_PRESENTATION/S_MOTION/0], Payload:[433b Keller (Radar)]

Seems to be fine now. Notice how the initial mqtt connection fails and later the sendInitialStatus() function is called.

Nice @jkandasa