linux printk

by sven — on  ,  , 

###1. printk

printk 是 linux kernel 中的 printf

printk最大的优点是：你能在任何地方调用它–在中断上下文， 进程上下文， 持有锁的地方，在多处理器上。唯一不好的是，你必须要等到终端初始化好， printk才能工作（另外，在suspend的过程中， printk也会停止工作）。在终端和控制台被初始化之前printk的所有信息都被缓存在printk的简单的ring buffer（环形缓冲区）中，直到终端和控制台被初始化之后，所有缓存信息都被一并输出。

###2. 当printk还没有开始工作时

如果你要调试的是启动过程最开始的部分（如setup_arch()），此时printk()还不可使用， 可以依靠此时能够工作的硬件设备（如串口）与外界通信，使用printk()的变体early_printk()函数。她在启动过程初期就具有在终端上打印的能力，功能与prink()类似，区别在于：

  • 函数名
  • 能够更早地工作（输出信息）
  • 她有自己的小缓存（一般为512B）
  • 一次性输出到硬件设备，不再以ring buffer的形式保留信息。
  • 该函数在一些构架上无法实现，所以这种办法缺少可移植性。（大多数构架都可以，包括x86和arm）。

###3. printk的缺点

  • 这个函数的效率很低：做字符拷贝时一次只拷贝一个字节，且去调用console输出可能还产生中断。所以如果你的驱动在功能调试完成以后做性能测试或者发布的时候千万记得尽量减少printk输出，做到仅在出错时输出少量信息。
  • printk的临时缓存printk_buf只有1K，所有一次printk函数只能记录&lt1K的信息到log buffer

###4. printk的消息等级

printk和c库的printf功能基本相同，但是printk多了一个调试等级

printk(LEVEL "debug string\n");

可选的debug level有

#define KERN_MERG		"0"
#define KERN_ALERT		"1"
#define KERN_CRIT		"2"
#define KERN_ERR		"3"
#define KERN_WARNING	"4"
#define KERN_NOTICE	"5"
#define KERN_INFO		"6"
#define KERN_DEBUG		"7"
#define KERN_DEFAULT	"d"
#define KERN_CONT		""

例如
printk(KERN_DEBUG “hello”);

linux 默认等级一般为 KERN_WARNING, 等级数字比它大的消息不会输出

如何改变默认的等级?, 有如下5种方法

  1. include/linux/kernel.h文件中， DEFAULT_CONSOLE_LOGLEVEL 宏
  2. CONFIG_DEFAULT_MESSAGE_LOGLEVEL, 在内核的配置时（make menuconfig-> Kernel Hacking -> Default message log level）
  3. /proc/sys/kernel/printk 有四个数字：控制台级别 缺省消息级别 最低控制台级别 缺省控制台级别
  4. klogctl 系统调用（曾用名syslog）
  5. dmesg 命令 ，如 “# dmesg -n 5” 将等级调到5

/proc/sys/kernel/printk 的信息如下

$ cat /proc/sys/kernel/printk
7       4       1       7
current	default	minimum	boot-time-default

例如要将printk的级别调到8

# echo 8 > /proc/sys/kernel/printk

KERN_CONT and pr_cont用于继续上在一条printk输出（没有“\n”）之后输出， 除了启动初期的 core/arch code，不要使用它（不是SMP安全的）

printk(KERN_ERR "Doing something was ");
/* <100 lines of whatever>*/
if (success)
   		printk(KERN_CONT "successful\n");
else
   		printk(KERN_CONT "NOT successful\n");

###5. printk的格式字符

常见的数据类型对应的printk的格式字符如下

  • int %d or %x
  • unsigned int %u, %x
  • long %ld, %lx
  • unsigned long %lu, %lx
  • long long %lld, %llx
  • unsigned long long %llu, %llx
  • size_t %zu, %zx
  • ssize_t %zd, %zx

####5.1 打印指针的扩展字符

使用 %p 来打印指针， 但是在printk里面对此进行了扩展

符号和函数指针

  • %pS, %pF 打印对应的符号名/函数名和偏移量
  • %ps, %pf 打印对应的符号名/函数名

在ia64， ppc64 等体系上， 函数指针其实是函数描述符， 因此需要进行转换， %pF与%pf会自动进行转换， 其它与%pS和%ps相同

