dynamic_debug: update Documentation/*, Kconfig.debug
In dynamic-debug-howto.txt: - add section: Debug Messages at Module Initialization Time - update flags indicators in example outputs to include '=' - make flags descriptions tabular - add item on '_' flag-char - add dyndbg, boot-args examples - rewrap some paragraphs with long lines In Kconfig.debug, note that compiling with -DDEBUG enables all pr_debug()s in that code. In kernel-parameters.txt, add dyndbg and module.dyndbg items, and deprecate ddebug_query. Signed-off-by: Jim Cromie <jim.cromie@gmail.com> Acked-by: Jason Baron <jbaron@redhat.com> Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
This commit is contained in:
parent
8e59b5cfb9
commit
29e36c9ffb
3 changed files with 138 additions and 70 deletions
|
@ -2,17 +2,17 @@
|
||||||
Introduction
|
Introduction
|
||||||
============
|
============
|
||||||
|
|
||||||
This document describes how to use the dynamic debug (ddebug) feature.
|
This document describes how to use the dynamic debug (dyndbg) feature.
|
||||||
|
|
||||||
Dynamic debug is designed to allow you to dynamically enable/disable kernel
|
Dynamic debug is designed to allow you to dynamically enable/disable
|
||||||
code to obtain additional kernel information. Currently, if
|
kernel code to obtain additional kernel information. Currently, if
|
||||||
CONFIG_DYNAMIC_DEBUG is set, then all pr_debug()/dev_dbg() calls can be
|
CONFIG_DYNAMIC_DEBUG is set, then all pr_debug()/dev_dbg() calls can
|
||||||
dynamically enabled per-callsite.
|
be dynamically enabled per-callsite.
|
||||||
|
|
||||||
Dynamic debug has even more useful features:
|
Dynamic debug has even more useful features:
|
||||||
|
|
||||||
* Simple query language allows turning on and off debugging statements by
|
* Simple query language allows turning on and off debugging
|
||||||
matching any combination of 0 or 1 of:
|
statements by matching any combination of 0 or 1 of:
|
||||||
|
|
||||||
- source filename
|
- source filename
|
||||||
- function name
|
- function name
|
||||||
|
@ -20,17 +20,19 @@ Dynamic debug has even more useful features:
|
||||||
- module name
|
- module name
|
||||||
- format string
|
- format string
|
||||||
|
|
||||||
* Provides a debugfs control file: <debugfs>/dynamic_debug/control which can be
|
* Provides a debugfs control file: <debugfs>/dynamic_debug/control
|
||||||
read to display the complete list of known debug statements, to help guide you
|
which can be read to display the complete list of known debug
|
||||||
|
statements, to help guide you
|
||||||
|
|
||||||
Controlling dynamic debug Behaviour
|
Controlling dynamic debug Behaviour
|
||||||
===================================
|
===================================
|
||||||
|
|
||||||
The behaviour of pr_debug()/dev_dbg()s are controlled via writing to a
|
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
|
control file in the 'debugfs' filesystem. Thus, you must first mount
|
||||||
filesystem, in order to make use of this feature. Subsequently, we refer to the
|
the debugfs filesystem, in order to make use of this feature.
|
||||||
control file as: <debugfs>/dynamic_debug/control. For example, if you want to
|
Subsequently, we refer to the control file as:
|
||||||
enable printing from source file 'svcsock.c', line 1603 you simply do:
|
<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' >
|
nullarbor:~ # echo 'file svcsock.c line 1603 +p' >
|
||||||
<debugfs>/dynamic_debug/control
|
<debugfs>/dynamic_debug/control
|
||||||
|
@ -44,15 +46,15 @@ nullarbor:~ # echo 'file svcsock.c wtf 1 +p' >
|
||||||
Viewing Dynamic Debug Behaviour
|
Viewing Dynamic Debug Behaviour
|
||||||
===========================
|
===========================
|
||||||
|
|
||||||
You can view the currently configured behaviour of all the debug statements
|
You can view the currently configured behaviour of all the debug
|
||||||
via:
|
statements via:
|
||||||
|
|
||||||
nullarbor:~ # cat <debugfs>/dynamic_debug/control
|
nullarbor:~ # cat <debugfs>/dynamic_debug/control
|
||||||
# filename:lineno [module]function flags format
|
# 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: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: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: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"
|
/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:338 [svcxprt_rdma]svc_rdma_init =_ "\011max_requests : %d\012"
|
||||||
...
|
...
|
||||||
|
|
||||||
|
|
||||||
|
@ -65,12 +67,12 @@ nullarbor:~ # grep -i rdma <debugfs>/dynamic_debug/control | wc -l
|
||||||
nullarbor:~ # grep -i tcp <debugfs>/dynamic_debug/control | wc -l
|
nullarbor:~ # grep -i tcp <debugfs>/dynamic_debug/control | wc -l
|
||||||
42
|
42
|
||||||
|
|
||||||
Note in particular that the third column shows the enabled behaviour
|
The third column shows the currently enabled flags for each debug
|
||||||
flags for each debug statement callsite (see below for definitions of the
|
statement callsite (see below for definitions of the flags). The
|
||||||
flags). The default value, no extra behaviour enabled, is "-". So
|
default value, with no flags enabled, is "=_". So you can view all
|
||||||
you can view all the debug statement callsites with any non-default flags:
|
the debug statement callsites with any non-default flags:
|
||||||
|
|
||||||
nullarbor:~ # awk '$3 != "-"' <debugfs>/dynamic_debug/control
|
nullarbor:~ # awk '$3 != "=_"' <debugfs>/dynamic_debug/control
|
||||||
# filename:lineno [module]function flags format
|
# 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"
|
/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"
|
||||||
|
|
||||||
|
@ -103,15 +105,14 @@ specifications, followed by a flags change specification.
|
||||||
|
|
||||||
command ::= match-spec* flags-spec
|
command ::= match-spec* flags-spec
|
||||||
|
|
||||||
The match-spec's are used to choose a subset of the known dprintk()
|
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
|
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
|
with implicit ANDs between each pair. Note that an empty list of
|
||||||
match-specs is possible, but is not very useful because it will not
|
match-specs will select all debug statement callsites.
|
||||||
match any debug statement callsites.
|
|
||||||
|
|
||||||
A match specification comprises a keyword, which controls the attribute
|
A match specification comprises a keyword, which controls the
|
||||||
of the callsite to be compared, and a value to compare against. Possible
|
attribute of the callsite to be compared, and a value to compare
|
||||||
keywords are:
|
against. Possible keywords are:
|
||||||
|
|
||||||
match-spec ::= 'func' string |
|
match-spec ::= 'func' string |
|
||||||
'file' string |
|
'file' string |
|
||||||
|
@ -164,15 +165,15 @@ format
|
||||||
characters (") or single quote characters (').
|
characters (") or single quote characters (').
|
||||||
Examples:
|
Examples:
|
||||||
|
|
||||||
format svcrdma: // many of the NFS/RDMA server dprintks
|
format svcrdma: // many of the NFS/RDMA server pr_debugs
|
||||||
format readahead // some dprintks in the readahead cache
|
format readahead // some pr_debugs in the readahead cache
|
||||||
format nfsd:\040SETATTR // one way to match a format with whitespace
|
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" // a neater way to match a format with whitespace
|
||||||
format 'nfsd: SETATTR' // yet another way to match a format with whitespace
|
format 'nfsd: SETATTR' // yet another way to match a format with whitespace
|
||||||
|
|
||||||
line
|
line
|
||||||
The given line number or range of line numbers is compared
|
The given line number or range of line numbers is compared
|
||||||
against the line number of each dprintk() callsite. A single
|
against the line number of each pr_debug() callsite. A single
|
||||||
line number matches the callsite line number exactly. A
|
line number matches the callsite line number exactly. A
|
||||||
range of line numbers matches any callsite between the first
|
range of line numbers matches any callsite between the first
|
||||||
and last line number inclusive. An empty first number means
|
and last line number inclusive. An empty first number means
|
||||||
|
@ -188,51 +189,93 @@ The flags specification comprises a change operation followed
|
||||||
by one or more flag characters. The change operation is one
|
by one or more flag characters. The change operation is one
|
||||||
of the characters:
|
of the characters:
|
||||||
|
|
||||||
-
|
- remove the given flags
|
||||||
remove the given flags
|
+ add the given flags
|
||||||
|
= set the flags to the given flags
|
||||||
+
|
|
||||||
add the given flags
|
|
||||||
|
|
||||||
=
|
|
||||||
set the flags to the given flags
|
|
||||||
|
|
||||||
The flags are:
|
The flags are:
|
||||||
|
|
||||||
f
|
p enables the pr_debug() callsite.
|
||||||
Include the function name in the printed message
|
f Include the function name in the printed message
|
||||||
l
|
l Include line number in the printed message
|
||||||
Include line number in the printed message
|
m Include module name in the printed message
|
||||||
m
|
t Include thread ID in messages not generated from interrupt context
|
||||||
Include module name in the printed message
|
_ No flags are set. (Or'd with others on input)
|
||||||
p
|
|
||||||
Causes a printk() message to be emitted to dmesg
|
|
||||||
t
|
|
||||||
Include thread ID in messages not generated from interrupt context
|
|
||||||
|
|
||||||
Note the regexp ^[-+=][flmpt]+$ matches a flags specification.
|
For display, the flags are preceded by '='
|
||||||
Note also that there is no convenient syntax to remove all
|
(mnemonic: what the flags are currently equal to).
|
||||||
the flags at once, you need to use "-flmpt".
|
|
||||||
|
Note the regexp ^[-+=][flmpt_]+$ matches a flags specification.
|
||||||
|
To clear all flags at once, use "=_" or "-flmpt".
|
||||||
|
|
||||||
|
|
||||||
Debug messages during boot process
|
Debug messages during Boot Process
|
||||||
==================================
|
==================================
|
||||||
|
|
||||||
To be able to activate debug messages during the boot process,
|
To activate debug messages for core code and built-in modules during
|
||||||
even before userspace and debugfs exists, use the boot parameter:
|
the boot process, even before userspace and debugfs exists, use
|
||||||
ddebug_query="QUERY"
|
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.
|
||||||
|
|
||||||
QUERY follows the syntax described above, but must not exceed 1023
|
|
||||||
characters. The enablement of debug messages is done as an arch_initcall.
|
|
||||||
Thus you can enable debug messages in all code processed after this
|
|
||||||
arch_initcall via this boot parameter.
|
|
||||||
On an x86 system for example ACPI enablement is a subsys_initcall and
|
On an x86 system for example ACPI enablement is a subsys_initcall and
|
||||||
ddebug_query="file ec.c +p"
|
dyndbg="file ec.c +p"
|
||||||
will show early Embedded Controller transactions during ACPI setup if
|
will show early Embedded Controller transactions during ACPI setup if
|
||||||
your machine (typically a laptop) has an Embedded Controller.
|
your machine (typically a laptop) has an Embedded Controller.
|
||||||
PCI (or other devices) initialization also is a hot candidate for using
|
PCI (or other devices) initialization also is a hot candidate for using
|
||||||
this boot parameter for debugging purposes.
|
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 doesnt 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
|
Examples
|
||||||
========
|
========
|
||||||
|
@ -260,3 +303,18 @@ nullarbor:~ # echo -n 'func svc_process -p' >
|
||||||
// enable messages for NFS calls READ, READLINK, READDIR and READDIR+.
|
// enable messages for NFS calls READ, READLINK, READDIR and READDIR+.
|
||||||
nullarbor:~ # echo -n 'format "nfsd: READ" +p' >
|
nullarbor:~ # echo -n 'format "nfsd: READ" +p' >
|
||||||
<debugfs>/dynamic_debug/control
|
<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"
|
||||||
|
|
|
@ -610,7 +610,7 @@ bytes respectively. Such letter suffixes can also be entirely omitted.
|
||||||
|
|
||||||
ddebug_query= [KNL,DYNAMIC_DEBUG] Enable debug messages at early boot
|
ddebug_query= [KNL,DYNAMIC_DEBUG] Enable debug messages at early boot
|
||||||
time. See Documentation/dynamic-debug-howto.txt for
|
time. See Documentation/dynamic-debug-howto.txt for
|
||||||
details.
|
details. Deprecated, see dyndbg.
|
||||||
|
|
||||||
debug [KNL] Enable kernel debugging (events log level).
|
debug [KNL] Enable kernel debugging (events log level).
|
||||||
|
|
||||||
|
@ -730,6 +730,11 @@ bytes respectively. Such letter suffixes can also be entirely omitted.
|
||||||
|
|
||||||
dscc4.setup= [NET]
|
dscc4.setup= [NET]
|
||||||
|
|
||||||
|
dyndbg[="val"] [KNL,DYNAMIC_DEBUG]
|
||||||
|
module.dyndbg[="val"]
|
||||||
|
Enable debug messages at boot time. See
|
||||||
|
Documentation/dynamic-debug-howto.txt for details.
|
||||||
|
|
||||||
earlycon= [KNL] Output early console device and options.
|
earlycon= [KNL] Output early console device and options.
|
||||||
uart[8250],io,<addr>[,options]
|
uart[8250],io,<addr>[,options]
|
||||||
uart[8250],mmio,<addr>[,options]
|
uart[8250],mmio,<addr>[,options]
|
||||||
|
|
|
@ -1205,8 +1205,13 @@ config DYNAMIC_DEBUG
|
||||||
otherwise be available at runtime. These messages can then be
|
otherwise be available at runtime. These messages can then be
|
||||||
enabled/disabled based on various levels of scope - per source file,
|
enabled/disabled based on various levels of scope - per source file,
|
||||||
function, module, format string, and line number. This mechanism
|
function, module, format string, and line number. This mechanism
|
||||||
implicitly enables all pr_debug() and dev_dbg() calls. The impact of
|
implicitly compiles in all pr_debug() and dev_dbg() calls, which
|
||||||
this compile option is a larger kernel text size of about 2%.
|
enlarges the kernel text size by about 2%.
|
||||||
|
|
||||||
|
If a source file is compiled with DEBUG flag set, any
|
||||||
|
pr_debug() calls in it are enabled by default, but can be
|
||||||
|
disabled at runtime as below. Note that DEBUG flag is
|
||||||
|
turned on by many CONFIG_*DEBUG* options.
|
||||||
|
|
||||||
Usage:
|
Usage:
|
||||||
|
|
||||||
|
@ -1223,16 +1228,16 @@ config DYNAMIC_DEBUG
|
||||||
lineno : line number of the debug statement
|
lineno : line number of the debug statement
|
||||||
module : module that contains the debug statement
|
module : module that contains the debug statement
|
||||||
function : function that contains the debug statement
|
function : function that contains the debug statement
|
||||||
flags : 'p' means the line is turned 'on' for printing
|
flags : '=p' means the line is turned 'on' for printing
|
||||||
format : the format used for the debug statement
|
format : the format used for the debug statement
|
||||||
|
|
||||||
From a live system:
|
From a live system:
|
||||||
|
|
||||||
nullarbor:~ # cat <debugfs>/dynamic_debug/control
|
nullarbor:~ # cat <debugfs>/dynamic_debug/control
|
||||||
# filename:lineno [module]function flags format
|
# filename:lineno [module]function flags format
|
||||||
fs/aio.c:222 [aio]__put_ioctx - "__put_ioctx:\040freeing\040%p\012"
|
fs/aio.c:222 [aio]__put_ioctx =_ "__put_ioctx:\040freeing\040%p\012"
|
||||||
fs/aio.c:248 [aio]ioctx_alloc - "ENOMEM:\040nr_events\040too\040high\012"
|
fs/aio.c:248 [aio]ioctx_alloc =_ "ENOMEM:\040nr_events\040too\040high\012"
|
||||||
fs/aio.c:1770 [aio]sys_io_cancel - "calling\040cancel\012"
|
fs/aio.c:1770 [aio]sys_io_cancel =_ "calling\040cancel\012"
|
||||||
|
|
||||||
Example usage:
|
Example usage:
|
||||||
|
|
||||||
|
|
Loading…
Reference in a new issue