About Kernel Documentation Linux Kernel Contact Linux Resources Linux Blog

Documentation / admin-guide / dynamic-debug-howto.rst




Custom Search

Based on kernel version 4.16.1. Page generated on 2018-04-09 11:52 EST.

1	Dynamic debug
2	+++++++++++++
3	
4	
5	Introduction
6	============
7	
8	This document describes how to use the dynamic debug (dyndbg) feature.
9	
10	Dynamic debug is designed to allow you to dynamically enable/disable
11	kernel code to obtain additional kernel information.  Currently, if
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
14	enabled per-callsite.
15	
16	If ``CONFIG_DYNAMIC_DEBUG`` is not set, ``print_hex_dump_debug()`` is just
17	shortcut for ``print_hex_dump(KERN_DEBUG)``.
18	
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 built dynamically.
22	
23	Dynamic debug has even more useful features:
24	
25	 * Simple query language allows turning on and off debugging
26	   statements by matching any combination of 0 or 1 of:
27	
28	   - source filename
29	   - function name
30	   - line number (including ranges of line numbers)
31	   - module name
32	   - format string
33	
34	 * Provides a debugfs control file: ``<debugfs>/dynamic_debug/control``
35	   which can be read to display the complete list of known debug
36	   statements, to help guide you
37	
38	Controlling dynamic debug Behaviour
39	===================================
40	
41	The behaviour of ``pr_debug()``/``dev_dbg()`` are controlled via writing to a
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:
45	``<debugfs>/dynamic_debug/control``. For example, if you want to enable
46	printing from source file ``svcsock.c``, line 1603 you simply do::
47	
48	  nullarbor:~ # echo 'file svcsock.c line 1603 +p' >
49					<debugfs>/dynamic_debug/control
50	
51	If you make a mistake with the syntax, the write will fail thus::
52	
53	  nullarbor:~ # echo 'file svcsock.c wtf 1 +p' >
54					<debugfs>/dynamic_debug/control
55	  -bash: echo: write error: Invalid argument
56	
57	Viewing Dynamic Debug Behaviour
58	===============================
59	
60	You can view the currently configured behaviour of all the debug
61	statements via::
62	
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	  ...
70	
71	
72	You can also apply standard Unix text manipulation filters to this
73	data, e.g.::
74	
75	  nullarbor:~ # grep -i rdma <debugfs>/dynamic_debug/control  | wc -l
76	  62
77	
78	  nullarbor:~ # grep -i tcp <debugfs>/dynamic_debug/control | wc -l
79	  42
80	
81	The third column shows the currently enabled flags for each debug
82	statement callsite (see below for definitions of the flags).  The
83	default value, with no flags enabled, is ``=_``.  So you can view all
84	the debug statement callsites with any non-default flags::
85	
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"
89	
90	Command Language Reference
91	==========================
92	
93	At the lexical level, a command comprises a sequence of words separated
94	by spaces or tabs.  So these are all equivalent::
95	
96	  nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
97					<debugfs>/dynamic_debug/control
98	  nullarbor:~ # echo -n '  file   svcsock.c     line  1603 +p  ' >
99					<debugfs>/dynamic_debug/control
100	  nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
101					<debugfs>/dynamic_debug/control
102	
103	Command submissions are bounded by a write() system call.
104	Multiple commands can be written together, separated by ``;`` or ``\n``::
105	
106	  ~# echo "func pnpacpi_get_resources +p; func pnp_assign_mem +p" \
107	     > <debugfs>/dynamic_debug/control
108	
109	If your query set is big, you can batch them too::
110	
111	  ~# cat query-batch-file > <debugfs>/dynamic_debug/control
112	
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::
116	
117	  ~# echo "file drivers/usb/* +p" > <debugfs>/dynamic_debug/control
118	
119	At the syntactical level, a command comprises a sequence of match
120	specifications, followed by a flags change specification::
121	
122	  command ::= match-spec* flags-spec
123	
124	The match-spec's are used to choose a subset of the known pr_debug()
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
127	match-specs will select all debug statement callsites.
128	
129	A match specification comprises a keyword, which controls the
130	attribute of the callsite to be compared, and a value to compare
131	against.  Possible keywords are:::
132	
133	  match-spec ::= 'func' string |
134			 'file' string |
135			 'module' string |
136			 'format' string |
137			 'line' line-range
138	
139	  line-range ::= lineno |
140			 '-'lineno |
141			 lineno'-' |
142			 lineno'-'lineno
143	
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.
150	
151	
152	The meanings of each keyword are:
153	
154	func
155	    The given string is compared against the function name
156	    of each callsite.  Example::
157	
158		func svc_tcp_accept
159	
160	file
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
163	    each callsite.  Examples::
164	
165		file svcsock.c
166		file kernel/freezer.c
167		file /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svcsock.c
168	
169	module
170	    The given string is compared against the module name
171	    of each callsite.  The module name is the string as
172	    seen in ``lsmod``, i.e. without the directory or the ``.ko``
173	    suffix and with ``-`` changed to ``_``.  Examples::
174	
175		module sunrpc
176		module nfsd
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
183	    escape ``\ooo`` notation, e.g. the space character is ``\040``.
184	    Alternatively, the string can be enclosed in double quote
185	    characters (``"``) or single quote characters (``'``).
186	    Examples::
187	
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
193	
194	line
195	    The given line number or range of line numbers is compared
196	    against the line number of each ``pr_debug()`` callsite.  A single
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 last line number means the
201	    last line number in the file.  Examples::
202	
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
207	
208	The flags specification comprises a change operation followed
209	by one or more flag characters.  The change operation is one
210	of the characters::
211	
212	  -    remove the given flags
213	  +    add the given flags
214	  =    set the flags to the given flags
215	
216	The flags are::
217	
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	
225	For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only ``p`` flag
226	have meaning, other flags ignored.
227	
228	For display, the flags are preceded by ``=``
229	(mnemonic: what the flags are currently equal to).
230	
231	Note the regexp ``^[-+=][flmpt_]+$`` matches a flags specification.
232	To clear all flags at once, use ``=_`` or ``-flmpt``.
233	
234	
235	Debug messages during Boot Process
236	==================================
237	
238	To activate debug messages for core code and built-in modules during
239	the boot process, even before userspace and debugfs exists, use
240	``dyndbg="QUERY"``, ``module.dyndbg="QUERY"``, or ``ddebug_query="QUERY"``
241	(``ddebug_query`` is obsoleted by ``dyndbg``, and deprecated).  QUERY follows
242	the syntax described above, but must not exceed 1023 characters.  Your
243	bootloader may impose lower limits.
244	
245	These ``dyndbg`` params are processed just after the ddebug tables are
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.
249	
250	On an x86 system for example ACPI enablement is a subsys_initcall and::
251	
252	   dyndbg="file ec.c +p"
253	
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	
259	If ``foo`` module is not built-in, ``foo.dyndbg`` will still be processed at
260	boot time, without effect, but will be reprocessed when module is
261	loaded later. ``dyndbg_query=`` and bare ``dyndbg=`` are only processed at
262	boot.
263	
264	
265	Debug Messages at Module Initialization Time
266	============================================
267	
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,
271	in the following order:
272	
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::
279	
280		foo.dyndbg=" func bar +p; func buz +mp"
281	
282	3. args to modprobe::
283	
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``
288	(sensible, since 1 is system wide, 2 is kernel or boot specific), and
289	modprobe args to override both.
290	
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.
294	
295	The ``dyndbg`` option is a "fake" module parameter, which means:
296	
297	- modules do not need to define it explicitly
298	- every module gets it tacitly, whether they use pr_debug or not
299	- it doesn't appear in ``/sys/module/$module/parameters/``
300	  To see it, grep the control file, or inspect ``/proc/cmdline.``
301	
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::
305	
306	   echo "module module_name -p" > <debugfs>/dynamic_debug/control
307	
308	Examples
309	========
310	
311	::
312	
313	  // enable the message at line 1603 of file svcsock.c
314	  nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
315					<debugfs>/dynamic_debug/control
316	
317	  // enable all the messages in file svcsock.c
318	  nullarbor:~ # echo -n 'file svcsock.c +p' >
319					<debugfs>/dynamic_debug/control
320	
321	  // enable all the messages in the NFS server module
322	  nullarbor:~ # echo -n 'module nfsd +p' >
323					<debugfs>/dynamic_debug/control
324	
325	  // enable all 12 messages in the function svc_process()
326	  nullarbor:~ # echo -n 'func svc_process +p' >
327					<debugfs>/dynamic_debug/control
328	
329	  // disable all 12 messages in the function svc_process()
330	  nullarbor:~ # echo -n 'func svc_process -p' >
331					<debugfs>/dynamic_debug/control
332	
333	  // enable messages for NFS calls READ, READLINK, READDIR and READDIR+.
334	  nullarbor:~ # echo -n 'format "nfsd: READ" +p' >
335					<debugfs>/dynamic_debug/control
336	
337	  // enable messages in files of which the paths include string "usb"
338	  nullarbor:~ # echo -n '*usb* +p' > <debugfs>/dynamic_debug/control
339	
340	  // enable all messages
341	  nullarbor:~ # echo -n '+p' > <debugfs>/dynamic_debug/control
342	
343	  // add module, function to all enabled messages
344	  nullarbor:~ # echo -n '+mf' > <debugfs>/dynamic_debug/control
345	
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"
Hide Line Numbers
About Kernel Documentation Linux Kernel Contact Linux Resources Linux Blog

Information is copyright its respective author. All material is available from the Linux Kernel Source distributed under a GPL License. This page is provided as a free service by mjmwired.net.