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