Arduino Fix: Serial.print used to diagnose can adversely affect timing

While developing routines for my rover, especially diagnostic routines to identify sensor errors or conflicts, I have been using the Serial.print() function.   I've found it very useful over the past several months.

However, like all high level functions, it comes at a cost... timing... 

I decided to see how much of a cost, and if there was anything I could do to reduce this cost. 

Here are my results....

This is a typical diagnostic report for my distance ranging module. 

There are four Sharp Infrared Distance Sensors (one on each of front/rear/left/right)  and there are two MaxBotix Ultrasound modules on a servo 180 degrees from one another.  In this example, these give me Frontleft, Front, FrontRight, RearRight, Rear, RearLeft.

 

      Serial.print("StartTime with separate Serial.print statements = "); 

      Serial.println(test=millis()); 

 

         Serial.print("Front: ");  Serial.print(rangefront[midpoint]); 

         Serial.print("  Rear: ");  Serial.print(rangerear[midpoint]);  

         Serial.print("  Left: ");  Serial.print(rangeleft[midpoint]); 

         Serial.print("  Right: ");  Serial.print(rangeright[midpoint]);


         Serial.print("    Front Sonar: ");  Serial.print(FrontSonar[midpoint]/58); 

         Serial.print("  Rear Sonar: ");  Serial.print(RearSonar[midpoint]/58);  


         Serial.print("FrontLeft: ");  Serial.print(FrontLeft); 

         Serial.print("  FrontRight: ");  Serial.print(FrontRight);  

         Serial.print("  Front: ");  Serial.print(Front); 

         Serial.print("  RearLeft: ");  Serial.print(RearLeft); 

         Serial.print("  RearRight: ");  Serial.print(RearRight);  

         Serial.print("  Rear: ");  Serial.println(Rear); 


      Serial.print("EndTime with separate Serial.print statements = "); 

      Serial.println(millis()-test); 

On an 8Mhz Arduino Pro Mini, this snippit takes 17ms to generate and send this report. 

 

But what if I used string concatenation, and only sent ONE string our Serial like this? 

      Serial.print("StartTime with one Serial.print statement and concat strings = "); 

      Serial.println(test=millis()); 

        

         // Assemble the string first, then print it once.

         

         response = "";     // Flush previous message.

         response += "  Front: ";      response += rangefront[midpoint];  

         response += "  Rear: ";     response += rangerear[midpoint]; 

         response += "  Left: ";     response += rangeleft[midpoint];   

         response += "  Right: ";    response += rangeright[midpoint]; 


         response += "  Front Sonar: ";  response += FrontSonar[midpoint]/58; 

         response += "  Rear Sonar: ";  response += RearSonar[midpoint]/58;  


         response += "  FrontLeft: ";  response += FrontLeft; 

         response += "  FrontRight: ";  response += FrontRight;  

         response += "  Front: ";    response += Front; 

         response += "  RearLeft: "; response += RearLeft; 

         response += "  RearRight: ";  response += RearRight;  

         response += "  Rear: ";     response += Rear; 


         Serial.println(response);


      Serial.print("EndTime with one Serial.print statement and concat strings = "); 

      Serial.println(millis()-test); 

 On an 8Mhz Arduino Pro Mini, this snippit only takes 6ms to generate and send this report. 

And before you ask why I don't just serially concatenate in one statement... the Arduino IDE doesn't seem to support that, at least not for mixed data types.

 

Can I do any better?  What if I reduces the TEXT portion to just comma separators, and only sent ONE string our Serial like this? 

 

      Serial.print("StartTime with no filler and concat strings = "); 

      Serial.println(test=millis()); 

        

         // Assemble the string first, then print it once.

         

         response = "";     // Flush previous message.

         response += rangefront[midpoint];  response += ", ";    

         response += rangerear[midpoint];  response += ", "; 

         response += rangeleft[midpoint];   response += ", ";    

         response += rangeright[midpoint]; response += ", "; 


         response += FrontSonar[midpoint]/58; response += ", ";  

         response += RearSonar[midpoint]/58;   response += ", "; 


         response += FrontLeft; response += ", ";  

         response += FrontRight; response += ", ";    

         response += Front;  response += ", ";  

         response += RearLeft; response += ", ";  

         response += RearRight;  response += ", ";   

         response += Rear; 


         Serial.println(response);


      Serial.print("EndTime with no filler and concat strings = "); 

      Serial.println(millis()-test); 

 On an 8Mhz Arduino Pro Mini, this snippit now only takes between 3-4ms to generate and send this report. 

 

This is a significant improvement, and reduces the overall impact diagnostics has on my loop timing....

 

Hope you find this helpful...


Why?

Why does serial.print take so much time? The connection has been initialised already so it should only be a matter of passing variables.

I assumed that the delay I had to put in the code on my laptop to communicate with the Arduino was to synchronise things a bit, I didn’t try to optimise the code since it was only an experiment. Now that I read this post I have to rethink how to get fast communication altogether.

 

And then to think that my Mega has 3 serial ports, sending significant amounts of data to all ports will, according to your examples, take more time than acceptable and if that is true then I have to rethink using the Arduino altogether.

The arduino is quite acceptable for most cases…

In my post, I was simply concerned about the time Serial.print took during critical times in my code. 

When you need fast loops to control outputs like motor speed based on various inputs, every cycle counts. 

Typically you would not worry about the extra 10ms it takes to render your data to the Serial port, but when you are running diagnostic data in the very place that you need speed… well… this is just a minor way to optimise that output.

I’m personally only using Arduino UNO or Pro Mini and find them quite acceptable.  The Mega would be more so.

 

 

Just curious.

Could you try writing your data to an array and then using serial.write(arrayname, arraylength); and test the time that takes? Fair warning using serial.write will send bytes and not characters. For a group of 5 numbers [65,32,13,128,255] you will only see 5 characters on your serial monitor, at least that is how I understand it to be. If it works, you will only be sending 12 bytes instead of up to 47 bytes of data. The caveat being, your data is not in character format. You would have to do some kind of “heavy lifting” on your computer to actually make sense of the data.

**That is exactly what I’m doing over I2C **

That is exactly what I’m doing over I2C, but I have an application that parses the serial stream and analyzes it.  It expects it to be a character string comma separated, terminated by crlf.

On I2C I simply pack an array with the interger values in highbyte/lowbyte fashion and Bob is your proverbial uncle.

I just wanted a way to get more speed out of the Serial interface.  The Serial.print function is quite nice in it’s ability to transpose any data type into meaningful text, but because of that is just an overhead pig.

 

I am worried!

I’m quite worried about the delays. My robot is still a theoretical entity inside my brain, so everything is subject to change. Currently the idea is to use a dismantled laptop as the brain and the Arduino to do “low level” stuff, reading and passing sensors values, driving motors etc. So in my case it’s all about communication between the brain and the Arduino.

From what I’ve read (a search on slow serial Arduino gives 432.000 results) it’s quite a common problem and there are ways to speed up the serial communication considerably, but it will remain a bottle neck apparently. I guess the only real solution will be to use a controller board programmed in C or Assembly…

You might want to remove

You might want to remove your ( / 58) piece, and see how long that takes.

Good point!

I actually had the /58  in each ping received, then putting those into the array to be sorted for median, and realized I could still sort the larger numbers … ummm… yeah… 

 

Anyway, removing the divide-by  from the ranging loop sped it up tremendously.  I’m sure it’s guilty here as well.

 

you know… that’s why two sets of eyes are always better…  (Long Live Open Source!)