linux内核printk输出

Question

我是Linux内核开发方面的新手，当我尝试通过在timekeep.c文件中添加printk函数来修改系统调用函数时，例如

 printk("BEGIN!$$$$$\n");

dmesg实用程序给出了如下输出：

[   75.919335] BEGIN!$$$$$
[   75.919337] BEGIN!$$$$$
[   75.919340] BEGIN!$$$$$
[   75.919343] BEGIN!$$$$$
[   75.919347] BEGIN!$$$$$
[   75.919349] BEGIN!$$$$$
[   75.919353] BEGIN!$$$$$
[   75.919355] BEGIN!$$$$$
[   75.919358] BEGIN!$$$$$
[   75.919361] BEGIN!$$$$$
[   75.919364] BEGIN!$$$$$
[   75.919367] BEGIN!$$$$$
[   75.919370] BEGIN!$$$$$
[   75.919374] BEGIN!$$$$$

我真的不明白[]中的那些是如何生成的。有人能给我一点提示吗？

Answer 1

您的内核启用了CONFIG_PRINTK_TIME选项。此选项负责printk()消息之前的此时间戳字段。From kernel config选项

 "Selecting this option causes time stamps of the `printk()` messages to be
  added to the output of the `syslog()` system call and at the console."

来源：https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/lib/Kconfig.debug#n2

此选项可在内核配置时通过"Kernel Hacking“配置字段进行配置。您可以通过内核命令行参数启用/禁用它:printk.time=0 (禁用)或printk.time=1 (启用)。

Answer 2

它们实际上是系统启动后以秒为单位的dmesg时间戳。

你可以安全地忽略它们，除非你真的在寻找计时问题(比如一个司机花了30秒做一些本应该更快的事情)。

如果你想要一种可读性更好的格式，你可以使用dmesg -T，但是你会损失一些精度。

pax> dmesg -T | tail -5l

[Mon May 27 09:08:58 2013] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[Mon May 27 09:09:00 2013] usblp0: removed
[Mon May 27 09:09:00 2013] usblp0: USB Bidirectional printer dev 3 if 0 alt 0 proto 2 vid 0x03F0 pid 0x3A02
[Mon May 27 09:09:09 2013] eth0: no IPv6 routers present
[Mon May 27 10:09:59 2013] usblp0: removed

您也可以使用dmesg -t完全删除它们，但这样会丢失所有的计时信息。

pax> dmesg -t | tail -5l

ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
usblp0: removed
usblp0: USB Bidirectional printer dev 3 if 0 alt 0 proto 2 vid 0x03F0 pid 0x3A02
eth0: no IPv6 routers present
usblp0: removed