This blog is to describe how to use the logging system on the Nordic nRF5 SDK. I would cover how to do the print log through UART or RTT with difference debugging level. Also, I would introduce how to use the flash log or crash log to store the log inside the internal flash system. All the materials are based on the

https://infocenter.nordicsemi.com/topic/sdk_nrf5_v16.0.0/lib_nrf_log.html

Logger module

The logger module provides logging capability for your application. It is used by SDK modules and can be also used in the application code. Main features of this library are:

  • Four severity levels – ERROR, WARNING, INFO, and DEBUG.
  • Formatted string (printf-like) log format.
  • Dedicated macro for dumping data.
  • Configurable global severity level.
  • Independent severity level for each module.
  • Enabling and disabling logging per module and globally.
  • Filtering on module instance level.
  • Optional timestamping with time formatting.
  • Optional coloring of the logs for different modules and different severity levels.
  • Prefixing log entries with the module name or instance name, and severity.
  • Deferring of log processing to idle stage.
  • Logging mechanism decoupled from the logger backend.
  • Multiple backends supported.
  • Several backends provided: RTT, UART, console (Command Line Interface), flash (see Flash logger backend).
  • Optional dynamic (run time) filtering on module and instance basis.
  • Storing and loading logger configuration by using Flash Data Storage.

For API documentation of this module, see Logger module.

Log processing

Logs can be processed using one of the following modes:

In-place processing

When the deferred mode is switched off, the logs are processed in the place where the logger is used. This means that the pointer to a formatted string and the arguments are passed to the logger backend for processing. It is possible for the backend to buffer the logs, but the frontend part of the logging is performed once the backend processing function returns. This approach is straightforward but in many cases not optimal. It can significantly impact performance, especially when logs are used in interrupt context. The operation is not thread-safe and can lead to the corruption of the output.

Deferred processing

In the default deferred mode, whenever the logger is used, the pointer to the string and the arguments are stored in an internal buffer and the log is not processed. It is up to the user to trigger processing whenever suitable. In most cases, the processing is performed in an idle stage, when the system would normally sleep. The size of the buffer can be configured, so that it can be adjusted to the amount of log entries and the nature of idle periods in the application. In the deferred mode, logging takes considerably fewer cycles in the place where it is called (compared to in-place mode), because the processing cost is shifted to idle stage. If the buffer is too small, the logger detects it and injects an overflow marker. In such case, logging is blocked until there is room for new entries in the buffer.

Logger configuration

The following are the logger frontend configuration options:

  • NRF_LOG_ENABLED – Enable the logger. If disabled, the logger and all logger entries are not compiled.
  • NRF_LOG_DEFAULT_LEVEL – Default severity level. Available options are: ERROR (highest), WARNING, INFO, and DEBUG (lowest). This option configures the lowest severity level that can be present in the system. For example, if it is set to the INFO level, all DEBUG entries are not compiled. Every module can set a local severity level. The actual severity level that is applied for the module is the highest pick from local and global. For example, if the module severity level is set to DEBUG, but the default severity level is set to INFO, then all debug log entries in the module are not compiled.
  • NRF_LOG_USES_TIMESTAMP – If enabled, a timestamp is added to every log entry. The user must provide a function that returns a 32-bit timestamp value during initialization. The source of the timestamp is not important for the logger. If timestamping is enabled and this function is not provided, initialization fails with an error.
  • NRF_LOG_USES_COLORS – If enabled, every string is prefixed with an ANSI escape code with the configured color. The user can configure colors of errors (NRF_LOG_ERROR_COLOR) and warnings (NRF_LOG_WARNING_COLOR) for all modules, and the default color for info and debug logs. Colors for info and debug logs can be overriden by every module.
  • NRF_LOG_DEFERRED – If enabled, the logs are not processed directly where they are called, but deferred to idle state. See Log processing. When NRF_LOG_DEFERRED is enabled, the size of the internal buffer can also be configured (NRF_LOG_BUFSIZE). Standard entries take from 4 to 32 bytes.
  • NRF_LOG_ALLOW_OVERFLOW – If enabled and if the internal circular buffer is full, the oldest entries are removed and new entries are stored.
  • NRF_LOG_FILTERS_ENABLED – If enabled, logs can be compiled as part of a binary file, but not used unless they are enabled (which is especially useful when Command Line Interface is used as a backend).

A module can have a section that overrides its own default logger settings. Modules can override the following configuration:

  • Log activation in the module.
  • Independent lowest severity level.
  • Info log coloring.
  • Debug log coloring.

Logging

The nrf_log.h file contains the API used for logging. There are the following types of log entries:

  • Standard logs with syntax very similar to printf – NRF_LOG_<SEVERITY_LEVEL>().
  • Hexdump – a method for dumping the data – NRF_LOG_HEXDUMP_<SEVERITY_LEVEL>().

The following example shows the simplest way to log data in a module:

#include "nrf_log.h"
void send_func(uint8_t * p_data, uint32_t length)
{
    NRF_LOG_INFO("sending data\r\n");
    NRF_LOG_DEBUG("%d bytes, data:\r\n", length);
    NRF_LOG_HEXDUMP_DEBUG(p_data, length);
    if (phy_is_busy())
    { 
        NRF_LOG_ERROR("Phy is busy\r\n"); 
    }
}

Printing the float value

Due to certain limitations, logging a float requires you to use the following dedicated macros:

NRF_LOG_INFO(„float value:” NRF_LOG_FLOAT_MARKER „\r\n”, NRF_LOG_FLOAT(val))

How to enable the logger module in the code

Step 1:

Enable the logger module and select the logger level

// <e> NRF_LOG_ENABLED - nrf_log - Logger
//==========================================================
#ifndef NRF_LOG_ENABLED
#define NRF_LOG_ENABLED 1
#endif
// <h> Log message pool - Configuration of log message pool

// <0=> Off 
// <1=> Error 
// <2=> Warning 
// <3=> Info 
// <4=> Debug 

#ifndef NRF_LOG_DEFAULT_LEVEL
#define NRF_LOG_DEFAULT_LEVEL 3
#endif

Step 2:

Configure the UART or RTT backend

Or

If you are using the RTT log through Segger Embedded Studio, you need to set NRF_FPRINTF_FLAG_AUTOMATIC_CR_ON_LF_ENABLED = 0.

Step 3:

Initialize the logger module

Step 4:

Add the NRF_LOG_PROCESS at the idle_state_handle

Step 5:

Use the NRF_LOG_INFO to print out with difference arguments

Dump the hex through NRF_LOG_HEXDUMP_DEBUG / NRF_LOG_HEXDUMP_INFO