dynamic-debug-howto.txt 9.5 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269
  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:
  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 whitespace characters. Note that newlines are treated as word
  59. separators and do *not* end a command or allow multiple commands to
  60. be done together. So these are all equivalent:
  61. nullarbor:~ # echo -c 'file svcsock.c line 1603 +p' >
  62. <debugfs>/dynamic_debug/control
  63. nullarbor:~ # echo -c ' file svcsock.c line 1603 +p ' >
  64. <debugfs>/dynamic_debug/control
  65. nullarbor:~ # echo -c 'file svcsock.c\nline 1603 +p' >
  66. <debugfs>/dynamic_debug/control
  67. nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
  68. <debugfs>/dynamic_debug/control
  69. Commands are bounded by a write() system call. If you want to do
  70. multiple commands you need to do a separate "echo" for each, like:
  71. nullarbor:~ # echo 'file svcsock.c line 1603 +p' > /proc/dprintk ;\
  72. > echo 'file svcsock.c line 1563 +p' > /proc/dprintk
  73. or even like:
  74. nullarbor:~ # (
  75. > echo 'file svcsock.c line 1603 +p' ;\
  76. > echo 'file svcsock.c line 1563 +p' ;\
  77. > ) > /proc/dprintk
  78. At the syntactical level, a command comprises a sequence of match
  79. specifications, followed by a flags change specification.
  80. command ::= match-spec* flags-spec
  81. The match-spec's are used to choose a subset of the known dprintk()
  82. callsites to which to apply the flags-spec. Think of them as a query
  83. with implicit ANDs between each pair. Note that an empty list of
  84. match-specs is possible, but is not very useful because it will not
  85. match any debug statement callsites.
  86. A match specification comprises a keyword, which controls the attribute
  87. of the callsite to be compared, and a value to compare against. Possible
  88. keywords are:
  89. match-spec ::= 'func' string |
  90. 'file' string |
  91. 'module' string |
  92. 'format' string |
  93. 'line' line-range
  94. line-range ::= lineno |
  95. '-'lineno |
  96. lineno'-' |
  97. lineno'-'lineno
  98. // Note: line-range cannot contain space, e.g.
  99. // "1-30" is valid range but "1 - 30" is not.
  100. lineno ::= unsigned-int
  101. The meanings of each keyword are:
  102. func
  103. The given string is compared against the function name
  104. of each callsite. Example:
  105. func svc_tcp_accept
  106. file
  107. The given string is compared against either the full
  108. pathname or the basename of the source file of each
  109. callsite. Examples:
  110. file svcsock.c
  111. file /usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svcsock.c
  112. module
  113. The given string is compared against the module name
  114. of each callsite. The module name is the string as
  115. seen in "lsmod", i.e. without the directory or the .ko
  116. suffix and with '-' changed to '_'. Examples:
  117. module sunrpc
  118. module nfsd
  119. format
  120. The given string is searched for in the dynamic debug format
  121. string. Note that the string does not need to match the
  122. entire format, only some part. Whitespace and other
  123. special characters can be escaped using C octal character
  124. escape \ooo notation, e.g. the space character is \040.
  125. Alternatively, the string can be enclosed in double quote
  126. characters (") or single quote characters (').
  127. Examples:
  128. format svcrdma: // many of the NFS/RDMA server dprintks
  129. format readahead // some dprintks in the readahead cache
  130. format nfsd:\040SETATTR // one way to match a format with whitespace
  131. format "nfsd: SETATTR" // a neater way to match a format with whitespace
  132. format 'nfsd: SETATTR' // yet another way to match a format with whitespace
  133. line
  134. The given line number or range of line numbers is compared
  135. against the line number of each dprintk() callsite. A single
  136. line number matches the callsite line number exactly. A
  137. range of line numbers matches any callsite between the first
  138. and last line number inclusive. An empty first number means
  139. the first line in the file, an empty line number means the
  140. last number in the file. Examples:
  141. line 1603 // exactly line 1603
  142. line 1600-1605 // the six lines from line 1600 to line 1605
  143. line -1605 // the 1605 lines from line 1 to line 1605
  144. line 1600- // all lines from line 1600 to the end of the file
  145. The flags specification comprises a change operation followed
  146. by one or more flag characters. The change operation is one
  147. of the characters:
  148. -
  149. remove the given flags
  150. +
  151. add the given flags
  152. =
  153. set the flags to the given flags
  154. The flags are:
  155. f
  156. Include the function name in the printed message
  157. l
  158. Include line number in the printed message
  159. m
  160. Include module name in the printed message
  161. p
  162. Causes a printk() message to be emitted to dmesg
  163. t
  164. Include thread ID in messages not generated from interrupt context
  165. Note the regexp ^[-+=][flmpt]+$ matches a flags specification.
  166. Note also that there is no convenient syntax to remove all
  167. the flags at once, you need to use "-flmpt".
  168. Debug messages during boot process
  169. ==================================
  170. To be able to activate debug messages during the boot process,
  171. even before userspace and debugfs exists, use the boot parameter:
  172. ddebug_query="QUERY"
  173. QUERY follows the syntax described above, but must not exceed 1023
  174. characters. The enablement of debug messages is done as an arch_initcall.
  175. Thus you can enable debug messages in all code processed after this
  176. arch_initcall via this boot parameter.
  177. On an x86 system for example ACPI enablement is a subsys_initcall and
  178. ddebug_query="file ec.c +p"
  179. will show early Embedded Controller transactions during ACPI setup if
  180. your machine (typically a laptop) has an Embedded Controller.
  181. PCI (or other devices) initialization also is a hot candidate for using
  182. this boot parameter for debugging purposes.
  183. Examples
  184. ========
  185. // enable the message at line 1603 of file svcsock.c
  186. nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
  187. <debugfs>/dynamic_debug/control
  188. // enable all the messages in file svcsock.c
  189. nullarbor:~ # echo -n 'file svcsock.c +p' >
  190. <debugfs>/dynamic_debug/control
  191. // enable all the messages in the NFS server module
  192. nullarbor:~ # echo -n 'module nfsd +p' >
  193. <debugfs>/dynamic_debug/control
  194. // enable all 12 messages in the function svc_process()
  195. nullarbor:~ # echo -n 'func svc_process +p' >
  196. <debugfs>/dynamic_debug/control
  197. // disable all 12 messages in the function svc_process()
  198. nullarbor:~ # echo -n 'func svc_process -p' >
  199. <debugfs>/dynamic_debug/control
  200. // enable messages for NFS calls READ, READLINK, READDIR and READDIR+.
  201. nullarbor:~ # echo -n 'format "nfsd: READ" +p' >
  202. <debugfs>/dynamic_debug/control