打印受限的内核地址: %pK

  • %pK 且 /proc/sys/kernel/kptr_restrict = 0 时可直接打印
  • %pK 且 /proc/sys/kernel/kptr_restrict = 1 时所有的地址打印为0除非配置了CAP_SYSLOG
  • %pK 且 /proc/sys/kernel/kptr_restrict = 2 时所有的地址打印为0

打印结构资源

  • %pr 打印结构体资源
  • %pR 打印结构体资源，包含一个解码标记

打印物理地址

  • %pa

打印raw buffer（64字节以下，较大的buffer应使用print_hex_dump）

  • %*ph 空格分割，如 00 01 02
  • %*phC 冒号分割，如 00:01:02
  • %*phD 横杠分割，如 00-01-02
  • %*phN 无分割符，如 000102

打印MAC/FDDI

  • %pM 冒号分割， 如 00：01：02：03：04：05
  • %pMR 冒号分割，反序， 如 05：04;03；02：01：00
  • %pMF 横杠分割， 如 00-01-02-03-04-05
  • %pm 无分割， 如 000102030405
  • %pmR 无分割， 反序，如 0504030201

打印ipv4地址

  • %pI4 1.2.3.4的形式
  • %pi4 001.002.003.004的形式
  • [hnbl] 附加的’h’ ‘n’ ‘b’ ‘l’ 用于指定参数的字节序是主机字节序还是网络字节序， 或者是大端对齐还是小端对齐， printk 默认地址是网络字节序的, 并且自动转换为主机字节序再打印， 不需要做额外的字节序转换

打印ipv6地址

  • %pI6 0001:0002:0003；0004;0005；0006;0007:0008 的形式
  • %pi6 001002003004005006007008 的形式
  • %pI6C 1;2；3：4;5；6：7：8 的形式

打印 UUID/GUID

  • %pUb 小写字母大端序
  • %pUB 大写字母大端序
  • %pUl 小写字母小端序
  • %pUL 大写字母小端序

打印结构体

  • %pV 打印结构的各个成员的名称和值

###6. hex dump

有时候， 需要 dump 一个 binary buffer, 当大小超出了64byte之后， printk对此无能为力了， 需要借助 print_hex_dump()

void print_hex_dump(const char *level, const char *prefix_str,
		   int prefix_type, int rowsize, int groupsize,
		   const void *buf, size_t len, bool ascii);

还有一个dynamic debug版的 hex dump (dynamic debug是指可以在系统运行时， 控制是否打印某一条内核消息， 参见 dynamic debug 章节)

dynamic_hex_dump(prefix_str, prefix_type, rowsize, groupsize, buf, len, ascii)

###7. 基于 printk 的宏

每次使用printk都要指定log level太过于麻烦， 内核定义了一组宏

#ifndef pr_fmt
	#define pr_fmt(fmt) fmt
#endif

#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__)

