Linux内核pr_debug的应用及log级别控制原理简析

调试环境------

CPU:freescale i.mx6

操作系统:Linux

内核版本号:3.0.35

最近在调试一个spi nor flash芯片的时候用到了gpio倒出的功能,就是可以在linux起来以后,通过串口倒出,并可以控制输入输出方向和高低电平的一种功能。配置好对应的pin后发现怎么都不能在/sys/class/gpio的目录下生成相应的接口目录,我要倒出的GPIO是gpio bank6的第11教,根据imx6平台gpio编号的计算方法IMX_GPIO_NR(6, 11),得到这个GPIO的编号是174(有兴趣的同学可以再imx6的平台代码上查看IMX_GPIO_NR这个宏的实现方法),通过如下命令实现倒出:

echo 174 > /sys/class/gpio/export

如果顺利倒出的话,会在gpio目录下生成gpio174这样的目录(/sys/class/gpio/gpio174),这个目录底下的接口可以对相应的gpio进行控制

执行了上述命令以后,没有生成gpio174这个目录,只好查看gpio_export函数实现,大概看了一下,整个倒出过程在关键步骤加了pr_debug调用,要用这个宏打印log可以通过DEBUG宏打开,具体打开方法如下:

1. 在内核根目录执行makemenuconfig

2. 进入内核配置图形界面以后查找

并选中

3. 退回到根菜单进入

 选中

4. 重新编译uImage,烧录

5. 现在还不能实现pr_debug的打印,还要降低prink的打印级别:

echo 8 > /proc/sys/kernel/printk

再执行gpio倒出,于是打印了下面的log:

在代码/drivers/gpio/gpiolib.c中找到了这个错误打印的位置

if(status)

pr_debug("gpio_request:gpio-%d (%s) status %d\n",

gpio,label ? : "?", status);

在status不为0的情况下打印出来的,status是-16,经过查询-16是EBUSY的errorcode,EBUSY解释是:

#define     EBUSY                16     /* Device or resource busy */

这个gpio可能是被哪个设备占用了,所以导致倒出失败,查bsp代码还真是,注释调以后让我来用,再编译运行果然成功了,看来这个pr_debug还是挺有用的。

但是printk的级别控制引起了我的好奇心,为什么echo比7大的数值才能使用pr_debug呢?带着这个疑问开始看printk相关的内核代码:

先从printk的读写控制入手,看看proc文件系统中是怎么实现对printk节点进行读写的:

/fs/proc/proc_sysctl.c中proc_sys_init函数建立/proc/sys/目录,kernel目录是在/kernel/sysctl.c中structctl_table root_table中定义的,具体定义如下:

