LTE MQTT Stability

[SeamusTappert]

We need to identify the cause of the sporadic LTE connection issues and error handling when uploading via hologram.io. First start by investigating these zero-byte sessions logged to the hologram.io website, if we can learn why this is happening as well as what the response behavior is we can than develop proper error handling to ensure a reliable transmission of data.

Zero-byte Session Example

[SeamusTappert]

Soren suggested that this issue is being caused by a lack of power, as the LTE board will draw upwards of 200mA during transmission so if the batteries are at low voltage there simply won't be enough current available.

[ReidP-source]

Assuming current is the issue, devices with solar panels which can recover should have the option to go into low-power and recharge until the device has sufficient voltage to complete a transmission. We could also consider having a separate emergency power source used only to send a final message detailing the device health (heartbeat).

I have implemented a voltage check outside of the analog class that checks for a minimum voltage before proceeding. This can be used to flag if the device needs to shutdown and remain out of normal operation until the voltage check is passed. Current this implementation is in reid-dev-branch I will be merging it with dev after verifying their won't be any conflicts.

[ReidP-source]

I'll make an implementation of a low-power state that can be set by the voltage check. It should be flagged when the mean voltage of the voltage check is below the minimum required voltage of the device. A device in low-power should maintain the sleep cycle but only check the voltage when it wakes. It will continue the cycle until the device recovers and can proceed to send a new transmission, the new transmission should include the devices state(heartbeat?) as well as anything else it has to send.

Devices without solar panels should have an emergency power source for sending a final status before the device reaches an inoperable state. Implementation for this should be discussed further but it can be assumed that it will trigger when the voltage check fails (maybe more than once) and the device has no solar panel connected (how do we know this? possibly an increase in voltage over 2-3 vchecks sets a solar flag? Ideally the MCU has a way to know if its connected without needing a flag).

[SorenEmmons]

I am currently working with the unit here is a screenshot of what happeining

[ReidP-source]

Can you also post function summaries with the free memory for packet 34+?

[ReidP-source]

This bug is very tricky and I'm not sure what exactly is going wrong but I've determined the order of problems. I'd like to get a copy of the function summaries and debug outputs from the SD card. @SorenEmmons Could you email me the func_summaries and output file? My email is pettibor@oregonstate.edu

I've determined that stop() is being called during packet 35 which ends the connection and flips the _connected flag to false. Then since the publish batch loop in mongoDB only checks if its connected once before it enters the loop it succeeds for each packet when it should be failing. This is why MQTTComponent:publishMessage fails while MongoDB:Publish succeeds.

This can be "fixed" by adding a connected() check within the loop. This would move the failure to MongoDB:Publish rather than failing in MQTTComponent:publishMessage. Once it fails we'd have to restart the connection and retain the packet state (likely skipping the packet that caused the failure) and continue sending.

I'd also like for you to add #define MQTT_CLIENT_DEBUG so I can see what clientWrite is doing. I need to see why endMessage is failing for packet 35 and stop() is being called. I'm assuming it is caused by clientWrite failing because the packet is malformed, too large, or writing headers failed.

From what I've found these are the failure points:

From ArduinoMQTT: Leads to the MQTTComponent not connected to broker error message

uint8_t MqttClient::connected()
{
  return clientConnected() && _connected;
}

From ArduinoMQTT: Leads to the close packet failure message