#define pr_cont(fmt, ...) \
 	printk(KERN_CONT fmt, ##__VA_ARGS__)

###8. pr_debug, pr_devel

内核还定义了一组打印宏pr_devel在build debug版kernel时才会有效， 但是也可用DEBUG宏来开启

#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

还有一组宏pr_debug， 与pr_devel相比，它还能用于dynamic debug（详见dynamic debug章节）

#if defined(DEBUG)
	#define pr_debug(fmt, ...) \
 		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_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif

###9. 防止printk刷屏

在频繁被执行的地方， 插入 printk 会导致输出大量消息， 刷掉其它的消息， 为了控制printk输出的次数，

printk_ratelimited(...)

你需要 “#include <kernel/ratelimit.h>”

printk_ratelimited(…)会保证每一条在5秒钟内输出次数不大于10次， 如果你需要更精细的频率控制， 设置 DEFINE_RATELIMIT_STATE 宏并使用__ratelimit函数（可以参考printk_ratelimited(…)函数的实现）。

“/proc/sys/kernel/printk_ratelimit” 定义了消息之间的最小时间间隔， “/proc/sys/kernel/printk_ratelimit_burst”定义了消息的数量，即在 printk_ratelimit 秒内最多打印 printk_ratelimit_burst 条消息。

是的， 每一个level的printk还有 “pr_err_ratelimited”, “pr_debug_ratelimited”, “pr_info_ratelimited”这些对应的宏。

如果只需要打印一次的话， 可以使用

printk_once(...)

printk_once()会保证只被打印一次

###10. dev_xxx()

在开发设备驱动的过程中， 在输出消息时， 往往希望能够附带device相关的信息， 例如 device name等，可以使用 dev_printk()

int dev_printk(const char *level, const struct device *dev, const char *fmt, ...);

dev_printk() 能够额外输出设备的 driver name 或者 bus name， device name， 如果你对这些输出内容不满意的话， 可以基于__dev_printk()自己封装一个消息输出函数, dev_printk()正是基于该函数的封装

如果希望在 DEBUG 版中才输出消息， 或者是dynamic debug， 则可以使用 dev_dbg()

#if defined(CONFIG_DYNAMIC_DEBUG)
	#define dev_dbg(dev, format, ...)		     \
	do {						     \
		dynamic_dev_dbg(dev, format, ##__VA_ARGS__); \
	} while (0)
#elif defined(DEBUG)
	#define dev_dbg(dev, format, arg...)		\
	dev_printk(KERN_DEBUG, dev, format, ##arg)
#else
	#define dev_dbg(dev, format, arg...)				\
	({								\
		if (0)							\
			dev_printk(KERN_DEBUG, dev, format, ##arg);	\
		0;							\
	})
#endif

同样， 有限制输出频率的不同消息等级的 dev_xxx() 宏

#define dev_emerg_ratelimited(dev, fmt, ...)				\
dev_level_ratelimited(dev_emerg, dev, fmt, ##__VA_ARGS__)

#define dev_alert_ratelimited(dev, fmt, ...)				\
dev_level_ratelimited(dev_alert, dev, fmt, ##__VA_ARGS__)

#define dev_crit_ratelimited(dev, fmt, ...)				\
dev_level_ratelimited(dev_crit, dev, fmt, ##__VA_ARGS__)

#define dev_err_ratelimited(dev, fmt, ...)				\
dev_level_ratelimited(dev_err, dev, fmt, ##__VA_ARGS__)

#define dev_warn_ratelimited(dev, fmt, ...)				\
dev_level_ratelimited(dev_warn, dev, fmt, ##__VA_ARGS__)

#define dev_notice_ratelimited(dev, fmt, ...)				\
dev_level_ratelimited(dev_notice, dev, fmt, ##__VA_ARGS__)

#define dev_info_ratelimited(dev, fmt, ...)				\
dev_level_ratelimited(dev_info, dev, fmt, ##__VA_ARGS__)

DEBUG版 和 dynamic debug 版本也可以限制输出频率， dev_dbg_ratelimited()

#if defined(CONFIG_DYNAMIC_DEBUG) || defined(DEBUG)
	#define dev_dbg_ratelimited(dev, fmt, ...)				\
	do {									\
		static DEFINE_RATELIMIT_STATE(_rs,				\
			DEFAULT_RATELIMIT_INTERVAL,	\
			DEFAULT_RATELIMIT_BURST);		\
			DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt);			\
		if (unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT) &&	\
			__ratelimit(&_rs))						\
			__dynamic_pr_debug(&descriptor, pr_fmt(fmt),		\
			##__VA_ARGS__);			\
	} while (0)
#else
	#define dev_dbg_ratelimited(dev, fmt, ...)			\
	no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif

###11. 在用户空间打印内核消息

“/dev/kmsg“ 设备提供了在用户空间输出内核消息的途径， 如果你找不到它， 可以使用mknod -m 600 /dev/kmsg c 1 11命令来创建一个

# echo "Hello Kernel-World" > /dev/kmsg

或者你还可以使用前置数字来指明消息等级

# echo "2Writing critical printk messages from userspace" >/dev/kmsg

数字2等于 KERN_CRIT 的等级。

使用 dmesg -u 可以看到所有从用户空间打印的的内核消息

###12. 查看printk输出的消息

在用户空间， 可以使用如下几种方式查看 内核消息

  • dmesg 命令
  • cat /proc/kmsg (不会返回， 会一直等待并输出新的内核消息， 再次之前的消息不会输出)
  • cat //var/log/syslog

dmesg是最常用的方式， 使用dmesg命令时可以加一些控制参数

  • -C 清空存放内核消息的环形缓冲区
  • -c 列出内核消息然后清空环形缓冲
  • -k 仅仅打印从内核中输出的内核消息
  • -u 仅仅打印从用户空间打印的内核消息
  • -n 调整将被打印到控制台的消息的等级
  • -s 设置环形缓冲区的大小
sven's photo Author

sven

lishiwen4@gmail.com

实迷途其未远，觉今是而昨非