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   l    Include line number
 220
 221 For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only
 222 the ``p`` flag has meaning, other flags are ignored.
 223
 224 Note the regexp ``^[-+=][flmpt_]+$`` matches a flags specification.
 225 To clear all flags at once, use ``=_`` or ``-flmpt``.
 226
 227
 228 Debug messages during Boot Process
 229 ==================================
 230
 231 To activate debug messages for core code and built-in modules during
 232 the boot process, even before userspace and debugfs exists, use
 233 ``dyndbg="QUERY"`` or ``module.dyndbg="QUERY"``.  QUERY follows
 234 the syntax described above, but must not exceed 1023 characters.  Your
 235 bootloader may impose lower limits.
 236
 237 These ``dyndbg`` params are processed just after the ddebug tables are
 238 processed, as part of the early_initcall.  Thus you can enable debug
 239 messages in all code run after this early_initcall via this boot
 240 parameter.
 241
 242 On an x86 system for example ACPI enablement is a subsys_initcall and::
 243
 244    dyndbg="file ec.c +p"
 245
 246 will show early Embedded Controller transactions during ACPI setup if
 247 your machine (typically a laptop) has an Embedded Controller.
 248 PCI (or other devices) initialization also is a hot candidate for using
 249 this boot parameter for debugging purposes.
 250
 251 If ``foo`` module is not built-in, ``foo.dyndbg`` will still be processed at
 252 boot time, without effect, but will be reprocessed when module is
 253 loaded later. Bare ``dyndbg=`` is only processed at boot.
 254
 255
 256 Debug Messages at Module Initialization Time
 257 ============================================
 258
 259 When ``modprobe foo`` is called, modprobe scans ``/proc/cmdline`` for
 260 ``foo.params``, strips ``foo.``, and passes them to the kernel along with
 261 params given in modprobe args or ``/etc/modprob.d/*.conf`` files,
 262 in the following order:
 263
 264 1. parameters given via ``/etc/modprobe.d/*.conf``::
 265
 266         options foo dyndbg=+pt
 267         options foo dyndbg # defaults to +p
 268
 269 2. ``foo.dyndbg`` as given in boot args, ``foo.`` is stripped and passed::
 270
 271         foo.dyndbg=" func bar +p; func buz +mp"
 272
 273 3. args to modprobe::
 274
 275         modprobe foo dyndbg==pmf # override previous settings
 276
 277 These ``dyndbg`` queries are applied in order, with last having final say.
 278 This allows boot args to override or modify those from ``/etc/modprobe.d``
 279 (sensible, since 1 is system wide, 2 is kernel or boot specific), and
 280 modprobe args to override both.
 281
 282 In the ``foo.dyndbg="QUERY"`` form, the query must exclude ``module foo``.
 283 ``foo`` is extracted from the param-name, and applied to each query in
 284 ``QUERY``, and only 1 match-spec of each type is allowed.
 285
 286 The ``dyndbg`` option is a "fake" module parameter, which means:
 287
 288 - modules do not need to define it explicitly
 289 - every module gets it tacitly, whether they use pr_debug or not
 290 - it doesn't appear in ``/sys/module/$module/parameters/``
 291   To see it, grep the control file, or inspect ``/proc/cmdline.``
 292
 293 For ``CONFIG_DYNAMIC_DEBUG`` kernels, any settings given at boot-time (or
 294 enabled by ``-DDEBUG`` flag during compilation) can be disabled later via
 295 the debugfs interface if the debug messages are no longer needed::
 296
 297    echo "module module_name -p" > /proc/dynamic_debug/control
 298
 299 Examples
 300 ========
 301
 302 ::
 303
 304   // enable the message at line 1603 of file svcsock.c
 305   :#> ddcmd 'file svcsock.c line 1603 +p'
 306
 307   // enable all the messages in file svcsock.c
 308   :#> ddcmd 'file svcsock.c +p'
 309
 310   // enable all the messages in the NFS server module
 311   :#> ddcmd 'module nfsd +p'
 312
 313   // enable all 12 messages in the function svc_process()
 314   :#> ddcmd 'func svc_process +p'
 315
 316   // disable all 12 messages in the function svc_process()
 317   :#> ddcmd 'func svc_process -p'
 318
 319   // enable messages for NFS calls READ, READLINK, READDIR and READDIR+.
 320   :#> ddcmd 'format "nfsd: READ" +p'
 321
 322   // enable messages in files of which the paths include string "usb"
 323   :#> ddcmd 'file *usb* +p' > /proc/dynamic_debug/control
 324
 325   // enable all messages
 326   :#> ddcmd '+p' > /proc/dynamic_debug/control
 327
 328   // add module, function to all enabled messages
 329   :#> ddcmd '+mf' > /proc/dynamic_debug/control
 330
 331   // boot-args example, with newlines and comments for readability
 332   Kernel command line: ...
 333     // see whats going on in dyndbg=value processing
 334     dynamic_debug.verbose=3
 335     // enable pr_debugs in the btrfs module (can be builtin or loadable)
 336     btrfs.dyndbg="+p"
 337     // enable pr_debugs in all files under init/
 338     // and the function parse_one, #cmt is stripped
 339     dyndbg="file init/* +p #cmt ; func parse_one +p"
 340     // enable pr_debugs in 2 functions in a module loaded later
 341     pc87360.dyndbg="func pc87360_init_device +p; func pc87360_find +p"
 342
 343 Kernel Configuration
 344 ====================
 345
 346 Dynamic Debug is enabled via kernel config items::
 347
 348   CONFIG_DYNAMIC_DEBUG=y        # build catalog, enables CORE
 349   CONFIG_DYNAMIC_DEBUG_CORE=y   # enable mechanics only, skip catalog
 350
 351 If you do not want to enable dynamic debug globally (i.e. in some embedded
 352 system), you may set ``CONFIG_DYNAMIC_DEBUG_CORE`` as basic support of dynamic
 353 debug and add ``ccflags := -DDYNAMIC_DEBUG_MODULE`` into the Makefile of any
 354 modules which you'd like to dynamically debug later.
 355
 356
 357 Kernel *prdbg* API
 358 ==================
 359
 360 The following functions are cataloged and controllable when dynamic
 361 debug is enabled::
 362
 363   pr_debug()
 364   dev_dbg()
 365   print_hex_dump_debug()
 366   print_hex_dump_bytes()
 367
 368 Otherwise, they are off by default; ``ccflags += -DDEBUG`` or
 369 ``#define DEBUG`` in a source file will enable them appropriately.
 370
 371 If ``CONFIG_DYNAMIC_DEBUG`` is not set, ``print_hex_dump_debug()`` is
 372 just a shortcut for ``print_hex_dump(KERN_DEBUG)``.
 373
 374 For ``print_hex_dump_debug()``/``print_hex_dump_bytes()``, format string is
 375 its ``prefix_str`` argument, if it is constant string; or ``hexdump``
 376 in case ``prefix_str`` is built dynamically.