int MqttClient::endMessage()
{
/*
*
*  This fails during packet 35 and calls stop()
*/
  if (!_txStreamPayload) {
    if (!publishHeader(_txPayloadBufferIndex) ||
        (clientWrite(_txPayloadBuffer, _txPayloadBufferIndex) != _txPayloadBufferIndex)) {
      stop();

      return 0;
    }
  }

  _txStreamPayload = false;

  if (_txMessageQoS) {
    if (_txMessageQoS == 2) {
      // wait for PUBREC
      _returnCode = -1;

      for (unsigned long start = millis(); ((millis() - start) < _connectionTimeout) && clientConnected();) {
        poll();

        if (_returnCode != -1) {
          if (_returnCode == 0) {
            break;
          } else {
            return 0;
          }
        }
        yield();
      }

      // reply with PUBREL
      pubrel(_txPacketId);
    }

    // wait for PUBACK or PUBCOMP
    _returnCode = -1;

From MQTTComponent Line 80:

# Leads to the Error MQTTClient not connected to broker 
# This is what's being called for every packet in publishMessage and why it's failing in publishMessage rather than MongoDB:publish
if(mqttClient.connected())    

ClientWrite has debug messaging that allows us to see why the packet failed

size_t MqttClient::clientWrite(const uint8_t *buf, size_t size)
{
#ifdef MQTT_CLIENT_DEBUG
  Serial.print("TX[");
  Serial.print(size);
  Serial.print("]: ");
  for (size_t i = 0; i < size; i++) {
    uint8_t b = buf[i];

    if (b < 16) {
      Serial.print('0');
    }

    Serial.print(b, HEX);
    Serial.print(' ');
  }
  Serial.println();
#endif

  return _client->write(buf, size);
}

MongoDB Successfully connects to the broker even after packet 35 but fails during MQTT publishing. Once again because connection is only being checked once here when publish is called not for every packet in the loop

The fix for this is restarting the connection and skipping the packet that caused the stop(). We don't need to add a connection check in the loop since it's already in publishMessage but it doesn't hurt and we can restart the connection mid loop if we do.

bool Loom_MongoDB::publish(Loom_BatchSD& batchSD){
              
             ...

             /* 

                   This is successful everytime because it's only called at the start of the publishing not within the batchSD loop.   
             
            */
            /* Attempt to connect to the broker */                                            
            if(!connectToBroker())
                return false;
            
              ...
           
            # This is the beginning of the packet batch loop              <-------------------------------

            /* Utilize a stream so it doesn't matter how much data we have as its read in one by one */
            while(fileOutput.available()){
                c = fileOutput.read();

                // \r Marks the end of a line, at this point we want to publish that whole packet
                if(c == '\r'){

                    // Track the packet number we are currently publishing 
                    snprintf_P(output, OUTPUT_SIZE, PSTR("Publishing Packet %i of %i"), packetNumber+1, batchSD.getBatchSize());
                    LOG(output);

                    // Replace the \r with a null character
                    line[index] = '\0';

                   
                    /* 

                   It's getting to here every packet and then failing. PublishMessage is failing because it's checking the connection rather                                  

                   than checking it here. We'd need to restart the connection after packet 35 fails to ever have a chance of this succeeding again. 
             
                    */

                    if(!publishMessage(topic, line)){                                         
                        snprintf(output, OUTPUT_SIZE, PSTR("Failed to publish packet #%i"), packetNumber+1);
                        WARNING(output);
                        allDataSuccess = false;
                    }

This is where its failing because it's rechecking the connection for every packet. This fails because stop() was called during packet 35 and the connection was never restarted. _connected flag is set to false

bool MQTTComponent::publishMessage(const char* topic, const char* message, bool retain, int qos){
    FUNCTION_START;

    // Make sure the module is initialized
    if(moduleInitialized && internetClient.moduleInitialized){      

           /*

             This fails after packet 35 and outputs ERROR("MQTT Client not connected to broker ");
   
           */          
        if(mqttClient.connected()){
            // Tell the broker we are still here
            mqttClient.poll();

            // Start a message write the data and close the message, publish all messages with retain
            if(mqttClient.beginMessage(topic, retain, qos) != 1){
                ERROR(F("Failed to begin message!"));
            }

            // Print the message to the topic
            mqttClient.println(message);

            // Check to see if we are actually closing messages properly

           /*

            This fails during packet 35
          
            */
            if(mqttClient.endMessage() != 1){                                              
                ERROR(F("Failed to close message!"));
                FUNCTION_END;
                return false;
            }
            else{
                LOG(F("Data has been successfully sent!"));
                FUNCTION_END;
                return true;
            }   
        }
        else{
            ERROR("MQTT Client not connected to broker ");
        }

[ReidP-source]

Other than figuring out why the packet actually failed in the first place all we need to do to fix it is restart the connection during the loop if it has failed and skip the bad packets. Ideally we don't have any bad packets but recovering is better than total failure.

[ReidP-source]

This line is also spooky because it's causing overflows if the packet line has more characters than the max_json_buffer. It is adding each character to the line without regard to the buffer which is probably why packet 35 broke the connection. Currently the publish method sends the packet only when it hits \r (end of the line) not when it reaches max buffer size -1.

MongoDB.cpp Line 176
// If not just add the packet to the line array
else{
line[index] = c;
index++;
}

We will need to split lines that are longer than the buffer and send chunks. MongoDB will also need to be able to accept chunks and be able to reassemble the packet.

[ReidP-source]

SDManager:Log isn't actually preventing the lines from going past the max_json_size.

strncat(output, utcArr, MAX_JSON_SIZE);
strncat(output, ",", MAX_JSON_SIZE);
strncat(output, localArr, MAX_JSON_SIZE);
strncat(output, ",", MAX_JSON_SIZE);
JsonArray contentsArray = document["contents"].as<JsonArray>();

            // Loop over each 
            for(JsonVariant v : contentsArray) {

                // Get all JSON keys  
                for(JsonPair keyValue : v.as<JsonObject>()["data"].as<JsonObject>()){
                    strncat(output, keyValue.value().as<String>().c_str(), MAX_JSON_SIZE);  
                    strncat(output, ",", MAX_JSON_SIZE);
                }
            }

These all stack the output buffer

Strncat only limits the size of the number of characters being appended from the source to the destination. So if the output(dest) already has 257, strncat wouldn't stop an overflow because it doesn't care about the destination buffer only its only. It would continue to write stuff to destination up to max_json_size for each call. It's totally possible to have a ~1000 byte overflow depending on how much is in the contentsArray

[SorenEmmons]

This problem only appears to be happening to our Wisp V2, which sends a lot more data than our previous units, which dont seem to have this problem. Both units send 72 packet batches. Attached is a screenshot from another unit that has more consistent data uploads, but there about half of what they should be. They should look like the first transmission. I need to do some more testing with some new units we just built. I can also send the function summaries. It will take me some time, as I believe unit 56 currently only has SD_Logging enabled, but I can reflash it tomorrow.
{ "_id": { "$oid": "694b12d23c3f3306d2f07743" }, "Packet": { "Number": 1 }, "LTE": { "RSSI": 21 }, "Analog": { "Vbat": 4.144335747, "Vbat_MV": 4134.667969 }, "DFR_MultiGasSensor_0": { "CO": 0, "Temp(C)": 20.63698769 }, "DFR_MultiGasSensor_1": { "SO2": 0, "Temp(C)": 20.43614578 }, "SEN55_5": { "PM1_0": 1.110000014, "PM2_5": 2.75999999, "PM4_0": 4.070000172, "PM10_0": 4.699999809, "N_PM0_5": 4.059999943, "N_PM1_0": 7.220000267, "N_PM2_5": 8.710000038, "N_PM4_0": 9.010000229, "N_PM10_0": 9.089999199, "Typical_Particle_Size": 1.157900095, "AmbientHumidity": 58.34000015, "AmbientTemperature": 18.92499924, "VocIndex": 0, "NoxIndex": 0 }, "T6793_6": { "CO2": 470 }, "Timestamp": { "time_utc": "2025-12-23T21:47:53Z", "time_local": "2025-12-23T13:47:53" } }`