Documentation/dynamic-debug-howto.txt

   1
   2 Introduction
   3 ============
   4
   5 This document describes how to use the dynamic debug (ddebug) feature.
   6
   7 Dynamic debug is designed to allow you to dynamically enable/disable kernel
   8 code to obtain additional kernel information. Currently, if
   9 CONFIG_DYNAMIC_DEBUG is set, then all pr_debug()/dev_dbg() calls can be
  10 dynamically enabled per-callsite.
  11
  12 Dynamic debug has even more useful features:
  13
  14  * Simple query language allows turning on and off debugging statements by
  15    matching any combination of 0 or 1 of:
  16
  17    - source filename
  18    - function name
  19    - line number (including ranges of line numbers)
  20    - module name
  21    - format string
  22
  23  * Provides a debugfs control file: <debugfs>/dynamic_debug/control which can be
  24    read to display the complete list of known debug statements, to help guide you
  25
  26 Controlling dynamic debug Behaviour
  27 ===================================
  28
  29 The behaviour of pr_debug()/dev_dbg()s are controlled via writing to a
  30 control file in the 'debugfs' filesystem. Thus, you must first mount the debugfs
  31 filesystem, in order to make use of this feature. Subsequently, we refer to the
  32 control file as: <debugfs>/dynamic_debug/control. For example, if you want to
  33 enable printing from source file 'svcsock.c', line 1603 you simply do:
  34
  35 nullarbor:~ # echo 'file svcsock.c line 1603 +p' >
  36                                 <debugfs>/dynamic_debug/control
  37
  38 If you make a mistake with the syntax, the write will fail thus:
  39
  40 nullarbor:~ # echo 'file svcsock.c wtf 1 +p' >
  41                                 <debugfs>/dynamic_debug/control
  42 -bash: echo: write error: Invalid argument
  43
  44 Viewing Dynamic Debug Behaviour
  45 ===========================
  46
  47 You can view the currently configured behaviour of all the debug statements
  48 via:
  49
  50 nullarbor:~ # cat <debugfs>/dynamic_debug/control
  51 # filename:lineno [module]function flags format
  52 /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"
  53 /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:341 [svcxprt_rdma]svc_rdma_init - "\011max_inline       : %d\012"
  54 /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:340 [svcxprt_rdma]svc_rdma_init - "\011sq_depth         : %d\012"
  55 /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:338 [svcxprt_rdma]svc_rdma_init - "\011max_requests     : %d\012"
  56 ...
  57
  58
  59 You can also apply standard Unix text manipulation filters to this
  60 data, e.g.
  61
  62 nullarbor:~ # grep -i rdma <debugfs>/dynamic_debug/control  | wc -l
  63 62
  64
  65 nullarbor:~ # grep -i tcp <debugfs>/dynamic_debug/control | wc -l
  66 42
  67
  68 Note in particular that the third column shows the enabled behaviour
  69 flags for each debug statement callsite (see below for definitions of the
  70 flags).  The default value, no extra behaviour enabled, is "-".  So
  71 you can view all the debug statement callsites with any non-default flags:
  72
  73 nullarbor:~ # awk '$3 != "-"' <debugfs>/dynamic_debug/control
  74 # filename:lineno [module]function flags format
  75 /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"
  76
  77
  78 Command Language Reference
  79 ==========================
  80
  81 At the lexical level, a command comprises a sequence of words separated
  82 by spaces or tabs.  So these are all equivalent:
  83
  84 nullarbor:~ # echo -c 'file svcsock.c line 1603 +p' >
  85                                 <debugfs>/dynamic_debug/control
  86 nullarbor:~ # echo -c '  file   svcsock.c     line  1603 +p  ' >
  87                                 <debugfs>/dynamic_debug/control
  88 nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
  89                                 <debugfs>/dynamic_debug/control
  90
  91 Command submissions are bounded by a write() system call.
  92 Multiple commands can be written together, separated by ';' or '\n'.
  93
  94   ~# echo "func pnpacpi_get_resources +p; func pnp_assign_mem +p" \
  95      > <debugfs>/dynamic_debug/control
  96
  97 If your query set is big, you can batch them too:
  98
  99   ~# cat query-batch-file > <debugfs>/dynamic_debug/control
 100
 101 At the syntactical level, a command comprises a sequence of match
 102 specifications, followed by a flags change specification.
 103
 104 command ::= match-spec* flags-spec
 105
 106 The match-spec's are used to choose a subset of the known dprintk()
 107 callsites to which to apply the flags-spec.  Think of them as a query
 108 with implicit ANDs between each pair.  Note that an empty list of
 109 match-specs is possible, but is not very useful because it will not
 110 match any debug statement callsites.
 111
 112 A match specification comprises a keyword, which controls the attribute
 113 of the callsite to be compared, and a value to compare against.  Possible
 114 keywords are:
 115
 116 match-spec ::= 'func' string |
 117                'file' string |
 118                'module' string |
 119                'format' string |
 120                'line' line-range
 121
 122 line-range ::= lineno |
 123                '-'lineno |
 124                lineno'-' |
 125                lineno'-'lineno
 126 // Note: line-range cannot contain space, e.g.
 127 // "1-30" is valid range but "1 - 30" is not.
 128
 129 lineno ::= unsigned-int
 130
 131 The meanings of each keyword are:
 132
 133 func
 134     The given string is compared against the function name
 135     of each callsite.  Example:
 136
 137     func svc_tcp_accept
 138
 139 file
 140     The given string is compared against either the full pathname, the
 141     src-root relative pathname, or the basename of the source file of
 142     each callsite.  Examples:
 143
 144     file svcsock.c
 145     file kernel/freezer.c
 146     file /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svcsock.c
 147
 148 module
 149     The given string is compared against the module name
 150     of each callsite.  The module name is the string as
 151     seen in "lsmod", i.e. without the directory or the .ko
 152     suffix and with '-' changed to '_'.  Examples:
 153
 154     module sunrpc
 155     module nfsd
 156
 157 format
 158     The given string is searched for in the dynamic debug format
 159     string.  Note that the string does not need to match the
 160     entire format, only some part.  Whitespace and other
 161     special characters can be escaped using C octal character
 162     escape \ooo notation, e.g. the space character is \040.
 163     Alternatively, the string can be enclosed in double quote
 164     characters (") or single quote characters (').
 165     Examples:
 166
 167     format svcrdma:         // many of the NFS/RDMA server dprintks
 168     format readahead        // some dprintks in the readahead cache
 169     format nfsd:\040SETATTR // one way to match a format with whitespace
 170     format "nfsd: SETATTR"  // a neater way to match a format with whitespace
 171     format 'nfsd: SETATTR'  // yet another way to match a format with whitespace
 172
 173 line
 174     The given line number or range of line numbers is compared
 175     against the line number of each dprintk() callsite.  A single
 176     line number matches the callsite line number exactly.  A
 177     range of line numbers matches any callsite between the first
 178     and last line number inclusive.  An empty first number means
 179     the first line in the file, an empty line number means the
 180     last number in the file.  Examples:
 181
 182     line 1603       // exactly line 1603
 183     line 1600-1605  // the six lines from line 1600 to line 1605
 184     line -1605      // the 1605 lines from line 1 to line 1605
 185     line 1600-      // all lines from line 1600 to the end of the file
 186
 187 The flags specification comprises a change operation followed
 188 by one or more flag characters.  The change operation is one
 189 of the characters:
 190
 191 -
 192     remove the given flags
 193
 194 +
 195     add the given flags
 196
 197 =
 198     set the flags to the given flags
 199
 200 The flags are:
 201
 202 f
 203     Include the function name in the printed message
 204 l
 205     Include line number in the printed message
 206 m
 207     Include module name in the printed message
 208 p
 209     Causes a printk() message to be emitted to dmesg
 210 t
 211     Include thread ID in messages not generated from interrupt context
 212
 213 Note the regexp ^[-+=][flmpt]+$ matches a flags specification.
 214 Note also that there is no convenient syntax to remove all
 215 the flags at once, you need to use "-flmpt".
 216
 217
 218 Debug messages during boot process
 219 ==================================
 220
 221 To be able to activate debug messages during the boot process,
 222 even before userspace and debugfs exists, use the boot parameter:
 223 ddebug_query="QUERY"
 224
 225 QUERY follows the syntax described above, but must not exceed 1023
 226 characters. The enablement of debug messages is done as an arch_initcall.
 227 Thus you can enable debug messages in all code processed after this
 228 arch_initcall via this boot parameter.
 229 On an x86 system for example ACPI enablement is a subsys_initcall and
 230 ddebug_query="file ec.c +p"
 231 will show early Embedded Controller transactions during ACPI setup if
 232 your machine (typically a laptop) has an Embedded Controller.
 233 PCI (or other devices) initialization also is a hot candidate for using
 234 this boot parameter for debugging purposes.
 235
 236
 237 Examples
 238 ========
 239
 240 // enable the message at line 1603 of file svcsock.c
 241 nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
 242                                 <debugfs>/dynamic_debug/control
 243
 244 // enable all the messages in file svcsock.c
 245 nullarbor:~ # echo -n 'file svcsock.c +p' >
 246                                 <debugfs>/dynamic_debug/control
 247
 248 // enable all the messages in the NFS server module
 249 nullarbor:~ # echo -n 'module nfsd +p' >
 250                                 <debugfs>/dynamic_debug/control
 251
 252 // enable all 12 messages in the function svc_process()
 253 nullarbor:~ # echo -n 'func svc_process +p' >
 254                                 <debugfs>/dynamic_debug/control
 255
 256 // disable all 12 messages in the function svc_process()
 257 nullarbor:~ # echo -n 'func svc_process -p' >
 258                                 <debugfs>/dynamic_debug/control
 259
 260 // enable messages for NFS calls READ, READLINK, READDIR and READDIR+.
 261 nullarbor:~ # echo -n 'format "nfsd: READ" +p' >
 262                                 <debugfs>/dynamic_debug/control