Kernel Log Levels and printk Control
Free Linux Kernel Development Course — Debugging Tips Series
If you’ve ever stared at a wall of dmesg output trying to find the one line that matters, this lecture is for you. This is part of our free linux kernel development course, and today we go deep into how the kernel classifies, filters, and stores every message it prints — from pr_err() in your driver to the circular buffer that backs dmesg itself.
Understanding kernel log levels isn’t optional trivia — it’s one of the first tools you reach for the moment a driver misbehaves on real hardware. This lecture is part of our free linux device drivers course and continues directly from where we left off in the previous lecture on the kernel release model.
What You Will Learn
- The eight kernel log levels and what each one actually means in practice
- Why
pr_*()helpers are preferred over rawprintk()calls - How
pr_fmt()auto-prefixes every message in a source file - The device-aware
dev_*()logging family used inside real drivers - How
console_logleveldecides what actually reaches your screen - How to read and change the console log level with
/proc/sys/kernel/printkanddmesg -n - What the kernel log buffer is, why it’s circular, and how to resize it
- How to enable timestamped kernel messages with
CONFIG_PRINTK_TIME
Prerequisites
- A working kernel module build environment (covered in earlier lectures of this free embedded linux course)
- Basic familiarity with writing and loading a simple kernel module
- Root/sudo access on a test Linux machine or VM (never experiment on production hardware)
Why Kernel Log Levels Matter
Every message the kernel prints carries a priority, not just text. That priority is what lets the system decide, automatically, whether a message deserves your immediate attention on the console or should quietly wait in the log buffer for you to inspect later with dmesg. Without this classification, a driver spamming debug output would drown out the one line telling you a disk controller just died.
Priority 0 KERN_EMERG system unusable, about to crash
Priority 1 KERN_ALERT action must be taken immediately
Priority 2 KERN_CRIT critical hardware/software failure
Priority 3 KERN_ERR error condition (common in drivers)
Priority 4 KERN_WARNING something worth noting, not fatal
Priority 5 KERN_NOTICE normal but significant condition
Priority 6 KERN_INFO informational, e.g. driver startup
Priority 7 KERN_DEBUG verbose, dev-only, usually filtered
Lower numeric value means higher urgency. This is the part beginners trip over: KERN_EMERG is “0”, the most severe, while KERN_DEBUG is “7”, the least severe. If you don’t tag a message at all, it silently falls back to DEFAULT_MESSAGE_LOGLEVEL, which is usually 4 (KERN_WARNING), configurable via CONFIG_DEFAULT_MESSAGE_LOGLEVEL.
The pr_*() Family: Modern Kernel Logging
Writing raw printk(KERN_ERR "...") everywhere works, but it’s verbose and easy to get wrong. Modern kernel code almost always reaches for the pr_*() helpers instead, which bake the log level directly into the function name:
pr_emerg("message\n");
pr_alert("message\n");
pr_crit("message\n");
pr_err("message\n");
pr_warn("message\n");
pr_notice("message\n");
pr_info("message\n");
pr_debug("message\n"); /* compiled out unless DEBUG is defined */
The real productivity win, though, is pr_fmt(). Define it once at the very top of a source file — before any #include — and every pr_*() call in that file automatically gets prefixed with your module and function name:
#define pr_fmt(fmt) "%s:%s: " fmt, KBUILD_MODNAME, __func__
#include <linux/module.h>
#include <linux/kernel.h>
#include <linux/init.h>
static int __init ep_logdemo_init(void)
{
pr_info("driver loaded, starting probe sequence\n");
pr_debug("internal state initialized to defaults\n");
return 0;
}
static void __exit ep_logdemo_exit(void)
{
pr_info("driver unloaded\n");
}
module_init(ep_logdemo_init);
module_exit(ep_logdemo_exit);
MODULE_LICENSE("GPL");
Build and load it, then check dmesg:
$ make
$ sudo insmod ep_logdemo.ko
$ dmesg | tail -n 3
[12345.678901] ep_logdemo:ep_logdemo_init: driver loaded, starting probe sequence
$ sudo rmmod ep_logdemo
$ dmesg | tail -n 2
[12346.112233] ep_logdemo:ep_logdemo_exit: driver unloaded
Notice the pr_debug() line never showed up — that’s expected, since it’s compiled to nothing unless the module is built with DEBUG defined (or dynamic debug is enabled for it).
dev_*() Helpers: Logging Tied to a Device
Inside an actual device driver, prefer the device-aware family over the plain pr_*() calls. These accept a struct device * and automatically stamp the message with that device’s name, so you never lose track of which physical device produced a given line — invaluable the moment you have more than one instance of the same driver bound to different hardware.
void dev_emerg(const struct device *dev, const char *fmt, ...);
void dev_alert(const struct device *dev, const char *fmt, ...);
void dev_crit(const struct device *dev, const char *fmt, ...);
void dev_err(const struct device *dev, const char *fmt, ...);
void dev_warn(const struct device *dev, const char *fmt, ...);
void dev_notice(const struct device *dev, const char *fmt, ...);
void dev_info(const struct device *dev, const char *fmt, ...);
void dev_dbg(const struct device *dev, const char *fmt, ...);
A minimal platform driver probe using this family:
static int ep_devlog_probe(struct platform_device *pdev)
{
struct device *dev = &pdev->dev;
dev_info(dev, "probing ep_devlog on %s\n", dev_name(dev));
if (!pdev->dev.of_node) {
dev_err(dev, "no device tree node found, aborting probe\n");
return -ENODEV;
}
dev_dbg(dev, "probe finished, device ready\n");
return 0;
}
$ sudo insmod ep_devlog.ko
$ dmesg | tail -n 2
[9012.334455] ep_devlog ep_devlog0: probing ep_devlog on ep_devlog0
[9012.334460] ep_devlog ep_devlog0: probe finished, device ready
console_loglevel: What Actually Reaches Your Screen
Every kernel message is logged, but not every message is printed to the console. The kernel compares each message’s priority against a runtime variable called console_loglevel. If the message’s priority number is lower (meaning more urgent) than console_loglevel, it appears on the console immediately. Otherwise it’s recorded in the log buffer but stays invisible until you go looking with dmesg.
This is exactly why, with a default console_loglevel of 4, your pr_info() and pr_notice() calls never show up on a live console — their priority numbers (6 and 5) are higher than 4, so they’re filtered out. Check the current setting:
$ cat /proc/sys/kernel/printk
4 4 1 7
| Field | Value | Meaning |
|---|---|---|
| 1st | 4 | current console log level |
| 2nd | 4 | default console log level |
| 3rd | 1 | minimum level that can be set |
| 4th | 7 | boot-time default console log level |
To see absolutely everything, raise the threshold to 8 (past even KERN_DEBUG):
$ sudo sh -c 'echo 8 > /proc/sys/kernel/printk'
$ cat /proc/sys/kernel/printk
8 4 1 7
The friendlier way to do the same thing is with dmesg -n:
$ sudo dmesg -n 5
This sets console_loglevel so only KERN_WARNING (4) and more severe messages reach the console. You can also fix this at boot time using the loglevel kernel command-line parameter — check your bootloader config or Documentation/admin-guide/kernel-parameters.txt for the exact syntax on your kernel version.
driver calls pr_err() -> priority = 3
kernel compares: is priority (3) < console_loglevel (4)? -> YES
result: printed on console immediately AND stored in log buffer
driver calls pr_info() -> priority = 6
kernel compares: is priority (6) < console_loglevel (4)? -> NO
result: stored in log buffer only, visible via dmesg
A Note on KERN_CONT / pr_cont
There’s a special case worth knowing: KERN_CONT and its helper pr_cont() don’t specify any urgency level at all — they append to the previous line instead of starting a new one. Because a continued line isn’t safe on SMP systems outside of early boot, this pair should only ever be used by core/arch code during bootup, never in ordinary driver code. A conditional message is the classic use case:
pr_warn("last operation status: ");
if (success)
pr_cont("OK\n");
else
pr_cont("FAILED\n");
Only the very last pr_cont() in the chain should carry the trailing \n — every line before it stays open.
The Kernel Log Buffer
Whether or not a message reaches the console, it’s always recorded in the kernel’s log buffer — a fixed-size circular buffer. Circular means that once it’s full, new messages overwrite the oldest ones, so under heavy logging you can silently lose early entries before you ever get to read them with dmesg.
The buffer size is controlled at compile time by CONFIG_LOG_BUF_SHIFT. The value is a left-shift exponent, not a raw byte count:
| LOG_BUF_SHIFT | Calculation | Resulting Size |
|---|---|---|
| 16 | 1 << 16 | 64 KB |
| 17 | 1 << 17 | 128 KB |
| 18 | 1 << 18 | 256 KB |
If recompiling isn’t an option, you can override the size at boot time with the log_buf_len kernel parameter, which only accepts power-of-2 values:
log_buf_len=1M
log_buf_len is often the fastest fix — cheaper than recompiling the kernel just to bump CONFIG_LOG_BUF_SHIFT.
Adding Timing Information with CONFIG_PRINTK_TIME
Knowing what happened is only half the story — knowing when it happened relative to boot is often what actually solves a bug. Enable the CONFIG_PRINTK_TIME option (found under the Kernel Hacking menu at kernel configuration time) and every log line gets a timestamp prefix automatically:
$ dmesg
[ 1.260037] loop: module loaded
[ 1.260194] libphy: Fixed MDIO Bus: probed
[ 1.260260] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 1.260775] ehci-pci 0000:00:1a.7: EHCI Host Controller
[ 1.280103] ehci-pci 0000:00:1a.7: USB 2.0 started, EHCI 1.00
The number in brackets is seconds since boot, with microsecond precision. This is exactly what you want when correlating a driver failure with, say, a USB device enumeration that happened a fraction of a second earlier.
Common Mistakes and Troubleshooting
| Mistake | Why It Bites You | Fix |
|---|---|---|
Using raw printk() everywhere | Verbose, easy to forget the level, no automatic prefix | Use pr_*() with pr_fmt() instead |
Expecting pr_info() on the live console | Default console_loglevel filters it out | Lower console_loglevel with dmesg -n or check dmesg directly |
Using pr_*() instead of dev_*() in a driver | You lose the automatic device name in multi-instance drivers | Prefer dev_*() whenever a struct device * is available |
Using pr_cont() outside early boot | Not SMP-safe; interleaved output from other CPUs corrupts the line | Only use it in core/arch bootup code, never in regular drivers |
Assuming dmesg has everything | The log buffer is circular and can wrap, silently dropping old messages | Increase log_buf_len or CONFIG_LOG_BUF_SHIFT if you need a longer history |
Best Practices
- Always define
pr_fmt()at the top of every driver source file, before any includes - Use
dev_*()overpr_*()inside probe/remove and any function with device context - Reserve
KERN_EMERG/KERN_ALERTfor genuinely system-threatening conditions, not routine errors - Keep
pr_debug()/dev_dbg()calls in place permanently — they cost nothing when DEBUG isn’t enabled and save you re-instrumenting later - Enable
CONFIG_PRINTK_TIMEon development kernels; it’s nearly free and pays for itself the first time you chase a race condition
Performance Considerations
Excessive logging at high frequency — especially at low log levels that reach the console — can meaningfully slow down a driver’s hot path, since console output on a serial line is comparatively slow. Reserve pr_info() and above for events that happen rarely (init, probe, error paths); use pr_debug() for anything in a loop or fast path, since it compiles away entirely in production builds.
Summary and Key Takeaways
- Kernel messages carry one of eight priority levels, from
KERN_EMERG(0) toKERN_DEBUG(7) — lower number means more urgent pr_*()withpr_fmt()is the modern, concise way to log from core code;dev_*()is preferred inside device driversconsole_loglevel, readable and writable via/proc/sys/kernel/printkordmesg -n, decides what actually reaches the live console- Every message, printed or not, lands in the circular kernel log buffer sized by
CONFIG_LOG_BUF_SHIFTorlog_buf_len CONFIG_PRINTK_TIMEtimestamps every message, which is invaluable for correlating events during debugging
Conclusion
Kernel logging looks trivial from the outside — just print a string, right? — but the level you choose, the helper family you reach for, and how you tune console_loglevel and the log buffer directly determine how fast you can diagnose a problem on real hardware. Get comfortable with pr_*(), dev_*(), and dmesg -n now, and you’ll save yourself hours the first time a driver misbehaves in the field. In the next lecture of this free linux kernel development course, we continue the debugging toolkit with further kernel development tips.
Interview Questions
What’s the difference between the numeric value of a log level and its actual urgency?
They’re inverted — a lower numeric value (0 for KERN_EMERG) means higher urgency, while a higher value (7 for KERN_DEBUG) means lower urgency.
Why would you use dev_err() instead of pr_err() inside a driver?
dev_err() automatically stamps the message with the originating device’s name, which is essential when multiple instances of the same driver are bound to different physical devices.
What does console_loglevel actually control?
It’s the threshold priority a message must meet (numerically lower than or equal to it) to be printed immediately to the console, independent of whether it’s also stored in the log buffer.
Why is the kernel log buffer described as circular, and what’s the practical risk?
It’s a fixed-size buffer that wraps and overwrites the oldest entries once full, so under heavy logging you can silently lose early messages before reading them with dmesg.
Where should pr_cont() be used, and why not elsewhere?
Only in core/arch code during early bootup, because a continued line isn’t SMP-safe outside that context and can get corrupted by interleaved output from other CPUs.
Frequently Asked Questions
How many kernel log levels are there and what are they?
There are eight: KERN_EMERG, KERN_ALERT, KERN_CRIT, KERN_ERR, KERN_WARNING, KERN_NOTICE, KERN_INFO, and KERN_DEBUG, numbered 0 through 7 in decreasing order of urgency.
What happens if I don’t specify a log level in my message?
It defaults to DEFAULT_MESSAGE_LOGLEVEL, usually 4 (KERN_WARNING), which is itself configurable through CONFIG_DEFAULT_MESSAGE_LOGLEVEL.
Should I use printk() or pr_*() in new driver code?
Prefer pr_*() — it’s more concise, embeds the level in the function name, and works with pr_fmt() for automatic message prefixing.
How do I see every kernel message, including debug-level ones, on the console?
Raise console_loglevel to 8, either with `echo 8 > /proc/sys/kernel/printk` or `dmesg -n 8`.
How do I change the console log level permanently across reboots?
Set the loglevel kernel boot parameter in your bootloader configuration rather than changing it at runtime.
What determines the size of the kernel log buffer?
The compile-time CONFIG_LOG_BUF_SHIFT option, or the log_buf_len boot parameter, which only accepts power-of-2 sizes.
Why don’t my pr_info() messages show up on the console by default?
Because their priority (6) is numerically higher, meaning less urgent, than the default console_loglevel of 4, so they’re filtered from the live console but still visible via dmesg.
What’s the difference between pr_debug() and pr_devel()?
Both compile to printk(KERN_DEBUG …) only when the file is built with DEBUG defined; otherwise both are compiled out entirely as empty statements.
Want to master Linux kernel debugging from the ground up?
This lecture is part of EmbeddedPathashala’s free linux kernel development course — explore the full free linux device drivers course and free embedded systems course.
Browse the Full Course Join the Community