blob: d9c3e682312cf1c5f889b99bbf214700c4ca3e7a [file] [log] [blame]
Anton Arapovdecc6bf2013-04-03 18:00:39 +02001 Uprobe-tracer: Uprobe-based Event Tracing
2 =========================================
3
4 Documentation written by Srikar Dronamraju
5
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +05306
7Overview
8--------
9Uprobe based trace events are similar to kprobe based trace events.
Srikar Dronamrajuec83db02012-05-08 16:41:26 +053010To enable this feature, build your kernel with CONFIG_UPROBE_EVENT=y.
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053011
12Similar to the kprobe-event tracer, this doesn't need to be activated via
13current_tracer. Instead of that, add probe points via
14/sys/kernel/debug/tracing/uprobe_events, and enable it via
15/sys/kernel/debug/tracing/events/uprobes/<EVENT>/enabled.
16
17However unlike kprobe-event tracer, the uprobe event interface expects the
Anton Arapovdecc6bf2013-04-03 18:00:39 +020018user to calculate the offset of the probepoint in the object.
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053019
20Synopsis of uprobe_tracer
21-------------------------
Anton Arapovdecc6bf2013-04-03 18:00:39 +020022 p[:[GRP/]EVENT] PATH:SYMBOL[+offs] [FETCHARGS] : Set a uprobe
23 r[:[GRP/]EVENT] PATH:SYMBOL[+offs] [FETCHARGS] : Set a return uprobe (uretprobe)
24 -:[GRP/]EVENT : Clear uprobe or uretprobe event
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053025
Anton Arapovdecc6bf2013-04-03 18:00:39 +020026 GRP : Group name. If omitted, "uprobes" is the default value.
27 EVENT : Event name. If omitted, the event name is generated based
28 on SYMBOL+offs.
29 PATH : Path to an executable or a library.
30 SYMBOL[+offs] : Symbol+offset where the probe is inserted.
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053031
Anton Arapovdecc6bf2013-04-03 18:00:39 +020032 FETCHARGS : Arguments. Each probe can have up to 128 args.
33 %REG : Fetch register REG
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053034
35Event Profiling
36---------------
Anton Arapovdecc6bf2013-04-03 18:00:39 +020037You can check the total number of probe hits and probe miss-hits via
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053038/sys/kernel/debug/tracing/uprobe_profile.
Anton Arapovdecc6bf2013-04-03 18:00:39 +020039The first column is event name, the second is the number of probe hits,
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053040the third is the number of probe miss-hits.
41
42Usage examples
43--------------
Anton Arapovdecc6bf2013-04-03 18:00:39 +020044 * Add a probe as a new uprobe event, write a new definition to uprobe_events
45as below: (sets a uprobe at an offset of 0x4245c0 in the executable /bin/bash)
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053046
Anton Arapovdecc6bf2013-04-03 18:00:39 +020047 echo 'p: /bin/bash:0x4245c0' > /sys/kernel/debug/tracing/uprobe_events
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053048
Anton Arapovdecc6bf2013-04-03 18:00:39 +020049 * Add a probe as a new uretprobe event:
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053050
Anton Arapovdecc6bf2013-04-03 18:00:39 +020051 echo 'r: /bin/bash:0x4245c0' > /sys/kernel/debug/tracing/uprobe_events
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053052
Anton Arapovdecc6bf2013-04-03 18:00:39 +020053 * Unset registered event:
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053054
Anton Arapovdecc6bf2013-04-03 18:00:39 +020055 echo '-:bash_0x4245c0' >> /sys/kernel/debug/tracing/uprobe_events
56
57 * Print out the events that are registered:
58
59 cat /sys/kernel/debug/tracing/uprobe_events
60
61 * Clear all events:
62
63 echo > /sys/kernel/debug/tracing/uprobe_events
64
65Following example shows how to dump the instruction pointer and %ax register
66at the probed text address. Probe zfree function in /bin/zsh:
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053067
68 # cd /sys/kernel/debug/tracing/
Anton Arapovdecc6bf2013-04-03 18:00:39 +020069 # cat /proc/`pgrep zsh`/maps | grep /bin/zsh | grep r-xp
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053070 00400000-0048a000 r-xp 00000000 08:03 130904 /bin/zsh
71 # objdump -T /bin/zsh | grep -w zfree
72 0000000000446420 g DF .text 0000000000000012 Base zfree
73
Anton Arapovdecc6bf2013-04-03 18:00:39 +020074 0x46420 is the offset of zfree in object /bin/zsh that is loaded at
75 0x00400000. Hence the command to uprobe would be:
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053076
Anton Arapovdecc6bf2013-04-03 18:00:39 +020077 # echo 'p:zfree_entry /bin/zsh:0x46420 %ip %ax' > uprobe_events
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053078
Anton Arapovdecc6bf2013-04-03 18:00:39 +020079 And the same for the uretprobe would be:
80
81 # echo 'r:zfree_exit /bin/zsh:0x46420 %ip %ax' >> uprobe_events
82
83Please note: User has to explicitly calculate the offset of the probe-point
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +053084in the object. We can see the events that are registered by looking at the
85uprobe_events file.
86
87 # cat uprobe_events
Anton Arapovdecc6bf2013-04-03 18:00:39 +020088 p:uprobes/zfree_entry /bin/zsh:0x00046420 arg1=%ip arg2=%ax
89 r:uprobes/zfree_exit /bin/zsh:0x00046420 arg1=%ip arg2=%ax
Srikar Dronamrajuec83db02012-05-08 16:41:26 +053090
Anton Arapovdecc6bf2013-04-03 18:00:39 +020091Format of events can be seen by viewing the file events/uprobes/zfree_entry/format
Srikar Dronamrajuec83db02012-05-08 16:41:26 +053092
Anton Arapovdecc6bf2013-04-03 18:00:39 +020093 # cat events/uprobes/zfree_entry/format
94 name: zfree_entry
Srikar Dronamrajuec83db02012-05-08 16:41:26 +053095 ID: 922
96 format:
Anton Arapovdecc6bf2013-04-03 18:00:39 +020097 field:unsigned short common_type; offset:0; size:2; signed:0;
98 field:unsigned char common_flags; offset:2; size:1; signed:0;
99 field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
100 field:int common_pid; offset:4; size:4; signed:1;
101 field:int common_padding; offset:8; size:4; signed:1;
Srikar Dronamrajuec83db02012-05-08 16:41:26 +0530102
Anton Arapovdecc6bf2013-04-03 18:00:39 +0200103 field:unsigned long __probe_ip; offset:12; size:4; signed:0;
104 field:u32 arg1; offset:16; size:4; signed:0;
105 field:u32 arg2; offset:20; size:4; signed:0;
Srikar Dronamrajuec83db02012-05-08 16:41:26 +0530106
107 print fmt: "(%lx) arg1=%lx arg2=%lx", REC->__probe_ip, REC->arg1, REC->arg2
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +0530108
109Right after definition, each event is disabled by default. For tracing these
110events, you need to enable it by:
111
112 # echo 1 > events/uprobes/enable
113
114Lets disable the event after sleeping for some time.
Anton Arapovdecc6bf2013-04-03 18:00:39 +0200115
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +0530116 # sleep 20
117 # echo 0 > events/uprobes/enable
118
119And you can see the traced information via /sys/kernel/debug/tracing/trace.
120
121 # cat trace
122 # tracer: nop
123 #
124 # TASK-PID CPU# TIMESTAMP FUNCTION
125 # | | | | |
Anton Arapovdecc6bf2013-04-03 18:00:39 +0200126 zsh-24842 [006] 258544.995456: zfree_entry: (0x446420) arg1=446420 arg2=79
127 zsh-24842 [007] 258545.000270: zfree_exit: (0x446540 <- 0x446420) arg1=446540 arg2=0
128 zsh-24842 [002] 258545.043929: zfree_entry: (0x446420) arg1=446420 arg2=79
129 zsh-24842 [004] 258547.046129: zfree_exit: (0x446540 <- 0x446420) arg1=446540 arg2=0
Srikar Dronamrajuf3f096c2012-04-11 16:00:43 +0530130
Anton Arapovdecc6bf2013-04-03 18:00:39 +0200131Output shows us uprobe was triggered for a pid 24842 with ip being 0x446420
132and contents of ax register being 79. And uretprobe was triggered with ip at
1330x446540 with counterpart function entry at 0x446420.