Linux kernel logging complete tutorial

Linux Kernel Console Output Kernel Logging pr_debug Device Drivers Free Tutorial

Why Kernel Messages Don’t Appear on Your Terminal

If you’ve ever written a Linux kernel module and wondered why your printk messages don’t show up in your terminal window (like GNOME Terminal or Konsole), you’re not alone. This is one of the most common questions beginners ask when starting with Linux kernel programming.

The answer lies in understanding the fundamental difference between a real console and a terminal emulator. This comprehensive tutorial will explain why kernel messages don’t appear in your GUI terminal, how to access the real console, how to control which kernel messages appear where, and the critical difference between regular pr_* macros and the special pr_debug() function. This guide is part of our free embedded systems course at EmbeddedPathashala.

Understanding Console vs Terminal Emulator

What is a Linux Console?

In Linux, a console is a physical or virtual device that provides direct text input and output to the system. It operates at a very low level, directly interfacing with the kernel. During system boot, you see kernel messages scrolling by on the console – these are the boot logs showing different system activities.

Key Characteristics of a Console

  • Direct kernel access: The console communicates directly with the Linux kernel
  • No graphics layer: Pure text mode, no GUI framework required
  • Always available: Works even before the GUI starts
  • Receives kernel messages: Kernel printk output goes to the console

The X Window System and GUI Terminals

When you boot into a graphical desktop environment (like GNOME, KDE, or XFCE), you’re actually running the X Window System (often called “X” or “X11”). The X system is implemented entirely in user space – it’s not part of the kernel.

Here’s how it works:

  1. The X server runs as a user-space program
  2. All graphical applications (including terminal emulators) are X clients
  3. Applications communicate with the X server via Inter-Process Communication (IPC)
  4. When an application wants to display a window, it sends messages to the X server
  5. The X server handles the actual drawing to the screen

Common Terminal Emulators

These are graphical applications that emulate a terminal but are NOT real consoles:

  • xterm – The classic X terminal emulator
  • gnome-terminal – GNOME’s default terminal
  • konsole – KDE’s terminal emulator
  • terminator – Advanced terminal with multiple panes
  • alacritty – GPU-accelerated terminal emulator

Why Kernel Messages Don’t Appear in GUI Terminals

Kernel messages are output from the kernel space, not from user-space processes. Terminal emulators like xterm or gnome-terminal only receive output from user-space programs running in a shell. They cannot see kernel messages because:

  • Kernel printk writes to the kernel ring buffer
  • Terminal emulators are user-space programs
  • There’s no direct connection between kernel output and GUI terminals
  • Kernel messages go to the system console, not to terminal emulators

⚠️ Common Misconception: Running sudo insmod my_module.ko in a GUI terminal will NOT show printk messages in that terminal. The module loads successfully, but the kernel messages go to the console, not to your GUI window.

How to Access the Real Console

Linux provides multiple virtual consoles (also called virtual terminals or VTs). You can switch between these consoles and your graphical desktop using keyboard shortcuts.

Switching to Console

Access Console (Text Mode)

Ctrl + Alt + F4

This switches you to virtual console 4. On some systems, you might need to try:

  • Ctrl + Alt + F1 through Ctrl + Alt + F6 for different virtual consoles
  • Each F-key (F1-F12) may represent a different virtual terminal on your system

Return to GUI Desktop

Ctrl + Alt + F7   (or F1, or F2, depending on your system)

Common GUI locations:

  • Ubuntu/Debian: Usually Ctrl + Alt + F7 or Ctrl + Alt + F1
  • Fedora/RHEL: Often Ctrl + Alt + F1
  • Try different keys: If unsure, try F1 through F12 until you see your desktop

What You’ll See on the Console

When you switch to a console, you’ll see:

  • A text-based login prompt (if not already logged in)
  • A pure text environment (no graphics)
  • Kernel messages that meet the console log level threshold
  • Real-time kernel messages as they happen

Understanding Console Log Levels

Not all kernel messages appear on the console. Linux uses a filtering system based on log levels to control which messages are displayed on the console versus which are only stored in the kernel ring buffer.

The Four Values in /proc/sys/kernel/printk

