dynamic-debug-howto.txt 9.3 KB

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