1Dynamic debug 2+++++++++++++ 3 4 5Introduction 6============ 7 8This document describes how to use the dynamic debug (dyndbg) feature. 9 10Dynamic debug is designed to allow you to dynamically enable/disable 11kernel 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 14enabled per-callsite. 15 16If ``CONFIG_DYNAMIC_DEBUG`` is not set, ``print_hex_dump_debug()`` is just 17shortcut for ``print_hex_dump(KERN_DEBUG)``. 18 19For ``print_hex_dump_debug()``/``print_hex_dump_bytes()``, format string is 20its ``prefix_str`` argument, if it is constant string; or ``hexdump`` 21in case ``prefix_str`` is built dynamically. 22 23Dynamic 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 38Controlling dynamic debug Behaviour 39=================================== 40 41The behaviour of ``pr_debug()``/``dev_dbg()`` are controlled via writing to a 42control file in the 'debugfs' filesystem. Thus, you must first mount 43the debugfs filesystem, in order to make use of this feature. 44Subsequently, we refer to the control file as: 45``<debugfs>/dynamic_debug/control``. For example, if you want to enable 46printing 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 51If 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 57Note, for systems without 'debugfs' enabled, the control file can be 58found in ``/proc/dynamic_debug/control``. 59 60Viewing Dynamic Debug Behaviour 61=============================== 62 63You can view the currently configured behaviour of all the debug 64statements via:: 65 66 nullarbor:~ # cat <debugfs>/dynamic_debug/control 67 # filename:lineno [module]function flags format 68 /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" 69 /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:341 [svcxprt_rdma]svc_rdma_init =_ "\011max_inline : %d\012" 70 /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:340 [svcxprt_rdma]svc_rdma_init =_ "\011sq_depth : %d\012" 71 /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:338 [svcxprt_rdma]svc_rdma_init =_ "\011max_requests : %d\012" 72 ... 73 74 75You can also apply standard Unix text manipulation filters to this 76data, e.g.:: 77 78 nullarbor:~ # grep -i rdma <debugfs>/dynamic_debug/control | wc -l 79 62 80 81 nullarbor:~ # grep -i tcp <debugfs>/dynamic_debug/control | wc -l 82 42 83 84The third column shows the currently enabled flags for each debug 85statement callsite (see below for definitions of the flags). The 86default value, with no flags enabled, is ``=_``. So you can view all 87the debug statement callsites with any non-default flags:: 88 89 nullarbor:~ # awk '$3 != "=_"' <debugfs>/dynamic_debug/control 90 # filename:lineno [module]function flags format 91 /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" 92 93Command Language Reference 94========================== 95 96At the lexical level, a command comprises a sequence of words separated 97by spaces or tabs. So these are all equivalent:: 98 99 nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' > 100 <debugfs>/dynamic_debug/control 101 nullarbor:~ # echo -n ' file svcsock.c line 1603 +p ' > 102 <debugfs>/dynamic_debug/control 103 nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' > 104 <debugfs>/dynamic_debug/control 105 106Command submissions are bounded by a write() system call. 107Multiple commands can be written together, separated by ``;`` or ``\n``:: 108 109 ~# echo "func pnpacpi_get_resources +p; func pnp_assign_mem +p" \ 110 > <debugfs>/dynamic_debug/control 111 112If your query set is big, you can batch them too:: 113 114 ~# cat query-batch-file > <debugfs>/dynamic_debug/control 115 116Another way is to use wildcards. The match rule supports ``*`` (matches 117zero or more characters) and ``?`` (matches exactly one character). For 118example, you can match all usb drivers:: 119 120 ~# echo "file drivers/usb/* +p" > <debugfs>/dynamic_debug/control 121 122At the syntactical level, a command comprises a sequence of match 123specifications, followed by a flags change specification:: 124 125 command ::= match-spec* flags-spec 126 127The match-spec's are used to choose a subset of the known pr_debug() 128callsites to which to apply the flags-spec. Think of them as a query 129with implicit ANDs between each pair. Note that an empty list of 130match-specs will select all debug statement callsites. 131 132A match specification comprises a keyword, which controls the 133attribute of the callsite to be compared, and a value to compare 134against. Possible keywords are::: 135 136 match-spec ::= 'func' string | 137 'file' string | 138 'module' string | 139 'format' string | 140 'line' line-range 141 142 line-range ::= lineno | 143 '-'lineno | 144 lineno'-' | 145 lineno'-'lineno 146 147 lineno ::= unsigned-int 148 149.. note:: 150 151 ``line-range`` cannot contain space, e.g. 152 "1-30" is valid range but "1 - 30" is not. 153 154 155The meanings of each keyword are: 156 157func 158 The given string is compared against the function name 159 of each callsite. Example:: 160 161 func svc_tcp_accept 162 163file 164 The given string is compared against either the full pathname, the 165 src-root relative pathname, or the basename of the source file of 166 each callsite. Examples:: 167 168 file svcsock.c 169 file kernel/freezer.c 170 file /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svcsock.c 171 172module 173 The given string is compared against the module name 174 of each callsite. The module name is the string as 175 seen in ``lsmod``, i.e. without the directory or the ``.ko`` 176 suffix and with ``-`` changed to ``_``. Examples:: 177 178 module sunrpc 179 module nfsd 180 181format 182 The given string is searched for in the dynamic debug format 183 string. Note that the string does not need to match the 184 entire format, only some part. Whitespace and other 185 special characters can be escaped using C octal character 186 escape ``\ooo`` notation, e.g. the space character is ``\040``. 187 Alternatively, the string can be enclosed in double quote 188 characters (``"``) or single quote characters (``'``). 189 Examples:: 190 191 format svcrdma: // many of the NFS/RDMA server pr_debugs 192 format readahead // some pr_debugs in the readahead cache 193 format nfsd:\040SETATTR // one way to match a format with whitespace 194 format "nfsd: SETATTR" // a neater way to match a format with whitespace 195 format 'nfsd: SETATTR' // yet another way to match a format with whitespace 196 197line 198 The given line number or range of line numbers is compared 199 against the line number of each ``pr_debug()`` callsite. A single 200 line number matches the callsite line number exactly. A 201 range of line numbers matches any callsite between the first 202 and last line number inclusive. An empty first number means 203 the first line in the file, an empty last line number means the 204 last line number in the file. Examples:: 205 206 line 1603 // exactly line 1603 207 line 1600-1605 // the six lines from line 1600 to line 1605 208 line -1605 // the 1605 lines from line 1 to line 1605 209 line 1600- // all lines from line 1600 to the end of the file 210 211The flags specification comprises a change operation followed 212by one or more flag characters. The change operation is one 213of the characters:: 214 215 - remove the given flags 216 + add the given flags 217 = set the flags to the given flags 218 219The flags are:: 220 221 p enables the pr_debug() callsite. 222 f Include the function name in the printed message 223 l Include line number in the printed message 224 m Include module name in the printed message 225 t Include thread ID in messages not generated from interrupt context 226 _ No flags are set. (Or'd with others on input) 227 228For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only ``p`` flag 229have meaning, other flags ignored. 230 231For display, the flags are preceded by ``=`` 232(mnemonic: what the flags are currently equal to). 233 234Note the regexp ``^[-+=][flmpt_]+$`` matches a flags specification. 235To clear all flags at once, use ``=_`` or ``-flmpt``. 236 237 238Debug messages during Boot Process 239================================== 240 241To activate debug messages for core code and built-in modules during 242the boot process, even before userspace and debugfs exists, use 243``dyndbg="QUERY"``, ``module.dyndbg="QUERY"``, or ``ddebug_query="QUERY"`` 244(``ddebug_query`` is obsoleted by ``dyndbg``, and deprecated). QUERY follows 245the syntax described above, but must not exceed 1023 characters. Your 246bootloader may impose lower limits. 247 248These ``dyndbg`` params are processed just after the ddebug tables are 249processed, as part of the arch_initcall. Thus you can enable debug 250messages in all code run after this arch_initcall via this boot 251parameter. 252 253On an x86 system for example ACPI enablement is a subsys_initcall and:: 254 255 dyndbg="file ec.c +p" 256 257will show early Embedded Controller transactions during ACPI setup if 258your machine (typically a laptop) has an Embedded Controller. 259PCI (or other devices) initialization also is a hot candidate for using 260this boot parameter for debugging purposes. 261 262If ``foo`` module is not built-in, ``foo.dyndbg`` will still be processed at 263boot time, without effect, but will be reprocessed when module is 264loaded later. ``ddebug_query=`` and bare ``dyndbg=`` are only processed at 265boot. 266 267 268Debug Messages at Module Initialization Time 269============================================ 270 271When ``modprobe foo`` is called, modprobe scans ``/proc/cmdline`` for 272``foo.params``, strips ``foo.``, and passes them to the kernel along with 273params given in modprobe args or ``/etc/modprob.d/*.conf`` files, 274in the following order: 275 2761. parameters given via ``/etc/modprobe.d/*.conf``:: 277 278 options foo dyndbg=+pt 279 options foo dyndbg # defaults to +p 280 2812. ``foo.dyndbg`` as given in boot args, ``foo.`` is stripped and passed:: 282 283 foo.dyndbg=" func bar +p; func buz +mp" 284 2853. args to modprobe:: 286 287 modprobe foo dyndbg==pmf # override previous settings 288 289These ``dyndbg`` queries are applied in order, with last having final say. 290This allows boot args to override or modify those from ``/etc/modprobe.d`` 291(sensible, since 1 is system wide, 2 is kernel or boot specific), and 292modprobe args to override both. 293 294In the ``foo.dyndbg="QUERY"`` form, the query must exclude ``module foo``. 295``foo`` is extracted from the param-name, and applied to each query in 296``QUERY``, and only 1 match-spec of each type is allowed. 297 298The ``dyndbg`` option is a "fake" module parameter, which means: 299 300- modules do not need to define it explicitly 301- every module gets it tacitly, whether they use pr_debug or not 302- it doesn't appear in ``/sys/module/$module/parameters/`` 303 To see it, grep the control file, or inspect ``/proc/cmdline.`` 304 305For ``CONFIG_DYNAMIC_DEBUG`` kernels, any settings given at boot-time (or 306enabled by ``-DDEBUG`` flag during compilation) can be disabled later via 307the debugfs interface if the debug messages are no longer needed:: 308 309 echo "module module_name -p" > <debugfs>/dynamic_debug/control 310 311Examples 312======== 313 314:: 315 316 // enable the message at line 1603 of file svcsock.c 317 nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' > 318 <debugfs>/dynamic_debug/control 319 320 // enable all the messages in file svcsock.c 321 nullarbor:~ # echo -n 'file svcsock.c +p' > 322 <debugfs>/dynamic_debug/control 323 324 // enable all the messages in the NFS server module 325 nullarbor:~ # echo -n 'module nfsd +p' > 326 <debugfs>/dynamic_debug/control 327 328 // enable all 12 messages in the function svc_process() 329 nullarbor:~ # echo -n 'func svc_process +p' > 330 <debugfs>/dynamic_debug/control 331 332 // disable all 12 messages in the function svc_process() 333 nullarbor:~ # echo -n 'func svc_process -p' > 334 <debugfs>/dynamic_debug/control 335 336 // enable messages for NFS calls READ, READLINK, READDIR and READDIR+. 337 nullarbor:~ # echo -n 'format "nfsd: READ" +p' > 338 <debugfs>/dynamic_debug/control 339 340 // enable messages in files of which the paths include string "usb" 341 nullarbor:~ # echo -n '*usb* +p' > <debugfs>/dynamic_debug/control 342 343 // enable all messages 344 nullarbor:~ # echo -n '+p' > <debugfs>/dynamic_debug/control 345 346 // add module, function to all enabled messages 347 nullarbor:~ # echo -n '+mf' > <debugfs>/dynamic_debug/control 348 349 // boot-args example, with newlines and comments for readability 350 Kernel command line: ... 351 // see whats going on in dyndbg=value processing 352 dynamic_debug.verbose=1 353 // enable pr_debugs in 2 builtins, #cmt is stripped 354 dyndbg="module params +p #cmt ; module sys +p" 355 // enable pr_debugs in 2 functions in a module loaded later 356 pc87360.dyndbg="func pc87360_init_device +p; func pc87360_find +p" 357