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

作者:wowo 发布于:2014-1-23 20:52 分类:软件开发

前言

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

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

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

日志打印的注意事项

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

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

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

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

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

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

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

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

 

日志打印的实现

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

      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

标签: 日志 打印 printf debug 调试

评论:

pumpkin
2017-10-12 22:47
跟uvm verbosity的用法好像啊
anchen
2016-07-21 16:39
我这里有一个问题想请教,是关于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
2016-07-21 21:40
@anchen:多谢您的问题啊,这是我见过的最奇葩、最粗暴、也是最有意思的用法了。不过最近有点忙,没时间追根问底,建议您先看一下fprintf的源码,应该就有答案了。
anchen
2016-07-22 15:02
@wowo:一连三个最,我也要醉了。实际是Cortex A9的dual core里,实现AMP,一个是linux,一个是BM。BM输出到shared memory,由Linux应用读出来打印到串口。我实际去调试看看,有心得再来汇报。
我欲乘风归去
2015-06-04 15:22
日志提供单独的模块控制输出接口很重要啊。
我理解日志应该是一个全局接口,但是每个模块可以加上自己的tag比较好,这样控制输出的时候,可以通过配置的方式启用某些模块的输出。在系统大了以后非常有用。
wowo
2015-06-04 17:10
@我欲乘风归去:你说的很对,所以Linux Kernel的日志管理系统(Dynamic Debug)就相当复杂了,只有那样,才可以很方便的debug。我这边文章只是一个例子。

发表评论:

Copyright @ 2013-2015 蜗窝科技 All rights reserved. Powered by emlog