Mega2560 stops printing suddenly in the middle of a string

OVERVIEW:

  • Board: I’m using Wokwi in pair with PlatformIO, to simulate Arduino Mega 2560 locally;
  • Design: The code leverages from state design pattern, meaning it is highly modularized;
  • Compiler: The compilation is well executed, both with Arduino IDE and PlatformIO;

MEMORY MANAGEMENT:

  • Methods malloc() and free() are NEVER called in this code;
  • All variables and constants used in the code are declared in separate .h files (such as DeviceParameters.h and WifiParameters.h);

THE BUG:

Here is an exemple of output that points out the app behaviour, board status and the actual bug that brought me here:

************************ [main: 6 :loop] ************************
[main::loop] Free Memory: 5516 bytes
************************* [SimulationState::exit]* *************************
************************* [HTTPClientState::enter] *************************
[HTTPClientState::report_simulation_data] running...
[WifiComm::connect_wifi] Ru�

As we can see, the code:

  • Enters the 6th loop
  • Prints out the current amount of memory available
  • Changes state (from Simulation to HTTPClient)
  • Initiates a method inside the current state class (HTTPClientState::report_simulation_data)
  • The report_simulation_data method calls an external method (WifiComm::connect_wifi)
  • Processing stops outside the state class and the string is never printed till the end

INTRIGUING FACTS:

  • If I simply add more lines of Serial.println() right after that incomplete one, the code does not break in the same exact point, it will run a few more prints. Check it out:

************************* [HTTPClientState::enter] *************************
[HTTPClientState::report_simulation_data] running...
[WifiComm::connect_wifi] Running… 0

[WifiComm::connect_wifi] Running… 1

[WifiComm::connect_wifi] Running… 2

[WifiComm::connect_wifi] Ru�

  • The bug may also occur in the State files or other files called outside states (no pattern found in this matter)

