CODEWITHSUNDEEP
linuxkerneloutputprintk
user2423523
user2423523

Reputation: 21

linux kernel printk output

I am new in Linux kernel development and when I try to modify a system call function by just adding a printk function in timekeep.c file,like

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

the dmesg utility gives me output like:

[   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!$$$$$

I really don't understand how those in [] are generated. Can someone give me a hint on that?

Upvotes: 0

Views: 8222

Answers (2)

paxdiablo
paxdiablo

Reputation: 882336

They're actually timestamps in seconds since the system booted.

You can safely ignore them unless you're actually looking for timing problems (such as a driver taking 30 seconds to do something that should be much quicker).

If you want a more readable format, you can use dmesg -T but you lose some precision.

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

You can also remove them altogether with dmesg -t but then you'll lose all timing information.

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

Upvotes: 0

rakib_
rakib_

Reputation: 142795

Your kernel has CONFIG_PRINTK_TIME option enabled. This option is responsible for this timestamp field before printk() messages. From kernel config option 

 "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."

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

This option is configurable at kernel configuration time, via "Kernel Hacking" configuration field. And you can enable/disable it from kernel command line parameter :printk.time=0 (disable) or printk.time=1 (enable).

Upvotes: 2

Related Questions