static struct ctl_table root_table[] = {

{

.procname        = "kernel",

.mode                = 0555,

.child                  = kern_table,

},

kern_table包含了一对kernel目录下的子节点的定义,当然也包含了printk节点的定义:

{

/* 节点名称 */

.procname        = "printk",

/* 控制台log等级 */

.data                  = &console_loglevel,

.maxlen             = 4*sizeof(int),

/* 节点权限 */

.mode                = 0644,

/* 操作节点的回调函数 */

.proc_handler  = proc_dointvec,

},

其中有两个变量是比较重要的console_loglevel保存log级别,其中/kernel/printk.c源码中有如下定义:

#defineMINIMUM_CONSOLE_LOGLEVEL 1 /* Minimum loglevel we let people use */

#defineDEFAULT_CONSOLE_LOGLEVEL 7 /* anything MORE serious than KERN_DEBUG */

intconsole_printk[4] = {

DEFAULT_CONSOLE_LOGLEVEL,     /* console_loglevel */

DEFAULT_MESSAGE_LOGLEVEL,     /* default_message_loglevel */

MINIMUM_CONSOLE_LOGLEVEL, /* minimum_console_loglevel */

DEFAULT_CONSOLE_LOGLEVEL,     /* default_console_loglevel */

};

头文件/inclue/linux/printk.h对console_loglevel做了定义:

#defineconsole_loglevel (console_printk[0])

#definedefault_message_loglevel (console_printk[1])

#defineminimum_console_loglevel (console_printk[2])

#definedefault_console_loglevel (console_printk[3])

可以看到console_loglevel的值默认为7

proc_handler变量保存的函数指针proc_dointvec做了操作节点的工作,调用过程是 proc_dointvec->do_proc_dointvec->__do_proc_dointvec, 这个调用过程是多个kernel目录下的节点共用的,我以printk为例说明一下log级别是如何别改写的:

/*  tbl_data是data变量,printk的话也就是console_loglevel地址
*/

static int __do_proc_dointvec(void*tbl_data, struct ctl_table *table,

/* write是读写标志, buffer是内核与用户空间交换数据的缓冲区,属于用户空间 */

int write, void __user *buffer,

/* lenp buffer长度指针 */

size_t *lenp, loff_t *ppos,

/* conv最终实现读写操作的函数指针,negp正负数标志,lvalp要写入的数据指针,valp目标地址指针, write读写标志, data传入NULL不必关心*/

int (*conv)(bool *negp, unsigned long *lvalp,int *valp,

int write, void *data),

/*data传入NULL不必关心 */

void *data)

{

int*i, vleft, first = 1, err = 0;

unsignedlong page = 0;

size_tleft;

char*kbuf;

if(!tbl_data || !table->maxlen || !*lenp || (*ppos && !write)) {

*lenp= 0;

return0;

}

/*console_loglevel的地址指针存入局部指针整型指针变量i中 */

i= (int *) tbl_data;

/*console_logleve所在数组元素数量,也就是console_printk元素数量,我们知道是4 */

vleft= table->maxlen / sizeof(*i);

/* 传入用户buffer长度 */

left= *lenp;

if(!conv)

/* 实际实现读写操作的函数指针赋值 */

conv= do_proc_dointvec_conv;

if(write) {

if(left > PAGE_SIZE - 1)

left= PAGE_SIZE - 1;

page= __get_free_page(GFP_TEMPORARY);

/* 内核buffer获取空间 */

kbuf= (char *) page;

if(!kbuf)

return-ENOMEM;

/* 把用户空间传入的数据传入内核buffer中,如果执行的是echo 8到printk中,kbuf中保存的就是整数8的字节表示 */

if(copy_from_user(kbuf, buffer, left)) {

err= -EFAULT;

gotofree;

}

kbuf[left]= 0;

}

for(; left && vleft--; i++, first=0) {

unsignedlong lval;

boolneg;

/* 读写操作的判断 */

if(write) {

/* 写操作 */

/* 去掉多余的空格,并减去相应的去掉字符数量 */

left-= proc_skip_spaces(&kbuf);

/* 如果写操作完直接跳出for循环 */

if(!left)

break;

/* 转换kbuf为无符号长整型数值,并存入lval中,记录正负标志 */

err= proc_get_long(&kbuf, &left, &lval, &neg,

proc_wspace_sep,

sizeof(proc_wspace_sep), NULL);

if(err)

break;

/* 把lval的值改写到console_loglevel变量中,i是console_loglevel地址上面已经介绍 */

if(conv(&neg, &lval, i, 1, data)) {

err = -EINVAL;

break;

}

}else {

/* 读操作 */

/* 把i地址存储的值读入到lval中 */

if(conv(&neg, &lval, i, 0, data)) {

err= -EINVAL;

break;

}

if(!first)

/* 如果不是第一个数字就加入一个tab符号到用户buffer中,cat /proc/sys/kernel/printk节点的话就是打印”7          4       1       7”的效果  */

err= proc_put_char(&buffer, &left, ‘\t‘);

if(err)

break;

/* 把lval放入用户buffer中 */

err= proc_put_long(&buffer, &left, lval, neg);

if(err)

break;

}

}

if(!write && !first && left && !err)

err= proc_put_char(&buffer, &left, ‘\n‘);

if(write && !err && left)

left-= proc_skip_spaces(&kbuf);

free:

if(write) {

free_page(page);

if(first)

returnerr ? : -EINVAL;

}

*lenp-= left;

*ppos+= *lenp;

returnerr;

}

static int do_proc_dointvec_conv(bool*negp, unsigned long *lvalp,

int *valp,

int write, void *data)

{

if(write) {

/* console_loglevel在这里被改写的,这个最关键的,log level根据这个值进行判断 */

*valp = *negp ? -*lvalp : *lvalp;

}else {

intval = *valp;

/* 读取console_printk的元素值,每次for循环valp都是下一元素的地址*/

if(val < 0) {

*negp= true;

*lvalp= (unsigned long)-val;

}else {

*negp= false;

*lvalp= (unsigned long)val;

}

}

return0;

}

上面是对console_loglevel读写的操作,下面来看一下printk真正的级别控制是怎么样实现的,在include/linux/printk.h中对pr_debug的定义

#if defined(DEBUG)

#define pr_debug(fmt, ...) \

/* KERN_DEBUG是内核打印级别,也就是7 */

printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)

