File: funcslower

package info (click to toggle)
perf-tools-unstable 1.0.1~20200130%2Bgit49b8cdf-1
  • links: PTS, VCS
  • area: main
  • in suites: bookworm, bullseye, sid, trixie
  • size: 928 kB
  • sloc: sh: 2,528; perl: 278; makefile: 20
file content (248 lines) | stat: -rwxr-xr-x 7,579 bytes parent folder | download | duplicates (2)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
#!/bin/bash
#
# funcslower - trace kernel functions slower than a threshold (microseconds).
#              Uses Linux ftrace.
#
# This uses the Linux ftrace function graph profiler to time kernel functions
# and filter them based on a latency threshold. This is a proof of concept using
# Linux ftrace capabilities on older kernels.
#
# USAGE: funcslower [-aChHPt] [-p PID] [-d secs] funcstring latency_us
#
# Run "funcslower -h" for full usage.
#
# REQUIREMENTS: FTRACE function graph, which you may already have available
# and enabled in recent kernels. And awk.
#
# The output format is the same as the ftrace function graph trace format,
# described in the kernel source under Documentation/trace/ftrace.txt.
# Note that the output may be shuffled when different CPU buffers are read;
# check the CPU column for changes, or include timestamps (-t) and post sort.
#
# WARNING: This uses dynamic tracing of kernel functions, and could cause
# kernel panics or freezes. Test, and know what you are doing, before use.
#
# OVERHEADS: Timing and filtering is performed in-kernel context, costing
# lower overheads than post-processing in user space. If you trace frequent
# events (eg, pick a common function and a low threshold), you might want to
# try the "-d secs" option, which buffers events in-kernel instead of printing
# them live.
#
# From perf-tools: https://github.com/brendangregg/perf-tools
#
# COPYRIGHT: Copyright (c) 2014 Brendan Gregg.
#
#  This program is free software; you can redistribute it and/or
#  modify it under the terms of the GNU General Public License
#  as published by the Free Software Foundation; either version 2
#  of the License, or (at your option) any later version.
#
#  This program is distributed in the hope that it will be useful,
#  but WITHOUT ANY WARRANTY; without even the implied warranty of
#  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
#  GNU General Public License for more details.
#
#  You should have received a copy of the GNU General Public License
#  along with this program; if not, write to the Free Software Foundation,
#  Inc., 59 Temple Place - Suite 330, Boston, MA  02111-1307, USA.
#
#  (http://www.gnu.org/copyleft/gpl.html)
#
# 12-Jul-2014	Brendan Gregg	Created this.

### default variables
tracing=/sys/kernel/debug/tracing
flock=/var/tmp/.ftrace-lock
opt_duration=0; duration=; opt_pid=0; pid=; opt_tid=0; tid=
pidtext=; opt_headers=0; opt_proc=0; opt_time=0; opt_cpu=0
trap ':' INT QUIT TERM PIPE HUP	# sends execution to end tracing section

function usage {
	cat <<-END >&2
	USAGE: funcslower [-aChHPt] [-p PID] [-L TID] [-d secs] funcstring latency_us
	                 -a              # all info (same as -HPt)
	                 -C              # measure on-CPU time only
	                 -d seconds      # trace duration, and use buffers
	                 -h              # this usage message
	                 -H              # include column headers
	                 -p PID          # trace when this pid is on-CPU
	                 -L TID          # trace when this thread is on-CPU
	                 -P              # show process names & PIDs
	                 -t              # show timestamps
	  eg,
	       funcslower vfs_read 10000 # trace vfs_read() slower than 10 ms

	See the man page and example file for more info.
END
	exit
}

function warn {
	if ! eval "$@"; then
		echo >&2 "WARNING: command failed \"$@\""
	fi
}

function end {
	# disable tracing
	echo 2>/dev/null
	echo "Ending tracing..." 2>/dev/null
	cd $tracing

	(( opt_time )) && warn "echo nofuncgraph-abstime > trace_options"
	(( opt_proc )) && warn "echo nofuncgraph-proc > trace_options"
	(( opt_cpu )) && warn "echo sleep-time > trace_options"

	warn "echo nop > current_tracer"
	(( opt_pid )) && warn "echo > set_ftrace_pid"
	warn "echo > set_ftrace_filter"
	warn "echo > set_graph_function"
	warn "echo 0 > tracing_thresh"
	warn "echo > trace"

	(( wroteflock )) && warn "rm $flock"
}

function die {
	echo >&2 "$@"
	exit 1
}

function edie {
	# die with a quiet end()
	echo >&2 "$@"
	exec >/dev/null 2>&1
	end
	exit 1
}

