Using LogSerial with results


#1

I thought it may be useful to share my experiences with the Serial Monitor port and developing, in general.

The Arduino IDE lacks a lot of expected functionality for development and debug. I develop on an iMac so searching around I found a free Visual Studio Code (VSCode) tool, which I shared about on this forum here.

VSCode is a pretty good IDE (e.g. decent editing capabilities with visual feedback, github integration, and Arduino integration for compile and upload to Blink). With a couple of changes to the VSCode setup (described in my forum feedback above), I was now up and running. However, debugging using repeated print and println statements to print just a single debug message was cumbersome. Ultimately I wanted a printf style solution and decided to add it to the existing Serial Monitor code.

The most recent changes I made to LogSerial (submitted but not yet integrated in the official Blink library) make it easy to build log messages, remove some or all easily, and display then in the Serial Monitor. The LogSerial implementation makes it easy for the beginner to add and see Log messages. No requirement to learn a new library since everything is done with a few macros… i.e. you only need to be aware of a few macro’s!

Using this new Log functionality is straightforward: include the LogSerial header file, specify the Serial Monitor port speed, and sprinkle LOGXX lines (actually, macro calls) wherever you want to print output to the Serial Monitor. (Examples are provided towards the end of the article)

A big advantage over the existing Serial Monitor print and println methods, is that you can create formatted (printf style) strings with placeholders, with a variable number of arguments. It makes adding debug statements significantly easier. The LogSerial macros accept any format string acceptable to printf for your program. And, you can compile away your log statements easily (one-line change), so no need to manually search for and delete them prior to your final release compilation.

For example (using the current Serial Monitor methods), these 9 lines:

print("Today is ");
print(dow);
print(" (Date: ");
print(monthAbbr);
print("-");
print(day);
print("-");
print(year);
println(")");

become 1 line (with LogSerial):

LOGF("Today is %s (Date: %s-%02d-%s)\n", dow, monthAbbr, day, year); 

If you want your LOG lines compiled in, add a #define USE_LOG_LEVEL at the top of your file (before the LogSerial include.

#define USE_LOG_LEVEL  LOG_ALL
#include "LogSerial.h"

If you want the LOG lines compiled away (out), make a 1-line change: comment (or remove) that same #define.

// #define USE_LOG_LEVEL  LOG_ALL
#include “LogSerial.h”

There are 5 LOG levels: LOG_ERROR, LOG_WARN, LOG_INFO, LOG_DEBUG, LOG_ALL. These should look familiar if you know Log4J. The LOG levels are similarly ordered (ALL < DEBUG < INFO < WARN < ERROR). So, for example, LOG_ALL includes ALL log messages. And, LOG_WARN would exclude LOG_INFO and LOG_DEBUG messages.

Log macros (a LOGXF macro per Log level) are pre-defined in the LogSerial.h; LOGEF, LOGWF, LOGIF, and LOGDF for ERROR, WARN, INFO, DEBUG respectively. A generic LOGF macro is also available, which will be printed if USE_LOG_LEVEL level is defined. The ‘F’ at the end of the macro name means the format string will be stored in Flash for memory efficiency. For the odd case where you want to print out a string that’s already in Flash memory, use the corresponding LOGX macro (no ‘F’ at the end): i.e. LOGE instead of LOGEF, LOGW instead of LOGWF, etc. It’s expected that most will use the LOGXF macro’s.

For example, to print all messages except for DEBUG and INFO, you’d define USE_LOG_LEVEL as LOG_WARN. All DEBUG and INFO messages would be compiled away (not included in your compilation). And, only ERROR, WARNINGs and non-typed (LOGF) messages would be compiled in and printed.

////////////////////////////////////
// My Simple Sketch demonstrating LOG messages

#define USE_LOG_LEVEL   LOG_ALL

#include "LogSerial.h"

void setup() {
    // put your setup code here, to run once:

  // Uncomment the right line for your IDE.  VSCode shown.
  // LOG_SERIAL_BEGIN(SM_BAUD_RATE_500K);  // For Arduino IDE
  LOG_SERIAL_BEGIN(SM_BAUD_RATE_250K); // For VSCode IDE
  // Other setup code…
}

char myStateS[] = "START";
byte p2 = 42;

void loop() {
  // put your main code here, to run repeatedly:
  LOGEF("Unexpected state: %s\n", myStateS);

  LOGWF("New value %d\n", 42);

  LOGIF("Found the answer to life at %lu time\n", millis());

  LOGDF("Debug: S=%s P2=%d P2(hex)=%x P2(oct)=%o\n", myStateS, p2, p2, p2);

  LOGF("Always displayed if USE_LOG_LEVEL is defined.\n");

  while(1) ;
}

To demonstrate, I set the USE_LOG_LEVEL to 3 different values and re-compiled each time to show the changing program and memory footprint changes, as well as the resulting Serial Monitor output.

Using a USE_LOG_LEVEL of LOG_ALL and compiling,

Sketch uses 5022 bytes (31%) of program space.
Global variables use 227 bytes (22%) of dynamic memory.

and results in the Serial Monitor OUTPUT (all log messages):

ERROR:  Unexpected state: START
WARNING: New value 42
INFO: Found the answer to life at 1 time
DEBUG: Debug: S=START P2=42 P2(hex)=2a P2(oct)=52
Always displayed if USE_LOG_LEVEL is defined.

Now, changing USE_LOG_LEVEL to LOG_WARN and re-compiling (reduced program size),

Sketch uses 4872 bytes (30%) of program storage space
Global variables use 225 bytes (21%) of dynamic memory

and results in the Serial Monitor OUTPUT (Note, INFO and DEBUG message compiled away):

ERROR:  Unexpected state: START
WARNING: New value 42
Always displayed if USE_LOG_LEVEL is defined.

And finally, commenting out USE_LOG_LEVEL and re-compiling (removes all LOGXX and LOGX calls from the compilation),

Sketch uses 2750 bytes (17%) of program storage space
Global variables use 171 bytes (16%) of dynamic memory

with the expected result of NO log message in the Serial Monitor OUTPUT.

OTHER DETAILS (for those wanting additional formatting):
Note, each of the log messages has a customizable default header string. If you want to change the default value, specify your own corresponding #define before including the LogSerial.h file. The default header defines are:

  #define LOG_ERROR_HEAD "ERROR:  "
  #define LOG_WARN_HEAD "WARNING: "
  #define LOG_INFO_HEAD "INFO:  "
  #define LOG_DEBUG_HEAD "DEBUG:  "

That’s it. Hope this was helpful.


Serial Port debug printing - library recommendation