You can check the current console log level configuration:

cat /proc/sys/kernel/printk

Example output:

4  4  1  7

These four numbers represent:

Position Name Description
1st (4) Console Log Level Only messages with priority ≤ this value appear on console
2nd (4) Default Message Level Default priority for printk without explicit log level
3rd (1) Minimum Console Level Lowest log level allowed for console output
4th (7) Boot-time Default Log level used during system boot

Understanding the Console Log Level (First Value)

The console log level (first value) is the most important for determining what you see on the console. With a default value of 4:

Log Level Priority Name Appears on Console?
0 KERN_EMERG ✅ Yes (Emergency)
1 KERN_ALERT ✅ Yes (Alert)
2 KERN_CRIT ✅ Yes (Critical)
3 KERN_ERR ✅ Yes (Error)
4 KERN_WARNING ✅ Yes (Warning)
5 KERN_NOTICE ❌ No (only in dmesg)
6 KERN_INFO ❌ No (only in dmesg)
7 KERN_DEBUG ❌ No (only in dmesg)

Important Rule

With console log level set to 4, only messages with priority 4 or lower (more urgent) appear on the console. Messages with priority 5, 6, or 7 are stored in the kernel ring buffer but NOT displayed on the console.

This is why when you insert a module using pr_info() (level 6), you won’t see it on the console – you need to use dmesg to view it.

Changing Console Log Level

If you want to see more kernel messages on the console (like INFO or NOTICE messages), you need to increase the console log level.

Method 1: Using dmesg Command

sudo dmesg -n 5

This changes the console log level to 5, so you’ll now see:

  • KERN_EMERG (0)
  • KERN_ALERT (1)
  • KERN_CRIT (2)
  • KERN_ERR (3)
  • KERN_WARNING (4)
  • KERN_NOTICE (5) ← Now visible!

Method 2: Direct Write to /proc

echo 7 > /proc/sys/kernel/printk

This sets console log level to 7, showing ALL kernel messages on the console (including DEBUG messages).

Modern Logging: pr_* Macros

Instead of using printk(KERN_WARNING "message"), modern kernel code uses cleaner, more readable pr_* macros. These macros are defined in <linux/printk.h> and provide a simpler syntax.

Available pr_* Macros

Macro Log Level Equivalent printk Use For
pr_emerg() 0 printk(KERN_EMERG ...) System is unusable
pr_alert() 1 printk(KERN_ALERT ...) Action must be taken immediately
pr_crit() 2 printk(KERN_CRIT ...) Critical conditions
pr_err() 3 printk(KERN_ERR ...) Error conditions
pr_warn() 4 printk(KERN_WARNING ...) Warning conditions
pr_notice() 5 printk(KERN_NOTICE ...) Normal but significant
pr_info() 6 printk(KERN_INFO ...) Informational messages
pr_debug() 7 printk(KERN_DEBUG ...)* Debug-level messages

⚠️ Special Note on pr_debug(): Unlike the other pr_* macros, pr_debug() does NOT always expand to printk(). By default, it’s disabled and compiles to nothing! We’ll cover this in detail below.

Advantages of pr_* Macros

  • Cleaner syntax: More readable than printk(KERN_WARNING ...)
  • Type safety: Better compile-time checking
  • Automatic formatting: Includes module information via pr_fmt()
  • Modern standard: Preferred in new kernel code

Rate-Limited Versions

When logging inside loops or frequently-called functions, you can flood the kernel log buffer. Linux provides rate-limited versions of these macros to prevent log spam.

These macros are defined in <linux/printk.h>:

