ESP32 Logging

ESP32 logging falls into the same category as the recent post about embedding binary content. It is about how logging on ESP32 is different from logging on ESP8266. Yet, as “logging” is a software topic (mostly) and “ESP32” describes hardware we need to be more precise with terms. Therefore, this post will look into how logging with the Espressif ESP-IDF has improved over plain NONOS SDK. The same goes for Arduino Core for ESP32.

Rest assured the old stuff still works on ESP-IDF. However, this post hopefully manages to convince you to improve your code by using the new features.

Logging target

Coming to IoT from software development rather than from hardware engineering meant we had to get used to a whole new set of constraints. One was the lack of comfortable line-by-line debugging facilities in most environments.

Often you find yourself dumping application state to serial out to understand the twists and turns your application takes. So, you use serial out due to the lack of “proper” debugging facilities. Likely, serial out is the only logging target you ever write to. That is quite different from classical applications which write to console on your local machine but to one or multiple other targets in production environments (file, syslog, aggregator APIs, etc).

That being said you can build applications with non-volatile logging targets. Possible options include:

• Write log messages to an in-memory ring buffer. Regularly, or triggered by an action (e.g. error condition), you dump it to a file on SPIFFS.
• Route all log output to JTAG.

We do not cover such options in this post. Hence, we leave them as an exercise for the interested reader.

Writing straight to serial out

Over the last years you and countless others probably wrote millions of lines of code similar to the ones below. Note how it comes in all shapes and forms:

void setup() {
  Serial.begin(115200); // Setup serial object and define transmission speed
  Serial.println("Starting setup().");
  Serial.printf("Hello, %s!\n", "Paul");
  Serial.printf_P(PSTR("Time: %d\n"), millis()); // using PROGMEM
  Serial.println(F("Setup completed")); // using PROGMEM
}

Which ever way we directly or indirectly cobble together a log message we will always end up using one of the many Serial.print functions directly.

The major drawback with this approach is that you have got only a single log level – either all or nothing. This means that unless you introduce some #ifdef-style indirections, all your debugging / logging code also ends up in the production binary. This results in lower runtime performance and increased memory foot print. You can slightly improved this using PROGMEM but still.

ESP32 logging – looks familiar

In the following two paragraphs you will learn about the basic logging functionality provided by the Espressif ESP-IDF and the improvements built on top by the ESP32 Arduino Core.

ESP-IDF

The ESP-IDF added a logging library to its system level API. It supports the following five log levels using a dedicated macro for each:

• ESP_LOGE – error (lowest)
• ESP_LOGW – warning
• ESP_LOGI – info
• ESP_LOGD – debug
• ESP_LOGV – verbose (highest)

These levels can be set at compile time using the option CONFIG_LOG_DEFAULT_LEVEL. Furthermore, they can also be changed at runtime by calling esp_log_level_set(). In order to group log statements by origin (class, component or feature) each macro expects a tag as its first parameter. Example:

static const char* TAG = "MyModule";
ESP_LOGW(TAG, "Baud rate error %.1f%%. Requested: %d baud, actual: %d baud", error * 100, baud_req, baud_real);

ESP32 Arduino Core

ESP32 Arduino Core built their logging abstraction on top of the ESP-IDF library into esp32-hal-log.h. Here is why they felt the need to improve on the Espressif solution as per the developer:

I’m not particularly fond of IDF’s logging facility, because it’s controlled both by compile flags and also allow some runtime changes (but not all). That in effect means that most debug statements are actually compiled, regardless if you want to see them or not and at the same time switching serials is also not possible (all debug goes to UART0 or whatever the build flag is).

ESP32 Arduino also supports five levels but its macros are all lower-case like so:

• log_e – error (lowest)
• log_w – warning
• log_i – info
• log_d – debug
• log_v – verbose (highest)

The ESP32 Arduino Core supports but redefined the ESP-IDF macros. It simply routes them to their Arduino counter part. Hence, ESP_LOGE is routed to log_e.

Please note that their macros don’t enforce the use of a tag for each message to group them. That is a pity as you will have to embed it into each message manually yourself. That is an issue for the same reasons anything else you need to take care of manually is: lack of consistency, room for error. Developers might simply forget to include it in the message.

The log level is set at compile time through CORE_DEBUG_LEVEL=5 or via build_flags = -DCORE_DEBUG_LEVEL=5 for PlatformIO.

Summary

We hopefully managed to convince you that using Serial.println() for ESP32 logging should be a thing from the past. Instead, If you program directly against the ESP-IDF you should use its ESP_LOGx macros. On ESP32 Arduino Core you can use the same or choose to use their simplified log_x macros.

If you like this short introduction into ESP32 logging then you might also like the other articles about what you learn if you attend a ThingPulse ESP32 workshop. Subscribe to this site’s feed with your favorite RSS reader or follow us on Twitter to never miss new content.