总结一下:
1. printk 会把信息输出到console口(也称为控制台),如果我们不是通过console口登录的linux, 如何看到内核的调试信息呢?
回答:原来 printk的信息输出到console口的同时,也会通知 klogd进程,由klogd进程通知 syslogd进程,syslogd进程会把信息记录到/var/log/messages,
根据printk的调试级别(printk的第一个参数),syslogd可能会把信息直接显示到当前的用户终端上。
参见:http://baike.baidu.com/view/3201386.htm
2. printk有输出时,如何打印到console口的?如何通知klogd进程呢?
回答:见linux 内核源代码:
总的流程是: printk ---> 记录字符串到log_buf ---> 获取console口的信号量 ---> 调用console口底层write函数将内容输出到实际的console口 ---> 唤醒klogd进程。
/** * printk - print a kernel message * @fmt: format string * * This is printk(). It can be called from any context. We want it to work. * * We try to grab the console_sem. If we succeed, it's easy - we log the output and * call the console drivers. If we fail to get the semaphore we place the output * into the log buffer and return. The current holder of the console_sem will * notice the new output in release_console_sem() and will send it to the * consoles before releasing the semaphore. * * One effect of this deferred printing is that code which calls printk() and * then changes console_loglevel may break. This is because console_loglevel * is inspected when the actual printing occurs. * * See also: * printf(3) * * See the vsnprintf() documentation for format string extensions over C99. */
asmlinkage int printk(const char *fmt, ...)
{
va_list args;
int r;
va_start(args, fmt);
r = vprintk(fmt, args);
va_end(args);
return r;
}
下面再看 vprintk的实现:
asmlinkage int vprintk(const char *fmt, va_list args)
{
int printed_len = 0;
int current_log_level = default_message_loglevel;
unsigned long flags;
int this_cpu;
char *p;
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() on this CPU,
* then try to get the crash message out but make sure
* we can't deadlock. Otherwise just return to avoid the
* recursion and return - but flag the recursion so that
* it can be printed at the next appropriate moment:
*/
if (!oops_in_progress) {
recursion_bug = 1;
goto out_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 */
printed_len += vscnprintf(printk_buf + printed_len,
sizeof(printk_buf) - printed_len, fmt, args);
p = printk_buf;
/* Do we have a loglevel in the string? */
if (p[0] == '<') {
unsigned char c = p[1];
if (c && p[2] == '>') {
switch (c) {
case '0' ... '7': /* loglevel */
current_log_level = c - '0';
/* Fallthrough - make sure we're on a new line */
case 'd': /* KERN_DEFAULT */
if (!new_text_line) {
emit_log_char('\n');
new_text_line = 1;
}
/* Fallthrough - skip the loglevel */
case 'c': /* KERN_CONT */
p += 3;
break;
}
}
}
/*
* Copy the output into log_buf. If the caller didn't provide
* appropriate log level tags, we insert them here
*/
for ( ; *p; p++) {
if (new_text_line) {
/* Always output the token */
emit_log_char('<'); ----> 往log buf中记录。
emit_log_char(current_log_level + '0');
emit_log_char('>');
printed_len += 3;
new_text_line = 0;
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);
nanosec_rem = do_div(t, 1000000000);
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;
}
if (!*p)
break;
}
emit_log_char(*p);
if (*p == '\n')
new_text_line = 1;
}
/*
* Try to acquire and then immediately release the
* console semaphore. The release will do all the
* actual magic (print out buffers, wake up klogd,
* etc).
*
* The acquire_console_semaphore_for_printk() function
* will release 'logbuf_lock' regardless of whether it
* actually gets the semaphore or not.
*/
if (acquire_console_semaphore_for_printk(this_cpu)) ---> 尝试获取console口的信号量
release_console_sem(); ---> 获取到console口的信号量后,就向外打印输出printk内容。同时唤醒klogd进程
lockdep_on();
out_restore_irqs:
raw_local_irq_restore(flags);
preempt_enable();
return printed_len;
}
static void emit_log_char(char c)
{
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++;
}
/*
* Try to get console ownership to actually show the kernel
* messages from a 'printk'. Return true (and with the
* console_semaphore held, and 'console_locked' set) if it
* is successful, false otherwise.
*
* This gets called with the 'logbuf_lock' spinlock held and
* interrupts disabled. It should return with 'lockbuf_lock'
* released but interrupts still disabled.
*/
static int acquire_console_semaphore_for_printk(unsigned int cpu)
{
int retval = 0;
if (!try_acquire_console_sem()) {
retval = 1;
/*
* If we can't use the console, we need to release
* the console semaphore by hand to avoid flushing
* the buffer. We need to hold the console semaphore
* in order to do this test safely.
*/
if (!can_use_console(cpu)) {
console_locked = 0;
up(&console_sem);
retval = 0;
}
}
printk_cpu = UINT_MAX;
spin_unlock(&logbuf_lock);
return retval;
}
/**
* release_console_sem - unlock the console system
*
* Releases the semaphore which the caller holds on the console system
* and the console driver list.
*
* While the semaphore was held, console output may have been buffered
* by printk(). If this is the case, release_console_sem() emits
* the output prior to releasing the semaphore.
*
* If there is output waiting for klogd, we wake it up.
*
* release_console_sem() may be called from any context.
*/
void release_console_sem(void)
{
unsigned long flags;
unsigned _con_start, _log_end;
unsigned wake_klogd = 0;
if (console_suspended) {
up(&console_sem);
return;
}
console_may_schedule = 0;
for ( ; ; ) {
spin_lock_irqsave(&logbuf_lock, flags);
wake_klogd |= log_start - log_end;
if (con_start == log_end)
break; /* Nothing to print */
_con_start = con_start;
_log_end = log_end;
con_start = log_end; /* Flush */
spin_unlock(&logbuf_lock);
stop_critical_timings(); /* don't trace print latency */
call_console_drivers(_con_start, _log_end); ---> 函数很深,最终就是调用 con---> write() 将内容输出到console口。
start_critical_timings();
local_irq_restore(flags);
}
console_locked = 0;
up(&console_sem);
spin_unlock_irqrestore(&logbuf_lock, flags);
if (wake_klogd)
wake_up_klogd(); ---> 通知klogd进程。
}
void wake_up_klogd(void)
{
if (waitqueue_active(&log_wait))
__raw_get_cpu_var(printk_pending) = 1;
}
int try_acquire_console_sem(void)
{
if (down_trylock(&console_sem))
return -1;
if (console_suspended) {
up(&console_sem);
return -1;
}
console_locked = 1;
console_may_schedule = 0;
return 0;
}
http://blog.csdn.net/dog250/article/details/5707979
http://coaku.diandian.com/post/2011-09-08/4881756
http://liu1227787871.blog.163.com/blog/static/20536319720126954110820/
http://liu1227787871.blog.163.com/blog/static/205363197201269111953844/
http://www.newsmth.net/nForum/#!article/KernelTech/55039
http://wenku.baidu.com/view/e57a4564783e0912a2162a51.html