ulog log

Definition of log : Log is to output the software running status, process and other information to different media (such as files, consoles, display screens, etc.), and then display and save them. It provides a reference for software debugging, problem tracing, performance analysis, system monitoring, fault warning and other functions during maintenance. It can be said that the use of logs occupies at least 80% of the software life cycle.

Importance of logs : For operating systems, due to the complexity of the software, single-step debugging is not suitable in some scenarios, so log components are almost standard on operating systems. A complete log system can also make operating system debugging more efficient.

The origin of ulog : RT-Thread has always lacked a small and practical log component, and the birth of ulog has made up for this shortcoming. It will be open sourced as a basic component of RT-Thread, so that our developers can also use a simple and easy-to-use log system to improve development efficiency.

ulog is a very concise and easy-to-use C/C++ log component. The first letter u stands for μ, which means micro. It can achieve the minimum resource usage of ROM<1K and RAM<0.2K . ulog is not only small in size, but also has very comprehensive functions. Its design concept refers to another C/C++ open source log library: EasyLogger (elog for short), and has made many improvements in functions and performance. The main features are as follows:

  • The backends for log output are diversified and can support backend forms such as serial port, network, file, flash memory, etc.

  • Log output is designed to be thread-safe and supports asynchronous output mode.

  • The log system is highly reliable and can still be used in complex environments such as ISR interrupts and Hardfault.

  • The log supports setting the output level during runtime/compilation.

  • Log content supports global filtering by keywords and tags.

  • API and log format are compatible with Linux syslog.

  • Supports dumping debug data into the log in hex format.

  • Compatible with rtdbg (RTT's early log header file) and EasyLogger's log output API.

The following figure is the ulog log component architecture diagram:

  • Front-end : As the layer closest to the application, this layer provides users with two types of API interfaces: syslog and LOG_X, which are convenient for users to use in different scenarios.

  • Core : The main task of the middle core layer is to format and filter the logs passed from the upper layer according to different configuration requirements and then generate log frames, which are finally output to the bottom-level backend device through different output modules.

  • Backend : After receiving the log frame sent by the core layer, the log is output to the registered log backend device, such as files, consoles, log servers, etc.

The path to configure ulog using menuconfig in the ENV tool is as follows:

 RT-Thread Components → Utilities → Enable ulogcopymistakeCopy Success

The ulog configuration options are described as follows. In general, the default configuration can be used:

[*] Enable ulog                   /* 使能 ulog */
      The static output log level./* 选择静态的日志输出级别。选择完成后,比设定级别低的日志(这里特指使用 LOG_X API 的日志)将不会被编译到 ROM 中 */
[ ]   Enable ISR log.             /* 使能中断 ISR 日志,即在 ISR 中也可以使用日志输出 API */
[*]   Enable assert check.        /* 使能断言检查。关闭后,断言的日志将不会被编译到 ROM 中 */
(128) The log's max width.        /* 日志的最大长度。由于 ulog 的日志 API 按行作为单位,所以这个长度也代表一行日志的最大长度 */
[ ]   Enable async output mode.   /* 使能异步日志输出模式。开启这个模式后,日志不会立刻输出到后端,而是先缓存起来,然后交给日志输出线程(例如:idle 线程)去输出 */
      log format  --->            /* 配置日志的格式,例如:时间信息,颜色信息,线程信息,是否支持浮点等等 */
[*]   Enable console backend.     /* 使能控制台作为后端。使能后日志可以输出到控制台串口上。建议保持开启。 */
[ ]   Enable file backend.        /* ulog 的文件后端 */
[ ]   Enable runtime log filter.  /* 使能运行时的日志过滤器,即动态过滤。使能后,日志将支持按标签、关键词等方式,在系统运行时进行动态过滤。 */
[ ]   Enable syslog format log and API.  /* 启用 syslog 格式日志和 API */copymistakeCopy Success

The log format options are described as follows:

[ ] Enable float number support. It will using more thread stack.   /* 浮点型数字的支持(传统的 rtdbg/rt_kprintf 均不支持浮点数日志) */
[*] Enable color log.                   /* 带颜色的日志 */
[*] Enable time information.            /* 时间信息 */
[ ]   Enable timestamp format for time. /* 包括时间戳 */
[*] Enable level information.           /* 级别信息 */
[*] Enable tag information.             /* 标签信息 */
[ ] Enable thread information.          /* 线程信息 */copymistakeCopy Success

The log level represents the importance of the log. In ulog, there are several log levels from high to low:

level

name

describe

LOG_LVL_ASSERT

assertion

Assertion logs indicating that an unhandled, fatal error has occurred, causing the system to be unable to continue running

LOG_LVL_ERROR

mistake

The logs output when serious and unrecoverable errors occur are error-level logs.

LOG_LVL_WARNING

warn

These warning logs are output when some minor, fixable errors occur.

LOG_LVL_INFO

information

Important prompt information log for upper-level users of this module, such as: initialization success, current working status, etc. This level of log is generally retained during mass production.

LOG_LVL_DBG

debug

Debug log for developers of this module to view. This level of log is usually closed during mass production.

In ulog, the log levels are classified as follows:

  • Static level and dynamic level : Classify logs according to whether they can be modified during the run phase. The dynamic level is the level that can be modified during the run phase, and the static level is the level that can only be modified during the compilation phase . Logs lower than the static level (here specifically logs using the LOG_X API) will not be compiled into the ROM, and will not be output or displayed in the end. The dynamic level can control logs higher than or equal to the static level. When ulog is running, logs lower than the dynamic level will be filtered out.

  • Global level and module level : Classification by scope. In ulog, each file (module) can also set an independent log level. The global level scope is greater than the module level, that is, the module level can only control module logs that are higher than or equal to the global level.

From the above classification, we can see that in ulog, the output level of the log can be set in the following four aspects:

  • Global static log level: configured in menuconfig, corresponding to ULOG_OUTPUT_LVLmacro.

  • Global dynamic log level: void ulog_global_filter_lvl_set(rt_uint32_t level)set using the function.

  • Module static log level: define macros in the module (file) LOG_LVL, similar to the log tag macro LOG_TAGdefinition method.

  • Module dynamic log level: int ulog_tag_lvl_filter_set(const char *tag, rt_uint32_t level)set using function.

Their scopes are as follows: global static > global dynamic > module static > module dynamic .

As the amount of log output continues to increase, in order to avoid the logs being output in a disorderly manner, it is necessary to use tags to classify each log. Tags are defined in a modular way. For example, the Wi-Fi component includes modules such as device driver (wifi_driver) and device management (wifi_mgnt). The internal modules of the Wi-Fi component can use wifi.driver, wifi.mgntetc. as tags to classify the log output.

The tag attributes of each log can also be output and displayed. At the same time, ulog can also set the output level of the log corresponding to each tag (module). The logs of currently unimportant modules can be selectively closed, which not only reduces ROM resources, but also helps developers filter irrelevant logs.

See rt-thread\examples\ulog_example.cthe ulog routine file, at the top of the file there is a definition of LOG_TAGthe macro:

#define LOG_TAG     "example"     // 该模块对应的标签。不定义时,默认:NO_TAG
#define LOG_LVL     LOG_LVL_DBG   // 该模块对应的日志输出级别。不定义时,默认:调试级别
#include <ulog.h>                 // 必须在 LOG_TAG 与 LOG_LVL 下面copymistakeCopy Success

It should be noted that the defined log label must be located #include <ulog.h>above , otherwise the default one will be used NO_TAG(it is not recommended to define these macros in header files).

The scope of the log tag is the current source code file, and the project source code is usually classified by module. Therefore, when defining a tag, you can specify the module name or submodule name as the tag name, which is not only clear and intuitive when displaying the log output, but also convenient for dynamic adjustment of levels or filtering by tags in the future.

int ulog_init(void)copymistakeCopy Success

return

describe

>=0

success

-5

Failed, out of memory

Before using ulog, you must call this function to complete ulog initialization. If component automatic initialization is turned on, this function will also be called automatically.

void ulog_deinit(void)copymistakeCopy Success

When ulog is no longer used, you can execute deinit to release resources.

ulog has two main log output macro APIs, which are defined in the source code as follows:

#define LOG_E(...)                           ulog_e(LOG_TAG, __VA_ARGS__)
#define LOG_W(...)                           ulog_w(LOG_TAG, __VA_ARGS__)
#define LOG_I(...)                           ulog_i(LOG_TAG, __VA_ARGS__)
#define LOG_D(...)                           ulog_d(LOG_TAG, __VA_ARGS__)
#define LOG_RAW(...)                         ulog_raw(__VA_ARGS__)
#define LOG_HEX(name, width, buf, size)      ulog_hex(name, width, buf, size)copymistakeCopy Success
  • Macro LOG_X(...): XThe first letter of the corresponding level is capitalized. The parameter ...is the log content, and the format is the same as printf. This method is the first choice, because its API format is simple, there is only one input parameter, which is the log information, and it also supports filtering by module static log level.

  • Macro ulog_x(LOG_TAG, __VA_ARGS__): xcorresponds to the abbreviations of different levels. Parameter LOG_TAGis the log tag, parameter ...is the log content, and the format is consistent with printf. This API is suitable for using different tags to output logs in a file.

API

describe

LOG_E(...)

Error level log

LOG_W(...)

Warning level log

LOG_I(...)

Prompt level log

LOG_D(...)

Debug level log

LOG_RAW(...)

Output raw log

LOG_HEX(name, width, buf, size)

Output hexadecimal format data to the log

LOG_XThe output of ulog_xthese APIs are all formatted logs. Sometimes when you need to output logs without any format, you can use LOG_RAW or ulog_raw(). For example:

LOG_RAW("\r");
ulog_raw("\033[2A");copymistakeCopy Success

To dump data to the log in hexadecimal format, you can use LOG_HEX() or ulog_hex. The function parameters and descriptions are as follows:

parameter

describe

tag

Log Tags

width

The width of a line of hex content (number)

buf

Data content to be output

size

Data size

The hexdump log is at the DEBUG level and supports level filtering during runtime. The tag corresponding to the hexdump log supports tag filtering during runtime.

ulog also provides an assertion API: ASSERT(表达式)When an assertion is triggered, the system will stop running, the internal execution will also be executed ulog_flush(), and all log backends will execute flush. If asynchronous mode is turned on, all logs in the buffer will also be flushed. The following is an example of the use of assertions:

void show_string(const char *str)
{
    ASSERT(str);
    ...
}copymistakeCopy Success

The following will introduce the ulog routine. When you open it, rt-thread\examples\ulog_example.cyou can see that there are labels and static priorities defining the file at the top.

#define LOG_TAG              "example"
#define LOG_LVL              LOG_LVL_DBG
#include <ulog.h>copymistakeCopy Success

void ulog_example(void)The API is used in the function , LOG_Xas follows:

/* output different level log by LOG_X API */
LOG_D("LOG_D(%d): RT-Thread is an open source IoT operating system from China.", count);
LOG_I("LOG_I(%d): RT-Thread is an open source IoT operating system from China.", count);
LOG_W("LOG_W(%d): RT-Thread is an open source IoT operating system from China.", count);
LOG_E("LOG_E(%d): RT-Thread is an open source IoT operating system from China.", count);copymistakeCopy Success

These log output APIs all support the printf format and will automatically wrap at the end of the log.

The following will show the running effect of the ulog routine on qemu:

  • Copy rt-thread\examples\ulog_example.cto rt-thread\bsp\qemu-vexpress-a9\applicationsthe folder

  • rt-thread\bsp\qemu-vexpress-a9Enter the directory in Env

  • After confirming that ulog configuration has been executed before, execute sconsthe command and wait for the compilation to complete

  • Run qemu.batto open RT-Thread's qemu emulator

  • Enter ulog_examplethe command to see the results of the ulog routine. The general effect is as follows

You can see that each log is displayed in lines, and different levels of logs have different colors. At the beginning of the log, there is a tick of the current system, in the middle there are log levels and tags, and at the end there are specific log contents. These log formats and configuration instructions will also be introduced in detail later in this article.

In many cases, it is necessary to output logs in an interrupt ISR, but interrupting the ISR may interrupt the thread that is currently outputting logs. To ensure that the interrupt log and thread log do not interfere with each other, special processing must be performed for the interrupt situation.

Ulog has integrated the interrupt log function, but it is not enabled by default. Enable ISR logYou can turn on the option when using it. The log API is the same as that used in the thread, for example:

#define LOG_TAG              "driver.timer"
#define LOG_LVL              LOG_LVL_DBG
#include <ulog.h>

void Timer2_Handler(void)
{
    /* enter interrupt */
    rt_interrupt_enter();

    LOG_D("I'm in timer2 ISR");

    /* leave interrupt */
    rt_interrupt_leave();
}
copymistakeCopy Success

Here are the different strategies for interrupt logging when ulog is in synchronous mode and asynchronous mode:

In synchronous mode : If a thread is interrupted while outputting logs, and if there are logs to be output in the interrupt, they will be output directly to the console. Output to other backends is not supported.

In asynchronous mode : If the above situation occurs, the logs in the interrupt will be put into the buffer first, and finally handed over to the log output thread for processing together with the thread logs.

The log formats supported by ulog can be configured in menuconfig, located at RT-Thread ComponentsUtilitiesuloglog format. The specific configuration is as follows:

You can configure: floating point number support (traditional rtdbg/rt_kprintf do not support floating point number logs), colored logs, time information (including timestamps), level information, tag information, and thread information. Below we select all these options , save and recompile, and run the ulog routine again in qemu to see the actual effect:

It can be seen that compared with the first run of the routine, the time information has changed from the system tick value to the timestamp information, and the thread information has also been output.

Hexdump is also a commonly used function for log output. Through hexdump, a piece of data can be output in hex format. The corresponding API is: void ulog_hexdump(const char *tag, rt_size_t width, rt_uint8_t *buf, rt_size_t size). Let's take a look at the specific usage and operation effect:

/* 定义一个 128 个字节长度的数组 */
uint8_t i, buf[128];
/* 在数组内填充上数字 */
for (i = 0; i < sizeof(buf); i++)
{
    buf[i] = i;
}
/* 以 hex 格式 dump 数组内的数据,宽度为 16 */
ulog_hexdump("buf_dump_test", 16, buf, sizeof(buf));copymistakeCopy Success

You can copy the above code into the ulog routine and run it, and then look at the actual running results:

It can be seen that the middle part is the hexadecimal information of the buf data, and the rightmost part is the character information corresponding to each data.

After understanding the introduction of logs in the previous section, the basic functions of ulog can be mastered. In order to let everyone play ulog better, this application note will focus on introducing ulog's advanced functions and some log debugging experience and skills. After learning these advanced uses, developers can also greatly improve the efficiency of log debugging.

At the same time, we will also introduce the advanced mode of ulog: syslog mode. This mode can achieve full compatibility with Linux syslog from front-end API to log format, which greatly facilitates the migration of software from Linux.

Speaking of the backend, let's review the framework diagram of ulog. From the above figure, we can see that ulog adopts a design that separates the front-end and back-end, and the front-end and back-end have no dependencies. And it supports a variety of backends. No matter what kind of backend, as long as it is implemented, it can be registered.

Currently, ulog has integrated the console backend, which is the traditional rt_kprintfdevice for outputting and printing logs. ulog also supports the Flash backend, which is seamlessly integrated with EasyFlash. For details, please refer to its software package ( click to view ). In the future, ulog will also add the implementation of file backend, network backend and other backends. Of course, if there are special needs, users can also implement the backend themselves.

Registering backend devices

rt_err_t ulog_backend_register(ulog_backend_t backend, const char *name, rt_bool_t support_color)copymistakeCopy Success

parameter

describe

backend

The backend device handle to register

name

Backend device name

support_color

Whether to support color log

return

--

>=0

success

This function is used to register the backend device into ulog. Before registration, make sure the function members in the backend device structure have been set.

Deregistering a backend device

rt_err_t ulog_backend_unregister(ulog_backend_t backend);copymistakeCopy Success

parameter

describe

backend

The backend device handle to be deregistered

return

--

>=0

success

This function is used to unregister a registered backend device.

Backend implementation and registration example

The following takes the console backend as an example to briefly introduce the implementation and registration methods of the backend.

Open rt-thread/components/utilities/ulog/backend/console_be.cthe file and you can see the following contents:

#include <rthw.h>
#include <ulog.h>

/* 定义控制台后端设备 */
static struct ulog_backend console;
/* 控制台后端输出函数 */
void ulog_console_backend_output(struct ulog_backend *backend, rt_uint32_t level, const char *tag, rt_bool_t is_raw, const char *log, size_t len)
{
    ...
    /* 输出日志到控制台 */
    ...
}
/* 控制台后端初始化 */
int ulog_console_backend_init(void)
{
    /* 设定输出函数 */
    console.output = ulog_console_backend_output;
    /* 注册后端 */
    ulog_backend_register(&console, "console", RT_TRUE);

    return 0;
}
INIT_COMPONENT_EXPORT(ulog_console_backend_init);copymistakeCopy Success

From the above code, we can see that the implementation of the console backend is very simple. outputThe function of the backend device is implemented here, and the backend is registered in ulog. After that, the ulog log will be output to the console.

If you want to implement a more complex backend device, you need to understand the backend device structure, as follows:

struct ulog_backend
{
    char name[RT_NAME_MAX];
    rt_bool_t support_color;
    void (*init)  (struct ulog_backend *backend);
    void (*output)(struct ulog_backend *backend, rt_uint32_t level, const char *tag, rt_bool_t is_raw, const char *log, size_t len);
    void (*flush) (struct ulog_backend *backend);
    void (*deinit)(struct ulog_backend *backend);
    rt_slist_t list;
};copymistakeCopy Success

From the perspective of this structure, the requirements for implementing backend devices are as follows:

  • nameAnd support_colorproperties can ulog_backend_registerbe passed in during registration via the function.

  • outputThis is the specific output function of the backend. All backends must implement the interface.

  • init/ deinitOptional implementation, init will be called during register, deinit will be called during ulog_deinit.

  • flushIt is also optional to implement. Some backends with internal output cache must implement this interface. For example, some file systems with RAM cache. The backend flush is usually ulog_flushcalled by in abnormal situations such as assertion and hardfault.

File backend registration example

The following code will implement an example of a file backend implementation, saving the output log to the file system path /flash/log.

https://club.rt-thread.org/ask/article/73cedec4f1707abf.html

#include <ulog_be.h>

/*
* 后端注册表
*/
struct _log_file
{
    const char *name;                 //文件名
    ulog_backend_t backend;            
    struct ulog_file_be *file_be;
    const char *dir_path;             //保存路径
    rt_size_t max_num;                //保存最大文件数量
    rt_size_t max_size;                //保存最大文件大小
    rt_size_t buf_size;                //文件保存缓存大小
};
/*
* 文件后端标识
*/
typedef enum 
{
    console_id,
    sys_id,
    motion_id,
}ulog_file_be_name;

#define ROOT_PATH "/flash/log" //设置保存路径
#define FILE_SIZE 512 * 1024   //设置单个文件大小
#define BUFF_SIZE 512           //设备缓存区大小

static struct ulog_backend sys_log_backend;
static struct ulog_file_be sys_log_file;

static struct _log_file table[] =
{
    {"sys"      ,&sys_log_backend,&sys_log_file,ROOT_PATH,10,FILE_SIZE,BUFF_SIZE},
};
/* Private function prototypes -----------------------------------------------*/
/**
  * @brief  系统日志文件后端初始化.
  * @param  None.
  * @retval None.
  * @note   None.
*/
void sys_log_file_backend_init(void)
{
    struct ulog_file_be *file_be = &sys_log_file;
    uint8_t id = sys_id;
    file_be->parent = sys_log_backend;

    ulog_file_backend_init( file_be, 
                            table[id].name,
                            table[id].dir_path,
                            table[id].max_num,
                            table[id].max_size,
                            table[id].buf_size);

    ulog_file_backend_enable(file_be); //必须使能才能有效
}copymistakeCopy Success

Add the following code to implement the file backend filtering function.

/**
  * @brief  系统日志文件后端滤波器设置.
  * @param  None.
  * @retval The filter will be call before output. It will return TRUE when the filter condition is math.
  * @note   None.
*/
static rt_bool_t sys_log_file_backend_filter(struct ulog_backend *backend, rt_uint32_t level, const char *tag, rt_bool_t is_raw, 
                                      const char *log, rt_size_t len)
{
    //设置滤波规则,可以自己编写代码实现不同滤波规则
    if (rt_strncmp(tag,"MOVE", sizeof(MOTION_TAG)) == 0)//排除带有"MOVE"标签输出
      return RT_FALSE;
    else
      return RT_TRUE;

    //if (rt_strncmp(tag,"MOVE", sizeof(MOTION_TAG)) == 0)//带有"MOVE"标签输出
    //  return RT_TRUE;
    //else
    //  return RT_FALSE;
}

void sys_log_file_backend_init(void)
{
    //新增代码
    ulog_backend_filter_t filter = sys_log_file_backend_filter;

    ...

    ulog_file_backend_enable(file_be);
    //新增代码
    ulog_backend_set_filter(&file_be->parent,filter);
}copymistakeCopy Success

In ulog, the default output mode is synchronous mode, and users may also need asynchronous mode in many scenarios. When users call the log output API, the logs will be cached in the buffer, and a thread dedicated to log output will take out the logs and output them to the backend.

For users, there is no difference in the use of log API between asynchronous mode and synchronous mode, because ulog will be different in the underlying processing. The difference in the working principle of the two is roughly shown in the following figure:

The advantages and disadvantages of asynchronous mode are as follows:

advantage :

  • First of all, the current thread will not be blocked when the log is output. In addition, the output rate of some backends is low, so using the synchronous output mode may affect the timing of the current thread. The asynchronous mode does not have this problem.

  • Secondly, since each thread that uses the log omits the backend output action, the stack overhead of these threads may also be reduced, which can also reduce the resource usage of the entire system from this perspective.

  • In synchronous mode, interrupt logs can only be output to the console backend, while in asynchronous mode, interrupt logs can be output to all backends.

Disadvantages : First, the asynchronous mode requires a log buffer. Second, the output of asynchronous logs also requires a dedicated thread to complete, such as an idle thread or a user-defined thread, which is slightly complicated to use. Overall, the asynchronous mode uses more resources than the synchronous mode.

Configuration options

Use menuconfig in the ENV tool to enter the ulog configuration options:

 RT-Thread Components → Utilities → Enable ulogcopymistakeCopy Success

The description of the configuration options related to asynchronous mode is as follows:

[*]   Enable async output mode.                 /* 使能异步模式 */
(2048)  The async output buffer size.           /* 异步缓冲区大小,默认为 2048*/
[*]     Enable async output by thread.          /* 是否启用 ulog 里异步日志输出线程,该线程运行时将会等待日志通知,然后输出日志到所有的后端。该选项默认开启,如果想要修改为其他线程,例如:idle 线程,可关闭此选项。 */
(1024)    The async output thread stack size.   /* 异步输出线程的堆栈大小,默认为 1024 */
(30)      The async output thread stack priority./* 异步输出线程的优先级,默认为 30*/copymistakeCopy Success

When using idle thread output, the implementation is very simple and only requires calling at the application layer rt_thread_idle_sethook(ulog_async_output), but there are some limitations.

  • The idle thread stack size needs to be adjusted according to the actual backend usage.

  • Since thread suspension operations are not allowed inside an idle thread, backends such as Flash and network may not be used based on idle threads.

Usage Examples

Save the asynchronous output option configuration and rt-thread\examples\ulog_example.ccopy to rt-thread\bsp\qemu-vexpress-a9\applicationsthe folder.

Execute sconsthe command and wait for the compilation to complete. Run qemu.batto open the qemu simulator of RT-Thread. Enter ulog_examplethe command to see the running result of the ulog routine. The general effect is as follows:

If you observe carefully, you can find that after the asynchronous mode is turned on, the time information of these logs that are very close in code is almost the same. However, in the synchronous mode, the logs are output using user threads. Since log output takes a certain amount of time, there will be a certain interval between each log. This also fully demonstrates that the output efficiency of asynchronous logs is very high and it hardly takes up the caller's time.

In the previous section, we introduced some static filtering functions of logs. Static filtering has its advantages, such as saving resources, but in many cases, users need to dynamically adjust the filtering method of logs when the software is running, which can use the dynamic filter function of ulog. To use the dynamic filter function, you need to turn on Enable runtime log filter.the option in menuconfig, which is turned off by default .

Ulog supports the following four dynamic filtering methods, and each has a corresponding API function and Finsh/MSH command, which will be introduced one by one below.

Filter by module level

int ulog_tag_lvl_filter_set(const char *tag, rt_uint32_t level)copymistakeCopy Success

parameter

describe

tag

Log Tags

level

Set the log level

return

--

>=0

success

-5

Failed, not enough memory

  • Command format:ulog_tag_lvl <tag> <level>

The module here refers to a class of log codes with the same tag attributes. Sometimes you need to dynamically modify the log output level of a module at runtime.

The log level parameter can take the following values:

level

name

Value

LOG_LVL_ASSERT

assertion

0

LOG_LVL_ERROR

mistake

3

LOG_LVL_WARNING

warn

4

LOG_LVL_INFO

information

6

LOG_LVL_DBG

debug

7

LOG_FILTER_LVL_SILENT

Silence (stop output)

0

LOG_FILTER_LVL_ALL

all

7

Function call and command examples are as follows:

Function

Function Call

Execute Command

Close wifiall module logs

ulog_tag_lvl_filter_set("wifi", LOG_FILTER_LVL_SILENT);

ulog_tag_lvl wifi 0

Enable wifiall module logs

ulog_tag_lvl_filter_set("wifi", LOG_FILTER_LVL_ALL);

ulog_tag_lvl wifi 7

Set wifithe module log level to warning

ulog_tag_lvl_filter_set("wifi", LOG_LVL_WARNING);

ulog_tag_lvl wifi 4

Global filter by tag

void ulog_global_filter_tag_set(const char *tag)copymistakeCopy Success

parameter

describe

tag

Set filter tags

  • Command format: ulog_tag [tag], when tag is empty, tag filtering is canceled.

This filtering method can filter all logs by tag, and only logs containing tag information are allowed to be output.

For example, there are three types of log tags: wifi.driver, , wifi.mgntand . When the filter tag is set to , only logs with tags and will be output. Similarly, when the filter tag is set to , only logs with tags and will be output. The function calls and command examples corresponding to common functions are as follows:audio.driverwifiwifi.driverwifi.mgntdriverwifi.driveraudio.driver

Function

Function Call

Execute Command

Set the filter tag towifi

ulog_global_filter_tag_set("wifi");

ulog_tag wifi

Set the filter tag to driver

ulog_global_filter_tag_set("driver");

ulog_tag driver

Uncheck tag filtering

ulog_global_filter_tag_set("");

ulog_tag

Global filtering by level

void ulog_global_filter_lvl_set(rt_uint32_t level)copymistakeCopy Success

parameter

describe

level

Set the log level

  • Command format: ulog_lvl <level>, level values ​​refer to the following table:

Value

describe

0

assertion

3

mistake

4

warn

6

information

7

debug

After setting the global filtering level through functions or commands, logs below the set level will stop being output. The function calls and command examples corresponding to common functions are as follows:

Function

Function Call

Execute Command

Close all logs

ulog_global_filter_lvl_set(LOG_FILTER_LVL_SILENT);

ulog_lvl 0

Enable all logs

ulog_global_filter_lvl_set(LOG_FILTER_LVL_ALL);

ulog_lvl 7

Set the log level to warning

ulog_global_filter_lvl_set(LOG_LVL_WARNING);

ulog_lvl 4

Global filter by keyword

void ulog_global_filter_kw_set(const char *keyword)copymistakeCopy Success

parameter

describe

keyword

Set filter keywords

  • Command format: ulog_kw [keyword], when keyword is empty, keyword filtering will be canceled.

This filtering method can filter all logs by keywords, and only logs containing keyword information are allowed to be output. The function calls and command examples corresponding to common functions are as follows:

Function

Function Call

Execute Command

Set the filter keyword towifi

ulog_global_filter_kw_set("wifi");

ulog_kw wifi

Clear filter keywords

ulog_global_filter_kw_set("");

ulog_kw

View filter information

After setting the filter parameters, if you want to view the current filter information, you can enter ulog_filterthe command, the general effect is as follows:

msh />ulog_filter
--------------------------------------
ulog global filter:
level   : Debug
tag     : NULL
keyword : NULL
--------------------------------------
ulog tag's level filter:
wifi                   : Warning
audio.driver           : Error
msh />copymistakeCopy Success

Tip: Filter parameters can also be saved in Flash and automatically loaded when the system is powered on. If this function is required, please refer to the instructions for the ulog_easyflash software package. ( Click to view )

Usage Examples

Still executed in qemu BSP, first turn on dynamic filtering in menuconfig, then save the configuration and compile and run the routine. After the log is output about 20 times, the corresponding filtering code in ulog_example.c will be executed:

if (count == 20)
{
    /* Set the global filer level is INFO. All of DEBUG log will stop output */
    ulog_global_filter_lvl_set(LOG_LVL_INFO);
    /* Set the test tag's level filter's level is ERROR. The DEBUG, INFO, WARNING log will stop output. */
    ulog_tag_lvl_filter_set("test", LOG_LVL_ERROR);
}
...copymistakeCopy Success

At this time, the global filtering level is set to INFO, so logs lower than INFO level can no longer be seen. At the same time, testthe log output level of the tag is set to ERROR, and testthe logs lower than ERROR in the tag are also stopped from being output. In each log, there is a count value of the current log output times, and the comparison effect is as follows:

After the log is output about 30 times, the corresponding filtering code in ulog_example.c will be executed:

...
else if (count == 30)
{
    /* Set the example tag's level filter's level is LOG_FILTER_LVL_SILENT, the log enter silent mode. */
    ulog_tag_lvl_filter_set("example", LOG_FILTER_LVL_SILENT);
    /* Set the test tag's level filter's level is WARNING. The DEBUG, INFO log will stop output. */
    ulog_tag_lvl_filter_set("test", LOG_LVL_WARNING);
}
...copymistakeCopy Success

exampleAt this time , a filter for the module is added , and all logs of this module are stopped from being output, so the logs of this module will not be seen next. At the same time, testthe log output level of the tag is reduced to WARING, so only testthe WARING and ERROR level logs of the tag can be seen. The effect is as follows:

After the log is output about 40 times, the corresponding filtering code in ulog_example.c will be executed:

...
else if (count == 40)
{
    /* Set the test tag's level filter's level is LOG_FILTER_LVL_ALL. All level log will resume output. */
    ulog_tag_lvl_filter_set("test", LOG_FILTER_LVL_ALL);
    /* Set the global filer level is LOG_FILTER_LVL_ALL. All level log will resume output */
    ulog_global_filter_lvl_set(LOG_FILTER_LVL_ALL);
}copymistakeCopy Success

At this time, testthe log output level of the module is adjusted to LOG_FILTER_LVL_ALL, that is, no logs of any level of the module will be filtered. At the same time, the global filtering level is set to LOG_FILTER_LVL_ALL, so testall logs of the module will resume output. The effect is as follows:

Since ulog's asynchronous mode has a cache mechanism, the registered backend may also have a cache. If the system encounters hardfault, assertion or other errors, but there are logs in the cache that have not been output, this may cause log loss, and it will be difficult to find the cause of the exception.

For this scenario, ulog provides a unified log flush function: void ulog_flush(void), when an exception occurs, when the exception information log is output, calling this function at the same time can ensure that the remaining logs in the cache can also be output to the backend.

The following example uses RT-Thread assertions and CmBacktrace:

assertion

RT-Thread's assertion supports assertion callbacks (hooks). We define an assertion hook function similar to the following, and then rt_assert_set_hook(rtt_user_assert_hook);set it to the system through the function.

static void rtt_user_assert_hook(const char* ex, const char* func, rt_size_t line)
{
    rt_enter_critical();

    ulog_output(LOG_LVL_ASSERT, "rtt", RT_TRUE, "(%s) has assert failed at %s:%ld.", ex, func, line);
    /* flush all log */
    ulog_flush();
    while(1);
}copymistakeCopy Success

CmBacktrace

CmBacktrace is an error diagnosis library for ARM Cortex-M series MCUs. It also has a corresponding RT-Thread software package, and the latest version of the software package has been adapted for ulog. The adaptation code is located at cmb_cfg.h:

...
/* print line, must config by user */
#include <rtthread.h>
#ifndef RT_USING_ULOG
#define cmb_println(...)               rt_kprintf(__VA_ARGS__);rt_kprintf("\r\n")
#else
#include <ulog.h>
#define cmb_println(...)               ulog_e("cmb", __VA_ARGS__);ulog_flush()
#endif /* RT_USING_ULOG */
...copymistakeCopy Success

From this we can see that when ulog is enabled, each log output of CmBacktrace will use the error level and will be executed at the same time ulog_flush, and the user does not need to make any modifications.

On Unix-like operating systems, syslog is widely used for system logs. Common backends for syslog include files and networks. Syslog logs can be recorded in local files or sent to a syslog receiving server over the network.

ulog provides support for syslog mode. Not only is the front-end API completely consistent with the syslog API, but the log format also complies with the RFC standard. However, it should be noted that after turning on the syslog mode, no matter which log output API is used, the entire ulog log output format will use the syslog format.

Using syslog configuration requires turning on Enable syslog format log and API.the option.

Log Format

As shown in the figure above, the ulog syslog log format is divided into the following 4 parts:

Format

describe

PRI

The PRI part consists of a number enclosed in angle brackets. This number contains the program module (Facility) and severity (Severity) information. It is obtained by multiplying Facility by 8 and then adding Severity. Facility and Severity are passed in by the input parameters of the syslog function. For specific values, see syslog.h

Header

The header part is mainly a timestamp, indicating the time of the current log;

TAG

The label of the current log can be passed in through the openlog function. If not specified, rtt will be used as the default label

Content

Specific content of the log

How to use

Before use, you need to enable the syslog option in menuconfig. The main commonly used APIs are:

  • Open syslog: void openlog(const char *ident, int option, int facility)

  • Output syslog log: void syslog(int priority, const char *format, ...)

Tip: Calling openlog is optional. If you do not call openlog, it will be called automatically the first time syslog is called.

The usage of syslog() function is also very simple, and its input parameter format is the same as printf function. There is also a syslog routine in ulog_example.c, and the running effect in qemu is as follows:

If these two types of log components were used in the project before, when ulog is used, it will involve how to make the previous code support ulog. The following will focus on the migration process.

Migrate from rt_dbg.h

Currently, rtdbg has been seamlessly connected to ulog. After enabling ulog, the code using rtdbg in the old project can be used to complete log output using ulog without any modification.

Migrate from elog (EasyLogger)

If you cannot confirm that a source code file will use ulog on the target platform, it is recommended to add the following changes to the file:

#ifdef RT_USING_ULOG
#include <ulog.h>
#else
#include <elog.h>
#endif /* RT_USING_ULOG */copymistakeCopy Success

If you know that you will only use the ulog component, you only need to elog.hchange the header file reference from to ulog .h, and no other code needs to be changed.

With log tools, if they are used improperly, they may be abused and the log information may not highlight the key points. Here, we will share with you some tips on how to use log components to make log information more intuitive. The main points of concern are:

Reasonable use of label classification

Reasonable use of the tag function, each module code before using the log, first clarify the module, sub-module name. This can also make the log classification in the very beginning stage, also ready for the later log filtering.

Proper use of log levels

When you first start using the log library, you will often encounter problems such as being unable to distinguish between warning and error logs, and between information and debug logs, which leads to inappropriate log level selection. Some important logs may not be visible, and unimportant logs are everywhere. Therefore, be sure to read the log level section carefully before use, as there are clear standards for each level.

Avoid redundant logging

In some cases, the code may be called repeatedly or executed in a loop, and the same or similar logs may be output multiple times. Such logs will not only take up a lot of system resources, but also affect the developers' ability to locate the problem. Therefore, when encountering such a situation, it is recommended to add special processing for repetitive logs, such as: let the upper layer output some business-related logs, and the bottom layer only returns the specific result status; can the same logs at the same time point be deduplicated, and only output once when the error status does not change, etc.

Enable more log formats

The default log format of ulog does not have timestamp and thread information enabled. These two log information are very useful on RTOS. They can help developers intuitively understand the running time and time difference of each log, and clearly see which thread is executing the current code. So if conditions permit, it is recommended to enable them.

Disable unimportant logs

Ulog provides multiple dimensions of log switching and filtering functions, which can fully achieve fine-grained control. Therefore, if you are debugging a certain functional module, you can appropriately turn off the log output of other irrelevant modules, so that you can focus on the currently debugged module.

Q: The logging code has been executed, but there is no output.

A: Refer to the Log Level section to understand the log level classification and check the log filter parameters. Another possibility is that the console backend was accidentally closed. Just reopen it Enable console backend.

Q: After turning on ulog, the system crashes, for example: thread stack overflow.

A: ulog will occupy more thread stack space than rtdbg or print output function used before rt_kprintf. If floating point printing support is enabled, it is recommended to reserve 250 bytes more stack space because of the increased resource usage of libc vsnprintf. If the timestamp function is enabled, it is recommended to reserve 100 bytes more stack space.

Q: The end of the log content is missing.

A: This is because the log content exceeds the maximum width of the log. Check The log's max widththe option and increase it to an appropriate size.

Q: Why can't I see millisecond time after turning on timestamp?

A: This is because ulog currently only supports displaying millisecond timestamps when software emulation RTC is enabled. If you need to display it, just enable the RT-Thread software emulation RTC function.

Q: Every time before including the ulog header file, LOG_TAG and LOG_LVL must be defined. Can it be simplified?

A: LOG_TAG If not defined, the label will be used by default NO_TAG, which can easily cause misunderstandings in the output logs. Therefore, it is not recommended to omit the label macro.

LOG_LVLIf not defined, the debug level will be used by default. If the module is in the development stage, this process can be omitted. However, if the module code is already stable, it is recommended to define this macro and change the level to the information level.

Q: A warning message appears during operation: Warning: There is no enough buffer for saving async log, please increase the ULOG_ASYNC_OUTPUT_BUF_SIZE option.

A: When you encounter this prompt, it means that the buffer overflows in asynchronous mode, which will cause some logs to be lost. Increasing the ULOG_ASYNC_OUTPUT_BUF_SIZE option can solve this problem.

Q: Compilation time prompt: The idle thread stack size must be more than 384 when using async output by idle (ULOG_ASYNC_OUTPUT_BY_IDLE).

A: When using the idle thread as the output thread, the stack size of the idle thread needs to be increased. This also depends on the specific backend device. For example, when using the console backend, the idle thread must be at least 384 bytes.

Last updated

Assoc. Prof. Wiroon Sriborrirux, Founder of Advance Innovation Center (AIC) and Bangsaen Design House (BDH), Electrical Engineering Department, Faculty of Engineering, Burapha University