Beginner → Intermediate
Linux 6.x
1 of 3
When your kernel module prints something, you need to know which module and which function produced that line — especially when the kernel log contains thousands of entries from dozens of subsystems all mixed together.
This tutorial explains how the Linux kernel’s logging system gives you automatic, consistent prefixes on every log line, using two key tools: the printk() function and the pr_fmt() macro. We cover the Linux 6.x behaviour throughout.
1. What Is printk() and Why Does It Exist?
In user-space C programs you call printf() to write text to a terminal. The kernel runs long before any terminal exists, so it has its own equivalent: printk(). The name is short for print kernel.
Every kernel subsystem, every driver, and every loadable module uses printk() to write diagnostic and status messages. Those messages go into a ring buffer inside the kernel called the kernel log buffer. You can read it at any time with the dmesg command.
printk() accepts a log-level prefix that tells the kernel how urgent the message is. This lets the kernel decide whether to also send the message to the system console, depending on the current console log-level setting.
In Linux 6.x the log-level macros available to you are:
/* Log level constants defined in <linux/kern_levels.h> */
KERN_EMERG /* system is unusable */
KERN_ALERT /* action must be taken immediately */
KERN_CRIT /* critical conditions */
KERN_ERR /* error conditions */
KERN_WARNING /* warning conditions */
KERN_NOTICE /* normal but significant condition */
KERN_INFO /* informational */
KERN_DEBUG /* debug-level messages */
Instead of embedding these raw strings into every printk() call, the kernel provides convenience wrappers like pr_info(), pr_err(), pr_warn(), and pr_debug(). These automatically attach the right log-level prefix for you.
| Your LKM calls pr_info(“Module loaded”) |
| ↓ |
| pr_fmt() macro prepends module name + function name |
| ↓ |
| printk() attaches log-level (KERN_INFO) and timestamp |
| ↓ |
| Kernel writes message to ring buffer (/dev/kmsg) |
| ↓ |
| dmesg reads and displays: [12345.678901] mymodule:my_init(): Module loaded |
2. The Problem With Raw printk() Calls
Imagine you are debugging a kernel module called mydriver and it loads fine but something goes wrong after a few seconds. You run dmesg and see hundreds of log lines from multiple subsystems. How do you quickly find which lines came from your module?
If you wrote bare pr_info("init done\n") calls, the kernel log only shows the log-level and timestamp. Nothing identifies your module or the specific function that printed the message. Finding the relevant lines becomes a slow, manual process.
dmesg output can contain tens of thousands of lines during boot. A message that does not carry its source module name is almost impossible to trace quickly.
The Linux kernel community solved this long ago with a simple macro you define once at the top of each source file.
3. Introducing pr_fmt() — Your Automatic Log Prefix
The pr_fmt() macro acts as a format string preprocessor. Every time a pr_*() convenience function (like pr_info() or pr_err()) is called, it first passes the format string through pr_fmt(). Whatever pr_fmt() returns becomes the actual format string used in the log entry.
By defining pr_fmt() at the top of your source file, before any includes, you inject a consistent prefix into every single log message your file emits — with zero repetition in individual pr_info() calls.
/* Define pr_fmt() at the very top of your .c file,
BEFORE any #include statements */
#define pr_fmt(fmt) KBUILD_MODNAME ": " __func__ ": " fmt
#include <linux/init.h>
#include <linux/module.h>
#include <linux/kernel.h>
MODULE_LICENSE("GPL");
static int __init my_driver_init(void)
{
pr_info("driver inserted\n");
/* The kernel log will show:
[ 123.456789] mydriver: my_driver_init: driver inserted */
return 0;
}
static void __exit my_driver_exit(void)
{
pr_info("driver removed\n");
/* The kernel log will show:
[ 456.789012] mydriver: my_driver_exit: driver removed */
}
module_init(my_driver_init);
module_exit(my_driver_exit);
pr_fmt(). If you place your #define after the includes, the header’s definition takes effect first and your custom definition either has no effect or causes a redefinition error, depending on how the compiler sees it.
| What you write | What the compiler sees after macro expansion |
|---|---|
| pr_info(“loaded\n”) | printk(KERN_INFO “mydriver: my_init: loaded\n”) |
| pr_err(“failed\n”) | printk(KERN_ERR “mydriver: my_init: failed\n”) |
| pr_warn(“retry\n”) | printk(KERN_WARNING “mydriver: my_init: retry\n”) |
4. KBUILD_MODNAME and __func__ — The Two Pillars
KBUILD_MODNAME
This is a string constant the Kbuild build system automatically defines for you during compilation. Its value is the name of the kernel module being built — exactly the name of your .ko file without the extension. You never have to hard-code your module name in a string; the build system does it for you.
If your module file is serial_gpio_driver.c and the Makefile builds it as serial_gpio_driver.ko, then KBUILD_MODNAME expands to the string "serial_gpio_driver" at compile time.
__func__
This is a standard C99 predefined identifier. The compiler replaces it with a string literal containing the name of the current function. It is not a macro — it is a language feature, so it correctly resolves to the right function name even when the same header is included from many places.
KBUILD_MODNAME and __func__ in your pr_fmt() definition, every log line from your module automatically carries both its module name and the exact function that emitted it. You can pinpoint the source of any log message in seconds.
| [ 12345.678901 ] mydriver:my_driver_init: driver inserted | |||||||
|
5. Including Line Numbers in Log Output
Sometimes a function is long and you want to know not just which function printed a message, but at which exact line inside that function. The C preprocessor provides the __LINE__ macro for this. You can include it inline in your format string using a %d specifier.
/* Logging the line number alongside the message */
pr_info("checkpoint reached at line %d\n", __LINE__);
This produces output like:
[ 789.012345] mydriver: my_driver_init: checkpoint reached at line 42
6. pr_fmt() and dev_<foo>() — Device Driver Logging
For platform and character device drivers, the kernel provides a separate family of logging functions: dev_info(), dev_err(), dev_warn(), and others. These take a pointer to a struct device as their first argument and automatically prepend the device name to the log message.
The pr_fmt() macro also feeds into these functions under the hood. This means your module-level prefix and the device name both appear in the log line, giving you two levels of context at once.
/* Inside a probe function for a platform driver */
static int my_device_probe(struct platform_device *pdev)
{
dev_info(&pdev->dev, "device probed successfully\n");
/* Output in kernel log:
[ 100.000001] mydriver mydevice0: device probed successfully */
return 0;
}
pr_*() functions in module-level code (init, exit, non-device logic). Use dev_*() functions when you have a valid struct device * pointer available — typically inside probe, remove, and runtime PM callbacks.
7. Reading Kernel Log Messages in Linux 6.x
Linux 6.x changed how /dev/kmsg works compared to older kernels. The structured log format now carries additional metadata fields. Here are the main ways to read kernel log output:
| Command | What it shows | Best used for |
|---|---|---|
| dmesg | All messages in the ring buffer | Quick inspection after insmod |
| dmesg -w | Live follow mode (like tail -f) | Watching messages as your module runs |
| dmesg | grep mydriver | Only lines from your module | Isolating your module’s output |
| journalctl -k | Kernel messages via systemd journal | Persistent log across reboots |
| cat /proc/kmsg | Raw kernel message stream | Advanced tooling and log daemons |
8. pr_debug() — Conditional Debug Logging
The pr_debug() function is special. By default, when you call it, it compiles down to a no-op — the message is completely removed from the binary and has zero runtime cost. This means you can leave debug statements in your production code without any performance penalty.
To activate pr_debug() output for a specific module, you enable the DEBUG preprocessor flag when compiling that module. There are two ways to do this:
# Method 1: Add to EXTRA_CFLAGS in your module's Makefile
EXTRA_CFLAGS += -DDEBUG
# Method 2: Define it at the top of the specific .c file
#define DEBUG
#define pr_fmt(fmt) KBUILD_MODNAME ": " __func__ ": " fmt
#include <linux/kernel.h>
CONFIG_DYNAMIC_DEBUG). It lets you enable or disable specific debug messages at runtime through /sys/kernel/debug/dynamic_debug/control — without recompiling. This is the preferred approach for production kernel development.
Interview Questions & Answers
pr_fmt(). Placing your custom definition before the includes ensures that your version is seen by the compiler first, so all pr_*() calls in that file use your custom format string, which typically includes the module name and function name for easier log tracing.KBUILD_MODNAME is a string constant automatically defined by the Kbuild build system during compilation. Its value equals the name of the kernel module (.ko file) being built. You never hard-code it — the build system injects it so the module name is always accurate even if you rename the file.pr_info() is a general-purpose kernel logging macro that uses the module-level prefix defined in pr_fmt(). dev_info() takes a struct device * pointer and automatically includes the device name in the log output, making it more appropriate inside driver probe, remove, and runtime callbacks where a valid device object exists.DEBUG preprocessor symbol is not defined, the compiler expands pr_debug() to a no-op. The format string and arguments are still type-checked at compile time (to catch bugs), but no code is emitted. This means you get the benefits of extensive debug instrumentation in your source without any penalty in production builds./dev/kmsg, carrying metadata such as log sequence numbers, facility and priority fields, and timestamps in nanoseconds. The dmesg utility was updated to parse this structured format. Additionally, CONFIG_DYNAMIC_DEBUG is more widely used to control per-callsite debug output at runtime without recompilation.Continue Learning — Free Linux Kernel Course
Next up: printk format specifiers for writing portable, architecture-independent kernel code.
Next: Format Specifiers → Skip to: Kernel Makefile →