Commit | Line | Data |
---|---|---|
a5c7a39f PM |
1 | .. SPDX-License-Identifier: GPL-2.0 |
2 | ||
3 | ============ | |
4 | Printk Index | |
5 | ============ | |
6 | ||
7 | There are many ways how 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 subsystes 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. |