Saturday 22 December 2018

Autogate Adventures: Voice Control via Google Home. Part 3 of 3: Debugging Adafruit MQTT disconnects

One reason why I love doing software is the instant gratification: the speed at which you can try out something. And when a prototype works, the impulse is to immediately move to something else.

But a prototype is seldom suitable for customer use, and there are long weeks of grinding work where you monitor for failures and fix them as they appear.  A robust system is usually achieved sometimes years of constant fixing. If you are lucky enough to have a customer for your prototype the key is responsiveness- you need to fix it as fast as possible.

In Part 2, the MQTT-based ESP8266 IoT autogate was usable in less than a day. But it would not respond after a few days, usually after I disconnected the ADSL modem during thunderstorms (we get really spectacular lightning strikes and the ADSL modem is usually the first to go).

I can get the IoT Autogate to work again by power-cycling it, but it really looked bad next to the Sonoff switches, which seemed to recover after no more than 30 minutes as long as the broadband connection is restored. Since the Sonoff is also based on the ESP8266 and they both used the same ADSL modem and routers the problem must be the software.

Debug setup: ESP-01S on its CH340 USB Adapter


To debug the software, it would be nice to get to the Arduino IDE Serial Monitor, but since the  MQTT-based ESP8266 IoT autogate is out of reach inside the autogate enclosure. One way is to program another ESP-01S and run it on its CH340 USB adapter. When Google Assistant triggers the autogate (via IFTTT and Adafruit MQTT) both devices will now respond.

You will get messages like these every 5 seconds (Wife being the other House Member):

Wife Connecting to MQTT... Wife MQTT Connected!
Connecting to MQTT... MQTT Connected!
Wife Connecting to MQTT... Wife MQTT Connected!
Connecting to MQTT... MQTT Connected!

It would be nice to monitor it while at work, and since Adafruit's MQTT broker allows an IoT device to send messages to a feed, and since I have to make an IoT report it state back to Google Home at some point, I might as well use it to report debug messages.

In Adafruit-speak, when we want Google Assistant to control a device the ESP8266 IoT program (ie its Arduino sketch) needs to 'subscribe' to a feed. When it is sending data back to Google Assistant, it needs to 'publish'. So publish we shall. I added another feed, 'log' to my Adafruit account. 

Adafruit_MQTT_Publish mqtt_log = Adafruit_MQTT_Publish(&mqtt, AIO_USERNAME"/feeds/log");

No setup() code is necessary and you simple insert the following code snippet in loop():


{
    char logmsg[50]; 

          sprintf(logmsg, "YOUR_LOG_MESSAGE %d", Your_Log_Number); 
          if (! mqtt_log.publish(logmsg)) {
            Serial.println(F("publish Failed"));
          } else {
            Serial.println(F("publish OK!"));
          } 
}

Now log into your Adafruit account, navigate to

https://io.adafruit.com/youraccountname/feeds/log

And you have a remote Serial Monitor. It is that simple.

Logging debug messages in the Adafruit feed


But what of the ESP8266 MQTT IoT device going unresponsive problem? It turned out that just having the ESP8266 publish regularly (preferably not less than once every five minutes) made the problem go away. 

For now I can only guess when a device goes silently unresponsive, the MQTT broker may sometimes be unaware that the connection is broken, ie the mqtt.connect() function returned 0 (meaning connected) even when it is not. On the other hand we know when a periodic MQTT report does not arrive on schedule.

Notice I have disabled the "watchdog reset" to make the IoT keep trying to connect without restarting the WiFi code.    

void loop() {
  MQTT_connect();

    .
    .
    .
 publish++; 

  if (publish >= 20) //  ping every 4min
  {
    // Now we publish stuff! ping limit is 300s so 60s seems plenty
    Serial.print(F("\nPinging adafruit mqtt ... State "));
    Serial.print(State);
    Serial.print("...");
    sprintf(logmsg, "State is %d %d", State, Wife_Autogate_State);
    if (! mqtt_log.publish(logmsg)) {
      Serial.println(F("publish Failed"));
    } else {
      Serial.println(F("publish OK!"));
    }
    publish = 0;
  }
}

void MQTT_connect() {
  int8_t ret;

  // Stop if already connected.
  if (mqtt.connected()) {
    return;
  }
  
  Serial.print("Connecting to MQTT... ");
  
  uint8_t retries = 3;
  
  while ((ret = mqtt.connect()) != 0) { // connect will return 0 for connected
    Serial.println(mqtt.connectErrorString(ret));
    Serial.println("Retrying MQTT connection in 5 seconds...");
    mqtt.disconnect();
    delay(5000);  // wait 5 seconds
    //  retries--;
    if (retries == 0) {
      // basically die and wait for WDT to reset me
      while (1);
    }
  }
  Serial.println("MQTT Connected!");
}

So, for now the ESP8266 MQTT IoT Autogate goes back for more testing. We still do not know exactly what caused the problem- it might still be there for all we know. At least it is reconnecting when the Internet comes back, just like the Sonoff devices. Dave has some good work on ESP8266 reconnection problems. There is some talk here that it may be due to problems in the Expressif SDK.

By the way if you suspect the ESP8266 Adafruit MQTT library itself, you can turn on its debug messages:
 #define MQTT_DEBUG

Happily my customer (in this case Home Member Wife) does not seem to mind. We quickly got used to the Google Home/Assistant voice control of the autogate. It is especially handy when you have your hands full driving or carrying the groceries. Now if only I can get Google Assistant to recognize the dogs' voices ...

Happy Christmas, and Happy Trails.   

No comments:

Post a Comment