#define pr_emerg_ratelimited(fmt, ...)
        printk_ratelimited(KERN_EMERG pr_fmt(fmt), ##__VA_ARGS__)

#define pr_alert_ratelimited(fmt, ...)
        printk_ratelimited(KERN_ALERT pr_fmt(fmt), ##__VA_ARGS__)

#define pr_crit_ratelimited(fmt, ...)
        printk_ratelimited(KERN_CRIT pr_fmt(fmt), ##__VA_ARGS__)

#define pr_err_ratelimited(fmt, ...)
        printk_ratelimited(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__)

#define pr_warn_ratelimited(fmt, ...)
        printk_ratelimited(KERN_WARNING pr_fmt(fmt), ##__VA_ARGS__)

#define pr_notice_ratelimited(fmt, ...)
        printk_ratelimited(KERN_NOTICE pr_fmt(fmt), ##__VA_ARGS__)

#define pr_info_ratelimited(fmt, ...)
        printk_ratelimited(KERN_INFO pr_fmt(fmt), ##__VA_ARGS__)

When to Use Rate-Limited Macros

  • Inside interrupt handlers that fire frequently
  • In packet processing code (network drivers)
  • Within loops that may execute many times
  • Any code path that could generate excessive log messages

Practical Example 1: Using pr_info() and pr_warn()

Let’s create a simple kernel module that demonstrates the difference between pr_info() and pr_warn(), and shows how console log levels affect visibility.

Module Source Code (without_printk.c)

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

MODULE_LICENSE("GPL");

static int hello_init(void)
{
    pr_info("%s: init without printk\n", __func__);
    return 0;
}

static void hello_exit(void)
{
    pr_warn("%s: hello exit without printk\n", __func__);
}

module_init(hello_init);
module_exit(hello_exit);

Understanding the Code

  • pr_info(): Logs at KERN_INFO level (6) – won’t appear on console with default settings
  • pr_warn(): Logs at KERN_WARNING level (4) – WILL appear on console with default settings
  • __func__: Compiler macro that expands to the function name

Makefile

obj-m := without_printk.o

all:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) modules

clean:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) clean

Building and Testing Example 1

Step 1: Compile the Module

make

This creates without_printk.ko

Step 2: Load the Module

sudo insmod without_printk.ko

The module loads, but you won’t see any output in your terminal!

Step 3: Check dmesg

dmesg | tail

Output:

[6613.577912] hello_init: init without printk

The pr_info() message is logged but NOT shown on console (level 6 > 4)

Step 4: Remove the Module

sudo rmmod without_printk

Step 5: Check dmesg Again

dmesg | tail

Output:

[6613.577912] hello_init: init without printk
[6631.941546] hello_exit: hello exit without printk

Both messages are in the kernel ring buffer

Using dmesg -x to See Log Levels

The dmesg -x command shows messages with their log level tags:

dmesg -x | grep hello

Output:

kern  :info  : [6613.577912] hello_init: init without printk
kern  :warn  : [6631.941546] hello_exit: hello exit without printk

This clearly shows:

  • The init message is at info level (6)
  • The exit message is at warn level (4)

Testing with Console Log Level Changes

Experiment: Increase Console Log Level

sudo dmesg -n 7
cat /proc/sys/kernel/printk

Output:

7  4  1  7

Now switch to console (Ctrl+Alt+F4), login, and reload the module:

sudo insmod without_printk.ko

Result: You’ll now see the pr_info() message on the console!

The Special Case: pr_debug()

Among all the pr_* macros, pr_debug() is unique and requires special attention. Unlike other logging macros that always compile to actual printk() calls, pr_debug() is disabled by default for performance reasons.

⚠️ Important Discovery: If you use pr_debug() in your kernel module and don’t see the output in dmesg, it’s not a bug – it’s disabled by default! Your debug messages are being compiled into a dummy function that does nothing.

Why pr_debug() is Different

Debug messages are extremely useful during development but can cause performance overhead in production systems. The kernel developers designed pr_debug() to be conditionally compiled – it only generates actual logging code when explicitly enabled.

Understanding the Conditional Compilation

Let’s look at how pr_debug() is defined in <linux/printk.h>:

#if defined(CONFIG_DYNAMIC_DEBUG)
#define pr_debug(fmt, ...) \
    dynamic_pr_debug(fmt, ##__VA_ARGS__)

#elif defined(DEBUG)
#define pr_debug(fmt, ...) \
    printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)

#else
#define pr_debug(fmt, ...) \
    no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif

This preprocessor code shows three different behaviors:

Condition Macro Expands To Behavior
CONFIG_DYNAMIC_DEBUG defined dynamic_pr_debug() Runtime control via debugfs
DEBUG defined printk(KERN_DEBUG ...) Always prints (compile-time enabled)
Neither defined (default) no_printk() Does nothing (optimized out)

What is no_printk()?

The no_printk() macro is a “dummy printk” that does absolutely nothing. It’s designed to be optimized away by the compiler, resulting in zero runtime overhead. Your debug statements remain in the source code for readability, but they don’t affect the compiled binary size or performance.

The no_printk() Definition

static inline __printf(1, 2) __cold
int no_printk(const char *fmt, ...)
{
    return 0;
}

This inline function does nothing and gets completely optimized out by the compiler. It exists purely to maintain format string checking at compile time.

Practical Example 2: Understanding pr_debug()

Let’s create another kernel module that demonstrates the difference between printk(KERN_DEBUG) and pr_debug(), showing why one works by default and the other doesn’t.

Module Source Code (ex2.c)

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

MODULE_LICENSE("GPL");

static int init_fun(void)
{
    printk(KERN_DEBUG "%s: in init printk\n", __func__);
    pr_debug("%s: pr_debug fun\n", __func__);
    return 0;
}

static void exit_fun(void)
{
    pr_warn("%s: in exit pr_warn\n", __func__);
    pr_debug("%s: in exit pr_debug\n", __func__);
}

module_init(init_fun);
module_exit(exit_fun);

Understanding This Code

  • Line 8: printk(KERN_DEBUG ...) – Always logs to kernel buffer
  • Line 9: pr_debug() – Only logs if DEBUG is defined
  • Line 14: pr_warn() – Always logs (warning level)
  • Line 15: pr_debug() – Only logs if DEBUG is defined

Test 1: Default Behavior (DEBUG Not Defined)

Makefile (Without DEBUG)

obj-m := ex2.o

all:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) modules

clean:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) clean

Compile and Load

make
sudo insmod ex2.ko

Check dmesg Output

dmesg | tail

Output:

[7184.179250] init_fun: in init printk

Notice: Only ONE message appears! The pr_debug() message is missing.

Remove the Module

sudo rmmod ex2

Check dmesg Again

dmesg | tail

Output:

[7184.179250] init_fun: in init printk
[7356.590033] exit_fun: in exit pr_warn

Notice: The pr_debug() messages from both init and exit are MISSING!

Why Are pr_debug() Messages Missing?

Explanation

Without the DEBUG macro defined:

  • pr_debug() compiles to no_printk()
  • no_printk() is a dummy function that does nothing
  • The compiler optimizes it away completely
  • Result: Zero runtime overhead, but no debug output

Meanwhile, printk(KERN_DEBUG ...) ALWAYS generates a log message because it’s a direct printk() call, not a conditional macro.

Test 2: Enabling DEBUG with ccflags

To enable pr_debug(), we need to define the DEBUG macro during compilation. The cleanest way is to use ccflags-y in the Makefile.

Modified Makefile (With DEBUG Enabled)

obj-m := ex2.o
ccflags-y := -DDEBUG

all:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) modules

clean:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) clean

