Monday, July 21, 2008

There is Something About printk()

In the example myFirstModuleSource.c of Writing the First Kernel Module, I used printk() just as another name of printf(). In this post I note the differences between the two, and the way Linux kernel uses it.


At the first glance, the only difference between printk() and printf() is the way the two functions are called. However, this single difference causes all the mysteries of printk() in displaying the kernel outputs. I called it “mystery” because we don't see printk() outputs at the place where (as naive kernel learners) we expect them to come, i.e., on the console. Actually, all outputs of printk() are logged into file /var/log/messages. After executing our program (inserting/removing modules), we have to go check /var/log/messages to see the outputs. Let's have a look at how printk() is called, and then see how to get its outputs at the place we want, besides /var/log/messages.


The printk() is called with one more argument than printf(), like this:


printk(KERN_log_priority "hello world\n");


Here, log_priority is one of the eight values (predefined in linux/kernel.h, similar to /usr/include/sys/syslog.h), EMERG, ALERT, CRIT, ERR, WARNING, NOTICE, INFO, DEBUG (in order of decreasing priority). See line #31 to #38 in the snapshot of linux/kernel.h below. In the example of myFirstModuleSource.c, I used printk() without mentioning any log priority. default_message_loglevel is assigned to such cases (line #43 in the snapshot below), whenever the log level is not specified explicitly while calling printk().




The kernel gives different treatment to these different priorities of messages. Different rules are followed depending upon whether the system is in one of the six text console mode (Ctrl-Alt-F1 to Ctrl+Alt+F6) or GUI mode.


Logging in Console Mode and Getting the printk() Output on the Console:

The file /proc/sys/kernel/printk contains four integer values. E.g., my RHEL-4 machine has values 6,4,1,7. These integers correspond to currently set, default, minimum allowed, and boot time default message log level, respectively. These are the values in line #42 to #45 in linux/kernel.h. Any message with priority less than the current console log level (i.e. the first integer in the file) is displayed on the console. The rest are logged into /var/log/messages.


The values in file /proc/sys/kernel/printk can be changed according to the requirements. For instance, changing the first integer value (current console log level) to 8 in causes messages with any priority to be printed on console. Similarly, changing the second value changes the default priority level assignment. The third and fourth values are generally not changed.


Logging When in GUI Mode:

In this case, logging is done according to the rules defined in /etc/syslog.conf file (snapshot below). This file contains two columns, one for the type of message (in the form of facility.priority), and the other for the place where to display the corresponding kernel log message. The facility specifies the subsystem that produced the message and the priority specifies its severity.

For instance, EMERG messages are logged everywhere (all the terminals and log files), no matter produced by which subsystem (line #16). All the messages from MAIL subsystem are logged into /var/log/maillog (line #12), INFO messages from any subsystem are logged into /var/log/messages (line #7). See syslog.conf manual page for more details.


Getting printk() Messages Displayed on the Terminal in GUI Mode:

This is the point where I am stuck right now. One way to do this is to assign one terminal, say /dev/pts/3, in syslog.conf at line #7, so that that all INFO (and higher) messages will go there. But this solution is no better than looking for output in /var/log/messages. My requirement is to see the printk() messages on whichever terminal I am using at that time. klogd manual page suggests to start klogd daemon with –c switch to change the current console log level according to need. I changed it to 8, but could not see any change in the manner messages being logged. This did not solve the problem either.


Thoughts/Suggestions are welcome. If someone has done that, guidance needed.


No comments: