kernel module编程(六):printk-printf的debug

  本文包含《Linux Device Drivers》,即LDD3的第四章:Debugging Techniques的读书笔记之一,但我们不限于此内容。我在网上看到了LDD3的中文版:http://www.deansys.com/doc/ldd3/ ,我看了一下,最好和原文版一起阅读。

  在我们的程序的调测中,无论是JAVA,C(kernel module或者是用户应用),print都是非常重要的手段。在我以往的项目中,我会有一个log文件,将log根据项目需要分为几个级别log,通过setlogLevel可以设置打开或者关闭哪些些级别的debug,每一行log有[时间] [log-level] [log内容]三部分组成。可以决定是否将log写入文件,还是只是在terminal上显示。在一个JAVA的project中,可以将log输出到控制台客户端上,他们之间走TCP链接,如果TCP出现阻塞,将丢弃输出,直至TCP恢复。在C中,我们可以简单地在编译参数中加上-DMY_DEBUG_LEVEL来处理。从某种意义来讲DEBUG也是一门学问。

  对于写文件,我有一个惨痛的教训。写CDR计费原始数据单,每个业务有三条详细记录,两个callleg,有一个业务记录。我们的大话务量测试,至少48小时,通常我会压更长的时间。业务超过1千万次。所以需要写的数据非常多。在平时的测试中没有问题,但是在一次正式测试中出现磁盘满禁止写入的晕菜现象。这个虽然可以推给集成人员,但是很多时候也是我们自己考虑不周到。如果我们写文件,包括log文件,对于长期运行的系统,我们必须考虑磁盘空间的问题。在这次教训后,我写了一个根据时间、容量、文件数的判断进行压缩或者删除文件最初文件的后台小程序,明天定期执行。之后在另外一个下面也是压测性能,合作方的出现测试客户端log爆满磁盘的现象。这是一个在开发中容易被忽略的问题,但是在实际运行中可能产生严重问题。 【编程思想1:注意磁盘溢出情况】

  其实debug对开发很重要,他不仅可以跟踪我们的程序对他进行诊断,也可以跟踪我们的业务逻辑,查找性能瓶颈(对于性能瓶颈gdb是无法胜任的,因为断点使得系统性能上不去)。在内核模块编程也一样。我们开发的程序不应该分调测版本和正式版本,他们的source code是一致的,但是正式版本中没有调测信息的出现。我们下面将介绍printk的一些使用方法。

一些重要的宏

  printk和printf非常相似,但是不等同。下面是一个例子:

printk(KERN_DEBUG "wei mark here : %s : %d at %s()/n",__FILE__ ,__LINE__ ,__FUNCTION__ );

  其中__FILE__ 表示源代码文件,以绝对路径的方式出现,__LINE__ ,表示这行printk允许在这个源代码文件中的第几行,这是一个很好的给出调测点位置的信息。这个同样可以用在用户程序。__DATE____TIME__ 是非常常用的两个。不过有时我们需要使用msec,这种情况下只好自己写了。这4个宏,在debug中会经常使用。此外还有__STDC__ ,通常为1,表示为标准的ANSI C。还有一个常用的是__FUNCTION__ 表示在那个函数之中,也是比较好的定位方式。这些宏均可以在用户程序中使用,对debug非常有帮助。

  KERN_DEBUG是一个字符串,即"<7>",这是内核定义的8个debug等级中,最低等级的一个。从0-7,分别是KERN_EMERG,KERN_ALERT,KERN_CRIT,KERN_ERR, KERN_WARING, KERN_NOTICE, KERN_INFO, KERN_DEBUG。对应<0>, <1>, <2> ... ...。由于他是一个字符,所有他后面是没有逗号的。

  在fc10中,我查看的dmesg,以及/var/log/messages,发现KERN_DEBUG所代表的"<7>"并没有显示,而使用KVM运行的moblin中,这个"<7>"是显示的。我做了一个实验,直接用"<7>"来代替KERN_DEBUG,例如上面的例子,我写为"<7> wei ...",在fc10中,同样是不显示<7>,这和OSV集成的系统有关。

使用printk|printf

  一个好的编程习惯,在每个printk中都加上DEBUG等级,这样使得程序更容易了解。在scull的例子上,增加一个scull_debug.c文件,我们的目的是保证源代码的一致性,而是否显示debug信息,可以由编译来决定。

#ifndef WEI_SCULL_DEBUG_H

#undef PDEBUG
#ifdef SCULL_DEBUG
#  ifdef __KERNEL__
#    define PDEBUG(fmt,args...) printk(KERN_DEBUG "scull:" fmt , ## args)
#  else
#    define PDEBUG(fmt,args...) printf(fmt, ## args)
#  endif
#else
#  define PDEBUG(fmt,args...)
#endif

#undef PDEBUGG
#define PDEBUGG(fmt, args...)

#endif

  在上面的例子中,定义了PDEBUG的宏,如果需要我们也可以定义PDEBUGG的实际内容。如果我们定义了SCULL_DEBUG,进入DEBUG模式,PDEBUG根据是否内核编程,决定使用printk还是printf。也就是说这个头文件也可以在用户程序中使用 。下面是对Makefile的修改,简单的处理,就是在gcc那行,如果需要debug,加上参数 -DSCULL_DEBUG,就可以,不需要删除这个定义。下面是写得更好看,但是我个人认为不那么简洁易懂的方式。我会在EXTRA_CFLAGS的设置中直接加上-DSCULL_DEBUG,在他上面作一行注释说明参数的含义,不会去搞一堆脚本。下面是LDD3的例子,其中将CFLAGS改为EXTRA_CFLAGS。另一个注意的地方就是ifeq后面一定要加一个空格,否则报错。