Key Change: Added ccflags-y := -DDEBUG

This defines the DEBUG macro for all C files in the module.

Clean and Rebuild

make clean
make

This ensures the module is recompiled with DEBUG defined.

Load the Module

sudo insmod ex2.ko

Check dmesg Output

dmesg | tail

Output:

[7747.956990] init_fun: in init printk
[7747.956995] init_fun: pr_debug fun

Success! Both messages appear now!

Remove the Module

sudo rmmod ex2

Check dmesg Again

dmesg | tail

Output:

[7747.956990] init_fun: in init printk
[7747.956995] init_fun: pr_debug fun
[7758.197692] exit_fun: in exit pr_warn
[7758.197697] exit_fun: in exit pr_debug

Perfect! All four messages appear, including both pr_debug() calls!

Understanding ccflags-y

The Makefile variable ccflags-y passes compiler flags to all C files being compiled in the module.

Makefile Variable Purpose Scope
ccflags-y Compiler flags for all files All .c files in the module
ccflags-$(CONFIG_XXX) Conditional compilation flags Based on kernel config
CFLAGS_file.o Flags for specific file Only file.c

Common ccflags-y Uses

# Enable debug messages
ccflags-y := -DDEBUG

# Add include path
ccflags-y := -I$(src)/include

# Enable warnings
ccflags-y := -Wall -Wextra

