Documentation/core-api/printk-index.rst

   1 .. SPDX-License-Identifier: GPL-2.0
   2
   3 ============
   4 Printk Index
   5 ============
   6
   7 There are many ways to monitor the state of the system. One important
   8 source of information is the system log. It provides a lot of information,
   9 including more or less important warnings and error messages.
  10
  11 There are monitoring tools that filter and take action based on messages
  12 logged.
  13
  14 The kernel messages are evolving together with the code. As a result,
  15 particular kernel messages are not KABI and never will be!
  16
  17 It is a huge challenge for maintaining the system log monitors. It requires
  18 knowing what messages were updated in a particular kernel version and why.
  19 Finding these changes in the sources would require non-trivial parsers.
  20 Also it would require matching the sources with the binary kernel which
  21 is not always trivial. Various changes might be backported. Various kernel
  22 versions might be used on different monitored systems.
  23
  24 This is where the printk index feature might become useful. It provides
  25 a dump of printk formats used all over the source code used for the kernel
  26 and modules on the running system. It is accessible at runtime via debugfs.
  27
  28 The printk index helps to find changes in the message formats. Also it helps
  29 to track the strings back to the kernel sources and the related commit.
  30
  31
  32 User Interface
  33 ==============
  34
  35 The index of printk formats are split in into separate files. The files are
  36 named according to the binaries where the printk formats are built-in. There
  37 is always "vmlinux" and optionally also modules, for example::
  38
  39    /sys/kernel/debug/printk/index/vmlinux
  40    /sys/kernel/debug/printk/index/ext4
  41    /sys/kernel/debug/printk/index/scsi_mod
  42
  43 Note that only loaded modules are shown. Also printk formats from a module
  44 might appear in "vmlinux" when the module is built-in.
  45
  46 The content is inspired by the dynamic debug interface and looks like::
  47
  48    $> head -1 /sys/kernel/debug/printk/index/vmlinux; shuf -n 5 vmlinux
  49    # <level[,flags]> filename:line function "format"
  50    <5> block/blk-settings.c:661 disk_stack_limits "%s: Warning: Device %s is misaligned\n"
  51    <4> kernel/trace/trace.c:8296 trace_create_file "Could not create tracefs '%s' entry\n"
  52    <6> arch/x86/kernel/hpet.c:144 _hpet_print_config "hpet: %s(%d):\n"
  53    <6> init/do_mounts.c:605 prepare_namespace "Waiting for root device %s...\n"
  54    <6> drivers/acpi/osl.c:1410 acpi_no_auto_serialize_setup "ACPI: auto-serialization disabled\n"
  55
  56 , where the meaning is:
  57
  58    - :level: log level value: 0-7 for particular severity, -1 as default,
  59         'c' as continuous line without an explicit log level
  60    - :flags: optional flags: currently only 'c' for KERN_CONT
  61    - :filename\:line: source filename and line number of the related
  62         printk() call. Note that there are many wrappers, for example,
  63         pr_warn(), pr_warn_once(), dev_warn().
  64    - :function: function name where the printk() call is used.
  65    - :format: format string
  66
  67 The extra information makes it a bit harder to find differences
  68 between various kernels. Especially the line number might change
  69 very often. On the other hand, it helps a lot to confirm that
  70 it is the same string or find the commit that is responsible
  71 for eventual changes.
  72
  73
  74 printk() Is Not a Stable KABI
  75 =============================
  76
  77 Several developers are afraid that exporting all these implementation
  78 details into the user space will transform particular printk() calls
  79 into KABI.
  80
  81 But it is exactly the opposite. printk() calls must _not_ be KABI.
  82 And the printk index helps user space tools to deal with this.
  83
  84
  85 Subsystem specific printk wrappers
  86 ==================================
  87
  88 The printk index is generated using extra metadata that are stored in
  89 a dedicated .elf section ".printk_index". It is achieved using macro
  90 wrappers doing __printk_index_emit() together with the real printk()
  91 call. The same technique is used also for the metadata used by
  92 the dynamic debug feature.
  93
  94 The metadata are stored for a particular message only when it is printed
  95 using these special wrappers. It is implemented for the commonly
  96 used printk() calls, including, for example, pr_warn(), or pr_once().
  97
  98 Additional changes are necessary for various subsystem specific wrappers
  99 that call the original printk() via a common helper function. These needs
 100 their own wrappers adding __printk_index_emit().
 101
 102 Only few subsystem specific wrappers have been updated so far,
 103 for example, dev_printk(). As a result, the printk formats from
 104 some subsystems can be missing in the printk index.
 105
 106
 107 Subsystem specific prefix
 108 =========================
 109
 110 The macro pr_fmt() macro allows to define a prefix that is printed
 111 before the string generated by the related printk() calls.
 112
 113 Subsystem specific wrappers usually add even more complicated
 114 prefixes.
 115
 116 These prefixes can be stored into the printk index metadata
 117 by an optional parameter of __printk_index_emit(). The debugfs
 118 interface might then show the printk formats including these prefixes.
 119 For example, drivers/acpi/osl.c contains::
 120
 121   #define pr_fmt(fmt) "ACPI: OSL: " fmt
 122
 123   static int __init acpi_no_auto_serialize_setup(char *str)
 124   {
 125         acpi_gbl_auto_serialize_methods = FALSE;
 126         pr_info("Auto-serialization disabled\n");
 127
 128         return 1;
 129   }
 130
 131 This results in the following printk index entry::
 132
 133   <6> drivers/acpi/osl.c:1410 acpi_no_auto_serialize_setup "ACPI: auto-serialization disabled\n"
 134
 135 It helps matching messages from the real log with printk index.
 136 Then the source file name, line number, and function name can
 137 be used to match the string with the source code.