]>
Commit | Line | Data |
---|---|---|
7d4e3517 MCC |
1 | Dynamic debug |
2 | +++++++++++++ | |
3 | ||
86151fdf JB |
4 | |
5 | Introduction | |
6 | ============ | |
7 | ||
29e36c9f | 8 | This document describes how to use the dynamic debug (dyndbg) feature. |
86151fdf | 9 | |
29e36c9f JC |
10 | Dynamic debug is designed to allow you to dynamically enable/disable |
11 | kernel code to obtain additional kernel information. Currently, if | |
7d4e3517 MCC |
12 | ``CONFIG_DYNAMIC_DEBUG`` is set, then all ``pr_debug()``/``dev_dbg()`` and |
13 | ``print_hex_dump_debug()``/``print_hex_dump_bytes()`` calls can be dynamically | |
7a555613 VK |
14 | enabled per-callsite. |
15 | ||
7d4e3517 MCC |
16 | If ``CONFIG_DYNAMIC_DEBUG`` is not set, ``print_hex_dump_debug()`` is just |
17 | shortcut for ``print_hex_dump(KERN_DEBUG)``. | |
7a555613 | 18 | |
7d4e3517 MCC |
19 | For ``print_hex_dump_debug()``/``print_hex_dump_bytes()``, format string is |
20 | its ``prefix_str`` argument, if it is constant string; or ``hexdump`` | |
21 | in case ``prefix_str`` is build dynamically. | |
86151fdf JB |
22 | |
23 | Dynamic debug has even more useful features: | |
24 | ||
29e36c9f JC |
25 | * Simple query language allows turning on and off debugging |
26 | statements by matching any combination of 0 or 1 of: | |
86151fdf JB |
27 | |
28 | - source filename | |
29 | - function name | |
30 | - line number (including ranges of line numbers) | |
31 | - module name | |
32 | - format string | |
33 | ||
7d4e3517 | 34 | * Provides a debugfs control file: ``<debugfs>/dynamic_debug/control`` |
29e36c9f JC |
35 | which can be read to display the complete list of known debug |
36 | statements, to help guide you | |
86151fdf JB |
37 | |
38 | Controlling dynamic debug Behaviour | |
a648ec05 | 39 | =================================== |
86151fdf | 40 | |
7d4e3517 | 41 | The behaviour of ``pr_debug()``/``dev_dbg()`` are controlled via writing to a |
29e36c9f JC |
42 | control file in the 'debugfs' filesystem. Thus, you must first mount |
43 | the debugfs filesystem, in order to make use of this feature. | |
44 | Subsequently, we refer to the control file as: | |
7d4e3517 MCC |
45 | ``<debugfs>/dynamic_debug/control``. For example, if you want to enable |
46 | printing from source file ``svcsock.c``, line 1603 you simply do:: | |
86151fdf | 47 | |
7d4e3517 | 48 | nullarbor:~ # echo 'file svcsock.c line 1603 +p' > |
86151fdf JB |
49 | <debugfs>/dynamic_debug/control |
50 | ||
7d4e3517 | 51 | If you make a mistake with the syntax, the write will fail thus:: |
86151fdf | 52 | |
7d4e3517 | 53 | nullarbor:~ # echo 'file svcsock.c wtf 1 +p' > |
86151fdf | 54 | <debugfs>/dynamic_debug/control |
7d4e3517 | 55 | -bash: echo: write error: Invalid argument |
86151fdf JB |
56 | |
57 | Viewing Dynamic Debug Behaviour | |
7d4e3517 | 58 | =============================== |
86151fdf | 59 | |
29e36c9f | 60 | You can view the currently configured behaviour of all the debug |
7d4e3517 | 61 | statements via:: |
86151fdf | 62 | |
7d4e3517 MCC |
63 | nullarbor:~ # cat <debugfs>/dynamic_debug/control |
64 | # filename:lineno [module]function flags format | |
65 | /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:323 [svcxprt_rdma]svc_rdma_cleanup =_ "SVCRDMA Module Removed, deregister RPC RDMA transport\012" | |
66 | /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:341 [svcxprt_rdma]svc_rdma_init =_ "\011max_inline : %d\012" | |
67 | /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:340 [svcxprt_rdma]svc_rdma_init =_ "\011sq_depth : %d\012" | |
68 | /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:338 [svcxprt_rdma]svc_rdma_init =_ "\011max_requests : %d\012" | |
69 | ... | |
86151fdf JB |
70 | |
71 | ||
72 | You can also apply standard Unix text manipulation filters to this | |
7d4e3517 | 73 | data, e.g.:: |
86151fdf | 74 | |
7d4e3517 MCC |
75 | nullarbor:~ # grep -i rdma <debugfs>/dynamic_debug/control | wc -l |
76 | 62 | |
86151fdf | 77 | |
7d4e3517 MCC |
78 | nullarbor:~ # grep -i tcp <debugfs>/dynamic_debug/control | wc -l |
79 | 42 | |
86151fdf | 80 | |
29e36c9f JC |
81 | The third column shows the currently enabled flags for each debug |
82 | statement callsite (see below for definitions of the flags). The | |
7d4e3517 MCC |
83 | default value, with no flags enabled, is ``=_``. So you can view all |
84 | the debug statement callsites with any non-default flags:: | |
86151fdf | 85 | |
7d4e3517 MCC |
86 | nullarbor:~ # awk '$3 != "=_"' <debugfs>/dynamic_debug/control |
87 | # filename:lineno [module]function flags format | |
88 | /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svcsock.c:1603 [sunrpc]svc_send p "svc_process: st_sendto returned %d\012" | |
86151fdf JB |
89 | |
90 | Command Language Reference | |
91 | ========================== | |
92 | ||
93 | At the lexical level, a command comprises a sequence of words separated | |
7d4e3517 | 94 | by spaces or tabs. So these are all equivalent:: |
86151fdf | 95 | |
31fc93d5 | 96 | nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' > |
86151fdf | 97 | <debugfs>/dynamic_debug/control |
31fc93d5 | 98 | nullarbor:~ # echo -n ' file svcsock.c line 1603 +p ' > |
86151fdf | 99 | <debugfs>/dynamic_debug/control |
7d4e3517 | 100 | nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' > |
86151fdf JB |
101 | <debugfs>/dynamic_debug/control |
102 | ||
85f7f6c0 | 103 | Command submissions are bounded by a write() system call. |
7d4e3517 | 104 | Multiple commands can be written together, separated by ``;`` or ``\n``:: |
86151fdf | 105 | |
85f7f6c0 JC |
106 | ~# echo "func pnpacpi_get_resources +p; func pnp_assign_mem +p" \ |
107 | > <debugfs>/dynamic_debug/control | |
86151fdf | 108 | |
7d4e3517 | 109 | If your query set is big, you can batch them too:: |
86151fdf | 110 | |
85f7f6c0 | 111 | ~# cat query-batch-file > <debugfs>/dynamic_debug/control |
86151fdf | 112 | |
7d4e3517 MCC |
113 | A another way is to use wildcard. The match rule support ``*`` (matches |
114 | zero or more characters) and ``?`` (matches exactly one character).For | |
115 | example, you can match all usb drivers:: | |
8f073bd0 CD |
116 | |
117 | ~# echo "file drivers/usb/* +p" > <debugfs>/dynamic_debug/control | |
118 | ||
86151fdf | 119 | At the syntactical level, a command comprises a sequence of match |
7d4e3517 | 120 | specifications, followed by a flags change specification:: |
86151fdf | 121 | |
7d4e3517 | 122 | command ::= match-spec* flags-spec |
86151fdf | 123 | |
29e36c9f | 124 | The match-spec's are used to choose a subset of the known pr_debug() |
86151fdf JB |
125 | callsites to which to apply the flags-spec. Think of them as a query |
126 | with implicit ANDs between each pair. Note that an empty list of | |
29e36c9f | 127 | match-specs will select all debug statement callsites. |
86151fdf | 128 | |
29e36c9f JC |
129 | A match specification comprises a keyword, which controls the |
130 | attribute of the callsite to be compared, and a value to compare | |
7d4e3517 MCC |
131 | against. Possible keywords are::: |
132 | ||
133 | match-spec ::= 'func' string | | |
134 | 'file' string | | |
135 | 'module' string | | |
136 | 'format' string | | |
137 | 'line' line-range | |
86151fdf | 138 | |
7d4e3517 MCC |
139 | line-range ::= lineno | |
140 | '-'lineno | | |
141 | lineno'-' | | |
142 | lineno'-'lineno | |
86151fdf | 143 | |
7d4e3517 MCC |
144 | lineno ::= unsigned-int |
145 | ||
146 | .. note:: | |
147 | ||
148 | ``line-range`` cannot contain space, e.g. | |
149 | "1-30" is valid range but "1 - 30" is not. | |
86151fdf | 150 | |
86151fdf JB |
151 | |
152 | The meanings of each keyword are: | |
153 | ||
154 | func | |
155 | The given string is compared against the function name | |
7d4e3517 | 156 | of each callsite. Example:: |
86151fdf | 157 | |
7d4e3517 | 158 | func svc_tcp_accept |
86151fdf JB |
159 | |
160 | file | |
2b678319 JC |
161 | The given string is compared against either the full pathname, the |
162 | src-root relative pathname, or the basename of the source file of | |
7d4e3517 | 163 | each callsite. Examples:: |
86151fdf | 164 | |
7d4e3517 MCC |
165 | file svcsock.c |
166 | file kernel/freezer.c | |
167 | file /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svcsock.c | |
86151fdf JB |
168 | |
169 | module | |
170 | The given string is compared against the module name | |
171 | of each callsite. The module name is the string as | |
7d4e3517 MCC |
172 | seen in ``lsmod``, i.e. without the directory or the ``.ko`` |
173 | suffix and with ``-`` changed to ``_``. Examples:: | |
86151fdf | 174 | |
7d4e3517 MCC |
175 | module sunrpc |
176 | module nfsd | |
86151fdf JB |
177 | |
178 | format | |
179 | The given string is searched for in the dynamic debug format | |
180 | string. Note that the string does not need to match the | |
181 | entire format, only some part. Whitespace and other | |
182 | special characters can be escaped using C octal character | |
7d4e3517 | 183 | escape ``\ooo`` notation, e.g. the space character is ``\040``. |
9898abb3 | 184 | Alternatively, the string can be enclosed in double quote |
7d4e3517 MCC |
185 | characters (``"``) or single quote characters (``'``). |
186 | Examples:: | |
86151fdf | 187 | |
7d4e3517 MCC |
188 | format svcrdma: // many of the NFS/RDMA server pr_debugs |
189 | format readahead // some pr_debugs in the readahead cache | |
190 | format nfsd:\040SETATTR // one way to match a format with whitespace | |
191 | format "nfsd: SETATTR" // a neater way to match a format with whitespace | |
192 | format 'nfsd: SETATTR' // yet another way to match a format with whitespace | |
86151fdf JB |
193 | |
194 | line | |
195 | The given line number or range of line numbers is compared | |
7d4e3517 | 196 | against the line number of each ``pr_debug()`` callsite. A single |
86151fdf JB |
197 | line number matches the callsite line number exactly. A |
198 | range of line numbers matches any callsite between the first | |
199 | and last line number inclusive. An empty first number means | |
200 | the first line in the file, an empty line number means the | |
7d4e3517 | 201 | last number in the file. Examples:: |
86151fdf | 202 | |
7d4e3517 MCC |
203 | line 1603 // exactly line 1603 |
204 | line 1600-1605 // the six lines from line 1600 to line 1605 | |
205 | line -1605 // the 1605 lines from line 1 to line 1605 | |
206 | line 1600- // all lines from line 1600 to the end of the file | |
86151fdf JB |
207 | |
208 | The flags specification comprises a change operation followed | |
209 | by one or more flag characters. The change operation is one | |
7d4e3517 | 210 | of the characters:: |
86151fdf | 211 | |
29e36c9f JC |
212 | - remove the given flags |
213 | + add the given flags | |
214 | = set the flags to the given flags | |
86151fdf | 215 | |
7d4e3517 | 216 | The flags are:: |
86151fdf | 217 | |
29e36c9f JC |
218 | p enables the pr_debug() callsite. |
219 | f Include the function name in the printed message | |
220 | l Include line number in the printed message | |
221 | m Include module name in the printed message | |
222 | t Include thread ID in messages not generated from interrupt context | |
223 | _ No flags are set. (Or'd with others on input) | |
224 | ||
7d4e3517 | 225 | For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only ``p`` flag |
7a555613 VK |
226 | have meaning, other flags ignored. |
227 | ||
7d4e3517 | 228 | For display, the flags are preceded by ``=`` |
29e36c9f | 229 | (mnemonic: what the flags are currently equal to). |
86151fdf | 230 | |
7d4e3517 MCC |
231 | Note the regexp ``^[-+=][flmpt_]+$`` matches a flags specification. |
232 | To clear all flags at once, use ``=_`` or ``-flmpt``. | |
86151fdf | 233 | |
a648ec05 | 234 | |
29e36c9f | 235 | Debug messages during Boot Process |
a648ec05 TR |
236 | ================================== |
237 | ||
29e36c9f JC |
238 | To activate debug messages for core code and built-in modules during |
239 | the boot process, even before userspace and debugfs exists, use | |
7d4e3517 MCC |
240 | ``dyndbg="QUERY"``, ``module.dyndbg="QUERY"``, or ``ddebug_query="QUERY"`` |
241 | (``ddebug_query`` is obsoleted by ``dyndbg``, and deprecated). QUERY follows | |
29e36c9f JC |
242 | the syntax described above, but must not exceed 1023 characters. Your |
243 | bootloader may impose lower limits. | |
244 | ||
7d4e3517 | 245 | These ``dyndbg`` params are processed just after the ddebug tables are |
29e36c9f JC |
246 | processed, as part of the arch_initcall. Thus you can enable debug |
247 | messages in all code run after this arch_initcall via this boot | |
248 | parameter. | |
a648ec05 | 249 | |
7d4e3517 MCC |
250 | On an x86 system for example ACPI enablement is a subsys_initcall and:: |
251 | ||
29e36c9f | 252 | dyndbg="file ec.c +p" |
7d4e3517 | 253 | |
a648ec05 TR |
254 | will show early Embedded Controller transactions during ACPI setup if |
255 | your machine (typically a laptop) has an Embedded Controller. | |
256 | PCI (or other devices) initialization also is a hot candidate for using | |
257 | this boot parameter for debugging purposes. | |
258 | ||
7d4e3517 | 259 | If ``foo`` module is not built-in, ``foo.dyndbg`` will still be processed at |
29e36c9f | 260 | boot time, without effect, but will be reprocessed when module is |
7d4e3517 | 261 | loaded later. ``dyndbg_query=`` and bare ``dyndbg=`` are only processed at |
29e36c9f JC |
262 | boot. |
263 | ||
264 | ||
265 | Debug Messages at Module Initialization Time | |
266 | ============================================ | |
267 | ||
7d4e3517 MCC |
268 | When ``modprobe foo`` is called, modprobe scans ``/proc/cmdline`` for |
269 | ``foo.params``, strips ``foo.``, and passes them to the kernel along with | |
270 | params given in modprobe args or ``/etc/modprob.d/*.conf`` files, | |
29e36c9f JC |
271 | in the following order: |
272 | ||
7d4e3517 MCC |
273 | 1. parameters given via ``/etc/modprobe.d/*.conf``:: |
274 | ||
275 | options foo dyndbg=+pt | |
276 | options foo dyndbg # defaults to +p | |
277 | ||
278 | 2. ``foo.dyndbg`` as given in boot args, ``foo.`` is stripped and passed:: | |
29e36c9f | 279 | |
7d4e3517 | 280 | foo.dyndbg=" func bar +p; func buz +mp" |
29e36c9f | 281 | |
7d4e3517 | 282 | 3. args to modprobe:: |
29e36c9f | 283 | |
7d4e3517 MCC |
284 | modprobe foo dyndbg==pmf # override previous settings |
285 | ||
286 | These ``dyndbg`` queries are applied in order, with last having final say. | |
287 | This allows boot args to override or modify those from ``/etc/modprobe.d`` | |
29e36c9f JC |
288 | (sensible, since 1 is system wide, 2 is kernel or boot specific), and |
289 | modprobe args to override both. | |
290 | ||
7d4e3517 MCC |
291 | In the ``foo.dyndbg="QUERY"`` form, the query must exclude ``module foo``. |
292 | ``foo`` is extracted from the param-name, and applied to each query in | |
293 | ``QUERY``, and only 1 match-spec of each type is allowed. | |
29e36c9f | 294 | |
7d4e3517 | 295 | The ``dyndbg`` option is a "fake" module parameter, which means: |
29e36c9f JC |
296 | |
297 | - modules do not need to define it explicitly | |
298 | - every module gets it tacitly, whether they use pr_debug or not | |
7d4e3517 MCC |
299 | - it doesn't appear in ``/sys/module/$module/parameters/`` |
300 | To see it, grep the control file, or inspect ``/proc/cmdline.`` | |
29e36c9f | 301 | |
7d4e3517 MCC |
302 | For ``CONFIG_DYNAMIC_DEBUG`` kernels, any settings given at boot-time (or |
303 | enabled by ``-DDEBUG`` flag during compilation) can be disabled later via | |
304 | the sysfs interface if the debug messages are no longer needed:: | |
29e36c9f JC |
305 | |
306 | echo "module module_name -p" > <debugfs>/dynamic_debug/control | |
a648ec05 | 307 | |
86151fdf JB |
308 | Examples |
309 | ======== | |
310 | ||
7d4e3517 MCC |
311 | :: |
312 | ||
313 | // enable the message at line 1603 of file svcsock.c | |
314 | nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' > | |
86151fdf JB |
315 | <debugfs>/dynamic_debug/control |
316 | ||
7d4e3517 MCC |
317 | // enable all the messages in file svcsock.c |
318 | nullarbor:~ # echo -n 'file svcsock.c +p' > | |
86151fdf JB |
319 | <debugfs>/dynamic_debug/control |
320 | ||
7d4e3517 MCC |
321 | // enable all the messages in the NFS server module |
322 | nullarbor:~ # echo -n 'module nfsd +p' > | |
86151fdf JB |
323 | <debugfs>/dynamic_debug/control |
324 | ||
7d4e3517 MCC |
325 | // enable all 12 messages in the function svc_process() |
326 | nullarbor:~ # echo -n 'func svc_process +p' > | |
86151fdf JB |
327 | <debugfs>/dynamic_debug/control |
328 | ||
7d4e3517 MCC |
329 | // disable all 12 messages in the function svc_process() |
330 | nullarbor:~ # echo -n 'func svc_process -p' > | |
86151fdf | 331 | <debugfs>/dynamic_debug/control |
9898abb3 | 332 | |
7d4e3517 MCC |
333 | // enable messages for NFS calls READ, READLINK, READDIR and READDIR+. |
334 | nullarbor:~ # echo -n 'format "nfsd: READ" +p' > | |
9898abb3 | 335 | <debugfs>/dynamic_debug/control |
29e36c9f | 336 | |
7d4e3517 MCC |
337 | // enable messages in files of which the paths include string "usb" |
338 | nullarbor:~ # echo -n '*usb* +p' > <debugfs>/dynamic_debug/control | |
8f073bd0 | 339 | |
7d4e3517 MCC |
340 | // enable all messages |
341 | nullarbor:~ # echo -n '+p' > <debugfs>/dynamic_debug/control | |
29e36c9f | 342 | |
7d4e3517 MCC |
343 | // add module, function to all enabled messages |
344 | nullarbor:~ # echo -n '+mf' > <debugfs>/dynamic_debug/control | |
29e36c9f | 345 | |
7d4e3517 MCC |
346 | // boot-args example, with newlines and comments for readability |
347 | Kernel command line: ... | |
348 | // see whats going on in dyndbg=value processing | |
349 | dynamic_debug.verbose=1 | |
350 | // enable pr_debugs in 2 builtins, #cmt is stripped | |
351 | dyndbg="module params +p #cmt ; module sys +p" | |
352 | // enable pr_debugs in 2 functions in a module loaded later | |
353 | pc87360.dyndbg="func pc87360_init_device +p; func pc87360_find +p" |