Using the logger module

In this exercise, we will simply redo Exercise 1 of this lesson but this time we will be using the feature-rich logger module. We will enable the logger, and utilize it to print logs of different severities and to hexdump variables.

The timestamping feature (LOG_BACKEND_FORMAT_TIMESTAMP) and the coloring of error and warning logs feature (LOG_BACKEND_SHOW_COLOR) are enabled by default. Again, the logger gets the timestamp by calling the kernel function k_cycle_get_32() internally. This routine returns the current time since bootup (uptime), as measured by the system’s hardware clock. You could change this to return an actual time and date if an external Real-time clock is present on the system. We will use the previous exercise code as a starting point.

Before starting, ensure that your development kit is powered on and connected and that your terminal emulator is configured properly as we did in steps 2 through 4 in Exercise 1.

Exercise steps

1. In the GitHub repository for this course, open the base code for this exercise, found in l4/l4_e2 of the directory v1.9.1-v1.6.0.

2. Enable the logger module. This is done by adding the configuration line below to the application configuration file prj.conf

CONFIG_LOG=y

Make sure to save the prj.conf file (Ctrl+S). Adding the CONFIG_LOG=y will include the logger module source code into the build.

3. Open main.c inside the fund_less4_exer2/src directory.

4. Include the header file of the logger module.

Search for STEP 4 in main.c, and write the following line:

#include <logging/log.h>

5. Register your code with the logger module.

In order to use the logger, you must register with it first. This is done by using the macro LOG_MODULE_REGISTER() , which takes two parameters:

• A mandatory module name. The module name will be included in every log entry, which helps in distinguishing messages generated by different modules and/or filtering. The module name must NOT be passed as a string. In other words, don’t use quotation marks “”.  
• An optional maximal log level for the module. The maximal log level will determine which messages will be send to the console. For instance, if you set the log level of module X to LOG_LEVEL_DBG, it means all messages generated (Debug, Info, Warning, and Error) will be send to the console. On the other hand, if you set the maximal log level of module Y to LOG_LEVEL_WRN, it means only messages with severity level of warning and error will be sent to the console. If the minimum log level is not provided, then default global log level (CONFIG_LOG_DEFAULT_LEVEL) is used in the file. The default global log level is set to LOG_LEVEL_INF.

For this exercise, we will name the module Less4_Exer2 and we will use the lowest logging level, which is LOG_LEVEL_DBG (Send all messages generated by module Less4_Exer2 to console).

Search for STEP 5 in main.c, and write the following code:

LOG_MODULE_REGISTER(Less4_Exer2,LOG_LEVEL_DBG);

6. We are all set! Let’s write some logs. We will experiment with printing some messages (logs) will all levels (debug, info, warning, and error) and also hex dumping some variable.

Copy the code below:

    int exercise_num=2;
    uint8_t data[] = {0x00, 0x01, 0x02, 0x03,
                      0x04, 0x05, 0x06, 0x07,
                      'H', 'e', 'l', 'l','o'};
    //Printf-like messages
    LOG_INF("nRF Connect SDK Fundamentals");
    LOG_INF("Exercise %d",exercise_num);    
    LOG_DBG("A log message in debug level");
    LOG_WRN("A log message in warning level!");
    LOG_ERR("A log message in Error level!");
    //Hexdump some data
    LOG_HEXDUMP_INF(data, sizeof(data),"Sample Data!"); 

We will replace the old printk() from the previous exercise with the more capable logger macro calls as shown in the illustration below:

7. Change the callback function button_pressed() to use the asynchronous logger API instead of the blocking prinkt().

Copy the new button_pressed() function. The key difference between the old callback function and the new one is that the new one uses the logger macros instead of printk()blocking calls.

void button_pressed(const struct device *dev, struct gpio_callback *cb,
            uint32_t pins)
{
  int i;
  int j;
  long int factorial;
  LOG_INF("Calculating the factorials of numbers 1 to %d:",MAX_NUMBER_FACT);
  for (i=1;i<=MAX_NUMBER_FACT;i++){
       factorial =1;
        for (j=1;j<=i;j++){
            factorial = factorial*j;
        }
        LOG_INF("The factorial of %2d = %ld",i,factorial);
  }
  /*Important note! 
  Code in ISR runs at a high priority, therefore, it should be written with timing in mind.
  Too lengthy or too complex tasks should not be performed by an ISR, they should be deferred to a thread 
  */
}

Replace the button_pressed() function with the copied code as shown below:

8. Build the exercise as we have done in the previous lessons.

9. Flash it to the board as we have done in the previous lessons.

Using a serial terminal, you should see the following output:

Any time you press Button 1 you should observe that the factorials of the numbers from 1 to 10 are printed on the console as shown below:

[00:00:06.900,482] <inf> Less4_Exer2: Calculating the factorials of numbers 1 to 10: 
[00:00:06.900,512] <inf> Less4_Exer2: The factorial of  1 = 1 
[00:00:06.900,512] <inf> Less4_Exer2: The factorial of  2 = 2 
[00:00:06.900,512] <inf> Less4_Exer2: The factorial of  3 = 6 
[00:00:06.900,543] <inf> Less4_Exer2: The factorial of  4 = 24 
[00:00:06.900,543] <inf> Less4_Exer2: The factorial of  5 = 120 
[00:00:06.900,543] <inf> Less4_Exer2: The factorial of  6 = 720 
[00:00:06.900,543] <inf> Less4_Exer2: The factorial of  7 = 5040 
[00:00:06.900,543] <inf> Less4_Exer2: The factorial of  8 = 40320 
[00:00:06.900,573] <inf> Less4_Exer2: The factorial of  9 = 362880 
[00:00:06.900,573] <inf> Less4_Exer2: The factorial of 10 = 3628800 

The solution for this exercise can be found in the GitHub repository, in  l4/l4_e2_sol of the v1.9.1-v1.6.0 directory .