Linux Kernel Logging with printk() – Free Linux Kernel Development Course

Kernel Logging with printk()
Free Linux Kernel Programming Course · Part 5 · EmbeddedPathashala
8
Log Levels
Linux 6.x
Verified
Free
No Cost
Series: PREV_LEC NEXT_LEC

What is printk()?

When you write a kernel module, you cannot use the normal printf() from the C standard library — that library does not exist inside the kernel. Instead, the Linux kernel gives you printk(), its own logging function. Think of it as printf() for the kernel world.

Every message you write with printk() goes into a special memory area called the kernel ring buffer. You can read everything stored there using the dmesg command on your terminal. This ring buffer is circular — once it fills up, the oldest messages are overwritten by new ones.

Since Linux 5.10 this ring buffer is fully lock-free, meaning printk can safely write from any context — even during a hardware interrupt — without causing deadlocks.

printk() vs printf() — Key Differences

Knowing the differences saves you hours of confusion when you start writing modules.

printk() vs printf() Side-by-Side
Feature printf() — Userspace printk() — Kernel
Where output goes Standard output (terminal) Kernel ring buffer → read via dmesg
Log levels None 8 levels from EMERG to DEBUG
Floating point Supported (%f, %e, %g) NOT supported — kernel never uses FP
%n format Supported NOT allowed — security risk
Call context Only from a process Process, interrupt, NMI — anywhere
Extra format specs Standard C99 Extra: %pI4 (IPv4), %pI6 (IPv6), %pUb (UUID), %ph (hex dump) and more

Important: Never use floating point (%f, %e) or %n in a printk() format string. The kernel will either refuse to compile or produce wrong output.

Basic printk() Syntax

The log level is concatenated directly to the format string — no comma between them. This surprises many beginners.

/* Correct — no comma between level and format */
printk(KERN_INFO "My driver loaded, version %d\n", version);

/* Wrong — this is a common beginner mistake */
printk(KERN_INFO, "My driver loaded\n");  /* compile error */

The reason is that KERN_INFO expands to a two-byte string literal "\001" "6". The C compiler merges adjacent string literals, so KERN_INFO "hello" becomes one string "\0016hello". The kernel then reads the first two bytes to find the log level and prints the rest as the message.

/* A minimal kernel module showing printk in init and exit */
#include <linux/module.h>
#include <linux/kernel.h>
#include <linux/init.h>

/* Prefix every message with "mymodule: " automatically */
#define pr_fmt(fmt)  KBUILD_MODNAME ": " fmt

static int __init mymod_init(void)
{
    pr_info("Module loaded successfully\n");
    return 0;
}

static void __exit mymod_exit(void)
{
    pr_info("Module removed\n");
}

module_init(mymod_init);
module_exit(mymod_exit);
MODULE_LICENSE("GPL");
MODULE_DESCRIPTION("printk demo");

Notice we use pr_info() instead of raw printk(KERN_INFO ...). The pr_*() macros are the modern, recommended way — explained in detail below.

The 8 Log Levels — Explained Simply

Every printk message carries a log level — a number from 0 to 7. Lower number = more serious. The kernel uses this number to decide whether to print the message to your console (serial port, VGA screen) or keep it only in the ring buffer.

Log Level Severity Scale
KERN_EMERG [0]
System is completely broken — crash imminent
KERN_ALERT [1]
Action needed immediately
KERN_CRIT [2]
Critical hardware or software failure
KERN_ERR [3]
Error — driver or device failed
KERN_WARNING [4]
Something odd but recoverable
KERN_NOTICE [5]
Significant but normal event
KERN_INFO [6]
General information
KERN_DEBUG [7]
Debug messages

Lower number = higher severity. Shorter bar = less severity.

When to use each level

KERN_EMERG (0) — The system cannot continue. Used by panic() right before a kernel crash. You will almost never use this yourself in a normal module.
printk(KERN_EMERG "Critical: memory controller failure, halting\n");
KERN_ALERT (1) — Something bad happened and a human must act right now. Example: a hardware watchdog about to reset the system.
printk(KERN_ALERT "Hardware watchdog expires in 2 seconds!\n");
KERN_CRIT (2) — Serious failure that affects the whole system but has not yet crashed it.
printk(KERN_CRIT "DMA engine stuck, I/O subsystem degraded\n");
KERN_ERR (3) — Your driver hit an error. The most commonly used serious level in device drivers. Use it when an operation failed and the driver cannot recover on its own.
pr_err("Failed to map device registers: %d\n", ret);
KERN_WARNING (4) — Something unexpected happened but the system is still working fine. Good for “this feature is deprecated” or “retried operation succeeded after failure.”
pr_warn("Deprecated ioctl 0x%x used by process %s\n", cmd, current->comm);
KERN_NOTICE (5) — Something worth noting but not alarming. Used by networking code when an interface goes up/down.
pr_notice("eth0: link is down\n");
KERN_INFO (6) — General “I started, I found this device, I configured this.” The most common level in module init functions.
pr_info("MyDevice Rev.%d found at IRQ %d\n", rev, irq);
KERN_DEBUG (7) — Development-only messages. These are special — they are hidden by default. Read the next section on pr_debug() to understand how to enable them.
pr_debug("register value: 0x%08x\n", reg_val);
How the Console Log Level Works