### process options
while getopts aCd:hHp:L:Pt opt
do
	case $opt in
	a)	opt_headers=1; opt_proc=1; opt_time=1 ;;
	C)	opt_cpu=1; ;;
	d)	opt_duration=1; duration=$OPTARG ;;
	p)	opt_pid=1; pid=$OPTARG ;;
    L)  opt_tid=1; tid=$OPTARG ;;
	H)	opt_headers=1; ;;
	P)	opt_proc=1; ;;
	t)	opt_time=1; ;;
	h|?)	usage ;;
	esac
done
shift $(( $OPTIND - 1 ))

### option logic
(( $# < 2 )) && usage
(( opt_pid && opt_tid )) && edie "ERROR: You can use -p or -L but not both."
funcs="$1"
shift
thresh=$1
(( opt_pid )) && pidtext=" for PID $pid"
(( opt_tid )) && pidtext=" for TID $tid"
printf "Tracing \"$funcs\"$pidtext slower than $thresh us"
if (( opt_duration )); then
	echo " for $duration seconds..."
else
	echo "... Ctrl-C to end."
fi

## select awk
if (( opt_duration )); then
	[[ -x /usr/bin/mawk ]] && awk=mawk || awk=awk
else
	# workarounds for mawk/gawk fflush behavior
	if [[ -x /usr/bin/gawk ]]; then
		awk=gawk
	elif [[ -x /usr/bin/mawk ]]; then
		awk="mawk -W interactive"
	else
		awk=awk
	fi
fi

### check permissions
cd $tracing || die "ERROR: accessing tracing. Root user? Kernel has FTRACE?
    debugfs mounted? (mount -t debugfs debugfs /sys/kernel/debug)"

### ftrace lock
[[ -e $flock ]] && die "ERROR: ftrace may be in use by PID $(cat $flock) $flock"
echo $$ > $flock || die "ERROR: unable to write $flock."
wroteflock=1

### setup and commence tracing
sysctl -q kernel.ftrace_enabled=1	# doesn't set exit status
read mode < current_tracer
[[ "$mode" != "nop" ]] && edie "ERROR: ftrace active (current_tracer=$mode)"
if ! echo $thresh > tracing_thresh; then
	edie "ERROR: setting tracing_thresh to $thresh. Exiting."
fi
if (( opt_pid )); then
    echo '' > set_ftrace_pid
    # ftrace expects kernel pids, which are thread ids
    for tid in /proc/$pid/task/*; do
        if ! echo ${tid##*/} >> set_ftrace_pid; then
            edie "ERROR: setting -p $pid (PID exist?). Exiting."
        fi
    done
fi
if (( opt_tid )); then
    if ! echo $tid > set_ftrace_pid; then
        edie "ERROR: setting -L $tid (TID exist?). Exiting."
    fi
fi
if ! echo "$funcs" > set_ftrace_filter; then
	edie "ERROR: enabling \"$funcs\" filter. Function exist? Exiting."
fi
if ! echo "$funcs" > set_graph_function; then
	edie "ERROR: enabling \"$funcs\" graph. Exiting."
fi
if ! echo function_graph > current_tracer; then
	edie "ERROR: setting current_tracer to \"function_graph\". Exiting."
fi
if (( opt_cpu )); then
	if ! echo nosleep-time > trace_options; then
		edie "ERROR: setting -C (nosleep-time). Exiting."
	fi
fi
# the following must be done after setting current_tracer
if (( opt_time )); then
	if ! echo funcgraph-abstime > trace_options; then
		edie "ERROR: setting -t (funcgraph-abstime). Exiting."
	fi
fi
if (( opt_proc )); then
	if ! echo funcgraph-proc > trace_options; then
		edie "ERROR: setting -P (funcgraph-proc). Exiting."
	fi
fi

### setup output filter
cat=cat
if (( opt_proc )); then
	# remove proc change entries, since PID is included. example:
	#  ------------------------------------------
	#  0)  supervi-1699  =>  supervi-1693 
	#  ------------------------------------------
	#
	cat=$awk' "/(^ ---|^$)/ || \$3 == \"=>\" { next } { print \$0 }"'
fi

### print trace buffer
warn "echo > trace"
if (( opt_duration )); then
	sleep $duration
	if (( opt_headers )); then
		$cat trace
	else
		$cat trace | grep -v '^#'
	fi
else
	# trace_pipe lack headers, so fetch them from trace
	(( opt_headers )) && cat trace
	eval $cat trace_pipe
fi

### end tracing
end