0001 Dynamic debug
0002 +++++++++++++
0003
0004
0005 Introduction
0006 ============
0007
0008 This document describes how to use the dynamic debug (dyndbg) feature.
0009
0010 Dynamic debug is designed to allow you to dynamically enable/disable
0011 kernel code to obtain additional kernel information. Currently, if
0012 ``CONFIG_DYNAMIC_DEBUG`` is set, then all ``pr_debug()``/``dev_dbg()`` and
0013 ``print_hex_dump_debug()``/``print_hex_dump_bytes()`` calls can be dynamically
0014 enabled per-callsite.
0015
0016 If you do not want to enable dynamic debug globally (i.e. in some embedded
0017 system), you may set ``CONFIG_DYNAMIC_DEBUG_CORE`` as basic support of dynamic
0018 debug and add ``ccflags := -DDYNAMIC_DEBUG_MODULE`` into the Makefile of any
0019 modules which you'd like to dynamically debug later.
0020
0021 If ``CONFIG_DYNAMIC_DEBUG`` is not set, ``print_hex_dump_debug()`` is just
0022 shortcut for ``print_hex_dump(KERN_DEBUG)``.
0023
0024 For ``print_hex_dump_debug()``/``print_hex_dump_bytes()``, format string is
0025 its ``prefix_str`` argument, if it is constant string; or ``hexdump``
0026 in case ``prefix_str`` is built dynamically.
0027
0028 Dynamic debug has even more useful features:
0029
0030 * Simple query language allows turning on and off debugging
0031 statements by matching any combination of 0 or 1 of:
0032
0033 - source filename
0034 - function name
0035 - line number (including ranges of line numbers)
0036 - module name
0037 - format string
0038
0039 * Provides a debugfs control file: ``<debugfs>/dynamic_debug/control``
0040 which can be read to display the complete list of known debug
0041 statements, to help guide you
0042
0043 Controlling dynamic debug Behaviour
0044 ===================================
0045
0046 The behaviour of ``pr_debug()``/``dev_dbg()`` are controlled via writing to a
0047 control file in the 'debugfs' filesystem. Thus, you must first mount
0048 the debugfs filesystem, in order to make use of this feature.
0049 Subsequently, we refer to the control file as:
0050 ``<debugfs>/dynamic_debug/control``. For example, if you want to enable
0051 printing from source file ``svcsock.c``, line 1603 you simply do::
0052
0053 nullarbor:~ # echo 'file svcsock.c line 1603 +p' >
0054 <debugfs>/dynamic_debug/control
0055
0056 If you make a mistake with the syntax, the write will fail thus::
0057
0058 nullarbor:~ # echo 'file svcsock.c wtf 1 +p' >
0059 <debugfs>/dynamic_debug/control
0060 -bash: echo: write error: Invalid argument
0061
0062 Note, for systems without 'debugfs' enabled, the control file can be
0063 found in ``/proc/dynamic_debug/control``.
0064
0065 Viewing Dynamic Debug Behaviour
0066 ===============================
0067
0068 You can view the currently configured behaviour of all the debug
0069 statements via::
0070
0071 nullarbor:~ # cat <debugfs>/dynamic_debug/control
0072 # filename:lineno [module]function flags format
0073 net/sunrpc/svc_rdma.c:323 [svcxprt_rdma]svc_rdma_cleanup =_ "SVCRDMA Module Removed, deregister RPC RDMA transport\012"
0074 net/sunrpc/svc_rdma.c:341 [svcxprt_rdma]svc_rdma_init =_ "\011max_inline : %d\012"
0075 net/sunrpc/svc_rdma.c:340 [svcxprt_rdma]svc_rdma_init =_ "\011sq_depth : %d\012"
0076 net/sunrpc/svc_rdma.c:338 [svcxprt_rdma]svc_rdma_init =_ "\011max_requests : %d\012"
0077 ...
0078
0079
0080 You can also apply standard Unix text manipulation filters to this
0081 data, e.g.::
0082
0083 nullarbor:~ # grep -i rdma <debugfs>/dynamic_debug/control | wc -l
0084 62
0085
0086 nullarbor:~ # grep -i tcp <debugfs>/dynamic_debug/control | wc -l
0087 42
0088
0089 The third column shows the currently enabled flags for each debug
0090 statement callsite (see below for definitions of the flags). The
0091 default value, with no flags enabled, is ``=_``. So you can view all
0092 the debug statement callsites with any non-default flags::
0093
0094 nullarbor:~ # awk '$3 != "=_"' <debugfs>/dynamic_debug/control
0095 # filename:lineno [module]function flags format
0096 net/sunrpc/svcsock.c:1603 [sunrpc]svc_send p "svc_process: st_sendto returned %d\012"
0097
0098 Command Language Reference
0099 ==========================
0100
0101 At the lexical level, a command comprises a sequence of words separated
0102 by spaces or tabs. So these are all equivalent::
0103
0104 nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
0105 <debugfs>/dynamic_debug/control
0106 nullarbor:~ # echo -n ' file svcsock.c line 1603 +p ' >
0107 <debugfs>/dynamic_debug/control
0108 nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
0109 <debugfs>/dynamic_debug/control
0110
0111 Command submissions are bounded by a write() system call.
0112 Multiple commands can be written together, separated by ``;`` or ``\n``::
0113
0114 ~# echo "func pnpacpi_get_resources +p; func pnp_assign_mem +p" \
0115 > <debugfs>/dynamic_debug/control
0116
0117 If your query set is big, you can batch them too::
0118
0119 ~# cat query-batch-file > <debugfs>/dynamic_debug/control
0120
0121 Another way is to use wildcards. The match rule supports ``*`` (matches
0122 zero or more characters) and ``?`` (matches exactly one character). For
0123 example, you can match all usb drivers::
0124
0125 ~# echo "file drivers/usb/* +p" > <debugfs>/dynamic_debug/control
0126
0127 At the syntactical level, a command comprises a sequence of match
0128 specifications, followed by a flags change specification::
0129
0130 command ::= match-spec* flags-spec
0131
0132 The match-spec's are used to choose a subset of the known pr_debug()
0133 callsites to which to apply the flags-spec. Think of them as a query
0134 with implicit ANDs between each pair. Note that an empty list of
0135 match-specs will select all debug statement callsites.
0136
0137 A match specification comprises a keyword, which controls the
0138 attribute of the callsite to be compared, and a value to compare
0139 against. Possible keywords are:::
0140
0141 match-spec ::= 'func' string |
0142 'file' string |
0143 'module' string |
0144 'format' string |
0145 'line' line-range
0146
0147 line-range ::= lineno |
0148 '-'lineno |
0149 lineno'-' |
0150 lineno'-'lineno
0151
0152 lineno ::= unsigned-int
0153
0154 .. note::
0155
0156 ``line-range`` cannot contain space, e.g.
0157 "1-30" is valid range but "1 - 30" is not.
0158
0159
0160 The meanings of each keyword are:
0161
0162 func
0163 The given string is compared against the function name
0164 of each callsite. Example::
0165
0166 func svc_tcp_accept
0167 func *recv* # in rfcomm, bluetooth, ping, tcp
0168
0169 file
0170 The given string is compared against either the src-root relative
0171 pathname, or the basename of the source file of each callsite.
0172 Examples::
0173
0174 file svcsock.c
0175 file kernel/freezer.c # ie column 1 of control file
0176 file drivers/usb/* # all callsites under it
0177 file inode.c:start_* # parse :tail as a func (above)
0178 file inode.c:1-100 # parse :tail as a line-range (above)
0179
0180 module
0181 The given string is compared against the module name
0182 of each callsite. The module name is the string as
0183 seen in ``lsmod``, i.e. without the directory or the ``.ko``
0184 suffix and with ``-`` changed to ``_``. Examples::
0185
0186 module sunrpc
0187 module nfsd
0188 module drm* # both drm, drm_kms_helper
0189
0190 format
0191 The given string is searched for in the dynamic debug format
0192 string. Note that the string does not need to match the
0193 entire format, only some part. Whitespace and other
0194 special characters can be escaped using C octal character
0195 escape ``\ooo`` notation, e.g. the space character is ``\040``.
0196 Alternatively, the string can be enclosed in double quote
0197 characters (``"``) or single quote characters (``'``).
0198 Examples::
0199
0200 format svcrdma: // many of the NFS/RDMA server pr_debugs
0201 format readahead // some pr_debugs in the readahead cache
0202 format nfsd:\040SETATTR // one way to match a format with whitespace
0203 format "nfsd: SETATTR" // a neater way to match a format with whitespace
0204 format 'nfsd: SETATTR' // yet another way to match a format with whitespace
0205
0206 line
0207 The given line number or range of line numbers is compared
0208 against the line number of each ``pr_debug()`` callsite. A single
0209 line number matches the callsite line number exactly. A
0210 range of line numbers matches any callsite between the first
0211 and last line number inclusive. An empty first number means
0212 the first line in the file, an empty last line number means the
0213 last line number in the file. Examples::
0214
0215 line 1603 // exactly line 1603
0216 line 1600-1605 // the six lines from line 1600 to line 1605
0217 line -1605 // the 1605 lines from line 1 to line 1605
0218 line 1600- // all lines from line 1600 to the end of the file
0219
0220 The flags specification comprises a change operation followed
0221 by one or more flag characters. The change operation is one
0222 of the characters::
0223
0224 - remove the given flags
0225 + add the given flags
0226 = set the flags to the given flags
0227
0228 The flags are::
0229
0230 p enables the pr_debug() callsite.
0231 f Include the function name in the printed message
0232 l Include line number in the printed message
0233 m Include module name in the printed message
0234 t Include thread ID in messages not generated from interrupt context
0235 _ No flags are set. (Or'd with others on input)
0236
0237 For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only ``p`` flag
0238 have meaning, other flags ignored.
0239
0240 For display, the flags are preceded by ``=``
0241 (mnemonic: what the flags are currently equal to).
0242
0243 Note the regexp ``^[-+=][flmpt_]+$`` matches a flags specification.
0244 To clear all flags at once, use ``=_`` or ``-flmpt``.
0245
0246
0247 Debug messages during Boot Process
0248 ==================================
0249
0250 To activate debug messages for core code and built-in modules during
0251 the boot process, even before userspace and debugfs exists, use
0252 ``dyndbg="QUERY"`` or ``module.dyndbg="QUERY"``. QUERY follows
0253 the syntax described above, but must not exceed 1023 characters. Your
0254 bootloader may impose lower limits.
0255
0256 These ``dyndbg`` params are processed just after the ddebug tables are
0257 processed, as part of the early_initcall. Thus you can enable debug
0258 messages in all code run after this early_initcall via this boot
0259 parameter.
0260
0261 On an x86 system for example ACPI enablement is a subsys_initcall and::
0262
0263 dyndbg="file ec.c +p"
0264
0265 will show early Embedded Controller transactions during ACPI setup if
0266 your machine (typically a laptop) has an Embedded Controller.
0267 PCI (or other devices) initialization also is a hot candidate for using
0268 this boot parameter for debugging purposes.
0269
0270 If ``foo`` module is not built-in, ``foo.dyndbg`` will still be processed at
0271 boot time, without effect, but will be reprocessed when module is
0272 loaded later. Bare ``dyndbg=`` is only processed at boot.
0273
0274
0275 Debug Messages at Module Initialization Time
0276 ============================================
0277
0278 When ``modprobe foo`` is called, modprobe scans ``/proc/cmdline`` for
0279 ``foo.params``, strips ``foo.``, and passes them to the kernel along with
0280 params given in modprobe args or ``/etc/modprob.d/*.conf`` files,
0281 in the following order:
0282
0283 1. parameters given via ``/etc/modprobe.d/*.conf``::
0284
0285 options foo dyndbg=+pt
0286 options foo dyndbg # defaults to +p
0287
0288 2. ``foo.dyndbg`` as given in boot args, ``foo.`` is stripped and passed::
0289
0290 foo.dyndbg=" func bar +p; func buz +mp"
0291
0292 3. args to modprobe::
0293
0294 modprobe foo dyndbg==pmf # override previous settings
0295
0296 These ``dyndbg`` queries are applied in order, with last having final say.
0297 This allows boot args to override or modify those from ``/etc/modprobe.d``
0298 (sensible, since 1 is system wide, 2 is kernel or boot specific), and
0299 modprobe args to override both.
0300
0301 In the ``foo.dyndbg="QUERY"`` form, the query must exclude ``module foo``.
0302 ``foo`` is extracted from the param-name, and applied to each query in
0303 ``QUERY``, and only 1 match-spec of each type is allowed.
0304
0305 The ``dyndbg`` option is a "fake" module parameter, which means:
0306
0307 - modules do not need to define it explicitly
0308 - every module gets it tacitly, whether they use pr_debug or not
0309 - it doesn't appear in ``/sys/module/$module/parameters/``
0310 To see it, grep the control file, or inspect ``/proc/cmdline.``
0311
0312 For ``CONFIG_DYNAMIC_DEBUG`` kernels, any settings given at boot-time (or
0313 enabled by ``-DDEBUG`` flag during compilation) can be disabled later via
0314 the debugfs interface if the debug messages are no longer needed::
0315
0316 echo "module module_name -p" > <debugfs>/dynamic_debug/control
0317
0318 Examples
0319 ========
0320
0321 ::
0322
0323 // enable the message at line 1603 of file svcsock.c
0324 nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
0325 <debugfs>/dynamic_debug/control
0326
0327 // enable all the messages in file svcsock.c
0328 nullarbor:~ # echo -n 'file svcsock.c +p' >
0329 <debugfs>/dynamic_debug/control
0330
0331 // enable all the messages in the NFS server module
0332 nullarbor:~ # echo -n 'module nfsd +p' >
0333 <debugfs>/dynamic_debug/control
0334
0335 // enable all 12 messages in the function svc_process()
0336 nullarbor:~ # echo -n 'func svc_process +p' >
0337 <debugfs>/dynamic_debug/control
0338
0339 // disable all 12 messages in the function svc_process()
0340 nullarbor:~ # echo -n 'func svc_process -p' >
0341 <debugfs>/dynamic_debug/control
0342
0343 // enable messages for NFS calls READ, READLINK, READDIR and READDIR+.
0344 nullarbor:~ # echo -n 'format "nfsd: READ" +p' >
0345 <debugfs>/dynamic_debug/control
0346
0347 // enable messages in files of which the paths include string "usb"
0348 nullarbor:~ # echo -n 'file *usb* +p' > <debugfs>/dynamic_debug/control
0349
0350 // enable all messages
0351 nullarbor:~ # echo -n '+p' > <debugfs>/dynamic_debug/control
0352
0353 // add module, function to all enabled messages
0354 nullarbor:~ # echo -n '+mf' > <debugfs>/dynamic_debug/control
0355
0356 // boot-args example, with newlines and comments for readability
0357 Kernel command line: ...
0358 // see whats going on in dyndbg=value processing
0359 dynamic_debug.verbose=3
0360 // enable pr_debugs in the btrfs module (can be builtin or loadable)
0361 btrfs.dyndbg="+p"
0362 // enable pr_debugs in all files under init/
0363 // and the function parse_one, #cmt is stripped
0364 dyndbg="file init/* +p #cmt ; func parse_one +p"
0365 // enable pr_debugs in 2 functions in a module loaded later
0366 pc87360.dyndbg="func pc87360_init_device +p; func pc87360_find +p"