1.. SPDX-License-Identifier: GPL-2.0 2 3============ 4Printk Index 5============ 6 7There are many ways how to monitor the state of the system. One important 8source of information is the system log. It provides a lot of information, 9including more or less important warnings and error messages. 10 11There are monitoring tools that filter and take action based on messages 12logged. 13 14The kernel messages are evolving together with the code. As a result, 15particular kernel messages are not KABI and never will be! 16 17It is a huge challenge for maintaining the system log monitors. It requires 18knowing what messages were updated in a particular kernel version and why. 19Finding these changes in the sources would require non-trivial parsers. 20Also it would require matching the sources with the binary kernel which 21is not always trivial. Various changes might be backported. Various kernel 22versions might be used on different monitored systems. 23 24This is where the printk index feature might become useful. It provides 25a dump of printk formats used all over the source code used for the kernel 26and modules on the running system. It is accessible at runtime via debugfs. 27 28The printk index helps to find changes in the message formats. Also it helps 29to track the strings back to the kernel sources and the related commit. 30 31 32User Interface 33============== 34 35The index of printk formats are split in into separate files. The files are 36named according to the binaries where the printk formats are built-in. There 37is 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 43Note that only loaded modules are shown. Also printk formats from a module 44might appear in "vmlinux" when the module is built-in. 45 46The 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 67The extra information makes it a bit harder to find differences 68between various kernels. Especially the line number might change 69very often. On the other hand, it helps a lot to confirm that 70it is the same string or find the commit that is responsible 71for eventual changes. 72 73 74printk() Is Not a Stable KABI 75============================= 76 77Several developers are afraid that exporting all these implementation 78details into the user space will transform particular printk() calls 79into KABI. 80 81But it is exactly the opposite. printk() calls must _not_ be KABI. 82And the printk index helps user space tools to deal with this. 83 84 85Subsystem specific printk wrappers 86================================== 87 88The printk index is generated using extra metadata that are stored in 89a dedicated .elf section ".printk_index". It is achieved using macro 90wrappers doing __printk_index_emit() together with the real printk() 91call. The same technique is used also for the metadata used by 92the dynamic debug feature. 93 94The metadata are stored for a particular message only when it is printed 95using these special wrappers. It is implemented for the commonly 96used printk() calls, including, for example, pr_warn(), or pr_once(). 97 98Additional changes are necessary for various subsystem specific wrappers 99that call the original printk() via a common helper function. These needs 100their own wrappers adding __printk_index_emit(). 101 102Only few subsystem specific wrappers have been updated so far, 103for example, dev_printk(). As a result, the printk formats from 104some subsystes can be missing in the printk index. 105 106 107Subsystem specific prefix 108========================= 109 110The macro pr_fmt() macro allows to define a prefix that is printed 111before the string generated by the related printk() calls. 112 113Subsystem specific wrappers usually add even more complicated 114prefixes. 115 116These prefixes can be stored into the printk index metadata 117by an optional parameter of __printk_index_emit(). The debugfs 118interface might then show the printk formats including these prefixes. 119For 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 131This 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 135It helps matching messages from the real log with printk index. 136Then the source file name, line number, and function name can 137be used to match the string with the source code. 138