蜗窝科技

小printf大作用(用日志打印的方式调试程序)

wowo · · 软件开发 · 阅读 26923 · 2014年1月存档

前言

一般来说,初学编程者所写的第一个程序,就是使用printf打印“Hello world”。其实printf的功效远不只这些,在程序调试方面,printf也有非常大的用处。

“蜗蜗”在接触Linux driver开发之前,学习过桌面程序开发(如Turbo C、Visual C等),也从事了一段时间的嵌入式软件开发。这些开发有一个共同点,对调试工具非常依赖,如桌面程序的Debugger(调试器)、嵌入式开发的仿真器(JTAG等)。还依稀记得,刚工作时,为了插空使用仿真器,不得不趁周末别人不工作时加班使用。直到后来从事Linux driver开发、见识到了printk的魅力之后,多年来,就再也没有使用过仿真器或者调试器了。

下面我就总结一下使用日志打印辅助debug的心得。

日志打印的注意事项

在编写程序后,我们可以随手在需要的地方加入打印信息,同时需要考虑如下事项:

  1. 日志输出是有代价的,特别是在嵌入式系统,或者对执行时序要求较高的应用场景。因此

a) 只有在需要的地方加入,不能滥用

b) 一定要有一个全局的开关,在不需要或者产品发布的时候,关闭输出,或者降低日志输出的频率

  1. 日志输出需要有优先级控制,例如:发生错误时的日志优先级最高,一般都要输出;一些重要的提示,优先级中等,可能会在debug版的软件中打开;一些不重要的提示,可能只会在需要的时候(例如跟踪bug)打开

  2. 不要直接使用printf(或者printk)。日志输出的目标是多样的,例如通过printf输出到屏幕、通过串口输出到串口调试助手、通过文件操作写入到文件等等。要通过重定义的方式,将所有的日志输出指令定义到合适的输出路径,当需要修改输出路径的时候,只要修改重定义的部分即可。否则需要在整个代码中修改,就麻烦了

  3. 最好为每个软件模块提供单独的日志输出开关,以增加调试的灵活性

  4. 很多时候,日志输出语句,可以部分代替代码注释的功能

日志打印的实现

结合上面的注意事项,我们可以按照如下步骤实现一个小型的日志输出系统。

Step1. 新建debug.h(如果只是在PC上使用printf,则只需要一个头文件即可。如果有需要文件或者串口操作,可以在这个基础上增加debug.c,这里暂时不再描述)

Step2. 定义一个宏开关,用于控制日志输出的开关

/*

 * debug control, you can switch on (delete 'x' suffix)

 * to enable log output and assert mechanism

 */

#define CONFIG_ENABLE_DEBUG

Step3. 定义ERR、INFO、DEBUG三个日志级别

/*

 * debug level,

 * if is DEBUG_LEVEL_DISABLE, no log is allowed output,

 * if is DEBUG_LEVEL_ERR, only ERR is allowed output,

 * if is DEBUG_LEVEL_INFO, ERR and INFO are allowed output,

 * if is DEBUG_LEVEL_DEBUG, all log are allowed output,

 */

enum debug_level {

    DEBUG_LEVEL_DISABLE = 0,

    DEBUG_LEVEL_ERR,

    DEBUG_LEVEL_INFO,

    DEBUG_LEVEL_DEBUG

};

Step4. 如果使用系统的printf,需要包含stdio.h,并将printf重定义为PRINT(无论是Windows还是Linux,皆是如此,如果是嵌入式平台,可以自定义PRINT接口)

/* it can be change to others, such as file operations */

#include <stdio.h>

#define PRINT               printf

Step5. 定义一个宏,用于定义日志输出级别

/*

 * the macro to set debug level, you should call it

 * once in the files you need use debug system

 */

#define DEBUG_SET_LEVEL(x)  static int debug = x

需要在每一个需要日志输出的C文件中调用,如下:

/*

 * define the debug level of this file,

 * please see 'debug.h' for detail info

 */

DEBUG_SET_LEVEL(DEBUG_LEVEL_ERR);

Step6. 定义ASSERT、ERR、INFO、DEBUG等宏

#define ASSERT()                                        \

do {                                                    \

    PRINT("ASSERT: %s %s %d",                           \

           __FILE__, __FUNCTION__, __LINE__);           \

    while (1);                                          \

} while (0)

 

#define ERR(...)                                        \

do {                                                    \

    if (debug >= DEBUG_LEVEL_ERR) {                     \

        PRINT(__VA_ARGS__);                             \

    }                                                   \

} while (0)

 

…

Step7. 在需要日志输出的C文件中,包含debug.h,并定义所需的日志级别。就可以在需要的时候输出日志信息了

debug_test.c

-----------------------------------------------------

#include "debug.h"

 

/*

 * define the debug level of this file,

 * please see 'debug.h' for detail info

 */

DEBUG_SET_LEVEL(DEBUG_LEVEL_ERR);

 

int main(void) {

    ERR("This is a error message\n");

    INFO("This is a info message\n");

    DEBUG("This is a debug message\n");

 

    ASSERT();

return 0;

}

Step8. 可以根据需要,修改容许输出的日志级别

以上所有的源代码和测试代码都可以在下面获取:

       https://github.com/wowotech/wowolib/tree/master/debug

原创文章,转发请注明出处。蜗窝科技,www.wowotech.net。

标签:日志打印printfdebug调试

继续讨论

新讨论请用 GitHub 账号在下方发言——评论会保存在本仓库的 Discussions 里,与站点同寿; 再下方的「历史评论」是原站的只读存档。

评论(6 条,只读存档)

以下为原站的历史评论(只读存档);继续讨论请用上方的评论区。

  • 我欲乘风归去

    日志提供单独的模块控制输出接口很重要啊。 我理解日志应该是一个全局接口,但是每个模块可以加上自己的tag比较好,这样控制输出的时候,可以通过配置的方式启用某些模块的输出。在系统大了以后非常有用。
    • wowo

      @我欲乘风归去:你说的很对,所以Linux Kernel的日志管理系统(Dynamic Debug)就相当复杂了,只有那样,才可以很方便的debug。我这边文章只是一个例子。
  • anchen

    我这里有一个问题想请教,是关于fprintf(),因为想把输出重定向(写入)到一块存储区域,等后面需要的时候把他们读出来。我找到相关的类似代码,如下: typedef struct bufferInfo_t { void (*print_function)(void *context, char toprint); .. } bufferInfo; uint32 init_log_buffer(FILE *buffInfo, void *location, uint32 size); void buffer_putchar(void *port, char toprint); bufferInfo _LOG0; FILE *LOG0=(FILE *)&_LOG0; init_log_buffer(LOG0, (void *) Buffer_Address, Buffer_Size); fprintf(LOG0, "hello\n"); 就是不能理解,这里调用fprintf的时候,怎么就实际调用了buffer_putchar()来写入buffer了呢? 谢谢!
    • wowo

      @anchen:多谢您的问题啊,这是我见过的最奇葩、最粗暴、也是最有意思的用法了。不过最近有点忙,没时间追根问底,建议您先看一下fprintf的源码,应该就有答案了。
      • anchen

        @wowo:一连三个最,我也要醉了。实际是Cortex A9的dual core里,实现AMP,一个是linux,一个是BM。BM输出到shared memory,由Linux应用读出来打印到串口。我实际去调试看看,有心得再来汇报。
  • pumpkin

    跟uvm verbosity的用法好像啊