ADDITIONAL ANALYSIS:

  • Code size: Both compilers point out about 30% of memory usage, right after compilation;
  • Modularization: The state pattern is well validated, code enters and exitis all states without any issue;
  • Printing is not a problem (just a sympthom): if I put Serial.println() in the base loop() it will print endlesslly (as expected);
  • Processing never stops in the main file (regardless how many prints are called;

What else can I do to understand and solve this issue?

Start by posting your code here, using code tags when you do

Remember that unless you call flush() after your print, the printing happens slowly (even at 115200 bauds) compared to the speed of code execution and since the serial output is asynchronous, your main code continues.

Don’t trust where you see it stop printing to guess what was the last statement executed, your crash might be hundreds of lines further down in the code

The code has 7 states and each state has it’s own set of files. Once the bug occurs in many points of the code, there isn’t an specific code snippet for me to show yet. However, I can share the main file structure so you can understand the overall logic:

MAIN → Context → State → Specialized Module (such as ClientCommunication)

void loop() {

switch (context.stateFlow) {

    case 0: // Self

    context.change_state(selfDiagnosisStatePtr);

    context.printFreeMemory("\[main::loop1\]");

    context.run_health_check();                                     // !! stops printing

    break;

    case 1: // Comm

    context.change_state(communicationStatePtr);

    context.report_signature_request();

    context.session_new();                                            // !! stops printing

    context.report_config();                                           // !! stops printing

    context.report_health_check();                               // !! stops printing

    break;

    case 2: // Config update

    cyclobot.change_state(configUpdateStatePtr);

    cyclobot.update_config();

    break;

    case 3: // Code update

    cyclobot.change_state(codeUpdateStatePtr);

    cyclobot.update_simulation_code();

    break;

    case 4: // Comm

    cyclobot.change_state(communicationStatePtr);

    cyclobot.session_stop();                                           // !! stops printing

    break;

    case 5: // Simulation

    cyclobot.change_state(simulationStatePtr);

    // cyclobot.run_simulation();                                   // !! stops printing

    break;

    case 6: // Comm

    cyclobot.change_state(communicationStatePtr);

    cyclobot.report_simulation_data();                         // !! stops printing

    break;

}

cyclobot.stateFlow++;

};

Thanks! I’ll read more about flush() but, even if it takes a little longer to print than the code to run, it shouldn’t stop printing, right?

By the way: I’m using F() inside all my Serial.prinln() calls. I suppose that is a best practice to optimize memory usage but I’m not sure if that might be causing any damage to the code… Please let me nkow if you have any other clue.

Unless the arduino crashes

If you post the code and a description of the circuit we will be able to help more

Ok, but where is the code printing those messages you have shown us? What the code does before and after those printouts?
Please post a complete code if you want us being able to help you.

Looking at the code you did not post I see problems in lines 4,21,24,43,36,57,59,78 in the third include for starters. You also have the blue and purple wires swapped. This is what my crystal ball shows. Without the code and annotated schematic I say good by and good luck.

mine is still in the dishwasher...

Sorry guys!

I had to make sure that flush() wasn't enought to solve my problem and, then, isolate one of the bug’s traceback snippets into a propper branch. The following link points to a simplified version of the code that, besides exposing the firmware's base design, it also leads us straight to one of the breaking points where Serial.println() stops.

Besides the link, in the following lines we have the central snippets related to the bug, from main.cpp, Context.cpp and HTTPClientState.cpp (where the bug happens):

src/main.cpp :

#include <Arduino.h>
#include <SoftwareSerial.h>
#include <WiFiEsp.h>
#include "../include/core_states/BaseState.h"
#include "../include/core_states/self/IdleState.h"
#include "../include/core_states/comm/HTTPClientState.h"
#include "../include/Context.h"

// Set state classes
BaseState *communicationStatePtr = new HTTPClientState();
BaseState *idleStatePtr = new IdleState();

// Create state machine
FiniteStateMachine fsm_context(idleStatePtr);

// Extra serial port for wifi
SoftwareSerial esp8266(fsm_context.paramPtr->peripheralMappingPtr->wifiEspRX,
                       fsm_context.paramPtr->peripheralMappingPtr->wifiEspTX); // software-based serial port to communicate with wifi module
                       
void setup() {
    Serial.begin(9600); // Enable communication over the USB serial port console 9600 Bps

    fsm_context.printFreeMemory("[main::setup]");

    Serial.println(F("[main::setup] starting clock (rtc)"));
    fsm_context.rtc.begin();
    fsm_context.now = fsm_context.rtc.now();
    
    Serial.print(F("[main::setup] date: "));
    Serial.print(fsm_context.now.day());
    Serial.print(F("/"));
    Serial.print(fsm_context.now.month());
    Serial.print(F("/"));
    Serial.println(fsm_context.now.year());
    
    Serial.print(F("[main::setup] time: "));
    Serial.print(fsm_context.now.hour());
    Serial.print(F(":"));
    Serial.print(fsm_context.now.minute());
    Serial.print(F(":"));
    Serial.println(fsm_context.now.second());
    
    // Serial.println(F("[main::setup] initializing WiFi module"));
    // WiFi.init(&esp8266);
};

void loop() {
    Serial.print(F(" ************************  ************[main::loop"));
    Serial.print(fsm_context.stateFlow);
    Serial.println(F("]************  ************************ "));
    Serial.flush();
    fsm_context.printFreeMemory("[main::loop]");
    switch (fsm_context.stateFlow) {
        case 0:
        // this block is commented
        break;
        case 1:
        fsm_context.change_state(communicationStatePtr);
        fsm_context.report_signature_request();
        fsm_context.session_new();                      // !! [HTTPClientState::session_new] Free Memory: 55�
        // fsm_context.report_config();                 // !! [HTTPClientState::report_conf�
        // fsm_context.report_health_check();           // !! [HTTPClientState::report_health_check]�
        break;
        case 2:
        // this block is commented
        break;
        default: // Reset
        fsm_context.stateFlow = -1; // Reset
        break;
    }
    fsm_context.stateFlow++;
};

src/Context.cpp :

#include <Arduino.h>
#include "..\include\Context.h"
#include "..\include\core_states\BaseState.h"

extern unsigned int __bss_end;   // Symbol marking the end of the .bss section (static & global variables in RAM).
extern void *__brkval;           // Current end of the heap. NULL (0) if no malloc() has been used yet.

FiniteStateMachine::FiniteStateMachine(BaseState *initialStatePtr) {
    currentStatePtr = initialStatePtr;
}

void FiniteStateMachine::change_state(BaseState *newStatePtr) {
    // get milliseconds + log start
    currentStatePtr->exit(this);
    currentStatePtr = newStatePtr;
    currentStatePtr->enter(this); // complete this line
    // log end + execution time
}

void FiniteStateMachine::report_signature_request() {
    // get milliseconds + log start
    currentStatePtr->report_signature_request(this);
    // log end + execution time
}

void FiniteStateMachine::session_new() {
    // get milliseconds + log start
    currentStatePtr->session_new(this);
    // log end + execution time
}

void FiniteStateMachine::report_config() {
    // get milliseconds + log start
    currentStatePtr->report_config(this);
    // log end + execution time
}

void FiniteStateMachine::report_health_check() {
    // get milliseconds + log start
    currentStatePtr->report_health_check(this);
    // log end + execution time
}

void FiniteStateMachine::session_stop() {
    // get milliseconds + log start
    currentStatePtr->session_stop(this);
    // log end + execution time
}

void FiniteStateMachine::take_a_nap() {
    // get milliseconds + log start
    currentStatePtr->take_a_nap(this);
    // log end + execution time
}

void FiniteStateMachine::printFreeMemory(char *currentMethodPtr) {
  int free_memory;
  
  // If the heap hasn't been used (__brkval == 0)
  if ((int)__brkval == 0) {
    // free space = (address of local var / stack pointer) - (end of bss section)
    free_memory = ((int)&free_memory) - ((int)&__bss_end);
  } else {
    // Otherwise, heap is in use
    // free space = (address of local var / stack pointer) - (current end of heap)
    free_memory = ((int)&free_memory) - ((int)__brkval);
  }

  Serial.print(currentMethodPtr);
  Serial.print(" Free Memory: ");
  Serial.print(free_memory);
  Serial.println(" bytes");
}

src/core_states/HTTPClientState.cpp :

#include "Arduino.h"
#include "../../../include/core_states/comm/HTTPClientState.h"
#include "../../../include/Context.h"

// used by context.changeState
void HTTPClientState::enter(FiniteStateMachine *fsm_context) {
    if (!fsm_context) {
        Serial.println(F("[HTTPClientState::enter] fsm_context pointer is null in HTTPClientState"));
        return;
    }
    Serial.println(F(" *************************  ******[HTTPClientState::enter]******  ************************* "));
};

void HTTPClientState::exit(FiniteStateMachine *fsm_context) {
    Serial.println(F(" *************************  ******[HTTPClientState::exit]*******  ************************* "));
};

// comm
void HTTPClientState::report_signature_request(FiniteStateMachine *fsm_context) {
    Serial.println(F("[HTTPClientState::report_signature_request] running..."));
    Serial.flush();
    if (fsm_context->paramPtr->deviceParametersPtr->firstAwakening) {
        fsm_context->commPtr->clientCommPtr->post_signature_request(fsm_context->paramPtr->clientParametersPtr,
                                                                  fsm_context->paramPtr->wifiParametersPtr,
                                                                  fsm_context->paramPtr->deviceParametersPtr);
        fsm_context->paramPtr->deviceParametersPtr->firstAwakening = false;
        Serial.println(F("[HTTPClientState::report_signature_request] fsm_context approved"));
        Serial.flush();
    } else {
        Serial.println(F("[HTTPClientState::report_signature_request] skipped"));
        Serial.flush();
    }
};

void HTTPClientState::session_new(FiniteStateMachine *fsm_context) {
    Serial.println(F("[HTTPClientState::session_new] running..."));
    fsm_context->printFreeMemory("[HTTPClientState::session_new]");
    fsm_context->commPtr->clientCommPtr->get_cyclobot_session_token(fsm_context->paramPtr->clientParametersPtr,
                                                                  fsm_context->paramPtr->wifiParametersPtr,
                                                                  fsm_context->paramPtr->deviceParametersPtr);
    Serial.println(F("[HTTPClientState::session_new] done"));
};

void HTTPClientState::report_config(FiniteStateMachine *fsm_context) {
    Serial.println(F("[HTTPClientState::report_config] running..."));
    fsm_context->commPtr->clientCommPtr->post_cyclobot_config(fsm_context->paramPtr->clientParametersPtr,
                                                            fsm_context->paramPtr->wifiParametersPtr,
                                                            fsm_context->paramPtr->deviceParametersPtr,
                                                            fsm_context->dataPtr->configDataPtr,
                                                            fsm_context->paramPtr->ecosystemParametersPtr);
    Serial.println(F("[HTTPClientState::report_config] done"));
};

void HTTPClientState::report_health_check(FiniteStateMachine *fsm_context) {
    Serial.println(F("[HTTPClientState::report_health_check] running..."));
    fsm_context->commPtr->clientCommPtr->post_cyclobot_diagnosis(fsm_context->paramPtr->clientParametersPtr,
                                                               fsm_context->paramPtr->wifiParametersPtr,
                                                               fsm_context->paramPtr->deviceParametersPtr,
                                                               fsm_context->dataPtr->selfDiagnosisDataPtr);
    Serial.println(F("[HTTPClientState::report_health_check] done"));
};

void HTTPClientState::session_stop(FiniteStateMachine *fsm_context) {
    // stop session and client
    Serial.println(F("[HTTPClientState::session_stop] running..."));
    fsm_context->commPtr->clientCommPtr->put_invalid_cyclobot_session_token();
    fsm_context->commPtr->wifiCommPtr->disconnect_wifi();
    Serial.println(F("[HTTPClientState::session_stop] done"));
};

// self
void HTTPClientState::take_a_nap(FiniteStateMachine *fsm_context) {
    // fsm_context->selfPtr->errorHandlerPtr->log_error_msg(fsm_context->paramPtr->errorHandlingParametersPtr, "HTTPClientState", "take_a_nap", 0, "wrong state");
    return;
};

// constructor
HTTPClientState::HTTPClientState() {
    return;
};

Hi! Thanks for spending your magic credits on your crystal ball! I’d say your analysis was “crystal“ clear and “roundly“ technical!

Hi! Does anyone have updates for this scenario?

I'd say you need to monitor free RAM in loop, watching for leaks, and track those down.
But. I don't see your code, so I can't say where, or when doing the above would be effective, or wasted time. Maybe start by dramatically lowering the amount of rubbish being printed, see if the code survives longer. May or may not be a hint as to what's going on. I.e. is the crash related to Serial dropping to it's knees and slowing down, or is it related to the number of times loop() cycles, and therefore something loop is calling is drawing down free memory on every pass.
Good luck.

Apologies for that, first read through the thread your code postings did not appear at all. I see you're already monitoring memory, so I have no further contributions.

I think you have a memory issue as 55 is almost nothing

the challenge monitoring available RAM is that you don't see allocations which have failed and the processing did not occur (the String class for example would fail silently) so you can see the situation before and after and not understand that it went wrong.

No problem... Tks for the hints anyway! Although I have already tried your suggestions, it’s good to know this rational make sense to you too.

Tks for the hint but 55 is not the real amount of free memory. Note that 55 is followed by �, meaning the code stoped before finishing that print (the actual free memory is something around 5526 in most of the time). The available memory is one of the reasons I decided using Mega2560. This board should be able to handle at least 3x more code than we have in this scenario.

About the challenge of monitoring RAM, I'm not sure I understood it. If I can see the situation before and after a silent fail, I should be able to notice some decay of available memory at some point, which does not seem to occur.

OK - sorry I misread that

regarding the monitoring, imagine that case

  • read available ram ➜ OK
  • call some library function where a huge allocation is done and fails safely
  • read available ram ➜ OK

as you can't inject your memory check at every single point, you can't know what happens internally.

for example, in case of memory shortage

readAvailableRam(); // say it's OK
String x = a + b + c + d + e + f; // say a,b, c, d, e and f are large strings
readAvailableRam(); // say it's OK

➜ you have no way of knowing if the concatenation failed because ram went low or if it succeeded. Transient Strings were created during the execution of that line to accumulate the data for the new final String and this could have failed.

I see… String “x“ could be incomplete (due to lack of memory) and the code would still run. But the second “readAvailableRam()“ would indicate a significant memory decay, which would be enough for me to guess that the problem is in the previous line.

Either way, unless my “printFreeMemory()“ method is badlly written, this memory leak scenario does not seem to occur in my code, since the free memory is always higher then 5500. Please fell free to review that method in src/Context.cpp and point out if there’s anything wrong with it.

Another detail that I consider relevant for this case is one that I mentioned in my introduction: If I simply add more lines of Serial.println() right after that incomplete one, the code does not break in the same exact point, it will run a few more prints.

Exemple:

Serial.println(F(“hello world“)); // prints out “hello w�“ and stops processing

If I add more prints, the code goes a little further before stoping:

Serial.println(F(“hello world“)); // prints out “hello world“
Serial.println(F(“hello Bob“)); // prints out “hello Bob“
Serial.println(F(“hello James“)); // prints out “hello Ja�“ and stops processing

I don’t know how but I belive this is an important hint to understand the problem.

You need to have Serial.flush() after every print, if you want to really see the last print.

That makes sense if the Serial buffer is full, because print() will not return until all the text is places in the print buffer. The actual last character printed may be as much as 63 characters past the last one you see.