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