value of using Serial.print() for debugging

Using Arduino Programming Questions
#1

Hi all,
here is an interesting observation when using Serial.print() statements for debugging with the Arduino IDE.
Be aware that outputs on a hardware UART are running in parallel to the processing of code.

The following example took me a lot of time to find the bug because of the delay between the statement Serial.print() and the output on the Serial Monitor.

In a sketch a function is called:

...
    if ((millis()-t_gprs) > 300000) { // alle 5 Minuten
    Serial.print(millis());                                           // inserted for debugging
    Serial.println("---------> Daten an Server");          // inserted for debugging
    t_gprs=millis();
   
    wdir = getServerData(19, &wmean, &wmin, &wmax);
...

The function with the error looks like this:

byte getServerData(byte anz, word* wmean, word* wmin, word* wmax) {
  // berechnet Mittelwert, Minimum und Maximum der letzten anz Winddaten;
  // die Windrichtung wird als return-Wert geliefert
  word j, i;
  byte whist[16];

  for (i=0; i<16; i++) whist[i]=0;
  j=rbuf_idx-1;              // unsigned int rbuf_idx is the position in a circular buffer with size 600
  if (j>BUFFLEN) j=BUFFLEN-1; // neg. Zahl ergibt sehr große pos. Zahl
  *wmean=0; *wmin=*wmax=windspeed[j];
  for (i=0; i<anz;i++) {
    *wmean += windspeed[j];
    if (windspeed[j] > *wmax) *wmax=windspeed[j];
    else if (windspeed[j] < *wmin) *wmin=windspeed[j];
    whist[j]++;                                                // here is the error: j may be larger than 15!!!
    j--;
    if (j>BUFFLEN) j=BUFFLEN-1; // neg. Zahl ergibt sehr große pos. Zahl
  }
...

The effect of the error was that the controller (Mega2560, 16 MHz) was reseted, i.e. the sketch started from the beginning.
On the Serial Monitor the output was only a part of Serial.print(millis()), e.g. 109, and nothing more. Really the time should have been in the order of 100000.

What happened?
The controller started to output the time for millis() on the Serial Monitor (see sketch). But after some digits the processing of the sketch was advanced to the line within the function getServerData() where the error occured and the controller was reseted.
The statement Serial.print() filles the output buffer (what size?) of the hardware UART and continues with processing code of the sketch. The hardware of the UART outputs digit after digit (in my example with 38400 baud) in parallel to the processing of the controller.
When I saw that the controller was reseted, the processing of the code was much further than the output on the Serial Monitor, which confused me.
The output on the Serial Monitor looked like a problem within the statement Serial.print(millis()) :o .

SupArdu

#2

The statement Serial.print() filles the output buffer (what size?) of the hardware UART

The tx buffer is 63 bytes. It's a software buffer, not a hardware buffer.

Serial.print is interrupt driven. A byte is placed in the hardware tx register and transmitted; once transmission of that byte is completed an interrupt occurs and the next byte is copied from the software buffer into the hardware tx register. This continues till no bytes are available in the software buffer for sending.

Your code basically caused a call or jump to the reset vector and after that whatever was available in the software buffer is gone.

#3

Your code basically caused a call or jump to the reset vector and after that whatever was available in the software buffer is gone.

If you want to wait after a Serial.print() until all the data has actually been sent, use Serial.flush(). That is the ONLY time flush() is useful.

#4

PaulS:
If you want to wait after a Serial.print() until all the data has actually been sent, use Serial.flush(). That is the ONLY time flush() is useful.

But that is ‘blocking’ and might effect the rest of the code.

#5

sterretje:
But that is 'blocking' and might effect the rest of the code.

You can't have everything. 8)

#6

I know :wink: Better something then nothing.

#7