dynamic-debug-howto.rst 13 KB

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