123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137 |
- .. SPDX-License-Identifier: GPL-2.0
- ============
- Printk Index
- ============
- There are many ways how to monitor the state of the system. One important
- source of information is the system log. It provides a lot of information,
- including more or less important warnings and error messages.
- There are monitoring tools that filter and take action based on messages
- logged.
- The kernel messages are evolving together with the code. As a result,
- particular kernel messages are not KABI and never will be!
- It is a huge challenge for maintaining the system log monitors. It requires
- knowing what messages were updated in a particular kernel version and why.
- Finding these changes in the sources would require non-trivial parsers.
- Also it would require matching the sources with the binary kernel which
- is not always trivial. Various changes might be backported. Various kernel
- versions might be used on different monitored systems.
- This is where the printk index feature might become useful. It provides
- a dump of printk formats used all over the source code used for the kernel
- and modules on the running system. It is accessible at runtime via debugfs.
- 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.
- User Interface
- ==============
- The index of printk formats are split in into separate files. The files are
- named according to the binaries where the printk formats are built-in. There
- is always "vmlinux" and optionally also modules, for example::
- /sys/kernel/debug/printk/index/vmlinux
- /sys/kernel/debug/printk/index/ext4
- /sys/kernel/debug/printk/index/scsi_mod
- Note that only loaded modules are shown. Also printk formats from a module
- might appear in "vmlinux" when the module is built-in.
- 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"
- , where the meaning is:
- - :level: log level value: 0-7 for particular severity, -1 as default,
- 'c' as continuous line without an explicit log level
- - :flags: optional flags: currently only 'c' for KERN_CONT
- - :filename\:line: source filename and line number of the related
- printk() call. Note that there are many wrappers, for example,
- pr_warn(), pr_warn_once(), dev_warn().
- - :function: function name where the printk() call is used.
- - :format: format string
- The extra information makes it a bit harder to find differences
- between various kernels. Especially the line number might change
- very often. On the other hand, it helps a lot to confirm that
- it is the same string or find the commit that is responsible
- for eventual changes.
- printk() Is Not a Stable KABI
- =============================
- Several developers are afraid that exporting all these implementation
- details into the user space will transform particular printk() calls
- into KABI.
- But it is exactly the opposite. printk() calls must _not_ be KABI.
- And the printk index helps user space tools to deal with this.
- Subsystem specific printk wrappers
- ==================================
- The printk index is generated using extra metadata that are stored in
- a dedicated .elf section ".printk_index". It is achieved using macro
- wrappers doing __printk_index_emit() together with the real printk()
- call. The same technique is used also for the metadata used by
- the dynamic debug feature.
- The metadata are stored for a particular message only when it is printed
- using these special wrappers. It is implemented for the commonly
- used printk() calls, including, for example, pr_warn(), or pr_once().
- Additional changes are necessary for various subsystem specific wrappers
- that call the original printk() via a common helper function. These needs
- their own wrappers adding __printk_index_emit().
- Only few subsystem specific wrappers have been updated so far,
- for example, dev_printk(). As a result, the printk formats from
- some subsystes can be missing in the printk index.
- 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.
- Subsystem specific wrappers usually add even more complicated
- prefixes.
- These prefixes can be stored into the printk index metadata
- by an optional parameter of __printk_index_emit(). The debugfs
- interface might then show the printk formats including these prefixes.
- For example, drivers/acpi/osl.c contains::
- #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"
- It helps matching messages from the real log with printk index.
- Then the source file name, line number, and function name can
- be used to match the string with the source code.
|