0001 ==========================
0002 Kprobe-based Event Tracing
0003 ==========================
0004
0005 :Author: Masami Hiramatsu
0006
0007 Overview
0008 --------
0009 These events are similar to tracepoint based events. Instead of Tracepoint,
0010 this is based on kprobes (kprobe and kretprobe). So it can probe wherever
0011 kprobes can probe (this means, all functions except those with
0012 __kprobes/nokprobe_inline annotation and those marked NOKPROBE_SYMBOL).
0013 Unlike the Tracepoint based event, this can be added and removed
0014 dynamically, on the fly.
0015
0016 To enable this feature, build your kernel with CONFIG_KPROBE_EVENTS=y.
0017
0018 Similar to the events tracer, this doesn't need to be activated via
0019 current_tracer. Instead of that, add probe points via
0020 /sys/kernel/debug/tracing/kprobe_events, and enable it via
0021 /sys/kernel/debug/tracing/events/kprobes/<EVENT>/enable.
0022
0023 You can also use /sys/kernel/debug/tracing/dynamic_events instead of
0024 kprobe_events. That interface will provide unified access to other
0025 dynamic events too.
0026
0027 Synopsis of kprobe_events
0028 -------------------------
0029 ::
0030
0031 p[:[GRP/][EVENT]] [MOD:]SYM[+offs]|MEMADDR [FETCHARGS] : Set a probe
0032 r[MAXACTIVE][:[GRP/][EVENT]] [MOD:]SYM[+0] [FETCHARGS] : Set a return probe
0033 p[:[GRP/][EVENT]] [MOD:]SYM[+0]%return [FETCHARGS] : Set a return probe
0034 -:[GRP/][EVENT] : Clear a probe
0035
0036 GRP : Group name. If omitted, use "kprobes" for it.
0037 EVENT : Event name. If omitted, the event name is generated
0038 based on SYM+offs or MEMADDR.
0039 MOD : Module name which has given SYM.
0040 SYM[+offs] : Symbol+offset where the probe is inserted.
0041 SYM%return : Return address of the symbol
0042 MEMADDR : Address where the probe is inserted.
0043 MAXACTIVE : Maximum number of instances of the specified function that
0044 can be probed simultaneously, or 0 for the default value
0045 as defined in Documentation/trace/kprobes.rst section 1.3.1.
0046
0047 FETCHARGS : Arguments. Each probe can have up to 128 args.
0048 %REG : Fetch register REG
0049 @ADDR : Fetch memory at ADDR (ADDR should be in kernel)
0050 @SYM[+|-offs] : Fetch memory at SYM +|- offs (SYM should be a data symbol)
0051 $stackN : Fetch Nth entry of stack (N >= 0)
0052 $stack : Fetch stack address.
0053 $argN : Fetch the Nth function argument. (N >= 1) (\*1)
0054 $retval : Fetch return value.(\*2)
0055 $comm : Fetch current task comm.
0056 +|-[u]OFFS(FETCHARG) : Fetch memory at FETCHARG +|- OFFS address.(\*3)(\*4)
0057 \IMM : Store an immediate value to the argument.
0058 NAME=FETCHARG : Set NAME as the argument name of FETCHARG.
0059 FETCHARG:TYPE : Set TYPE as the type of FETCHARG. Currently, basic types
0060 (u8/u16/u32/u64/s8/s16/s32/s64), hexadecimal types
0061 (x8/x16/x32/x64), "string", "ustring" and bitfield
0062 are supported.
0063
0064 (\*1) only for the probe on function entry (offs == 0).
0065 (\*2) only for return probe.
0066 (\*3) this is useful for fetching a field of data structures.
0067 (\*4) "u" means user-space dereference. See :ref:`user_mem_access`.
0068
0069 Types
0070 -----
0071 Several types are supported for fetch-args. Kprobe tracer will access memory
0072 by given type. Prefix 's' and 'u' means those types are signed and unsigned
0073 respectively. 'x' prefix implies it is unsigned. Traced arguments are shown
0074 in decimal ('s' and 'u') or hexadecimal ('x'). Without type casting, 'x32'
0075 or 'x64' is used depends on the architecture (e.g. x86-32 uses x32, and
0076 x86-64 uses x64).
0077 These value types can be an array. To record array data, you can add '[N]'
0078 (where N is a fixed number, less than 64) to the base type.
0079 E.g. 'x16[4]' means an array of x16 (2bytes hex) with 4 elements.
0080 Note that the array can be applied to memory type fetchargs, you can not
0081 apply it to registers/stack-entries etc. (for example, '$stack1:x8[8]' is
0082 wrong, but '+8($stack):x8[8]' is OK.)
0083 String type is a special type, which fetches a "null-terminated" string from
0084 kernel space. This means it will fail and store NULL if the string container
0085 has been paged out. "ustring" type is an alternative of string for user-space.
0086 See :ref:`user_mem_access` for more info..
0087 The string array type is a bit different from other types. For other base
0088 types, <base-type>[1] is equal to <base-type> (e.g. +0(%di):x32[1] is same
0089 as +0(%di):x32.) But string[1] is not equal to string. The string type itself
0090 represents "char array", but string array type represents "char * array".
0091 So, for example, +0(%di):string[1] is equal to +0(+0(%di)):string.
0092 Bitfield is another special type, which takes 3 parameters, bit-width, bit-
0093 offset, and container-size (usually 32). The syntax is::
0094
0095 b<bit-width>@<bit-offset>/<container-size>
0096
0097 Symbol type('symbol') is an alias of u32 or u64 type (depends on BITS_PER_LONG)
0098 which shows given pointer in "symbol+offset" style.
0099 For $comm, the default type is "string"; any other type is invalid.
0100
0101 .. _user_mem_access:
0102
0103 User Memory Access
0104 ------------------
0105 Kprobe events supports user-space memory access. For that purpose, you can use
0106 either user-space dereference syntax or 'ustring' type.
0107
0108 The user-space dereference syntax allows you to access a field of a data
0109 structure in user-space. This is done by adding the "u" prefix to the
0110 dereference syntax. For example, +u4(%si) means it will read memory from the
0111 address in the register %si offset by 4, and the memory is expected to be in
0112 user-space. You can use this for strings too, e.g. +u0(%si):string will read
0113 a string from the address in the register %si that is expected to be in user-
0114 space. 'ustring' is a shortcut way of performing the same task. That is,
0115 +0(%si):ustring is equivalent to +u0(%si):string.
0116
0117 Note that kprobe-event provides the user-memory access syntax but it doesn't
0118 use it transparently. This means if you use normal dereference or string type
0119 for user memory, it might fail, and may always fail on some archs. The user
0120 has to carefully check if the target data is in kernel or user space.
0121
0122 Per-Probe Event Filtering
0123 -------------------------
0124 Per-probe event filtering feature allows you to set different filter on each
0125 probe and gives you what arguments will be shown in trace buffer. If an event
0126 name is specified right after 'p:' or 'r:' in kprobe_events, it adds an event
0127 under tracing/events/kprobes/<EVENT>, at the directory you can see 'id',
0128 'enable', 'format', 'filter' and 'trigger'.
0129
0130 enable:
0131 You can enable/disable the probe by writing 1 or 0 on it.
0132
0133 format:
0134 This shows the format of this probe event.
0135
0136 filter:
0137 You can write filtering rules of this event.
0138
0139 id:
0140 This shows the id of this probe event.
0141
0142 trigger:
0143 This allows to install trigger commands which are executed when the event is
0144 hit (for details, see Documentation/trace/events.rst, section 6).
0145
0146 Event Profiling
0147 ---------------
0148 You can check the total number of probe hits and probe miss-hits via
0149 /sys/kernel/debug/tracing/kprobe_profile.
0150 The first column is event name, the second is the number of probe hits,
0151 the third is the number of probe miss-hits.
0152
0153 Kernel Boot Parameter
0154 ---------------------
0155 You can add and enable new kprobe events when booting up the kernel by
0156 "kprobe_event=" parameter. The parameter accepts a semicolon-delimited
0157 kprobe events, which format is similar to the kprobe_events.
0158 The difference is that the probe definition parameters are comma-delimited
0159 instead of space. For example, adding myprobe event on do_sys_open like below
0160
0161 p:myprobe do_sys_open dfd=%ax filename=%dx flags=%cx mode=+4($stack)
0162
0163 should be below for kernel boot parameter (just replace spaces with comma)
0164
0165 p:myprobe,do_sys_open,dfd=%ax,filename=%dx,flags=%cx,mode=+4($stack)
0166
0167
0168 Usage examples
0169 --------------
0170 To add a probe as a new event, write a new definition to kprobe_events
0171 as below::
0172
0173 echo 'p:myprobe do_sys_open dfd=%ax filename=%dx flags=%cx mode=+4($stack)' > /sys/kernel/debug/tracing/kprobe_events
0174
0175 This sets a kprobe on the top of do_sys_open() function with recording
0176 1st to 4th arguments as "myprobe" event. Note, which register/stack entry is
0177 assigned to each function argument depends on arch-specific ABI. If you unsure
0178 the ABI, please try to use probe subcommand of perf-tools (you can find it
0179 under tools/perf/).
0180 As this example shows, users can choose more familiar names for each arguments.
0181 ::
0182
0183 echo 'r:myretprobe do_sys_open $retval' >> /sys/kernel/debug/tracing/kprobe_events
0184
0185 This sets a kretprobe on the return point of do_sys_open() function with
0186 recording return value as "myretprobe" event.
0187 You can see the format of these events via
0188 /sys/kernel/debug/tracing/events/kprobes/<EVENT>/format.
0189 ::
0190
0191 cat /sys/kernel/debug/tracing/events/kprobes/myprobe/format
0192 name: myprobe
0193 ID: 780
0194 format:
0195 field:unsigned short common_type; offset:0; size:2; signed:0;
0196 field:unsigned char common_flags; offset:2; size:1; signed:0;
0197 field:unsigned char common_preempt_count; offset:3; size:1;signed:0;
0198 field:int common_pid; offset:4; size:4; signed:1;
0199
0200 field:unsigned long __probe_ip; offset:12; size:4; signed:0;
0201 field:int __probe_nargs; offset:16; size:4; signed:1;
0202 field:unsigned long dfd; offset:20; size:4; signed:0;
0203 field:unsigned long filename; offset:24; size:4; signed:0;
0204 field:unsigned long flags; offset:28; size:4; signed:0;
0205 field:unsigned long mode; offset:32; size:4; signed:0;
0206
0207
0208 print fmt: "(%lx) dfd=%lx filename=%lx flags=%lx mode=%lx", REC->__probe_ip,
0209 REC->dfd, REC->filename, REC->flags, REC->mode
0210
0211 You can see that the event has 4 arguments as in the expressions you specified.
0212 ::
0213
0214 echo > /sys/kernel/debug/tracing/kprobe_events
0215
0216 This clears all probe points.
0217
0218 Or,
0219 ::
0220
0221 echo -:myprobe >> kprobe_events
0222
0223 This clears probe points selectively.
0224
0225 Right after definition, each event is disabled by default. For tracing these
0226 events, you need to enable it.
0227 ::
0228
0229 echo 1 > /sys/kernel/debug/tracing/events/kprobes/myprobe/enable
0230 echo 1 > /sys/kernel/debug/tracing/events/kprobes/myretprobe/enable
0231
0232 Use the following command to start tracing in an interval.
0233 ::
0234
0235 # echo 1 > tracing_on
0236 Open something...
0237 # echo 0 > tracing_on
0238
0239 And you can see the traced information via /sys/kernel/debug/tracing/trace.
0240 ::
0241
0242 cat /sys/kernel/debug/tracing/trace
0243 # tracer: nop
0244 #
0245 # TASK-PID CPU# TIMESTAMP FUNCTION
0246 # | | | | |
0247 <...>-1447 [001] 1038282.286875: myprobe: (do_sys_open+0x0/0xd6) dfd=3 filename=7fffd1ec4440 flags=8000 mode=0
0248 <...>-1447 [001] 1038282.286878: myretprobe: (sys_openat+0xc/0xe <- do_sys_open) $retval=fffffffffffffffe
0249 <...>-1447 [001] 1038282.286885: myprobe: (do_sys_open+0x0/0xd6) dfd=ffffff9c filename=40413c flags=8000 mode=1b6
0250 <...>-1447 [001] 1038282.286915: myretprobe: (sys_open+0x1b/0x1d <- do_sys_open) $retval=3
0251 <...>-1447 [001] 1038282.286969: myprobe: (do_sys_open+0x0/0xd6) dfd=ffffff9c filename=4041c6 flags=98800 mode=10
0252 <...>-1447 [001] 1038282.286976: myretprobe: (sys_open+0x1b/0x1d <- do_sys_open) $retval=3
0253
0254
0255 Each line shows when the kernel hits an event, and <- SYMBOL means kernel
0256 returns from SYMBOL(e.g. "sys_open+0x1b/0x1d <- do_sys_open" means kernel
0257 returns from do_sys_open to sys_open+0x1b).