From 29e36c9ffb696ed8d73e1aee713d483ec74a9a43 Mon Sep 17 00:00:00 2001 From: Jim Cromie Date: Fri, 27 Apr 2012 14:30:41 -0600 Subject: [PATCH] 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 Acked-by: Jason Baron Signed-off-by: Greg Kroah-Hartman --- Documentation/dynamic-debug-howto.txt | 184 +++++++++++++++++--------- Documentation/kernel-parameters.txt | 7 +- lib/Kconfig.debug | 17 ++- 3 files changed, 138 insertions(+), 70 deletions(-) diff --git a/Documentation/dynamic-debug-howto.txt b/Documentation/dynamic-debug-howto.txt index 74e6c7782678..6e1684981da2 100644 --- a/Documentation/dynamic-debug-howto.txt +++ b/Documentation/dynamic-debug-howto.txt @@ -2,17 +2,17 @@ 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 -code to obtain additional kernel information. Currently, if -CONFIG_DYNAMIC_DEBUG is set, then all pr_debug()/dev_dbg() calls can be -dynamically enabled per-callsite. +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() calls can +be dynamically enabled per-callsite. 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: + * Simple query language allows turning on and off debugging + statements by matching any combination of 0 or 1 of: - source filename - function name @@ -20,17 +20,19 @@ Dynamic debug has even more useful features: - module name - format string - * Provides a debugfs control file: /dynamic_debug/control which can be - read to display the complete list of known debug statements, to help guide you + * Provides a debugfs control file: /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: /dynamic_debug/control. For example, if you want to -enable printing from source file 'svcsock.c', line 1603 you simply do: +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: +/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' > /dynamic_debug/control @@ -44,15 +46,15 @@ nullarbor:~ # echo 'file svcsock.c wtf 1 +p' > Viewing Dynamic Debug Behaviour =========================== -You can view the currently configured behaviour of all the debug statements -via: +You can view the currently configured behaviour of all the debug +statements via: nullarbor:~ # cat /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" +/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" ... @@ -65,12 +67,12 @@ nullarbor:~ # grep -i rdma /dynamic_debug/control | wc -l nullarbor:~ # grep -i tcp /dynamic_debug/control | wc -l 42 -Note in particular that the third column shows the enabled behaviour -flags for each debug statement callsite (see below for definitions of the -flags). The default value, no extra behaviour enabled, is "-". So -you can view all the debug statement callsites with any non-default flags: +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 != "-"' /dynamic_debug/control +nullarbor:~ # awk '$3 != "=_"' /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" @@ -103,15 +105,14 @@ 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 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 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 any debug statement callsites. +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: +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 | @@ -164,15 +165,15 @@ format characters (") or single quote characters ('). Examples: - format svcrdma: // many of the NFS/RDMA server dprintks - format readahead // some dprintks in the readahead cache + 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 dprintk() callsite. A single + 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 @@ -188,51 +189,93 @@ 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 + - remove the given flags + + add the given flags + = set the flags to the given flags The flags are: -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 -p - Causes a printk() message to be emitted to dmesg -t - Include thread ID in messages not generated from interrupt context + 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 display, the flags are preceded by '=' +(mnemonic: what the flags are currently equal to). -Note the regexp ^[-+=][flmpt]+$ matches a flags specification. -Note also that there is no convenient syntax to remove all -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, -even before userspace and debugfs exists, use the boot parameter: -ddebug_query="QUERY" +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. -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 -ddebug_query="file ec.c +p" + 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 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" > /dynamic_debug/control Examples ======== @@ -260,3 +303,18 @@ nullarbor:~ # echo -n 'func svc_process -p' > // enable messages for NFS calls READ, READLINK, READDIR and READDIR+. nullarbor:~ # echo -n 'format "nfsd: READ" +p' > /dynamic_debug/control + +// enable all messages +nullarbor:~ # echo -n '+p' > /dynamic_debug/control + +// add module, function to all enabled messages +nullarbor:~ # echo -n '+mf' > /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" diff --git a/Documentation/kernel-parameters.txt b/Documentation/kernel-parameters.txt index c1601e5a8b71..d224225616b7 100644 --- a/Documentation/kernel-parameters.txt +++ b/Documentation/kernel-parameters.txt @@ -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 time. See Documentation/dynamic-debug-howto.txt for - details. + details. Deprecated, see dyndbg. 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] + 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. uart[8250],io,[,options] uart[8250],mmio,[,options] diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug index 6777153f18f3..ef8192bc0c33 100644 --- a/lib/Kconfig.debug +++ b/lib/Kconfig.debug @@ -1205,8 +1205,13 @@ config DYNAMIC_DEBUG otherwise be available at runtime. These messages can then be enabled/disabled based on various levels of scope - per source file, function, module, format string, and line number. This mechanism - implicitly enables all pr_debug() and dev_dbg() calls. The impact of - this compile option is a larger kernel text size of about 2%. + implicitly compiles in all pr_debug() and dev_dbg() calls, which + 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: @@ -1223,16 +1228,16 @@ config DYNAMIC_DEBUG lineno : line number of the debug statement module : module 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 From a live system: nullarbor:~ # cat /dynamic_debug/control # filename:lineno [module]function flags format - 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:1770 [aio]sys_io_cancel - "calling\040cancel\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:1770 [aio]sys_io_cancel =_ "calling\040cancel\012" Example usage: -- 2.20.1