DEBUG = y

ifeq ($(DEBUG),y)
        DEBFLAGS = -O -g -DSCULL_DEBUG
else
        DEBFLAGS = -O2
endif

EXTRA_CFLAGS += $(DEBFLAGS)

obj-m := scull.o
module-objs :=

PWD := $(shell pwd)
KDIR := /lib/modules/$(shell uname -r)/build

all:
        make -C $(KDIR) M=$(PWD) modules

clean:
        make -C $(KDIR) M=$(PWD) clean

在fc10中,我们还是希望能够看到debug的等级,另方面,我们对0-7对应的含义不熟悉,只知道数字越高,信息越为重要。我们将scull_debug.c改写为下面:

#ifndef WEI_SCULL_DEBUG_H

#ifdef __KERNEL__
#define WEI_KERN_ERMER          0
#define WEI_KERN_ALERT           1
#define WEI_KERN_CRIT             2
#define WEI_KERN_ERR              3
#define WEI_KERN_WARNING     4
#define WEI_KERN_NOTICE        5
#define WEI_KERN_INFO            6
#define WEI_KERN_DEBUG         7

static char * log_level[] = {
  "KERN_EMERG",
  "KERN_ALERT",
  "KERN_CRIT",
  "KERN_ERR",
  "KERN_WARNING",
  "KERN_NOTICE",
  "KERN_INFO",
  "KERN_DEBUG"
};

#endif

#undef PDEBUG
#ifdef SCULL_DEBUG
#ifdef __KERNEL__
#  define PDEBUG(fmt,args...) printk(KERN_DEBUG "scull:" fmt , ## args)

#    ifdef WEI_DEBUG_LEVEL
#      define WDEBUG(level,fmt,args...) /
        if( level <= WEI_DEBUG_LEVEL)  printk("%s %s scull [%s] : " fmt , __DATE__ , __TIME__ , log_level[level], ## args)
#    else
#      define WDEBUG(level,fmt,args...) printk("%s scull [%s] : " fmt ,__TIME__ ,  log_level[level], ## args)
#    endif
#  else
#    define PDEBUG(fmt,args...) printf(fmt, ## args)
#    define WDEBUG(level,fmt,args...)
#  endif
#else
#  define PDEBUG(fmt,args...)
#endif

#undef PDEBUGG
#define PDEBUGG(fmt, args...)

#endif

  我们可以选择debug的级别,将debug等级用字符串打出来。对于简单程序可能意义不大,我们也可以设置自己的等级。将Makefile改写为下面:

DEBUG = y
DEBUGLEVEL = 6

ifeq ($(DEBUG),y)
        DEBFLAGS = -O -g -DSCULL_DEBUG -DWEI_DEBUG_LEVEL=$(DEBUGLEVEL)
else
        DEBFLAGS = -O2
endif

EXTRA_CFLAGS += $(DEBFLAGS)

obj-m := scull.o
module-objs :=

PWD := $(shell pwd)
KDIR := /lib/modules/$(shell uname -r)/build

all:
        make -C $(KDIR) M=$(PWD) modules

clean:
        make -C $(KDIR) M=$(PWD) clean

 

在scull的例子,通过load和unload,我们从dmesg中可以获得下面的信息:

Sep  9 2009 14:18:14 scull [KERN_NOTICE] : Scull module init enter
Sep  9 2009 14:18:18 scull [KERN_NOTICE] : Scull module exit

避免printk产生阻塞

  由于某些原因,频繁设置循环调用某个printk的语句,将会造成CPU的拥堵,如果输入终端是慢速,就会造成拥堵,我们也不可能从这种狂刷屏幕上读取到什么有效信息,基本上就看不清。内核编程提供了一下保护机制。下面是一个测试的例子:

        for(i = 0 ; i < 1000; i ++){
                if(printk_ratelimit()){
                        printk(KERN_DEBUG "Test for ratelimte i = %d j = %d/n",i ,++j);
                }
        }
        printk(KERN_NOTICE "After Test i = %d j = %d/n",i , j);

  printk_ratelimit()根据打印的频繁程度返回的一个值,根据这个值我们决定是否将debug信息打印出来。这个返回值取决于两个因素,分别定义在/proc/sys/kernel/printk_ratelimit和/proc/sys/kernel/printk_ratelimit_burst。前者表示当这个值置为0后隔多少秒后恢复为1,即等待允许再次打印的时间(秒),后者可能和缓存队列长度有关,他表示在值为0之前,可以printk的条目数。系统缺省值为5和10,也就是在printk_ratelimit()的控制下,每秒可以有两个输出。在上面的例子,我们看到输出了10次。我想象的处理机制是,系统根据printk_ratelimit_burst的值设置一个队列长度,如果这个队列满,则值printk_ratelimit()为0,禁止新的消息加入队列,等待printk_ratelimit秒设定的时间,将 printk_ratelimit()设为1,即允许新的消息加入队列。这种方式我曾用于处理业务请求,设定允许接纳请求的频率,避免burst的出现。我猜想这里面的机制也是类似的。不管如何,这是一种看行之有效的方法。 【编程思想2:控制输入/输出、控制业务量】

相关链接:
我的与kernel module有关的文章
我的与编程思想相关的文章

  • 0
    点赞
  • 2
    收藏
    觉得还不错? 一键收藏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值