# Multiple flags
ccflags-y := -DDEBUG -Wall -I$(src)/include

Comparison: printk(KERN_DEBUG) vs pr_debug()

Now that we’ve seen both approaches in action, let’s compare them:

Aspect printk(KERN_DEBUG …) pr_debug(…)
Always Compiled? ✅ Yes ❌ No (conditional)
Runtime Overhead Always present Zero when disabled
Binary Size Impact Increases binary size No impact when disabled
Enable Method N/A (always on) Define DEBUG macro
Production Use Not recommended Safe (optimized out)
Syntax Verbose Clean
Best For Always-needed logs Development debugging

When to Use Each

Use printk(KERN_DEBUG …) when:

  • You want the message to ALWAYS be logged
  • The log is critical for diagnostics even in production
  • You’re okay with the runtime overhead

Use pr_debug() when:

  • The message is only needed during development
  • You want zero overhead in production builds
  • You’re following modern kernel coding standards
  • You want cleaner, more maintainable code

Advanced: Dynamic Debug

For even more flexibility, the kernel provides dynamic debug, which allows you to enable/disable specific debug messages at runtime without recompiling.

Enabling Dynamic Debug

Dynamic debug is enabled when the kernel is compiled with CONFIG_DYNAMIC_DEBUG=y. Check if it’s available:

cat /boot/config-$(uname -r) | grep CONFIG_DYNAMIC_DEBUG

If enabled, pr_debug() messages can be controlled via the debugfs interface:

# Enable all pr_debug in a specific module
echo 'module my_module +p' > /sys/kernel/debug/dynamic_debug/control

# Disable all pr_debug in a module
echo 'module my_module -p' > /sys/kernel/debug/dynamic_debug/control

# Enable pr_debug for specific file
echo 'file my_driver.c +p' > /sys/kernel/debug/dynamic_debug/control

# Enable pr_debug for specific function
echo 'func my_function +p' > /sys/kernel/debug/dynamic_debug/control

Advantages of Dynamic Debug

  • No recompilation: Enable/disable at runtime
  • Fine-grained control: Enable specific files, functions, or lines
  • Production debugging: Can enable debug when issues occur
  • Minimal overhead: Small runtime cost when disabled

Best Practices for Kernel Logging

  1. Use pr_* macros instead of raw printk: More readable and maintainable
    // Good
    pr_info("Device initialized successfully\n");
    
    // Avoid
    printk(KERN_INFO "Device initialized successfully\n");
  2. Use pr_debug() for development-only messages:
    // Good - zero overhead in production
    pr_debug("%s: Entered function, state=%d\n", __func__, state);
    
    // Avoid in production
    pr_info("%s: Entered function, state=%d\n", __func__, state);
  3. Choose appropriate log levels: Match severity to the situation
    • pr_err(): Actual errors that prevent functionality
    • pr_warn(): Unusual conditions that may need attention
    • pr_info(): Normal operational messages
    • pr_debug(): Detailed debugging information
  4. Use rate-limited versions in hot paths: Prevent log flooding
    // In frequently-called function
    pr_warn_ratelimited("Packet dropped: buffer full\n");
  5. Include context in messages: Use __func__ for function names
    pr_info("%s: Starting initialization\n", __func__);
  6. Enable DEBUG only during development:
    # Development Makefile
    ccflags-y := -DDEBUG
    
    # Production Makefile (comment it out)
    # ccflags-y := -DDEBUG
  7. Always clean before rebuilding with new flags:
    make clean
    make
  8. For device drivers, use dev_* variants: Automatically includes device information
    dev_info(&pdev->dev, "Device probe successful\n");

Common Issues and Solutions

Issue 1: Module Loads But No Messages Anywhere

Problem: You insert a module but don’t see messages in dmesg or console.

Solution:

  • Check if the module actually loaded: lsmod | grep your_module
  • Verify the init function is being called: dmesg | tail -20
  • Ensure you’re using correct log level: Try pr_warn() instead of pr_info()
  • Check for compilation errors: Look at make output carefully

