========================================================
v0.1 3.4.2009 by arethe Email: qinchenggang@sict.ac.cn
========================================================
printk()的参数个数是可变的，linux内核中提供了va_arg机制。该机制主要通过3个宏来实现：
va_arg(ap, T)：获取ap中的一个参数，该参数的类型是T，然后ap自加sizeof(T)，跳过刚获取的参数。
va_end(ap)：该宏定义为空。
va_start(ap, A)：通过A获取参数列表的地址，A是printk的第一个参数（fmt）。一个函数的参数，是按从右到左的顺序逐个入栈的，因此通过A的地址加上A的大小(通常为4Bytes),就可以获得从第二个参数开始的参数列表的首地址。
printk()函数首先使用va_start(args, fmt)，将第二个参数的地址存入args变量。然后调用vprintk(fmt, args)，vprintk完成具体的输出任务，返回值为输出的字符的个数。
下面我们详细讨论vprintk的实现。
printk机制中有两个主要的缓存：一个是printk_buf,一个是log_buf。前者用来存储将要输出的字符串，fmt+报错信息（如果有的话）。后者用来存储最终要输出的字符串，是整个printk机制的核心。log_buf是一个环形数组，默认大小为128K。配合这个缓冲使用的有3个变量：
static unsigned log_start; /* Index into log_buf: next char to be read by syslog() */
static unsigned con_start; /* Index into log_buf: next char to be sent to consoles */
static unsigned log_end; /* Index into log_buf: most-recently-written-char + 1 */
在用到这个缓冲时，我们再详细的介绍。
vprintk首先会调用函数boot_delay_msec()，进行忙等待一段时间。这段时间的大小是由内核启动参数boot_delay指定的。boot_delay的单位是毫秒。不知道这里为什么要等待。
然后调用preempt_disable()禁止抢占机制。接下来是关中断，获取当前CPU的编号。
如果在某个CPU上正在执行printk时，突然崩溃掉，........
vscnprintf()函数，将输出的字符串按fmt中的格式编排好，放入printk_buf中，并返回应该输出的字符的个数。为了保证完整性，我们还是来谈谈vscnprintf()函数的实现吧。
vscnprintf()调用的是vsnprintf(buf,size,fmt,args)。该函数进行主要的格式化操作。其首先判断size是否小于0，若小于0，则给出一个警告，并返回0。然后对格式化字符串fmt进行遍历，如果fmt当前的字符不是"%",直接将其考入buf中，若是"%"，则后面的处理要复杂一点。相信读者对printf和printk的使用方法都很熟悉，"%"后面一般会跟一个标志符，这种标志符共有5个，'-','+','#','SPACE','0'。标志符'-'表示后面的字符靠左输出，比如printk("%-10c",'a'),会先输出'a',再输出9个空格。'#'标志的作用是当后面输出16进制的数据时，会自动在数据前加上"0x",比如printk("%#x",10),会输出"0xa"。'+'标志的作用是在输出的数字前自动加上一个"+",比如printk("%+d/n",10),输出结果为:"+10"。这里会根据不同的标志符对一个标志变量"flags"进行置位。各标志符对应的bit如下：
#define ZEROPAD 1 /* pad with zero -- '0'*/
#define SIGN 2 /* unsigned/signed long -- */
#define PLUS 4 /* show plus -- '+' */
#define SPACE 8 /* space if plus -- ' ' */
#define LEFT 16 /* left justified -- '-' */
#define SMALL 32 /* Must be 32 == 0x20 */
#define SPECIAL 64 /* 0x -- '#' */
在标志符的后面通常是输出宽度，这是一个数字，vsnprintf()定义了一个变量来获取这个值，首先，我们需要判断紧接着标志符后面的是不是数字，如果是则通过skip_atoi()将该数字字符串转化成数字。skip_atoi()的实现很简洁：
static int skip_atoi(const char **s)
{//change the string "s" to digit
int i=0;
while (isdigit(**s))
i = i*10 + *((*s)++) - '0';
return i;
}
对于内核中的这类函数最好能记熟一点，在用的时候就不用再费时间自己实现了。在这里有一点需要强调的是"%*"，至少我以前并不知道"%*"的含义，"*"对应后面的一个参数，这个参数指定输出的宽度。比如:printk("%*c",10,'a');会先输出9个空格再输出字符'a'。你甚至可以给一个负值，表示靠左输出。获取的输出宽度保存在变量field_width中。
接下来处理的是输出精度，在格式化输出浮点数时，我们经常采用".num"的形式来指定小数点后输出几位有效数字。在处理的时候，首先判度当前字符是不是'.'，如果是，那么读入后面紧跟着的数字，保存在变量precision中。这里也可以使用".*"的形式，将精度放到后面的参数中指定。
接着是读取限定符，如果有的话。什么是限定符呢? 如果我们想输出一个长整数，会用到"%ld",这里的"l"便是限定符，用于辅助说明输出数据的具体类型。printf或printk中用的限定符有:"h,l,L,Z,z,t"。另外"ll"相当于"L"。大家应该能猜到下一步应该做什么了，没错，判断输出数据的类型。可能的类型有"c,s,p,n,%,o,X,x,d,i,u"，这里的实现都很简单，如果大家有兴趣，可以自己去看源代码。
有一个问题到现在一直没有说明，就是如何从参数列表中获得想要的参数。其实在文章刚开始的时候提到了一点，就是va_arg()宏，该宏每次根据指定的类型读取一个参数，然后将参数列表的开始位置自动向前移一个。这样，我们在分析"fmt"的格式的同时也就把对应的参数放到了输出字符串(printk_buf)中合适的位置上。
分析完"fmt"后，函数vsnprintf()返回应该输出的字符个数。
执行流有返回到了函数vprintk()中，我们接着来看。下面是一个for循环，用于将printk_buf中的输出字符串拷贝到日志缓存log_buf中。首先需要判度输出的级别，我们知道在printk中，可以指定8个输出级别，通过printk("...")来指定。这里的输出级别被保存到变量current_log_level中。
下面用到了一个函数emit_log_char():
static void emit_log_char(char c)
{// write c into log. the log buf is ring queue, the defaut is 128K.
LOG_BUF(log_end) = c;
log_end++;
if (log_end - log_start > log_buf_len)
log_start = log_end - log_buf_len;
if (log_end - con_start > log_buf_len)
con_start = log_end - log_buf_len;
if (logged_chars < log_buf_len)
logged_chars++;
}
这个函数的作用是把字符c写道日志缓存log_buf中，并更新log_start，log_end，con_start的值。
接下来有个需要解释一下的问题，就是printk_time。我们在启动内核的时候可以通过指定一个内核启动参数"time",来使所有printk出来的数据前加入当前时间。这个时间是从系统启动到这个printk时所逝去的时间。
if (printk_time) {
/* Follow the token with the time */
char tbuf[50], *tp;
unsigned tlen;
unsigned long long t;
unsigned long nanosec_rem;
t = cpu_clock(printk_cpu);//the unit of t is
nanosecond
nanosec_rem = do_div(t, 1000000000);//Now, the
unit of t is second, the unit of nanosec_rem is nanosecond.
tlen = sprintf(tbuf, "[%5lu.%06lu] ",
(unsigned long) t,
nanosec_rem / 1000);
for (tp = tbuf; tp < tbuf + tlen; tp++)
emit_log_char(*tp);
printed_len += tlen;
}
函数cpu_clock()返回从系统启动到当前的纳秒值。do_div(a,b)是一个宏，它计算a/b,将商放在a中，返回余数。那么tbuf中的数据便是"[second.nanosecond]"形式的。有兴趣的话，大家可以在内核启动时加入time参数试一试，看看会有什么效果。
在for循环结束后，printk_buf中的数据便按照新的输出格式(比如在每一行前面加入print_time)copy到了log_buf中。
下面便是具体的输出工作了，在输出之前，需要先获取信号量console_sem，这里获取的方式采用的是down_trylock(&console_sem)。这个函数在没有获取信号量时不会睡眠，而是立即返回一个非0值。另外，我们还需要释放锁console_locked和logbuf_lock。这些工作在函数acquire_console_semaphore_for_printk(this_cpu)中完成，当该函数成功返回时，会调用函数release_console_sem()进行显示工作。这个函数会再调用call_console_drivers(_con_start, _log_end)将_con_start，_log_end之间的log_buf中的内容。函数call_console_drivers()首先判断输出级别，然后根据输出内容，按行调用函数_call_console_drivers(start_print, cur_index, msg_level)，该函数的作用是处理环形队列，将正确的内容作为参数调用函数__call_console_drivers(start, end)，该将输出内容发送给console的驱动。在内核中，所有的console都被链入了一个链表--console_drivers，在这里，我们要遍历这个链表，如果某个console允许输出的话，就调用它的write()方法。
/*
* Call the console drivers on a range of log_buf
*/
static void __call_console_drivers(unsigned start, unsigned end)
{
struct console *con;
for (con = console_drivers; con; con = con->next) {//All consoles belongs to a list -- console_drivers.
if ((con->flags & CON_ENABLED) && con->write &&
(cpu_online(smp_processor_id()) ||
(con->flags & CON_ANYTIME)))
con->write(con, &LOG_BUF(start), end - start);
}
}
到此为止，整个printk的过程就结束了。哦，不！还有一个工作没有做，就是将输出内容同时写入日志。这个工作是由内核中的守护进程klogd来完成的。在函数release_console_sem(void)的最后，会判断是否需要唤醒klogd，然后调用wake_up_klogd()来唤醒守护进程。那么什么时候需要唤醒klogd呢?只要log_buf中有未输出的信息，便需唤醒klogd将其写入日志文件。
OK!现在是真的结束了。如果有什么问题，可以跟我联系，共同讨论。
阅读(2199) | 评论(0) | 转发(0) |
