Use → Tutorials → Basic: Logging

Basic: Logging

We all know that debugging is fundamental to develop correct applications. However, when using an embedded cpu which is low on resources, printing debug messages can be too expensive. BeRTOS offers a wide range of debugging and logging facilities to suit your needs.

Debug

In Basic: First Application with BeRTOS we saw how to set up debug messages. Looking closely at debug functions (eg. kprintf()), we can see that these are defined only when the project is compiled in debug mode. When you compile the project in release mode, the debug function calls are stripped, so you get maximum performance.

To compile in release mode, open the makefile fragment for your project, for example hello_world.mk and edit the line:

hello_world_DEBUG = 1

to be .

As we can see, debug is an all-or-nothing solution. Most of the time, it's not what you want, since you may have well tested modules where you want debug on errors only and not tested modules where you want full debugging power. This is where logging module comes to rescue.

Logging

The logging module (found in <cfg/log.h>) is a powerful tool to set different log levels for each module. To stay on the practical track, let's say you have two modules, library and tested_library and you want to use both of them in your project. Since tested_library is well tested, you would like to print error messages only on critical errors and those messages must be concise, since you have few of them in the code. On the contrary, you just wrote library and you would like to have more debugging messages complete with context (function name + line) where the message is written.

Log facilities

BeRTOS defines 4 levels of logging, ranging from no logging (LOG_LVL_NONE) to full debug (LOG_LVL_INFO). Instead of using kprintf() directly, you should use the three macros LOG_ERR, LOG_WARN and LOG_INFO. For each module, the compiler determines the log level for that module and removes all the messages that are above the current log level.

For example, if you define the log level to be LOG_LVL_WARN, all the calls to LOG_INFO will be removed; similarly, if you set log level to be LOG_LVL_NONE all LOG_* messages will be removed.

The logging module also defines two different formats for log messages: LOG_FMT_TERSE and LOG_FMT_VERBOSE. With the first, all module's messages will be formatted in this way:

ERR: [msg]
WARN: [msg]
INFO: [msg]

With the verbose option, the output will be like this:

function():[line_number]:WARN: [msg]

Example

How do you define per-module logging macros? Let's open tested_library.h. We have to define two macros, like this:

#define tested_library_LOG_LEVEL    LOG_LVL_ERR
#define tested_library_LOG_FORMAT   LOG_FMT_TERSE

The first macro, tested_library_LOG_LEVEL, defines the log level specific for this module, while the second, tested_library_LOG_FORMAT, defines the log output format. Since this is a well tested module, we set the minimum logging possible. You could also use LOG_LVL_NONE, but I wouldn't recommend it, as if something goes really wrong you have no clue to where to look for.

Now, inside tested_library.c we define the following macros before using any LOG_* function:

#include "tested_library.h"

#define LOG_LEVEL    tested_library_LOG_LEVEL
#define LOG_FORMAT   tested_library_LOG_FORMAT
#include <cfg/log.h>

Ta dah! Here you have your module specific log level and format. Remember to include log.h after you have defined LOG_LEVEL and LOG_FORMAT, otherwise the preprocessor magic can't take place.

Now, we're going to do the same for our untested library. Open library.h and input:

#define library_LOG_LEVEL    LOG_LVL_WARN
#define library_LOG_FORMAT   LOG_FMT_VERBOSE

Then open library.c and input:

#include "library.h"

#define LOG_LEVEL    library_LOG_LEVEL
#define LOG_FORMAT   library_LOG_FORMAT
#include <cfg/log.h>

This time the module is not tested so we use a high log level to quickly find problems.

To test your new logging system, simple define a function in each module like this:

void do_something()
{
        LOG_ERR("library error\n");
        LOG_WARN("library warning\n");
        LOG_INFO("library info\n");
}

and call it in your main program:

#include "buildrev.h"
#include "library.h"
#include "tested_library.h"

#include <cfg/debug.h>
int main(void)
{
        kdbg_init();
        kprintf("Program build: %d\n", VERS_BUILD);
        do_something();
        tested_do_something();
        return ;
}