Issue 2: Messages in dmesg But Not on Console

Problem: dmesg shows your messages, but they don’t appear on the console.

Solution:

cat /proc/sys/kernel/printk

Check the first value (console log level). If your message priority is higher than this value, increase it:

sudo dmesg -n 7  # Show all messages on console

Issue 3: pr_debug() Messages Still Not Appearing

Problem: Even after adding ccflags-y := -DDEBUG, messages don’t appear.

Solutions:

Solution 1: Ensure Clean Rebuild

make clean
make

Object files may be cached. Always clean before rebuilding with new flags.

Solution 2: Check Console Log Level

cat /proc/sys/kernel/printk

If the first value is less than 7, KERN_DEBUG messages won’t appear on console:

sudo dmesg -n 7

Solution 3: Verify Compilation

make V=1

Verbose output shows if -DDEBUG is actually being passed to gcc:

gcc ... -DDEBUG ... -c -o ex2.o ex2.c

Solution 4: Check dmesg, Not Console

dmesg | grep "init_fun"

Debug messages always go to kernel buffer first, even if not on console.

Issue 4: Can’t Switch to Console

Problem: Ctrl+Alt+F4 doesn’t switch to console.

Solutions:

  • Try other function keys: F1 through F12
  • Some systems use Ctrl+Alt+F1 or Ctrl+Alt+F2
  • On some laptops, you need Fn + Ctrl + Alt + F4
  • Check if your system has virtual consoles enabled
  • Try from a different desktop environment

Conclusion: Mastering Kernel Message Output and Debug Logging

Understanding the difference between consoles and terminal emulators, combined with proper use of logging macros, is crucial for effective kernel development. Remember these key points:

  • GUI terminals don’t show kernel messages – they’re user-space applications
  • Use real consoles (Ctrl+Alt+F4) to see kernel messages in real-time
  • Console log level determines which messages appear on console vs dmesg only
  • pr_* macros are the modern, preferred way to log kernel messages
  • pr_info() and pr_warn() always work – use for normal logging
  • pr_debug() is special – disabled by default, enabled with ccflags-y := -DDEBUG
  • Always use make clean when changing compiler flags
  • printk(KERN_DEBUG) always logs, but pr_debug() is optimized out when disabled
  • Use appropriate log levels – info for information, warn for warnings, err for errors, debug for debugging
  • pr_debug() has zero overhead when disabled – perfect for development logging

⚠️ Most Common Mistake: Developers often forget to clean and rebuild after adding ccflags-y := -DDEBUG. The module loads successfully but pr_debug() still doesn’t work because old object files without DEBUG were used. Always run make clean first!

With this knowledge, you can now effectively debug kernel modules, understand why messages appear where they do, control kernel logging behavior for both development and production systems, and use both pr_info()/pr_warn() for normal logging and pr_debug() for development-only debugging without any production overhead.

🎓 Learn More: Free Embedded Systems Course

This tutorial is part of our comprehensive free embedded systems course at EmbeddedPathashala. We offer in-depth tutorials on:

  • Linux kernel programming and device drivers
  • Embedded Linux development
  • Kernel debugging and troubleshooting
  • Real-time operating systems
  • Hardware-software integration
  • Kernel module programming

Visit EmbeddedPathashala.com →

Related Topics You Might Find Useful

  • Understanding Linux Kernel printk: Complete Guide to Ring Buffer Management
  • Linux Device Driver Development: Getting Started
  • Kernel Debugging Techniques for Embedded Systems
  • Understanding the Linux Boot Process
  • Writing Your First Linux Kernel Module
  • Dynamic Debug: Runtime Control of Kernel Logging

Keywords: Linux console, kernel messages, printk console output, pr_info, pr_warn, pr_debug, DEBUG macro, ccflags-y, no_printk, printk vs pr_debug, terminal emulator vs console, X Window System, console log level, dmesg, kernel logging, Linux device drivers, embedded systems programming, kernel module development, virtual console, /proc/sys/kernel/printk, rate limited logging, embedded Linux tutorial, free embedded systems course, kernel debugging

Leave a Reply

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