Documentation/admin-guide/dynamic-debug-howto.rst

   1 Dynamic debug
   2 +++++++++++++
   3
   4
   5 Introduction
   6 ============
   7
   8 Dynamic debug allows you to dynamically enable/disable kernel
   9 debug-print code to obtain additional kernel information.
  10
  11 If ``/proc/dynamic_debug/control`` exists, your kernel has dynamic
  12 debug.  You'll need root access (sudo su) to use this.
  13
  14 Dynamic debug provides:
  15
  16  * a Catalog of all *prdbgs* in your kernel.
  17    ``cat /proc/dynamic_debug/control`` to see them.
  18
  19  * a Simple query/command language to alter *prdbgs* by selecting on
  20    any combination of 0 or 1 of:
  21
  22    - source filename
  23    - function name
  24    - line number (including ranges of line numbers)
  25    - module name
  26    - format string
  27    - class name (as known/declared by each module)
  28
  29 Viewing Dynamic Debug Behaviour
  30 ===============================
  31
  32 You can view the currently configured behaviour in the *prdbg* catalog::
  33
  34   :#> head -n7 /proc/dynamic_debug/control
  35   # filename:lineno [module]function flags format
  36   init/main.c:1179 [main]initcall_blacklist =_ "blacklisting initcall %s\012
  37   init/main.c:1218 [main]initcall_blacklisted =_ "initcall %s blacklisted\012"
  38   init/main.c:1424 [main]run_init_process =_ "  with arguments:\012"
  39   init/main.c:1426 [main]run_init_process =_ "    %s\012"
  40   init/main.c:1427 [main]run_init_process =_ "  with environment:\012"
  41   init/main.c:1429 [main]run_init_process =_ "    %s\012"
  42
  43 The 3rd space-delimited column shows the current flags, preceded by
  44 a ``=`` for easy use with grep/cut. ``=p`` shows enabled callsites.
  45
  46 Controlling dynamic debug Behaviour
  47 ===================================
  48
  49 The behaviour of *prdbg* sites are controlled by writing
  50 query/commands to the control file.  Example::
  51
  52   # grease the interface
  53   :#> alias ddcmd='echo $* > /proc/dynamic_debug/control'
  54
  55   :#> ddcmd '-p; module main func run* +p'
  56   :#> grep =p /proc/dynamic_debug/control
  57   init/main.c:1424 [main]run_init_process =p "  with arguments:\012"
  58   init/main.c:1426 [main]run_init_process =p "    %s\012"
  59   init/main.c:1427 [main]run_init_process =p "  with environment:\012"
  60   init/main.c:1429 [main]run_init_process =p "    %s\012"
  61
  62 Error messages go to console/syslog::
  63
  64   :#> ddcmd mode foo +p
  65   dyndbg: unknown keyword "mode"
  66   dyndbg: query parse failed
  67   bash: echo: write error: Invalid argument
  68
  69 If debugfs is also enabled and mounted, ``dynamic_debug/control`` is
  70 also under the mount-dir, typically ``/sys/kernel/debug/``.
  71
  72 Command Language Reference
  73 ==========================
  74
  75 At the basic lexical level, a command is a sequence of words separated
  76 by spaces or tabs.  So these are all equivalent::
  77
  78   :#> ddcmd file svcsock.c line 1603 +p
  79   :#> ddcmd "file svcsock.c line 1603 +p"
  80   :#> ddcmd '  file   svcsock.c     line  1603 +p  '
  81
  82 Command submissions are bounded by a write() system call.
  83 Multiple commands can be written together, separated by ``;`` or ``\n``::
  84
  85   :#> ddcmd "func pnpacpi_get_resources +p; func pnp_assign_mem +p"
  86   :#> ddcmd <<"EOC"
  87   func pnpacpi_get_resources +p
  88   func pnp_assign_mem +p
  89   EOC
  90   :#> cat query-batch-file > /proc/dynamic_debug/control
  91
  92 You can also use wildcards in each query term. The match rule supports
  93 ``*`` (matches zero or more characters) and ``?`` (matches exactly one
  94 character). For example, you can match all usb drivers::
  95
  96   :#> ddcmd file "drivers/usb/*" +p     # "" to suppress shell expansion
  97
  98 Syntactically, a command is pairs of keyword values, followed by a
  99 flags change or setting::
 100
 101   command ::= match-spec* flags-spec
 102
 103 The match-spec's select *prdbgs* from the catalog, upon which to apply
 104 the flags-spec, all constraints are ANDed together.  An absent keyword
 105 is the same as keyword "*".
 106
 107
 108 A match specification is a keyword, which selects the attribute of
 109 the callsite to be compared, and a value to compare against.  Possible
 110 keywords are:::
 111
 112   match-spec ::= 'func' string |
 113                  'file' string |
 114                  'module' string |
 115                  'format' string |
 116                  'class' string |
 117                  'line' line-range
 118
 119   line-range ::= lineno |
 120                  '-'lineno |
 121                  lineno'-' |
 122                  lineno'-'lineno
 123
 124   lineno ::= unsigned-int
 125
 126 .. note::
 127
 128   ``line-range`` cannot contain space, e.g.
 129   "1-30" is valid range but "1 - 30" is not.
 130
 131
 132 The meanings of each keyword are:
 133
 134 func
 135     The given string is compared against the function name
 136     of each callsite.  Example::
 137
 138         func svc_tcp_accept
 139         func *recv*             # in rfcomm, bluetooth, ping, tcp
 140
 141 file
 142     The given string is compared against either the src-root relative
 143     pathname, or the basename of the source file of each callsite.
 144     Examples::
 145
 146         file svcsock.c
 147         file kernel/freezer.c   # ie column 1 of control file
 148         file drivers/usb/*      # all callsites under it
 149         file inode.c:start_*    # parse :tail as a func (above)
 150         file inode.c:1-100      # parse :tail as a line-range (above)
 151
 152 module
 153     The given string is compared against the module name
 154     of each callsite.  The module name is the string as
 155     seen in ``lsmod``, i.e. without the directory or the ``.ko``
 156     suffix and with ``-`` changed to ``_``.  Examples::
 157
 158         module sunrpc
 159         module nfsd
 160         module drm*     # both drm, drm_kms_helper
 161
 162 format
 163     The given string is searched for in the dynamic debug format
 164     string.  Note that the string does not need to match the
 165     entire format, only some part.  Whitespace and other
 166     special characters can be escaped using C octal character
 167     escape ``\ooo`` notation, e.g. the space character is ``\040``.
 168     Alternatively, the string can be enclosed in double quote
 169     characters (``"``) or single quote characters (``'``).
 170     Examples::
 171
 172         format svcrdma:         // many of the NFS/RDMA server pr_debugs
 173         format readahead        // some pr_debugs in the readahead cache
 174         format nfsd:\040SETATTR // one way to match a format with whitespace
 175         format "nfsd: SETATTR"  // a neater way to match a format with whitespace
 176         format 'nfsd: SETATTR'  // yet another way to match a format with whitespace
 177
 178 class
 179     The given class_name is validated against each module, which may
 180     have declared a list of known class_names.  If the class_name is
 181     found for a module, callsite & class matching and adjustment
 182     proceeds.  Examples::
 183
 184         class DRM_UT_KMS        # a DRM.debug category
 185         class JUNK              # silent non-match
 186         // class TLD_*          # NOTICE: no wildcard in class names
 187
 188 line
 189     The given line number or range of line numbers is compared
 190     against the line number of each ``pr_debug()`` callsite.  A single
 191     line number matches the callsite line number exactly.  A
 192     range of line numbers matches any callsite between the first
 193     and last line number inclusive.  An empty first number means
 194     the first line in the file, an empty last line number means the
 195     last line number in the file.  Examples::
 196
 197         line 1603           // exactly line 1603
 198         line 1600-1605      // the six lines from line 1600 to line 1605
 199         line -1605          // the 1605 lines from line 1 to line 1605
 200         line 1600-          // all lines from line 1600 to the end of the file
 201
 202 The flags specification comprises a change operation followed
 203 by one or more flag characters.  The change operation is one
 204 of the characters::
 205
 206   -    remove the given flags
 207   +    add the given flags
 208   =    set the flags to the given flags
 209
 210 The flags are::
 211
 212   p    enables the pr_debug() callsite.
 213   _    enables no flags.
 214
 215   Decorator flags add to the message-prefix, in order:
 216   t    Include thread ID, or <intr>
 217   m    Include module name
 218   f    Include the function name
 219   s    Include the source file name
 220   l    Include line number
 221
 222 For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only
 223 the ``p`` flag has meaning, other flags are ignored.
 224
 225 Note the regexp ``^[-+=][fslmpt_]+$`` matches a flags specification.
 226 To clear all flags at once, use ``=_`` or ``-fslmpt``.
 227
 228
 229 Debug messages during Boot Process
 230 ==================================
 231
 232 To activate debug messages for core code and built-in modules during
 233 the boot process, even before userspace and debugfs exists, use
 234 ``dyndbg="QUERY"`` or ``module.dyndbg="QUERY"``.  QUERY follows
 235 the syntax described above, but must not exceed 1023 characters.  Your
 236 bootloader may impose lower limits.
 237
 238 These ``dyndbg`` params are processed just after the ddebug tables are
 239 processed, as part of the early_initcall.  Thus you can enable debug
 240 messages in all code run after this early_initcall via this boot
 241 parameter.
 242
 243 On an x86 system for example ACPI enablement is a subsys_initcall and::
 244
 245    dyndbg="file ec.c +p"
 246
 247 will show early Embedded Controller transactions during ACPI setup if
 248 your machine (typically a laptop) has an Embedded Controller.
 249 PCI (or other devices) initialization also is a hot candidate for using
 250 this boot parameter for debugging purposes.
 251
 252 If ``foo`` module is not built-in, ``foo.dyndbg`` will still be processed at
 253 boot time, without effect, but will be reprocessed when module is
 254 loaded later. Bare ``dyndbg=`` is only processed at boot.
 255
 256
 257 Debug Messages at Module Initialization Time
 258 ============================================
 259
 260 When ``modprobe foo`` is called, modprobe scans ``/proc/cmdline`` for
 261 ``foo.params``, strips ``foo.``, and passes them to the kernel along with
 262 params given in modprobe args or ``/etc/modprob.d/*.conf`` files,
 263 in the following order:
 264
 265 1. parameters given via ``/etc/modprobe.d/*.conf``::
 266
 267         options foo dyndbg=+pt
 268         options foo dyndbg # defaults to +p
 269
 270 2. ``foo.dyndbg`` as given in boot args, ``foo.`` is stripped and passed::
 271
 272         foo.dyndbg=" func bar +p; func buz +mp"
 273
 274 3. args to modprobe::
 275
 276         modprobe foo dyndbg==pmf # override previous settings
 277
 278 These ``dyndbg`` queries are applied in order, with last having final say.
 279 This allows boot args to override or modify those from ``/etc/modprobe.d``
 280 (sensible, since 1 is system wide, 2 is kernel or boot specific), and
 281 modprobe args to override both.
 282
 283 In the ``foo.dyndbg="QUERY"`` form, the query must exclude ``module foo``.
 284 ``foo`` is extracted from the param-name, and applied to each query in
 285 ``QUERY``, and only 1 match-spec of each type is allowed.
 286
 287 The ``dyndbg`` option is a "fake" module parameter, which means:
 288
 289 - modules do not need to define it explicitly
 290 - every module gets it tacitly, whether they use pr_debug or not
 291 - it doesn't appear in ``/sys/module/$module/parameters/``
 292   To see it, grep the control file, or inspect ``/proc/cmdline.``
 293
 294 For ``CONFIG_DYNAMIC_DEBUG`` kernels, any settings given at boot-time (or
 295 enabled by ``-DDEBUG`` flag during compilation) can be disabled later via
 296 the debugfs interface if the debug messages are no longer needed::
 297
 298    echo "module module_name -p" > /proc/dynamic_debug/control
 299
 300 Examples
 301 ========
 302
 303 ::
 304
 305   // enable the message at line 1603 of file svcsock.c
 306   :#> ddcmd 'file svcsock.c line 1603 +p'
 307
 308   // enable all the messages in file svcsock.c
 309   :#> ddcmd 'file svcsock.c +p'
 310
 311   // enable all the messages in the NFS server module
 312   :#> ddcmd 'module nfsd +p'
 313
 314   // enable all 12 messages in the function svc_process()
 315   :#> ddcmd 'func svc_process +p'
 316
 317   // disable all 12 messages in the function svc_process()
 318   :#> ddcmd 'func svc_process -p'
 319
 320   // enable messages for NFS calls READ, READLINK, READDIR and READDIR+.
 321   :#> ddcmd 'format "nfsd: READ" +p'
 322
 323   // enable messages in files of which the paths include string "usb"
 324   :#> ddcmd 'file *usb* +p' > /proc/dynamic_debug/control
 325
 326   // enable all messages
 327   :#> ddcmd '+p' > /proc/dynamic_debug/control
 328
 329   // add module, function to all enabled messages
 330   :#> ddcmd '+mf' > /proc/dynamic_debug/control
 331
 332   // boot-args example, with newlines and comments for readability
 333   Kernel command line: ...
 334     // see what's going on in dyndbg=value processing
 335     dynamic_debug.verbose=3
 336     // enable pr_debugs in the btrfs module (can be builtin or loadable)
 337     btrfs.dyndbg="+p"
 338     // enable pr_debugs in all files under init/
 339     // and the function parse_one, #cmt is stripped
 340     dyndbg="file init/* +p #cmt ; func parse_one +p"
 341     // enable pr_debugs in 2 functions in a module loaded later
 342     pc87360.dyndbg="func pc87360_init_device +p; func pc87360_find +p"
 343
 344 Kernel Configuration
 345 ====================
 346
 347 Dynamic Debug is enabled via kernel config items::
 348
 349   CONFIG_DYNAMIC_DEBUG=y        # build catalog, enables CORE
 350   CONFIG_DYNAMIC_DEBUG_CORE=y   # enable mechanics only, skip catalog
 351
 352 If you do not want to enable dynamic debug globally (i.e. in some embedded
 353 system), you may set ``CONFIG_DYNAMIC_DEBUG_CORE`` as basic support of dynamic
 354 debug and add ``ccflags := -DDYNAMIC_DEBUG_MODULE`` into the Makefile of any
 355 modules which you'd like to dynamically debug later.
 356
 357
 358 Kernel *prdbg* API
 359 ==================
 360
 361 The following functions are cataloged and controllable when dynamic
 362 debug is enabled::
 363
 364   pr_debug()
 365   dev_dbg()
 366   print_hex_dump_debug()
 367   print_hex_dump_bytes()
 368
 369 Otherwise, they are off by default; ``ccflags += -DDEBUG`` or
 370 ``#define DEBUG`` in a source file will enable them appropriately.
 371
 372 If ``CONFIG_DYNAMIC_DEBUG`` is not set, ``print_hex_dump_debug()`` is
 373 just a shortcut for ``print_hex_dump(KERN_DEBUG)``.
 374
 375 For ``print_hex_dump_debug()``/``print_hex_dump_bytes()``, format string is
 376 its ``prefix_str`` argument, if it is constant string; or ``hexdump``
 377 in case ``prefix_str`` is built dynamically.