#elif defined(CONFIG_DYNAMIC_DEBUG)

/* dynamic_pr_debug() uses pr_fmt()internally so we don‘t need it here */

#define pr_debug(fmt, ...) \

dynamic_pr_debug(fmt,##__VA_ARGS__)

#else

#define pr_debug(fmt, ...) \

no_printk(KERN_DEBUGpr_fmt(fmt), ##__VA_ARGS__)

#endif

如何定义了DEBUG宏呢?,上面选中了DEBUGGPIO calls选项,也就是打开了CONFIG_DEBUG_GPIO这个宏,/drivers/gpio/Makefile中根据这个宏加入了DEBUG宏的定义

也就是gpio driver包含pirntk.h头文件后自动打开DEBUG宏,下面看printk函数的实现,代码位置是kernel/printk.c:

asmlinkage int printk(const char *fmt, ...)

{

va_listargs;

intr;

#ifdef CONFIG_KGDB_KDB

if(unlikely(kdb_trap_printk)) {

va_start(args,fmt);

r= vkdb_printf(fmt, args);

va_end(args);

returnr;

}

#endif

va_start(args,fmt);

/*最终调用vprintk实现打印功能 */

r= vprintk(fmt, args);

va_end(args);

returnr;

}

vprintk实现:

asmlinkage int vprintk(const char *fmt,va_list args)

{

intprinted_len = 0;

/* 先复制当前log级别为缺省的默认消息级别,也就是4 */

intcurrent_log_level = default_message_loglevel;

unsignedlong flags;

intthis_cpu;

char*p;

size_tplen;

charspecial;

boot_delay_msec();

printk_delay();

preempt_disable();

/*This stops the holder of console_sem just where we want him */

raw_local_irq_save(flags);

this_cpu= smp_processor_id();

/*

* Ouch, printk recursed into itself!

*/

if(unlikely(printk_cpu == this_cpu)) {

/*

* If a crash is occurring during printk() onthis CPU,

* then try to get the crash message out butmake sure

* we can‘t deadlock. Otherwise just return toavoid the

* recursion and return - but flag therecursion so that

* it can be printed at the next appropriatemoment:

*/

if(!oops_in_progress) {

recursion_bug= 1;

gotoout_restore_irqs;

}

zap_locks();

}

lockdep_off();

spin_lock(&logbuf_lock);

printk_cpu= this_cpu;

if(recursion_bug) {

recursion_bug= 0;

strcpy(printk_buf,recursion_bug_msg);

printed_len= strlen(recursion_bug_msg);

}

/*Emit the output into the temporary buffer */

/* 按fmt格式化要打印字符串到printk_buf中,并返回长度 */

printed_len+= vscnprintf(printk_buf + printed_len,

sizeof(printk_buf) - printed_len, fmt, args);

p= printk_buf;

/* Read log level and handle special printk prefix */

/* 获取printk中加入的打印级别前缀,pr_debug加入的是KERN_DEBUG,也就是7,并返回代表打印级别的字符串长度,例<7>,长度是3
*/

plen = log_prefix(p, &current_log_level, &special);

if(plen) {

p+= plen;

switch(special) {

case‘c‘: /* Strip <c> KERN_CONT, continue line */

plen= 0;

break;

case‘d‘: /* Strip <d> KERN_DEFAULT, start new line */

plen= 0;

default:

if(!new_text_line) {

emit_log_char(‘\n‘);

new_text_line= 1;

}

}

}

/*

* Copy the output into log_buf. If the callerdidn‘t provide

* the appropriate log prefix, we insert themhere

*/

for(; *p; p++) {

if(new_text_line) {

new_text_line= 0;

if(plen) {

/*Copy original log prefix */

/*printk_buf已经包含了传入的log级别字符串 */

inti;

for(i = 0; i < plen; i++)

/* 把要打印的字符串放入log_buf中 */

emit_log_char(printk_buf[i]);

printed_len+= plen;

}else {

/* Add log prefix */

/* 在printk特殊的应用时传入的并不是打印级别,这时候默认的log打印级别为4*/

emit_log_char(‘<‘);

emit_log_char(current_log_level+ ‘0‘);

emit_log_char(‘>‘);

printed_len+= 3;

}

if(printk_time) {

/*Add the current time stamp */

chartbuf[50], *tp;

unsignedtlen;

unsignedlong long t;

unsignedlong nanosec_rem;

t= cpu_clock(printk_cpu);

nanosec_rem= do_div(t, 1000000000);

tlen= sprintf(tbuf, "[%5lu.%06lu] ",

(unsignedlong) t,

nanosec_rem/ 1000);

for(tp = tbuf; tp < tbuf + tlen; tp++)

emit_log_char(*tp);

printed_len+= tlen;

}

if(!*p)

break;

}

emit_log_char(*p);

if(*p == ‘\n‘)

new_text_line= 1;

}

/*

* Try to acquire and then immediately releasethe

* console semaphore. The release will do allthe

* actual magic (print out buffers, wake upklogd,

* etc).

*

* The console_trylock_for_printk() function

* will release ‘logbuf_lock‘ regardless ofwhether it

* actually gets the semaphore or not.

*/

if(console_trylock_for_printk(this_cpu))

/* 关键函数 */

console_unlock();

lockdep_on();

out_restore_irqs:

raw_local_irq_restore(flags);

preempt_enable();

returnprinted_len;

}

/* 打印级别的判断和实际打印操作要通过下面一系列函数调用*/

console_unlock->call_console_drivers->_call_console_drivers

static void call_console_drivers(unsignedstart, unsigned end)

{

unsignedcur_index, start_print;

staticint msg_level = -1;

BUG_ON(((int)(start- end)) > 0);

cur_index= start;

start_print= start;

while(cur_index != end) {

if(msg_level < 0 && ((end - cur_index) > 2)) {

/*strip log prefix */

/* 在log_bug中获取传入的打印级别,以pr_debug为例就是7
*/

cur_index +=log_prefix(&LOG_BUF(cur_index), &msg_level, NULL);

start_print= cur_index;

}

while(cur_index != end) {

charc = LOG_BUF(cur_index);

cur_index++;

if(c == ‘\n‘) {

if(msg_level < 0) {

/*

* printk() has already given us loglevel tagsin

* the buffer. This code is here in case the

* log buffer has wrapped right round andscribbled

* on those tags

*/

/* 如果没有传入打印级别,使用默认值4 */

msg_level= default_message_loglevel;

}

_call_console_drivers(start_print,cur_index, msg_level);

msg_level= -1;

start_print= cur_index;

break;

}

}

}

_call_console_drivers(start_print,end, msg_level);

}

static void _call_console_drivers(unsignedstart,

unsignedend, int msg_log_level)

{

/* 如果printk传入的打印级别小于console_loglevel,或者忽略打印级别满足打印条件ignore_loglevel,pr_debug传入的级别是7,
console_loglevel 默认值也是7,所以在执行echo 8 > /proc/sys/kernel/printk中,pr_debug就可以打印出来了,根据上面的printk节点的说明,echo动作直接改写了console_loglevel的值,满足了
msg_log_level < console_loglevel这个条件 */

if((msg_log_level < console_loglevel ||ignore_loglevel) &&

console_drivers&& start != end) {

if((start & LOG_BUF_MASK) > (end & LOG_BUF_MASK)) {

/*wrapped write */

__call_console_drivers(start& LOG_BUF_MASK,

log_buf_len);

__call_console_drivers(0,end & LOG_BUF_MASK);

}else {

__call_console_drivers(start,end);

}

}

}

好了,上面就是printk log级别控制的大致过程。

时间: 2024-10-08 06:40:58

Linux内核pr_debug的应用及log级别控制原理简析的相关文章

linux内核打印级别

1.printk()是一个内核的一个记录日志的机制,经常用来记录信息或者警告.printk可以指定输出日志的优先级,在include/linux/kern_levels.h中有相应的宏定义 1 #define KERN_SOH "\001" /* ASCII Start Of Header */ 2 #define KERN_SOH_ASCII '\001' 3 4 #define KERN_EMERG KERN_SOH "0" /* system is unusa

Linux内核驱动定时微秒级别实现

Linux内核驱动定时微秒级别实现 #include <linux/module.h> #include <linux/kthread.h> #define TIMEOUT_HR 1000000 /* 1us */ static struct hrtimer etx_hr_timer; ktime_t ktime; enum hrtimer_restart hrtimer_callback(struct hrtimer *timer) { static int count; pri

Linux内核调试方法总结

一  调试前的准备 二  内核中的bug 三  内核调试配置选项 1  内核配置 2  调试原子操作 四  引发bug并打印信息 1  BUG()和BUG_ON() 2  dump_stack() 五  printk() 1  printk函数的健壮性 2  printk函数脆弱之处 3  LOG等级 4  记录缓冲区 5  syslogd/klogd 6  dmesg 7 注意 8 内核printk和日志系统的总体结构 9  动态调试 六  内存调试工具 1  MEMWATCH 2  YAMD

linux内核编译与开发

一.Linux内核简介linux kernel map: linux 系统体系结构: linux kernel体系结构: arm有7种工作模式,x86也实现了4个不同级别RING0-RING3,RING0级别最高, 这样linux用户代码运行在RING3下,内核运行在RING0,这样系统本身就得到了 充分的保护 用户空间(用户模式)转到内核空间(系统模式)方法: ·系统调用 ·硬件中断 linux kernel 体系结构: 虚拟文件系统VFS: VFS(虚拟文件系统)隐藏各种文件系统的具体细节,

Linux内核设计与实现读书笔记——第十八章

第18章 调试 调试工作艰难是内核级开发区别于用户级开发的一个显著特点,相比于用户级开发,内核调试的难度确实要艰苦得多.更可怕的是,它带来的风险比用户级别更高,内核的一个错误往往立刻就能让系统崩溃. 18.1 准备开始 一个bug.听起来很可笑,但确实需要一个确定的bug.如果错误总是能够重现的话,那对我们会有很大的帮助(有一部分错误确实如此).然而不幸的是,大部分bug通常都不是行为可靠而且定义明确的. 一个藏匿bug的内核版本.如果你知道这个bug最早出现在哪个内核版本中那就再理想不过了.

Linux内核工程导论——基础架构

基础功能元素 workqueue linux下的工作队列时一种将工作推后执行的方式,其可以被睡眠.调度,与内核线程表现基本一致,但又比内核线程使用简单,一般用来处理任务内容比较动态的任务链.workqueue有个特点是自动的根据CPU不同生成不同数目的队列.每个workqueue都可以添加多个work(使用queue_work函数). 模块支持 模块概述 可访问地址空间,可使用资源, 模块参数 用户空间通过"echo-n ${value} > /sys/module/${modulenam

解析 Linux 内核可装载模块的版本检查机制

转自:http://www.ibm.com/developerworks/cn/linux/l-cn-kernelmodules/ 为保持 Linux 内核的稳定与可持续发展,内核在发展过程中引进了可装载模块这一特性.内核可装载模块就是可在内核运行时加载到内核的一组代码.通常 , 我们会在两个版本不同的内核上装载同一模块失败,即使是在两个相邻的补丁级(Patch Level)版本上.这是因为内核在引入可装载模块的同时,对模块采取了版本信息校验.这是一个与模块代码无关,却与内核相连的机制.该校验机

《Linux内核设计与实现》第十八章读书笔记

1.内核中的bug 内核中的bug表现得不像用户级程序中那么清晰——因为内核.用户以及硬件之间的交互会很微妙: 从隐藏在源代码中的错误到展现在目击者面前的bug,往往是经历一系列连锁反应的事件才可能触发的. 内核调试的难点 重现bug困难 调试风险比较大 定位bug的初始版本困难 2. 内核调试的工具和方法 2.1 输出 LOG 输出LOG不光是内核调试, 即使是在用户态程序的调试中, 也是经常使用的一个调试手段. 通过在可疑的代码周围加上一些LOG输出, 可以准确的了解bug发生前后的一些重要

源码分析:动态分析 Linux 内核函数调用关系

源码分析:动态分析 Linux 内核函数调用关系 时间 2015-04-22 23:56:07  泰晓科技 原文  http://www.tinylab.org/source-code-analysis-dynamic-analysis-of-linux-kernel-function-calls/ 主题 Linux源码分析 By Falcon ofTinyLab.org 2015/04/18 缘由 源码分析是程序员离不开的话题. 无论是研究开源项目,还是平时做各类移植.开发,都避免不了对源码的