printk

• Printk

  • Message logging

  • Specifiers

  • Printk Index

  • Subsystem specific prefix

  • References

Printk

• printk() is one of the most widely known functions in the Linux kernel

• standard tool we have for printing messages and usually the most basic way of tracing and debugging

• All printk() messages are printed to the kernel log buffer, which is a ring buffer exported to userspace through /dev/kmsg. The usual way to read it is using dmesg.

Message logging

• printk() can specify a log level : printk(KERN_INFO "Message: %s\n", arg);

Name	String	Alias function
KERN_EMERG	“0”	pr_emerg()
KERN_ALERT	“1”	pr_alert()
KERN_CRIT	“2”	pr_crit()
KERN_ERR	“3”	pr_err()
KERN_WARNING	“4”	pr_warn()
KERN_NOTICE	“5”	pr_notice()
KERN_INFO	“6”	pr_info()
KERN_DEBUG	“7”	pr_debug() and pr_devel() if DEBUG is defined
KERN_DEFAULT	“”
KERN_CONT	“c”	pr_cont()

• To check the current console_loglevel : (shows current, default, minimum and boot-time-default log levels)

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

• This can be changed using # echo 8 > /proc/sys/kernel/printk or # dmesg -n 5.

• pr_info, pr_debug are macros that help to print logs at different levels

Specifiers

There are many print specifiers present, it’s better to check these specifiers before using printk. These are available at : Printk Formats - Kernel Docs.

The common types are :

• Integer Types (signed char, unsigned char, int, unsigned short int, etc.)

• Pointer Types

  • Plain Pointers

  • Error Pointers

  • Symbol/Function Pointers (Eg : %pS versatile_init+0x0/0x110)

  • Probe pointers from BPF/tracing

  • Kernel Pointers

  • Unmodified address

  • Pointer Differences

  • Struct Resources

  • Physical addresses (%pa[p] 0x01234567 or 0x0123456789abcdef)

  • DMA addresses (%pad 0x01234567 or 0x0123456789abcdef)

  • Raw buffer

  • MAC addresses (%pM 00:01:02:03:04:05)

  • IPv4/v6 Addresses (%pI4 1.2.3.4)

  • UID/GUID (%pUb 00010203-0405-0607-0809-0a0b0c0d0e0f)

  • Dentrys (%pd{,2,3,4})

  • And many more …

Printk Index

The kernel messages are evolving together with the code. As a result, particular kernel messages are not KABI and never will be! (See : Kernel ABI doc for KABI)

• The printk index helps to find changes in the message formats. Also it helps to track the strings back to the kernel sources and the related commit.

• The index of printk formats are split in into separate files.

/sys/kernel/debug/printk/index/vmlinux
/sys/kernel/debug/printk/index/ext4
/sys/kernel/debug/printk/index/scsi_mod

The content is inspired by the dynamic debug interface and looks like:

$> head -1 /sys/kernel/debug/printk/index/vmlinux; shuf -n 5 vmlinux
# <level[,flags]> filename:line function "format"
<5> block/blk-settings.c:661 disk_stack_limits "%s: Warning: Device %s is misaligned\n"
<4> kernel/trace/trace.c:8296 trace_create_file "Could not create tracefs '%s' entry\n"
<6> arch/x86/kernel/hpet.c:144 _hpet_print_config "hpet: %s(%d):\n"
<6> init/do_mounts.c:605 prepare_namespace "Waiting for root device %s...\n"
<6> drivers/acpi/osl.c:1410 acpi_no_auto_serialize_setup "ACPI: auto-serialization disabled\n"

Subsystem specific prefix

• The macro pr_fmt() macro allows to define a prefix that is printed before the string generated by the related printk() calls.

#define pr_fmt(fmt) "ACPI: OSL: " fmt

static int __init acpi_no_auto_serialize_setup(char *str)
{
      acpi_gbl_auto_serialize_methods = FALSE;
      pr_info("Auto-serialization disabled\n");

      return 1;
}

This results in the following printk index entry:

<6> drivers/acpi/osl.c:1410 acpi_no_auto_serialize_setup "ACPI: auto-serialization disabled\n"

References

• Printk Basics - Kernel Docs
• Printk Formats - Kernel Docs
• Printk Index - Kernel Docs