linux内核调试-printk
----------------------------------------------------------------------------------------------------------------------------
内核版本：linux 5.2.8
根文件系统：busybox 1.25.0
u-boot：2016.05
----------------------------------------------------------------------------------------------------------------------------
一、printk介绍
我们在学习C语言的时候，经常使用printf函数将内容输出到控制台，printf 是格式化输出函数，主要功能是向标准输出设备按规定格式输出信息。printf是C语言标准库函数，定义于头文件 <stdio.h>。
而在linux内核中是无法使用printf 函数的，取而代之的是printk函数。printk在内核源码中用来记录日志信息的函数，只能在内核源码范围内使用，用法类似于printf函数。
一个较大的差别在于printk支持多种日志级别，从而允许printk根据消息的等级选择性进行打印。
printk函数主要做两件事情：
- 将信息记录日志文件中（一般为/var/log/message）；
- 调用控制台驱动来将信息输出到控制台；
1.1 日志缓冲区
printk将内核日志输出到内核日志缓冲区中，缓冲区定义在在kernel/printk/printk.c文件中：
/* record buffer */ #define LOG_ALIGN __alignof__(struct printk_log) #define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT) #define LOG_BUF_LEN_MAX (u32)(1 << 31) static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN); static char *log_buf = __log_buf; static u32 log_buf_len = __LOG_BUF_LEN;
内核日志缓冲区__log_buf的大小为$2^{CONFIG\_LOG\_BUF\_SHIFT}$ ，CONFIG_LOG_BUF_SHIFT默认为17，即128KB，可以通过make menuconfig配置，对应的配置项为LOG_BUF_SHIFT。
用户态可以通过syslog相关的系统调用或者/proc文件以及/dev/kmsg设备节点来查看__log_buf的信息，这些操作都是通过do_syslog的系统调用接口来实现的。
1.2 日志级别
日志级别用来控制printk打印的这条信息是否在控制台上显示，linux内核共提供了8种不同的日志级别，分为级别 0~7。数值越大，表示级别越低，对应的消息越不重要。
linux内核日志级别相应的宏定义在include/linux/kern_levels.h 文件中。
#define KERN_EMERG KERN_SOH "0" /* system is unusable */ #define KERN_ALERT KERN_SOH "1" /* action must be taken immediately */ #define KERN_CRIT KERN_SOH "2" /* critical conditions */ #define KERN_ERR KERN_SOH "3" /* error conditions */ #define KERN_WARNING KERN_SOH "4" /* warning conditions */ #define KERN_NOTICE KERN_SOH "5" /* normal but significant condition */ #define KERN_INFO KERN_SOH "6" /* informational */ #define KERN_DEBUG KERN_SOH "7" /* debug-level messages */ #define KERN_DEFAULT "" /* the default kernel loglevel */
各个日志级别含义如下：
- KERN_EMERG 表示紧急事件，一般是系统崩溃之前提示的消息；
- KERN_ALERT 表示必须立即采取行动的消息；
- KERN_CRIT 表示临界状态，通常涉及严重的硬件或软件操作失败；
- KERN_ERR 用于报告错误状态，设备驱动程序会经常使用该级别来报告来自硬件的问题；
- KERN_WARNING 对可能出现问题的情况进行警告，这类情况通常不会对系统造成严重的问题；
- KERN_NOTICE 表示有必要进行提示的正常情形，许多与安全相关的状况用这个级别进行汇报；
- KERN_INFO 表示内核提示信息，很多驱动程序在启动的时候，用这个级别打印出它们找到的硬件信息；
- KERN_DEBUG 用于调试信息；
1.3 函数使用
在使用printk时，会将日志级别放到最开始的位置，使用方式如下：
printk(log_level "message...");
例如：
printk(KERN_EMERG "GetIot: KERN_EMERG\n"); printk(KERN_ALERT "GetIot: KERN_ALERT\n"); printk(KERN_CRIT "GetIot: KERN_CRIT\n"); printk(KERN_ERR "GetIot: KERN_ERR\n"); printk(KERN_WARNING "GetIot: KERN_WARNING\n"); printk(KERN_NOTICE "GetIot: KERN_NOTICE\n"); printk(KERN_INFO "GetIot: KERN_INFO\n"); printk(KERN_DEBUG "GetIot: KERN_DEBUG\n");
若未设置日志级别，printk默认使用内核定义的全局变量default_message_loglevel作为的默认打印的日志级别。
当printk中的消息日志级别小于当前控制台日志级别时，printk要打印的信息才会在控制台打印出来，否则不会显示在控制台。
printk的用法与printf基本一致, 最大的区别是printk对%p的扩展，在应用层使用printf打印一个指针的地址时直接使用%p即可, 但是内核为了防止泄漏内存布局的敏感信息，直接使用%p输出的地址是经过hash处理的, 如果想实现和printf的%p一样的效果, printk需要使用%px。
1.4 查看日志
无论当前控制台日志级别是何值，即使没有在控制台打印出来，都可以通过下面两种方法查看日志：
- 第一种是使用dmesg命令查看日志；
- 第二种是通过cat /proc/kmsg来查看日志；
另外如果配置好并运行了syslogd 或klogd，没有在控制台上显示的printk的信息也会追加到/var/log/messages.log中。
1.4.1 dmesg
执行dmesg查看日志：
[root@zy:/]# dmesg Booting Linux on physical CPU 0x0 Linux version 5.2.8 (root@zhengyang) (gcc version 4.8.3 20140320 (prerelease) (Sourcery CodeBench Lite 2014.05-29)) #23 Sun Mar 26 14:53:14 CST 2023 ...
1.4.2 /proc/kmsg
执行cat /proc/kmsg查看日志：
[root@zy:/]# cat /proc/kmsg <6>Booting Linux on physical CPU 0x0 <5>Linux version 5.2.8 (root@zhengyang) (gcc version 4.8.3 20140320 (prerelease) (Sourcery CodeBench Lite 2014.05-29)) #23 Sun Mar 26 14:53:14 CST 2023 ...
1.5 调整日志级别
linux系统支持在运行时，通过proc文件系统查看和调整内核日志的输出等级。查看当前控制台的打印级别的命令如下：
[root@zy:/]# cat /proc/sys/kernel/printk 7 4 1 7
该文件有4个数字值，含义如下：
- 控制台日志级别：优先级高于该值的消息将被打印至控制台；
- 默认的消息日志级别：将用该优先级来打印没有优先级的消息（即 printk 没有指定消息级别）；
- 最低的控制台日志级别：控制台日志级别可被设置的最小值（最高优先级）；
- 默认的控制台日志级别：控制台日志级别的缺省值，如果没有指定控制台日志级别，则使用这个；
这四个值是在 kernel/printk/printk.c 中被定义的，如下：
int console_printk[4] = { CONSOLE_LOGLEVEL_DEFAULT, /* console_loglevel */ MESSAGE_LOGLEVEL_DEFAULT, /* default_message_loglevel */ CONSOLE_LOGLEVEL_MIN, /* minimum_console_loglevel */ CONSOLE_LOGLEVEL_DEFAULT, /* default_console_loglevel */ }; EXPORT_SYMBOL_GPL(console_printk);
修改日志级别有两种方式，配置menuconfig和修改/proc/sys/kernel/printk文件。
1.5.1 配置menuconfig
修改CONFIG_MESSAGE_LOGLEVEL_DEFAULT的值，然后重新编译，更新内核。menuconfig配置路径如下：
Kernel hacking ---> printk and dmesg options ---> (4) Default message log level (1-7)
如下图所示：
1.5.2 在系统中修改
在系统运行期间，可以通过执行以下命令，修改当前控制态的日志级别：
echo "新的打印级别 4 1 7" > /proc/sys/kernel/printk
如屏蔽掉所有的内核printk打印，只需要把第一个数值调到最小值1或者0，此时可以敲如下命令：
echo "1 4 1 7" > /proc/sys/kernel/printk
1.5.3 打开调试日志
内核中的大部分驱动都使用了dev_dbg接口打印调试信息，日志级别为7，默认是不会输出到控制台的。在需要打印dev_dbg调试信息的驱动文件开头定义DEBUG宏，注意必须是在include/linux/device.h前面：
#define DEBUG
打开DEBUG宏是第一步，这个时候还是不能输出到控制台的，还必须要修改控制台日志级别为8。
二、其他常见用法
为了方便开发者使用，在linux内核中除了直接使用printk加消息级别的方式，内核还提供了pr_xx和dev_xx系列的打印接口，本质上，它们都是基于printk实现的。其中：
- pr_xx系列函数简化了日志级别的使用；
- dev_xx系列函数可以用于设备驱动程序中，便于打印设备相关的信息；
2.1 pr_xx系列函数
在 <linux/printk.h> 中定义了 pr_notice、pr_info、pr_warn、pr_err 等接口。使用这些 pr_xxx 接口，就可以省去指定消息级别的麻烦。
#define pr_emerg(fmt, ...) printk(KERN_EMERG pr_fmt(fmt), ##__VA_ARGS__) #define pr_alert(fmt, ...) printk(KERN_ALERT pr_fmt(fmt), ##__VA_ARGS__) #define pr_crit(fmt, ...) printk(KERN_CRIT pr_fmt(fmt), ##__VA_ARGS__) #define pr_err(fmt, ...) printk(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__) #define pr_warning(fmt, ...) printk(KERN_WARNING pr_fmt(fmt), ##__VA_ARGS__) #define pr_warn pr_warning #define pr_notice(fmt, ...) printk(KERN_NOTICE pr_fmt(fmt), ##__VA_ARGS__) #define pr_info(fmt, ...) printk(KERN_INFO pr_fmt(fmt), ##__VA_ARGS__) #ifdef DEBUG #define pr_devel(fmt, ...) \ printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__) #else #define pr_devel(fmt, ...) \ no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__) #endif #if defined(CONFIG_DYNAMIC_DEBUG) #define pr_debug(fmt, ...) \ dynamic_pr_debug(fmt, ##__VA_ARGS__) #elif defined(DEBUG) #define pr_debug(fmt, ...) \ printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__) #else #define pr_debug(fmt, ...) \ no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__) #endif
如上各pr_xx定义，都是对printk+日志级别的封装，故都能和prink一样在linux内核中直接使用；
但是对于pr_devel需要在定义了DEBUG宏，pr_debug需要在定义了DEBUG或CONFIG_DYNAMIC_DEBUG宏才有实意。
2.2 dev_xx系列函数
在 <linux/dev_printk.h> 里也提供了一些驱动模型诊断宏，例如dev_err、dev_warn、dev_info等等。使用它们，不仅可以按标记的消息级别打印，还会打印对应的设备和驱动信息，这对于驱动调试来说相当重要。
#define dev_emerg(dev, fmt, ...) \ dev_printk_index_wrap(_dev_emerg, KERN_EMERG, dev, dev_fmt(fmt), ##__VA_ARGS__) #define dev_crit(dev, fmt, ...) \ dev_printk_index_wrap(_dev_crit, KERN_CRIT, dev, dev_fmt(fmt), ##__VA_ARGS__) #define dev_alert(dev, fmt, ...) \ dev_printk_index_wrap(_dev_alert, KERN_ALERT, dev, dev_fmt(fmt), ##__VA_ARGS__) #define dev_err(dev, fmt, ...) \ dev_printk_index_wrap(_dev_err, KERN_ERR, dev, dev_fmt(fmt), ##__VA_ARGS__) #define dev_warn(dev, fmt, ...) \ dev_printk_index_wrap(_dev_warn, KERN_WARNING, dev, dev_fmt(fmt), ##__VA_ARGS__) #define dev_notice(dev, fmt, ...) \ dev_printk_index_wrap(_dev_notice, KERN_NOTICE, dev, dev_fmt(fmt), ##__VA_ARGS__) #define dev_info(dev, fmt, ...) \ dev_printk_index_wrap(_dev_info, KERN_INFO, dev, dev_fmt(fmt), ##__VA_ARGS__) #if defined(CONFIG_DYNAMIC_DEBUG) || \ (defined(CONFIG_DYNAMIC_DEBUG_CORE) && defined(DYNAMIC_DEBUG_MODULE)) #define dev_dbg(dev, fmt, ...) \ dynamic_dev_dbg(dev, dev_fmt(fmt), ##__VA_ARGS__) #elif defined(DEBUG) #define dev_dbg(dev, fmt, ...) \ dev_printk(KERN_DEBUG, dev, dev_fmt(fmt), ##__VA_ARGS__) #else #define dev_dbg(dev, fmt, ...) \ ({ \ if (0) \ dev_printk(KERN_DEBUG, dev, dev_fmt(fmt), ##__VA_ARGS__); \ }) #endif
如上dev_xx定义，其和pr_xx类似，都可以直接理解为printk+日志级别的封装，一般在linux驱动程序中使用；
同样需要注意，dev_dbg也不是无条件打印的，除非定义了DEBUG或设定了CONFIG_DYNAMIC_DEBUG。一个相关约定是在已经开启了 DEBUG 时，使用VERBOSE_DEBUG来添加dev_vdbg。
2.3 测试
目前在内核驱动代码中，都不再建议直接使用printk直接添加打印信息，而是使用dev_info、dev_dbg、dev_err之类的函数代替，虽然这些 dev_xxx 函数的本质还是使用printk打印的，但是相比起printk，dev_xxx 的好处是：
- 支持打印模块信息、dev信息；
- 支持动态调试（dynamic debug）方式；
比如，如下代码：
dev_warn(&rtc->dev, "invalid alarm value: %ptR\n", &alarm->time); // %ptR输出时间
输出日志如下：
rtc rtc0: invalid alarm value: 1900-02-01T00:00:00
三、实现原理
之前我们说printk会将日志输出到控制台，比如我们在uboot的bootargs里配置“console=ttySA0,115200”，这样将会将日志信息输出在串口UART0上。
同样如果配置“console=tty1 console=ttySA0,115200”，将会同时将将日志信息输出到串口UART0以及LCD屏幕上。
显然printk根据命令行参数来调用不同控制台的硬件处理函数来输出日志。接下来我们研究一下printk函数的源码。
3.1 printk函数
我们看一下printk函数调用栈，首先定位到printk函数，函数定义在kernel/printk/printk.c
/** * 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_lock. 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 console_unlock(); and will * send it to the consoles before releasing the lock. * * 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 __visible int printk(const char *fmt, ...) { va_list args; int r; va_start(args, fmt); r = vprintk_func(fmt, args); va_end(args); return r; }
该函数最终会调用vprintk_func，参数args和fmt的值就是我们printk传入的参数。
va_start和va_end宏定义如下：
#define va_start(v, l) __builtin_va_start(v, l) #define va_end(v) __builtin_va_end(v)
3.1.1 vprintk_func
vprintk_func函数定义在kernel/printk/printk_safe.c；
//关于vprintk_func()函数，首先来看如下的宏定义： #define __printf(a, b) __attribute__((__format__(printf, a, b))) //该宏定义主要通过__format__属性，来让编译器按照printf()函数的参数格式来对函数的参数进行检查。 __printf(1, 0) int vprintk_func(const char *fmt, va_list args) { /* * Try to use the main logbuf even in NMI. But avoid calling console * drivers that might have their own locks. */ if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK) && raw_spin_trylock(&logbuf_lock)) { int len; len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args); raw_spin_unlock(&logbuf_lock); defer_console_output(); return len; } /* Use extra buffer in NMI when logbuf_lock is taken or in safe mode. */ if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK) return vprintk_nmi(fmt, args); /* Use extra buffer to prevent a recursion deadlock in safe mode. */ if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK) return vprintk_safe(fmt, args); /* No obstacles. */ return vprintk_default(fmt, args); }
可以看到，这个函数有三个分支：vprintk_nmi、vprintk_safe、vprintk_default。其中：
- vprintk_default：正常走的分支；
- vprintk_nmi：在nmi中断中调用printk走的分支；
- vprintk_safe：在不安全的上下文中调用printk走的分支。
下面我们主要以vprintk_default为例分析。
3.1.2 vprintk_default
我们知道，printk最终会将日志信息保存在内核日志缓冲区__log_buf中。如果多核同时调用printk，则最简单的情况，都走到vprintk_default分支，最终是由logbuf_lock_irqsave以及logbuf_unlock_irqrestore来完成并发处理的。
int vprintk_default(const char *fmt, va_list args) { int r; //假设配置中，未开启KGDB，则直接执行vprintk_emit函数。 #ifdef CONFIG_KGDB_KDB if (unlikely(kdb_trap_printk && kdb_print_cpu < 0)) { r = vkdb_printf(KDB_MSGRC_PRINTK, fmt, args); } #endif r = vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args); //这里，默认日志等级为-1,即#define LOGLEVEL_DEFAULT -1。 return r; } asmlinkage int vprintk_emit(int facility, int level, const char *dict, size_t ditclen, const char *fmt, va_list args) { int printed_len; bool in_sched = false, pending_output; unsigned long flags; u64 curr_log_seq; if (unlikely(suppress_printk)) //suppress_printk为全局只读变量，假设该值当前为0。 return 0; if (level == LOGLEVEL_SCHED) { //在当前情况下，level并不为LOGLEVEL_SCHED，因此条件不成立 level = LOGLEVEL_DEFAULT; in_sched = true; } //延时 boot_delay_msce(level); prinkt_delay(); logbuf_lock_irqsave(flags); curr_log_seq = log_next_seq; printed_len = vprintk_store(facility, level, dict, dictlen, fmt, args); //将所要输出的内容保存到内核日志缓冲区log_buf pending_output = (curr_log_seq != log_next_seq) logbuf_unlock_irqrestore(flags); if (!in_sched && pending_output) { //in_sched为false，且pending_output为true。因此，该条件成立 ... preempt_disable(); if (console_trylock_spinning()) console_unlock(); //根据设定的日志级别决定是否将日志缓冲中的内容输出到console premmpt_enable(); } ... }
vprintk_default的流程大致可以分为两步：
- 调用vprintk_store将所有日志输出到内核的日志缓冲区，该日志缓冲区是一个循环缓冲区，其地址可以在内核中用log_buf变量访问；
- 调用console_unlock根据设定的日志级别决定是否将日志输出到console；
3.1.3 vprintk_store
vprintk_store将所有日志输出到内核的日志缓冲区log_buf中；
//将所要输出的内容保存到内核日志缓冲区log_buf int vprintk_store(int facility, int level, const char *dict, size_t dictlen, const char *fmt, va_list args) { static char textbuf[LOG_LINE_MAX]; char *text = textbuf; size_t text_len; enum log_flags lflags = 0; text_len = vscnprintf(text, sizeof(textbuf), fmt, args); //该函数最终通过调用vsprintf()函数，vsprintf函数通过对fmt进行解析，将参数按照fmt格式填入，并将最终字符串写入text中。text_len表示写入的字节数。 if (text_len && text[text_len - 1] == '\n') { text_len--; lflags |= LOG_NEWLINE; } if (facility == 0) { int kern_level; while ((kern_level = printk_get_level(text)) != 0) {//如果text的首字符为‘\001’，且第二字符为0～7或c,则返回第二字符。否则，返回0。假设当前返回值为0。 switch (kern_level) { case '0' ... '7': if (level == LOGLEVEL_DEFAULT) level = kern_level - '0'; break; case 'c': lflags |= LOG_CONT; } text_len -= 2; text += 2; } } if (level == LOGLEVEL_DEFAULT) //如果等级为默认的，则将其值更改为dafault_message_loglevel。 level = default_message_loglevel; if (dict) lflags |= LOG_NEWLINE; //开始调用日志输出函数。 return log_output(facility, level, lflags, dict, dictlen, text, text_len); } static size_t log_output(int facility, int level, enum log_flags lflags, const char *dict, size_t dictlen, char *text, size_t text_len) { const u32 caller_id = printk_caller_id(); //首先获取一个caller_id，即当前的进程号。 if (cont.len) { //cont为类型为struct cont的全局变量，启动阶段cont.len为0。跳过该执行条件 if (cont.caller_id == caller_id && (lflags & LOG_CONT)) { if (cont_add(caller_id, facility, level, lflags, text, text_len)) return text_len; } cont_flush(); } if (!text_len && (lflags & LOG_CONT)) return 0; if (!(lflags & LOG_NEWLINE)) { //假设当前输出的内容为完整的一行内容，也会跳过该执行条件 if (cont_add(caller_id, facility, level, lflags, text, text_len)) return text_len; } //将所要输出的内容保存到内核日志缓冲区log_buf return log_store(caller_id, facility, level, lflags, 0, dict, dictlen, text, text_len); } static int log_store(u32 caller_id, int facility, int level, enum log_flags flags, u64 ts_nsec, const char *dict, u16 dict_len, const char *text, u16 text_len) { ... msg = (struct printk_log *)(log_buf + log_next_idx); //申请struct printk_log结构体对象，log_buf就是内核日志缓冲区 memcpy(log_text(msg), text, text_len); //将所要输出的内容复制到申请的struct printk_log结构体对象中 msg->text_len = text_len; ... /* insert message */ log_next_idx += msg->len; log_next_seq++; return msg->text_len; }
其中log_text函数定义如下：
/* human readable text of the record */ static char *log_text(const struct printk_log *msg) { return (char *)msg + sizeof(struct printk_log); }
在上述代码中出现了两个结构体，这里对它们进行简单的说明：
struct printk_log { u64 ts_nsec; u16 len; u16 text_len; u16 dict_len; u8 facility; u8 flags:5; u8 level:3; #iddef CONFIG_PRINTK_CALLER u32 caller_id #endif } #ifdef CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS __packed __aligned(4) #endif ; static struct cont { char buf[LOG_LINE_MAX]; size_t len; u32 caller_id; u64 ts_nesc; u8 level; u8 facility; enum log_flags flags; } cont;
3.1.4 console_unlock
通过log_store函数可以知道printk函数将所要输出的日志全部存储到内核日志缓冲区log_buf的一段空间中。内核中有一些全局变量会记录当前日志缓冲区log_buf以及console的状态信息；
/* the next printk record to read by syslog(READ) or /proc/kmsg */ static u64 syslog_seq; static u32 syslog_idx; static size_t syslog_partial; static bool syslog_time; /* index and sequence number of the first record stored in the buffer */ static u64 log_first_seq; static u32 log_first_idx; // 第一条日志在log_buf的索引，为什么记录这个？是因为log_buf是作为环形缓冲区使用的，所以要记录日志存储的起始位置； /* index and sequence number of the next record to store in the buffer */ static u64 log_next_seq; // 日志的总数量 static u32 log_next_idx; // 下一条日志写入log_buf的索引 /* the next printk record to write to the console */ static u64 console_seq; // 通过console输出日志的数量 static u32 console_idx; // console输出的下一条日志位于log_buf的索引 static u64 exclusive_console_stop_seq; /* the next printk record to read after the last 'clear' command */ static u64 clear_seq; static u32 clear_idx;
随后通过struct printk_log *msg= log_from_idx(console_idx)获取到需要输出的日志信息，从而通过console打印出内容。打印日志信息由console_unlock函数来完成。
void console_unlock(void) { static char ext_text[CONSOLE_EXT_LOG_MAX]; static char text[LOG_LINE_MAX + PREFIX_MAX]; ... for (;;) { ... msg = log_from_idx(console_idx); // (struct printk_log *)(log_buf + idx)即从log_buf缓冲区获取要输出的日志信息 ... len += msg_print_text(msg,console_msg_format & MSG_FORMAT_SYSLOG,printk_time, text + len, sizeof(text) - len); // 将要输出的日志存储到text ... console_idx = log_next(console_idx); console_seq++; ... call_console_drivers(ext_text, ext_len, text, len); //调用控制台驱动 ... } ... } static void call_console_drivers(const char *ext_text, size_t ext_len, const_char *text, size_t len) { struct console *con; trace_console_rcuidle(text, len); for_each_console(con) { //遍历以console_drivers为表头的链表，访问每一个已经注册的console，并调用该console中定义的write方法来打印日志信息 ... if (con->flags & CON_EXTENDED) con->write(con, ext_text, ext_len); else con->write(con, text, len); //通用模式下的打印日志信息方法 } }
可以看到console_unlock函数会遍历注册的console_drivers链表，然后调用每一个console的write方法将text中存储的日志打印出来。
既然我们已经了解到printk函数实际上就是遍历控制台链表console_drivers，调用console的write函数输出日志，那么console是如何注册的呢？内核提供了register_console函数进行控制台的注册。
3.1.5 总结
printk函数主要做两件事情：第一件就是将信息记录到log_bug中，而第二件事就是调用控制台驱动来将信息输出。
3.2 控制台注册
register_console函数用于注册控制台，它支持两种类型的控制台：boot console和real console，它们有不同的处理方式。可以注册任意数量的boot console，一旦注册了一个real console，所有的boot console将自动取消注册，如果尝试注册boot console ，将被拒绝。
其注册流程：就是遍历console_cmdline全局数组，如果console_cmdline[i].name和注册的console的name匹配，就将该console添加到console_drivers链表，函数定义在kernel/printk/printk.c。
/* * The console driver calls this routine during kernel initialization * to register the console printing procedure with printk() and to * print any messages that were printed by the kernel before the * console driver was initialized. * * This can happen pretty early during the boot process (because of * early_printk) - sometimes before setup_arch() completes - be careful * of what kernel features are used - they may not be initialised yet. * * There are two types of consoles - bootconsoles (early_printk) and * "real" consoles (everything which is not a bootconsole) which are * handled differently. * - Any number of bootconsoles can be registered at any time. * - As soon as a "real" console is registered, all bootconsoles * will be unregistered automatically. * - Once a "real" console is registered, any attempt to register a * bootconsoles will be rejected */ void register_console(struct console *newcon) { int i; unsigned long flags; struct console *bcon = NULL; struct console_cmdline *c; static bool has_preferred; if (console_drivers) // 全局链表，存放注册的console for_each_console(bcon) // 校验console是否重复注册 if (WARN(bcon == newcon, "console '%s%d' already registered\n", bcon->name, bcon->index)) return; /* * before we register a new CON_BOOT console, make sure we don't * already have a valid console */ if (console_drivers && newcon->flags & CON_BOOT) { // 注册的console类型判断，带有CON_BOOT标志 /* find the last or real console */ for_each_console(bcon) { if (!(bcon->flags & CON_BOOT)) { // 查找是否注册过非CON_BOOT类型的控制台，如果注册过了，就退出 pr_info("Too late to register bootconsole %s%d\n", newcon->name, newcon->index); return; } } } if (console_drivers && console_drivers->flags & CON_BOOT) bcon = console_drivers; if (!has_preferred || bcon || !console_drivers) has_preferred = preferred_console >= 0; /* * See if we want to use this console driver. If we * didn't select a console we take the first one * that registers here. */ if (!has_preferred) { if (newcon->index < 0) newcon->index = 0; if (newcon->setup == NULL || newcon->setup(newcon, NULL) == 0) { newcon->flags |= CON_ENABLED; if (newcon->device) { newcon->flags |= CON_CONSDEV; has_preferred = true; } } } /* * See if this console matches one we selected on * the command line. */ for (i = 0, c = console_cmdline; i < MAX_CMDLINECONSOLES && c->name[0]; // 判断bootargs中配置的控制台的名称是否和当前注册的console的名字匹配，如果配置就注册 i++, c++) { if (!newcon->match || newcon->match(newcon, c->name, c->index, c->options) != 0) { /* default matching */ BUILD_BUG_ON(sizeof(c->name) != sizeof(newcon->name)); if (strcmp(c->name, newcon->name) != 0) // 匹配name continue; if (newcon->index >= 0 && // 匹配index newcon->index != c->index) continue; if (newcon->index < 0) newcon->index = c->index; if (_braille_register_console(newcon, c)) return; if (newcon->setup && newcon->setup(newcon, c->options) != 0) // 调用其setup函数 break; } newcon->flags |= CON_ENABLED; if (i == preferred_console) { newcon->flags |= CON_CONSDEV; has_preferred = true; } break; } if (!(newcon->flags & CON_ENABLED)) return; /* * If we have a bootconsole, and are switching to a real console, * don't print everything out again, since when the boot console, and * the real console are the same physical device, it's annoying to * see the beginning boot messages twice */ if (bcon && ((newcon->flags & (CON_CONSDEV | CON_BOOT)) == CON_CONSDEV)) newcon->flags &= ~CON_PRINTBUFFER; /* * Put this console in the list - keep the * preferred driver at the head of the list. */ console_lock(); if ((newcon->flags & CON_CONSDEV) || console_drivers == NULL) { newcon->next = console_drivers; console_drivers = newcon; if (newcon->next) newcon->next->flags &= ~CON_CONSDEV; } else { newcon->next = console_drivers->next; console_drivers->next = newcon; } if (newcon->flags & CON_EXTENDED) nr_ext_console_drivers++; if (newcon->flags & CON_PRINTBUFFER) { /* * console_unlock(); will print out the buffered messages * for us. */ logbuf_lock_irqsave(flags); console_seq = syslog_seq; console_idx = syslog_idx; /* * We're about to replay the log buffer. Only do this to the * just-registered console to avoid excessive message spam to * the already-registered consoles. * * Set exclusive_console with disabled interrupts to reduce * race window with eventual console_flush_on_panic() that * ignores console_lock. */ exclusive_console = newcon; exclusive_console_stop_seq = console_seq; logbuf_unlock_irqrestore(flags); } console_unlock(); console_sysfs_notify(); /* * By unregistering the bootconsoles after we enable the real console * we get the "console xxx enabled" message on all the consoles - * boot consoles, real consoles, etc - this is to ensure that end * users know there might be something in the kernel's log buffer that * went to the bootconsole (that they do not see on the real console) */ pr_info("%sconsole [%s%d] enabled\n", (newcon->flags & CON_BOOT) ? "boot" : "" , // 这里会输出控制台的注册信息 newcon->name, newcon->index); if (bcon && ((newcon->flags & (CON_CONSDEV | CON_BOOT)) == CON_CONSDEV) && !keep_bootcon) { /* We need to iterate through all boot consoles, to make * sure we print everything out, before we unregister them. */ for_each_console(bcon) if (bcon->flags & CON_BOOT) unregister_console(bcon); } }
当控制台注册完成后，会输出控制台的注册信息，比如：
printk: bootconsole [earlycon0] enabled
printk: console [ttySAC0] enabled
3.3 uart console注册
我们在linux驱动移植-UART设备驱动小节中介绍过uart_driver：
static struct uart_driver s3c24xx_uart_drv = { .owner = THIS_MODULE, .driver_name = "s3c2410_serial", .nr = CONFIG_SERIAL_SAMSUNG_UARTS, // 串口数量定义为4个，实际S3C2440只有3个 .cons = S3C24XX_SERIAL_CONSOLE, .dev_name = S3C24XX_SERIAL_NAME, // 设备名称ttySAC .major = S3C24XX_SERIAL_MAJOR, // 主设备号 204 .minor = S3C24XX_SERIAL_MINOR, // 次设备号 64 };
其中cons成员存储的是控制台，定义如下：
static struct console s3c24xx_serial_console = { .name = S3C24XX_SERIAL_NAME, // 控制台名称 ttySAC .device = uart_console_device, // 控制台设备 .flags = CON_PRINTBUFFER, // 标志位 .index = -1, // 索引值 .write = s3c24xx_serial_console_write, // 串口输出 .setup = s3c24xx_serial_console_setup, // 设置串口波特率、发送、接收等功能 .data = &s3c24xx_uart_drv, // 串口驱动uart_driver }; #define S3C24XX_SERIAL_CONSOLE &s3c24xx_serial_console
控制台s3c24xx_serial_console的是通过console_initcall注册到内核的，代码位于drivers/tty/serial/samsung.c:
static int __init s3c24xx_serial_console_init(void) { register_console(&s3c24xx_serial_console); return 0; } console_initcall(s3c24xx_serial_console_init);
在register_console函数里便会通过s3c24xx_uart_drv的name属性（这里是ttySAC）来匹配console_cmdline[i].name，当匹配成功，就会将控制台s3c24xx_uart_drv添加到console_drivers链表。那问题又来了，console_cmdline是什么？在哪里定义和初始化的？我们先来看一下uart控制台的write函数，然后再来说console_cmdline。
3.3.1 s3c24xx_serial_console_write
通过console_initcall我们注册了s3c24xx_serial_console，其write函数为s3c24xx_serial_console_write，该函数实际上就是通过对硬件寄存器配置，从而实现数据的发送。
函数定义在drivers/tty/serial/samsung.c:：
static int s3c24xx_serial_console_txrdy(struct uart_port *port, unsigned int ufcon) { struct s3c24xx_uart_info *info = s3c24xx_port_to_info(port); unsigned long ufstat, utrstat; if (ufcon & S3C2410_UFCON_FIFOMODE) { /* fifo mode - check amount of data in fifo registers... */ ufstat = rd_regl(port, S3C2410_UFSTAT); return (ufstat & info->tx_fifofull) ? 0 : 1; } /* in non-fifo mode, we go and use the tx buffer empty */ utrstat = rd_regl(port, S3C2410_UTRSTAT); return (utrstat & S3C2410_UTRSTAT_TXE) ? 1 : 0; } static bool s3c24xx_port_configured(unsigned int ucon) { /* consider the serial port configured if the tx/rx mode set */ return (ucon & 0xf) != 0; } static void s3c24xx_serial_console_putchar(struct uart_port *port, int ch) { unsigned int ufcon = rd_regl(port, S3C2410_UFCON); while (!s3c24xx_serial_console_txrdy(port, ufcon)) cpu_relax(); wr_regb(port, S3C2410_UTXH, ch); // UTXH UART发送缓冲区寄存器 } static void s3c24xx_serial_console_write(struct console *co, const char *s, unsigned int count) { unsigned int ucon = rd_regl(cons_uart, S3C2410_UCON); /* not possible to xmit on unconfigured port */ if (!s3c24xx_port_configured(ucon)) return; uart_console_write(cons_uart, s, count, s3c24xx_serial_console_putchar); }
3.4 console_cmdline
我们定位到kernel/printk/printk.c文件以下代码：
_setup("console=", console_setup);
其中_setup宏的作用就是：若uboot传递进来的bootargs字符包含"console="，就调用console_setup函数，并对"console="后面的字符串“ttySAC0,115200”进行解析。
需要注意的是：console_setup函数的执行优先级高于s3c24xx_serial_console_init。
3.4.1 console_setup
console_setup函数定义如下：
/* * Set up a console. Called via do_early_param() in init/main.c * for each "console=" parameter in the boot command line. */ static int __init console_setup(char *str) // "ttySAC0,115200" { char buf[sizeof(console_cmdline[0].name) + 4]; /* 4 for "ttyS" 声明一个字符数组，长度为20 */ char *s, *options, *brl_options = NULL; int idx; if (_braille_console_setup(&str, &brl_options)) return 1; /* * Decode str into name, index, options. */ if (str[0] >= '0' && str[0] <= '9') { // 首字符是数字，则将其驱动名设置为ttySn strcpy(buf, "ttyS"); strncpy(buf + 4, str, sizeof(buf) - 5); } else { strncpy(buf, str, sizeof(buf) - 1); // 直接拷贝 buf="ttySAC0,115200" } buf[sizeof(buf) - 1] = 0; options = strchr(str, ','); // 返回第一个,字符位置 此时options=",115200" if (options) *(options++) = 0; // options="115200" str="ttySAC0" #ifdef __sparc__ if (!strcmp(str, "ttya")) strcpy(buf, "ttyS0"); if (!strcmp(str, "ttyb")) strcpy(buf, "ttyS1"); #endif for (s = buf; *s; s++) if (isdigit(*s) || *s == ',') break; // s = ",115200" idx = simple_strtoul(s, NULL, 10); // 执行完 idx=0 s="0,115200" *s = 0; // 将'0'修改为0 buf="ttySAC" __add_preferred_console(buf, idx, options, brl_options); console_set_on_cmdline = 1; return 1; }
函数中console_cmdline是一个全局数组，数组长度为8，用来存放控制台的信息：
/* * Array of consoles built from command line options (console=) */ #define MAX_CMDLINECONSOLES 8 static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];
上面的代码最终调用__add_preferred_console("ttySAC", 0, "115200",...)将bootargs中传进来的控制台信息添加到console_cmdline全局数组。
补充：console_cmdline类型定义如下：
struct console_cmdline { char name[16]; /* Name of the driver 驱动名称 */ int index; /* Minor dev. to use 次设备号 */ char *options; /* Options for the driver 选项 */ #ifdef CONFIG_A11Y_BRAILLE_CONSOLE char *brl_options; /* Options for braille driver */ #endif };
3.4.2 __add_preferred_console
__add_preferred_console函数定义如下，该函数将控制台信息添加到console_cmdline全局数组，该数组及全局preferred_console ，在register_console中会使用到。
static int __add_preferred_console(char *name, int idx, char *options, char *brl_options) { struct console_cmdline *c; int i; /* * See if this tty is not yet registered, and * if we have a slot free. */ for (i = 0, c = console_cmdline; i < MAX_CMDLINECONSOLES && c->name[0]; // MAX_CMDLINECONSOLES为8，表示最多添加8个控制台 判断要添加的控制台信息在console_cmdline数组是否已经存在 i++, c++) { if (strcmp(c->name, name) == 0 && c->index == idx) { // 比较名称和索引 if (!brl_options) preferred_console = i; //设置全局selected_console索引号 return 0; } } if (i == MAX_CMDLINECONSOLES) //判断console_cmdline数组是否满了 return -E2BIG; if (!brl_options) preferred_console = i; strlcpy(c->name, name, sizeof(c->name)); // 添加控制台信息到console_cmdline数组第i个元素中 c->options = options; braille_set_options(c, brl_options); c->index = idx; return 0; }
3.5 early_console注册
我们已经知道printk函数打印日志信息是通过console的的write方法实现的，那么不知道你有没有想过一个问题，在linux内核启动的过程中， 我们一直能看到串口输出的启动信息，仔细思考一下，在linux系统还未注册串口控制台s3c24xx_serial_console_init之前这些日志信息是如何打印出来。
如果通过make menuconfig配置了CONFIG_EARLY_PRINTK（需要注意的是在arm64已经没有实现early_printk了）：
obj-$(CONFIG_EARLY_PRINTK) += early_printk.o
在控制台s3c24xx_serial_console注册之前，内核会通过register_console注册一个名字为earlycon的控制台early_console_dev，我们来看一下early_console_dev到底是什么，它是如何注册到内核的。
early_console_dev相关代码定义在arch/arm/kernel/early_printk.c文件中：
include <linux/kernel.h> #include <linux/console.h> #include <linux/init.h> #include <linux/string.h> extern void printascii(const char *); static void early_write(const char *s, unsigned n) { char buf[128]; while (n) { unsigned l = min(n, sizeof(buf)-1); memcpy(buf, s, l); // 一次最多拷贝128个字节到buf buf[l] = 0; s += l; n -= l; printascii(buf); // 一次最多发送128个字节 } } static void early_console_write(struct console *con, const char *s, unsigned n) { early_write(s, n); } static struct console early_console_dev = { // 此处定义了一个console设备 .name = "earlycon", .write = early_console_write, // 内核早期输出的信息都是通过该函数实现的 .flags = CON_PRINTBUFFER | CON_BOOT, .index = -1, }; static int __init setup_early_printk(char *buf) // earlycon初始化入口 { early_console = &early_console_dev; register_console(&early_console_dev); // 注册early_console_dev return 0; } early_param("earlyprintk", setup_early_printk);
CON_PRINTBUFFER标识，表示注册这个console的时候，需要把内核缓冲区__log_buf中的日志通过这个console进行输出。
CON_BOOT标识，表示这是一个boot console，当启动过程了注册其它非boot console的时候，将会卸载掉这个console。
可以看到只要调用了setup_early_printk函数，就可以实现控制台early_console_dev的注册。
3.5.1 early_param
我们看一下最后一行代码，early_param是一个宏，定义在include/linux/init.h：
/* * Only for really core code. See moduleparam.h for the normal way. * * Force the alignment so the compiler doesn't space elements of the * obs_kernel_param "array" too far apart in .init.setup. */ #define __setup_param(str, unique_id, fn, early) \ static const char __setup_str_##unique_id[] __initconst \ __aligned(1) = str; \ static struct obs_kernel_param __setup_##unique_id \ __used __section(.init.setup) \ __attribute__((aligned((sizeof(long))))) \ = { __setup_str_##unique_id, fn, early } #define __setup(str, fn) \ __setup_param(str, fn, fn, 0) /* * NOTE: fn is as per module_param, not __setup! * Emits warning if fn returns non-zero. */ #define early_param(str, fn) \ __setup_param(str, fn, fn, 1)
展开如下，定义一个变量，和一个结构体变量。结构体变量，放在了.init.setup段中；
static const char __setup_str_setup_early_printk[] __initconst \ __aligned(1) = "earlyprintk"; \ static struct obs_kernel_param __setup_setup_early_printk \ __used __section(.init.setup) \ __attribute__((aligned((sizeof(long))))) \ = {"earlyprintk", setup_early_printk, 1 }
struct obs_kernel_param定义如下：
struct obs_kernel_param { const char *str; // 设置为了"earlyprintk" int (*setup_func)(char *); // 设置为了setup_early_printk int early; // 设置为了1 };
在init/main.c文件中，通过uboot传递给内核的bootargs参数，进行early初始化。
start_kernel() // init/main.c 内核启动函数 pr_notice("%s", linux_banner); setup_arch(&command_line); // arch/arm/kernel/setup.c parse_early_param(); // init/main.c
pr_notice用于输出当前内核banner信息，该打印输出位于early print之前，且能正常的打出内核的banner：
Linux version 5.2.8 (root@zhengyang) (gcc version 4.8.3 20140320 (prerelease) (Sourcery CodeBench Lite 2014.05-29)) #11 Mon Apr 24 22:09:14 CST 2023
这主要是因为日志信息被寄存到了缓存区__log_buf中，等early print初始化完成后再从缓冲区输出来。
3.5.2 parse_early_param
parse_early_param定义在 init/main.c文件：
/* Arch code calls this early on, or if not, just before other parsing. */ void __init parse_early_param(void) { static int done __initdata; static char tmp_cmdline[COMMAND_LINE_SIZE] __initdata; if (done) return; /* All fall through to do_early_param. */ strlcpy(tmp_cmdline, boot_command_line, COMMAND_LINE_SIZE); // boot_command_line中保存的就是bootargs参数 parse_early_options(tmp_cmdline); done = 1; }
通过parse_early_options函数，分析cmdline，也就是bootargs参数，比如Mini2440将该参数设置为root=/dev/mtdblock3 console=ttySAC0,115200 init=/linuxrc earlyprintk；
void __init parse_early_options(char *cmdline) { parse_args("early options", cmdline, NULL, 0, 0, 0, NULL, do_early_param); }
这里通过统一的parse_args函数处理，函数原型如下：
int parse_args(const char *name, char *args, const struct kernel_param *params, unsigned num, int (*unknown)(char *param, char *val))
这个函数的处理方法主要是分离出每个类似“console=ttySAC0,115200"的形式，再给next_arg分离出参数名和参数值，并通过参数名在params指向的地址中搜索对应的数据结构，并调用其参数处理函数。如果没有找到就调用最后一个参数unknown传递进来的未知参数处理函数。由于此处params为NULL，必然找不到对应的数据结构，所有分离好的参数及参数名都由最后一个函数指针参数指定的函数do_early_param来处理。
因此，我们的bootargs岑姝：
root=/dev/mtdblock3 console=ttySAC0,115200 init=/linuxrc earlyprintk
将会被分成多个key-value对，并多次调用do_early_param函数进行处理。
root=/dev/mtdblock3 console=ttySAC0,115200 init=/linuxrc earlyprintk
其中key传递给给do_early_param函数的param参数，value传递给do_early_param函数的val参数。
3.5.3 do_early_param
do_early_param函数定义在init/main.c：
/* Check for early params. */ static int __init do_early_param(char *param, char *val, const char *unused, void *arg) { const struct obs_kernel_param *p; for (p = __setup_start; p < __setup_end; p++) { // 实际上就是遍历通过early_param宏注册的struct obs_kernel_param类型的数据 if ((p->early && parameq(param, p->str)) || // __setup_setup_early_printk的成员early为1，str为earlyprintk (strcmp(param, "console") == 0 && strcmp(p->str, "earlycon") == 0) ) { if (p->setup_func(val) != 0) pr_warn("Malformed early option '%s'\n", param); } } /* We accept everything at this stage. */ return 0; }
这里的__setup_start、__setup_end，是链接脚本中的变量，定义在arch/arm/kernel/vmlinux.lds，内容如下：
__setup_start = .; KEEP(*(.init.setup)) __setup_end = .;
__setup_start变量是段.init.setup的起始地址，__setup_end是.init.setup段的结束地址。
do_early_param函数的for循环中，从.init.setup段中，依次将struct obs_kernel_param结构体变量取出来，有两种情况会执行该结构体的setup_func函数。
- 如果成员early = 1并且bootargs中存在该结构体的str字符串；
- 如果该结构体的str为earlycon（即early_param宏第一个参数为earlycon），并且bootargs中有console关键字；
在前面，__setup_setup_early_printk变量是定义在.init.setup段。由于bootargs传递了earlyprintk参数，与__setup_setup_early_printk.str匹配，因此这里将会执行setup_early_printk函数，该函数会注册控制台early_console_dev。
3.5.4 printascii
控制台early_console_dev ，其write函数为early_console_write，该函数内部调用了early_write，而early_write又调用了printascii函数进行串口数据的输出。
printascii函数函数定义在arch/arm/kernel/debug.S：
ENTRY(printascii) addruart_current r3, r1, r2 1: teq r0, #0 ldrbne r1, [r0], #1 teqne r1, #0 reteq lr 2: teq r1, #'\n' bne 3f mov r1, #'\r' waituart r2, r3 senduart r1, r3 busyuart r2, r3 mov r1, #'\n' 3: waituart r2, r3 senduart r1, r3 busyuart r2, r3 b 1b ENDPROC(printascii) ENTRY(printch) addruart_current r3, r1, r2 mov r1, r0 mov r0, #0 b 2b ENDPROC(printch)
addruart_current 、waituart 、senduart 、busyuart就是往寄存器赋值控制了。
注意：直接往寄存器写值实现串口打印，是基于我们在uboot中已经把串口初始化过了。
addruart_current 和 addruart 都是宏定义，各个平台实现自己的 addruart 宏。
addruart_current 定义在arch/arm/kernel/debug.S：
#ifdef CONFIG_MMU .macro addruart_current, rx, tmp1, tmp2 addruart \tmp1, \tmp2, \rx mrc p15, 0, \rx, c1, c0 tst \rx, #1 moveq \rx, \tmp1 movne \rx, \tmp2 .endm #else /* !CONFIG_MMU */ .macro addruart_current, rx, tmp1, tmp2 addruart \rx, \tmp1, \tmp2 .endm #endif /* CONFIG_MMU */
addruart定义在在arch/arm/include/debug/s3c24xx.S文件：
#include <linux/serial_s3c.h>
.macro addruart, rp, rv, tmp
ldr \rp, = CONFIG_DEBUG_UART_PHYS // 0x50004000
ldr \rv, = CONFIG_DEBUG_UART_VIRT // 0xf7004000
.endm
作用是将串口寄存器基地址的虚拟地址和物理地址传递给寄存器r1、r3,
3.6 总结
综上分析，可知当执行printk函数时：
- 首先会将所要输出的信息寄存到日志缓冲区；
- 随后遍历所有的控制台，检查其是否满足当前要求，如果满足，则调用该控制台所指定的write函数，从而打印信息；
所以，关于内核启动时的日志打印，也需要在注册某个console之后，再次调用printk函数来进行日志的输出。
因此，内核在启动阶段首先注册了用于启动阶段的console，即early_console。随后，又初始化了内核启动之后的console，即s3c24xx_serial_console。与此同时，将前面注册的early_console进行了注销。
参考文章
[1]34.Linux-printk分析、使用__FILE__, __FUNCTION__, __LINE__ 调试
[2]Linux内核之 printk 打印（转）
[3]内核printk原理介绍
[4]How to get printk format specifiers right
[7]printk()函数分析