Every message goes into the ring buffer regardless of level. But whether it also appears on your console (serial terminal, screen) depends on the console log level.

A message is printed to the console only if its level number is less than the current console log level. So with a console log level of 4, levels 0, 1, 2, 3 appear on the console. Level 4 (WARNING) and above stay in the ring buffer only.

Message Routing Based on Console Log Level = 4
EMERG [0]
Console + Ring Buffer
ALERT [1]
Console + Ring Buffer
CRIT [2]
Console + Ring Buffer
ERR [3]
Console + Ring Buffer
WARNING [4]
Ring Buffer Only
INFO [6]
Ring Buffer Only

Reading and changing the console log level

The file /proc/sys/kernel/printk holds four numbers. Read it like this:

$ cat /proc/sys/kernel/printk
4    4    1    7

These four numbers mean:

/proc/sys/kernel/printk — What each number means
Position Example Value Meaning
1st4Current console log level — messages below this appear on console
2nd4Default level for messages that don’t specify any level
3rd1Minimum allowed console log level
4th7Boot-time default console log level

To show all messages on the console (useful during debugging):

# Show everything — level 8 means all 0-7 are less than 8
echo 8 > /proc/sys/kernel/printk

# Restore the default
echo "4 4 1 7" > /proc/sys/kernel/printk

# Or use dmesg to change console level to 5
dmesg -n 5

Changes to /proc/sys/kernel/printk take effect immediately but are lost on reboot. To make it permanent, use the loglevel=N kernel boot parameter in your bootloader config.

The pr_fmt() Macro — Auto-Prefix All Messages

One of the most useful things you can do in a kernel module is define pr_fmt() at the top of your source file. This automatically adds a prefix to every single pr_*() call in that file.

/*
 * Define this BEFORE any #include statements.
 * All pr_info(), pr_err() etc. will get "mymodule: " prepended.
 */
#define pr_fmt(fmt)  KBUILD_MODNAME ": " fmt

#include <linux/module.h>
#include <linux/kernel.h>

static int __init demo_init(void)
{
    pr_info("started\n");   /* prints:  mymodule: started         */
    pr_warn("retrying\n");  /* prints:  mymodule: retrying        */
    pr_err("failed: %d\n", -EIO); /* prints: mymodule: failed: -5 */
    return 0;
}

Without pr_fmt(), all your messages look the same in dmesg and it is hard to tell which module produced them. With it, every message is clearly tagged. You can also add the function name:

/* Include both module name and function name */
#define pr_fmt(fmt)  "%s:%s: " fmt, KBUILD_MODNAME, __func__

Interview Questions & Answers

Q: Why can’t we use printf() inside a Linux kernel module?

printf() is part of the C standard library (glibc). The kernel does not link against glibc — it has no access to userspace libraries at all. The kernel provides its own equivalent called printk(), which writes to the kernel ring buffer instead of stdout.

Q: What is the correct syntax for printk() with a log level?

The log level macro is concatenated (no comma) to the format string: printk(KERN_INFO "message\n"). KERN_INFO expands to a two-byte string, and the compiler merges adjacent string literals. Adding a comma between them is a compile error.

Q: What does the console log level control?

It controls which messages appear on the physical console (serial, VGA). A message is printed to the console only if its level number is strictly less than the current console log level. All messages always go to the ring buffer regardless. The current level is shown as the first number in /proc/sys/kernel/printk.

Q: What format specifiers are NOT allowed in printk?

Floating point specifiers (%f, %e, %g, %a) and %n are never allowed in printk format strings. The kernel never uses floating point in kernel code, and %n is a security concern. The kernel does add its own extra specifiers not in standard C, such as %pI4 for IPv4 addresses.

Q: Why do modern kernel developers prefer pr_info() over printk(KERN_INFO …)?

The pr_*() macros are shorter and work with pr_fmt() for automatic message prefixing. pr_fmt() lets you define a module-wide prefix once at the top of the file, and every pr_*() call in that file automatically includes it. With raw printk() you would need to repeat the prefix in every call manually.

Next: pr_debug(), Dynamic Debug & Rate Limiting

Learn how to use debug messages that are completely invisible in production and turn them on at runtime without rebooting.

Next Chapter → Course Index

Leave a Reply

Your email address will not be published. Required fields are marked *