341 lines
13 KiB
Plaintext
341 lines
13 KiB
Plaintext
|
|
Introduction
|
|
============
|
|
|
|
This document describes how to use the dynamic debug (dyndbg) feature.
|
|
|
|
Dynamic debug is designed to allow you to dynamically enable/disable
|
|
kernel code to obtain additional kernel information. Currently, if
|
|
CONFIG_DYNAMIC_DEBUG is set, then all pr_debug()/dev_dbg() and
|
|
print_hex_dump_debug()/print_hex_dump_bytes() calls can be dynamically
|
|
enabled per-callsite.
|
|
|
|
If CONFIG_DYNAMIC_DEBUG is not set, print_hex_dump_debug() is just
|
|
shortcut for print_hex_dump(KERN_DEBUG).
|
|
|
|
For print_hex_dump_debug()/print_hex_dump_bytes(), format string is
|
|
its 'prefix_str' argument, if it is constant string; or "hexdump"
|
|
in case 'prefix_str' is build dynamically.
|
|
|
|
Dynamic debug has even more useful features:
|
|
|
|
* Simple query language allows turning on and off debugging
|
|
statements by matching any combination of 0 or 1 of:
|
|
|
|
- source filename
|
|
- function name
|
|
- line number (including ranges of line numbers)
|
|
- module name
|
|
- format string
|
|
|
|
* Provides a debugfs control file: <debugfs>/dynamic_debug/control
|
|
which can be read to display the complete list of known debug
|
|
statements, to help guide you
|
|
|
|
Controlling dynamic debug Behaviour
|
|
===================================
|
|
|
|
The behaviour of pr_debug()/dev_dbg()s are controlled via writing to a
|
|
control file in the 'debugfs' filesystem. Thus, you must first mount
|
|
the debugfs filesystem, in order to make use of this feature.
|
|
Subsequently, we refer to the control file as:
|
|
<debugfs>/dynamic_debug/control. For example, if you want to enable
|
|
printing from source file 'svcsock.c', line 1603 you simply do:
|
|
|
|
nullarbor:~ # echo 'file svcsock.c line 1603 +p' >
|
|
<debugfs>/dynamic_debug/control
|
|
|
|
If you make a mistake with the syntax, the write will fail thus:
|
|
|
|
nullarbor:~ # echo 'file svcsock.c wtf 1 +p' >
|
|
<debugfs>/dynamic_debug/control
|
|
-bash: echo: write error: Invalid argument
|
|
|
|
Viewing Dynamic Debug Behaviour
|
|
===========================
|
|
|
|
You can view the currently configured behaviour of all the debug
|
|
statements via:
|
|
|
|
nullarbor:~ # cat <debugfs>/dynamic_debug/control
|
|
# filename:lineno [module]function flags format
|
|
/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"
|
|
/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:341 [svcxprt_rdma]svc_rdma_init =_ "\011max_inline : %d\012"
|
|
/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:340 [svcxprt_rdma]svc_rdma_init =_ "\011sq_depth : %d\012"
|
|
/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:338 [svcxprt_rdma]svc_rdma_init =_ "\011max_requests : %d\012"
|
|
...
|
|
|
|
|
|
You can also apply standard Unix text manipulation filters to this
|
|
data, e.g.
|
|
|
|
nullarbor:~ # grep -i rdma <debugfs>/dynamic_debug/control | wc -l
|
|
62
|
|
|
|
nullarbor:~ # grep -i tcp <debugfs>/dynamic_debug/control | wc -l
|
|
42
|
|
|
|
The third column shows the currently enabled flags for each debug
|
|
statement callsite (see below for definitions of the flags). The
|
|
default value, with no flags enabled, is "=_". So you can view all
|
|
the debug statement callsites with any non-default flags:
|
|
|
|
nullarbor:~ # awk '$3 != "=_"' <debugfs>/dynamic_debug/control
|
|
# filename:lineno [module]function flags format
|
|
/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"
|
|
|
|
|
|
Command Language Reference
|
|
==========================
|
|
|
|
At the lexical level, a command comprises a sequence of words separated
|
|
by spaces or tabs. So these are all equivalent:
|
|
|
|
nullarbor:~ # echo -c 'file svcsock.c line 1603 +p' >
|
|
<debugfs>/dynamic_debug/control
|
|
nullarbor:~ # echo -c ' file svcsock.c line 1603 +p ' >
|
|
<debugfs>/dynamic_debug/control
|
|
nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
|
|
<debugfs>/dynamic_debug/control
|
|
|
|
Command submissions are bounded by a write() system call.
|
|
Multiple commands can be written together, separated by ';' or '\n'.
|
|
|
|
~# echo "func pnpacpi_get_resources +p; func pnp_assign_mem +p" \
|
|
> <debugfs>/dynamic_debug/control
|
|
|
|
If your query set is big, you can batch them too:
|
|
|
|
~# cat query-batch-file > <debugfs>/dynamic_debug/control
|
|
|
|
A another way is to use wildcard. The match rule support '*' (matches
|
|
zero or more characters) and '?' (matches exactly one character).For
|
|
example, you can match all usb drivers:
|
|
|
|
~# echo "file drivers/usb/* +p" > <debugfs>/dynamic_debug/control
|
|
|
|
At the syntactical level, a command comprises a sequence of match
|
|
specifications, followed by a flags change specification.
|
|
|
|
command ::= match-spec* flags-spec
|
|
|
|
The match-spec's are used to choose a subset of the known pr_debug()
|
|
callsites to which to apply the flags-spec. Think of them as a query
|
|
with implicit ANDs between each pair. Note that an empty list of
|
|
match-specs will select all debug statement callsites.
|
|
|
|
A match specification comprises a keyword, which controls the
|
|
attribute of the callsite to be compared, and a value to compare
|
|
against. Possible keywords are:
|
|
|
|
match-spec ::= 'func' string |
|
|
'file' string |
|
|
'module' string |
|
|
'format' string |
|
|
'line' line-range
|
|
|
|
line-range ::= lineno |
|
|
'-'lineno |
|
|
lineno'-' |
|
|
lineno'-'lineno
|
|
// Note: line-range cannot contain space, e.g.
|
|
// "1-30" is valid range but "1 - 30" is not.
|
|
|
|
lineno ::= unsigned-int
|
|
|
|
The meanings of each keyword are:
|
|
|
|
func
|
|
The given string is compared against the function name
|
|
of each callsite. Example:
|
|
|
|
func svc_tcp_accept
|
|
|
|
file
|
|
The given string is compared against either the full pathname, the
|
|
src-root relative pathname, or the basename of the source file of
|
|
each callsite. Examples:
|
|
|
|
file svcsock.c
|
|
file kernel/freezer.c
|
|
file /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svcsock.c
|
|
|
|
module
|
|
The given string is compared against the module name
|
|
of each callsite. The module name is the string as
|
|
seen in "lsmod", i.e. without the directory or the .ko
|
|
suffix and with '-' changed to '_'. Examples:
|
|
|
|
module sunrpc
|
|
module nfsd
|
|
|
|
format
|
|
The given string is searched for in the dynamic debug format
|
|
string. Note that the string does not need to match the
|
|
entire format, only some part. Whitespace and other
|
|
special characters can be escaped using C octal character
|
|
escape \ooo notation, e.g. the space character is \040.
|
|
Alternatively, the string can be enclosed in double quote
|
|
characters (") or single quote characters (').
|
|
Examples:
|
|
|
|
format svcrdma: // many of the NFS/RDMA server pr_debugs
|
|
format readahead // some pr_debugs in the readahead cache
|
|
format nfsd:\040SETATTR // one way to match a format with whitespace
|
|
format "nfsd: SETATTR" // a neater way to match a format with whitespace
|
|
format 'nfsd: SETATTR' // yet another way to match a format with whitespace
|
|
|
|
line
|
|
The given line number or range of line numbers is compared
|
|
against the line number of each pr_debug() callsite. A single
|
|
line number matches the callsite line number exactly. A
|
|
range of line numbers matches any callsite between the first
|
|
and last line number inclusive. An empty first number means
|
|
the first line in the file, an empty line number means the
|
|
last number in the file. Examples:
|
|
|
|
line 1603 // exactly line 1603
|
|
line 1600-1605 // the six lines from line 1600 to line 1605
|
|
line -1605 // the 1605 lines from line 1 to line 1605
|
|
line 1600- // all lines from line 1600 to the end of the file
|
|
|
|
The flags specification comprises a change operation followed
|
|
by one or more flag characters. The change operation is one
|
|
of the characters:
|
|
|
|
- remove the given flags
|
|
+ add the given flags
|
|
= set the flags to the given flags
|
|
|
|
The flags are:
|
|
|
|
p enables the pr_debug() callsite.
|
|
f Include the function name in the printed message
|
|
l Include line number in the printed message
|
|
m Include module name in the printed message
|
|
t Include thread ID in messages not generated from interrupt context
|
|
_ No flags are set. (Or'd with others on input)
|
|
|
|
For print_hex_dump_debug() and print_hex_dump_bytes(), only 'p' flag
|
|
have meaning, other flags ignored.
|
|
|
|
For display, the flags are preceded by '='
|
|
(mnemonic: what the flags are currently equal to).
|
|
|
|
Note the regexp ^[-+=][flmpt_]+$ matches a flags specification.
|
|
To clear all flags at once, use "=_" or "-flmpt".
|
|
|
|
|
|
Debug messages during Boot Process
|
|
==================================
|
|
|
|
To activate debug messages for core code and built-in modules during
|
|
the boot process, even before userspace and debugfs exists, use
|
|
dyndbg="QUERY", module.dyndbg="QUERY", or ddebug_query="QUERY"
|
|
(ddebug_query is obsoleted by dyndbg, and deprecated). QUERY follows
|
|
the syntax described above, but must not exceed 1023 characters. Your
|
|
bootloader may impose lower limits.
|
|
|
|
These dyndbg params are processed just after the ddebug tables are
|
|
processed, as part of the arch_initcall. Thus you can enable debug
|
|
messages in all code run after this arch_initcall via this boot
|
|
parameter.
|
|
|
|
On an x86 system for example ACPI enablement is a subsys_initcall and
|
|
dyndbg="file ec.c +p"
|
|
will show early Embedded Controller transactions during ACPI setup if
|
|
your machine (typically a laptop) has an Embedded Controller.
|
|
PCI (or other devices) initialization also is a hot candidate for using
|
|
this boot parameter for debugging purposes.
|
|
|
|
If foo module is not built-in, foo.dyndbg will still be processed at
|
|
boot time, without effect, but will be reprocessed when module is
|
|
loaded later. dyndbg_query= and bare dyndbg= are only processed at
|
|
boot.
|
|
|
|
|
|
Debug Messages at Module Initialization Time
|
|
============================================
|
|
|
|
When "modprobe foo" is called, modprobe scans /proc/cmdline for
|
|
foo.params, strips "foo.", and passes them to the kernel along with
|
|
params given in modprobe args or /etc/modprob.d/*.conf files,
|
|
in the following order:
|
|
|
|
1. # parameters given via /etc/modprobe.d/*.conf
|
|
options foo dyndbg=+pt
|
|
options foo dyndbg # defaults to +p
|
|
|
|
2. # foo.dyndbg as given in boot args, "foo." is stripped and passed
|
|
foo.dyndbg=" func bar +p; func buz +mp"
|
|
|
|
3. # args to modprobe
|
|
modprobe foo dyndbg==pmf # override previous settings
|
|
|
|
These dyndbg queries are applied in order, with last having final say.
|
|
This allows boot args to override or modify those from /etc/modprobe.d
|
|
(sensible, since 1 is system wide, 2 is kernel or boot specific), and
|
|
modprobe args to override both.
|
|
|
|
In the foo.dyndbg="QUERY" form, the query must exclude "module foo".
|
|
"foo" is extracted from the param-name, and applied to each query in
|
|
"QUERY", and only 1 match-spec of each type is allowed.
|
|
|
|
The dyndbg option is a "fake" module parameter, which means:
|
|
|
|
- modules do not need to define it explicitly
|
|
- every module gets it tacitly, whether they use pr_debug or not
|
|
- it doesn't appear in /sys/module/$module/parameters/
|
|
To see it, grep the control file, or inspect /proc/cmdline.
|
|
|
|
For CONFIG_DYNAMIC_DEBUG kernels, any settings given at boot-time (or
|
|
enabled by -DDEBUG flag during compilation) can be disabled later via
|
|
the sysfs interface if the debug messages are no longer needed:
|
|
|
|
echo "module module_name -p" > <debugfs>/dynamic_debug/control
|
|
|
|
Examples
|
|
========
|
|
|
|
// enable the message at line 1603 of file svcsock.c
|
|
nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
|
|
<debugfs>/dynamic_debug/control
|
|
|
|
// enable all the messages in file svcsock.c
|
|
nullarbor:~ # echo -n 'file svcsock.c +p' >
|
|
<debugfs>/dynamic_debug/control
|
|
|
|
// enable all the messages in the NFS server module
|
|
nullarbor:~ # echo -n 'module nfsd +p' >
|
|
<debugfs>/dynamic_debug/control
|
|
|
|
// enable all 12 messages in the function svc_process()
|
|
nullarbor:~ # echo -n 'func svc_process +p' >
|
|
<debugfs>/dynamic_debug/control
|
|
|
|
// disable all 12 messages in the function svc_process()
|
|
nullarbor:~ # echo -n 'func svc_process -p' >
|
|
<debugfs>/dynamic_debug/control
|
|
|
|
// enable messages for NFS calls READ, READLINK, READDIR and READDIR+.
|
|
nullarbor:~ # echo -n 'format "nfsd: READ" +p' >
|
|
<debugfs>/dynamic_debug/control
|
|
|
|
// enable messages in files of which the paths include string "usb"
|
|
nullarbor:~ # echo -n '*usb* +p' > <debugfs>/dynamic_debug/control
|
|
|
|
// enable all messages
|
|
nullarbor:~ # echo -n '+p' > <debugfs>/dynamic_debug/control
|
|
|
|
// add module, function to all enabled messages
|
|
nullarbor:~ # echo -n '+mf' > <debugfs>/dynamic_debug/control
|
|
|
|
// boot-args example, with newlines and comments for readability
|
|
Kernel command line: ...
|
|
// see whats going on in dyndbg=value processing
|
|
dynamic_debug.verbose=1
|
|
// enable pr_debugs in 2 builtins, #cmt is stripped
|
|
dyndbg="module params +p #cmt ; module sys +p"
|
|
// enable pr_debugs in 2 functions in a module loaded later
|
|
pc87360.dyndbg="func pc87360_init_device +p; func pc87360_find +p"
|