boottime-trace.rst 10 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301
  1. .. SPDX-License-Identifier: GPL-2.0
  2. =================
  3. Boot-time tracing
  4. =================
  5. :Author: Masami Hiramatsu <[email protected]>
  6. Overview
  7. ========
  8. Boot-time tracing allows users to trace boot-time process including
  9. device initialization with full features of ftrace including per-event
  10. filter and actions, histograms, kprobe-events and synthetic-events,
  11. and trace instances.
  12. Since kernel command line is not enough to control these complex features,
  13. this uses bootconfig file to describe tracing feature programming.
  14. Options in the Boot Config
  15. ==========================
  16. Here is the list of available options list for boot time tracing in
  17. boot config file [1]_. All options are under "ftrace." or "kernel."
  18. prefix. See kernel parameters for the options which starts
  19. with "kernel." prefix [2]_.
  20. .. [1] See :ref:`Documentation/admin-guide/bootconfig.rst <bootconfig>`
  21. .. [2] See :ref:`Documentation/admin-guide/kernel-parameters.rst <kernelparameters>`
  22. Ftrace Global Options
  23. ---------------------
  24. Ftrace global options have "kernel." prefix in boot config, which means
  25. these options are passed as a part of kernel legacy command line.
  26. kernel.tp_printk
  27. Output trace-event data on printk buffer too.
  28. kernel.dump_on_oops [= MODE]
  29. Dump ftrace on Oops. If MODE = 1 or omitted, dump trace buffer
  30. on all CPUs. If MODE = 2, dump a buffer on a CPU which kicks Oops.
  31. kernel.traceoff_on_warning
  32. Stop tracing if WARN_ON() occurs.
  33. kernel.fgraph_max_depth = MAX_DEPTH
  34. Set MAX_DEPTH to maximum depth of fgraph tracer.
  35. kernel.fgraph_filters = FILTER[, FILTER2...]
  36. Add fgraph tracing function filters.
  37. kernel.fgraph_notraces = FILTER[, FILTER2...]
  38. Add fgraph non-tracing function filters.
  39. Ftrace Per-instance Options
  40. ---------------------------
  41. These options can be used for each instance including global ftrace node.
  42. ftrace.[instance.INSTANCE.]options = OPT1[, OPT2[...]]
  43. Enable given ftrace options.
  44. ftrace.[instance.INSTANCE.]tracing_on = 0|1
  45. Enable/Disable tracing on this instance when starting boot-time tracing.
  46. (you can enable it by the "traceon" event trigger action)
  47. ftrace.[instance.INSTANCE.]trace_clock = CLOCK
  48. Set given CLOCK to ftrace's trace_clock.
  49. ftrace.[instance.INSTANCE.]buffer_size = SIZE
  50. Configure ftrace buffer size to SIZE. You can use "KB" or "MB"
  51. for that SIZE.
  52. ftrace.[instance.INSTANCE.]alloc_snapshot
  53. Allocate snapshot buffer.
  54. ftrace.[instance.INSTANCE.]cpumask = CPUMASK
  55. Set CPUMASK as trace cpu-mask.
  56. ftrace.[instance.INSTANCE.]events = EVENT[, EVENT2[...]]
  57. Enable given events on boot. You can use a wild card in EVENT.
  58. ftrace.[instance.INSTANCE.]tracer = TRACER
  59. Set TRACER to current tracer on boot. (e.g. function)
  60. ftrace.[instance.INSTANCE.]ftrace.filters
  61. This will take an array of tracing function filter rules.
  62. ftrace.[instance.INSTANCE.]ftrace.notraces
  63. This will take an array of NON-tracing function filter rules.
  64. Ftrace Per-Event Options
  65. ------------------------
  66. These options are setting per-event options.
  67. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.enable
  68. Enable GROUP:EVENT tracing.
  69. ftrace.[instance.INSTANCE.]event.GROUP.enable
  70. Enable all event tracing within GROUP.
  71. ftrace.[instance.INSTANCE.]event.enable
  72. Enable all event tracing.
  73. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.filter = FILTER
  74. Set FILTER rule to the GROUP:EVENT.
  75. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.actions = ACTION[, ACTION2[...]]
  76. Set ACTIONs to the GROUP:EVENT.
  77. ftrace.[instance.INSTANCE.]event.kprobes.EVENT.probes = PROBE[, PROBE2[...]]
  78. Defines new kprobe event based on PROBEs. It is able to define
  79. multiple probes on one event, but those must have same type of
  80. arguments. This option is available only for the event which
  81. group name is "kprobes".
  82. ftrace.[instance.INSTANCE.]event.synthetic.EVENT.fields = FIELD[, FIELD2[...]]
  83. Defines new synthetic event with FIELDs. Each field should be
  84. "type varname".
  85. Note that kprobe and synthetic event definitions can be written under
  86. instance node, but those are also visible from other instances. So please
  87. take care for event name conflict.
  88. Ftrace Histogram Options
  89. ------------------------
  90. Since it is too long to write a histogram action as a string for per-event
  91. action option, there are tree-style options under per-event 'hist' subkey
  92. for the histogram actions. For the detail of the each parameter,
  93. please read the event histogram document (Documentation/trace/histogram.rst)
  94. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]keys = KEY1[, KEY2[...]]
  95. Set histogram key parameters. (Mandatory)
  96. The 'N' is a digit string for the multiple histogram. You can omit it
  97. if there is one histogram on the event.
  98. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]values = VAL1[, VAL2[...]]
  99. Set histogram value parameters.
  100. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]sort = SORT1[, SORT2[...]]
  101. Set histogram sort parameter options.
  102. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]size = NR_ENTRIES
  103. Set histogram size (number of entries).
  104. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]name = NAME
  105. Set histogram name.
  106. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]var.VARIABLE = EXPR
  107. Define a new VARIABLE by EXPR expression.
  108. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]<pause|continue|clear>
  109. Set histogram control parameter. You can set one of them.
  110. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]onmatch.[M.]event = GROUP.EVENT
  111. Set histogram 'onmatch' handler matching event parameter.
  112. The 'M' is a digit string for the multiple 'onmatch' handler. You can omit it
  113. if there is one 'onmatch' handler on this histogram.
  114. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]onmatch.[M.]trace = EVENT[, ARG1[...]]
  115. Set histogram 'trace' action for 'onmatch'.
  116. EVENT must be a synthetic event name, and ARG1... are parameters
  117. for that event. Mandatory if 'onmatch.event' option is set.
  118. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]onmax.[M.]var = VAR
  119. Set histogram 'onmax' handler variable parameter.
  120. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]onchange.[M.]var = VAR
  121. Set histogram 'onchange' handler variable parameter.
  122. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]<onmax|onchange>.[M.]save = ARG1[, ARG2[...]]
  123. Set histogram 'save' action parameters for 'onmax' or 'onchange' handler.
  124. This option or below 'snapshot' option is mandatory if 'onmax.var' or
  125. 'onchange.var' option is set.
  126. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]<onmax|onchange>.[M.]snapshot
  127. Set histogram 'snapshot' action for 'onmax' or 'onchange' handler.
  128. This option or above 'save' option is mandatory if 'onmax.var' or
  129. 'onchange.var' option is set.
  130. ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.filter = FILTER_EXPR
  131. Set histogram filter expression. You don't need 'if' in the FILTER_EXPR.
  132. Note that this 'hist' option can conflict with the per-event 'actions'
  133. option if the 'actions' option has a histogram action.
  134. When to Start
  135. =============
  136. All boot-time tracing options starting with ``ftrace`` will be enabled at the
  137. end of core_initcall. This means you can trace the events from postcore_initcall.
  138. Most of the subsystems and architecture dependent drivers will be initialized
  139. after that (arch_initcall or subsys_initcall). Thus, you can trace those with
  140. boot-time tracing.
  141. If you want to trace events before core_initcall, you can use the options
  142. starting with ``kernel``. Some of them will be enabled eariler than the initcall
  143. processing (for example,. ``kernel.ftrace=function`` and ``kernel.trace_event``
  144. will start before the initcall.)
  145. Examples
  146. ========
  147. For example, to add filter and actions for each event, define kprobe
  148. events, and synthetic events with histogram, write a boot config like
  149. below::
  150. ftrace.event {
  151. task.task_newtask {
  152. filter = "pid < 128"
  153. enable
  154. }
  155. kprobes.vfs_read {
  156. probes = "vfs_read $arg1 $arg2"
  157. filter = "common_pid < 200"
  158. enable
  159. }
  160. synthetic.initcall_latency {
  161. fields = "unsigned long func", "u64 lat"
  162. hist {
  163. keys = func.sym, lat
  164. values = lat
  165. sort = lat
  166. }
  167. }
  168. initcall.initcall_start.hist {
  169. keys = func
  170. var.ts0 = common_timestamp.usecs
  171. }
  172. initcall.initcall_finish.hist {
  173. keys = func
  174. var.lat = common_timestamp.usecs - $ts0
  175. onmatch {
  176. event = initcall.initcall_start
  177. trace = initcall_latency, func, $lat
  178. }
  179. }
  180. }
  181. Also, boot-time tracing supports "instance" node, which allows us to run
  182. several tracers for different purpose at once. For example, one tracer
  183. is for tracing functions starting with "user\_", and others tracing
  184. "kernel\_" functions, you can write boot config as below::
  185. ftrace.instance {
  186. foo {
  187. tracer = "function"
  188. ftrace.filters = "user_*"
  189. }
  190. bar {
  191. tracer = "function"
  192. ftrace.filters = "kernel_*"
  193. }
  194. }
  195. The instance node also accepts event nodes so that each instance
  196. can customize its event tracing.
  197. With the trigger action and kprobes, you can trace function-graph while
  198. a function is called. For example, this will trace all function calls in
  199. the pci_proc_init()::
  200. ftrace {
  201. tracing_on = 0
  202. tracer = function_graph
  203. event.kprobes {
  204. start_event {
  205. probes = "pci_proc_init"
  206. actions = "traceon"
  207. }
  208. end_event {
  209. probes = "pci_proc_init%return"
  210. actions = "traceoff"
  211. }
  212. }
  213. }
  214. This boot-time tracing also supports ftrace kernel parameters via boot
  215. config.
  216. For example, following kernel parameters::
  217. trace_options=sym-addr trace_event=initcall:* tp_printk trace_buf_size=1M ftrace=function ftrace_filter="vfs*"
  218. This can be written in boot config like below::
  219. kernel {
  220. trace_options = sym-addr
  221. trace_event = "initcall:*"
  222. tp_printk
  223. trace_buf_size = 1M
  224. ftrace = function
  225. ftrace_filter = "vfs*"
  226. }
  227. Note that parameters start with "kernel" prefix instead of "ftrace".