3 # I'm sure this could be one cleaner perl script instead of a weird combination
4 # of awk and shell. This was the fastest path to feeding 'pl' for me. I'm
5 # all for improvements. Let me know. -- zab
12 echo "$1 "'('`echo "($1 * 100) / $2" | bc`'%)'
15 tmpdir=`mktemp -d /tmp/.tmpdirXXXXXX` || die "couldn't create tmp dir"
17 [ ${#tmpdir} == 18 ] && [ -d $tmpdir ] && rm -rf $tmpdir
23 0) echo "OST_REPLY" ;;
24 1) echo "OST_GETATTR" ;;
25 2) echo "OST_SETATTR" ;;
27 4) echo "OST_WRITE" ;;
28 5) echo "OST_CREATE" ;;
29 6) echo "OST_DESTROY" ;;
30 7) echo "OST_GET_INFO" ;;
31 8) echo "OST_CONNECT" ;;
32 9) echo "OST_DISCONNECT" ;;
33 10) echo "OST_PUNCH" ;;
34 11) echo "OST_OPEN" ;;
35 12) echo "OST_CLOSE" ;;
36 13) echo "OST_STATFS" ;;
37 14) echo "OST_SAN_READ" ;;
38 15) echo "OST_SAN_WRITE" ;;
39 16) echo "OST_SYNC" ;;
40 17) echo "OST_SET_INFO" ;;
41 33) echo "MDS_GETATTR" ;;
42 34) echo "MDS_GETATTR_NAME" ;;
43 35) echo "MDS_CLOSE" ;;
44 36) echo "MDS_REINT" ;;
45 37) echo "MDS_READPAGE" ;;
46 38) echo "MDS_CONNECT" ;;
47 39) echo "MDS_DISCONNECT" ;;
48 40) echo "MDS_GETSTATUS" ;;
49 41) echo "MDS_STATFS" ;;
51 43) echo "MDS_UNPIN" ;;
52 44) echo "MDS_SYNC" ;;
53 45) echo "MDS_DONE_WRITING" ;;
54 101) echo "LDLM_ENQUEUE" ;;
55 102) echo "LDLM_CONVERT" ;;
56 103) echo "LDLM_CANCEL" ;;
57 104) echo "LDLM_BL_CALLBACK" ;;
58 105) echo "LDLM_CP_CALLBACK" ;;
59 106) echo "LDLM_GL_CALLBACK" ;;
60 400) echo "OBD_PING" ;;
61 401) echo "OBD_LOG_CANCEL" ;;
68 echo " -l file (required)"
69 echo " Specifies a debug log that contains RPC 'Sending' and"
70 echo " 'Completed' entries generated by D_RPCTRACE."
72 echo " Usually the PostScript output is temporary and only"
73 echo " used for the gv instance during the script. This"
74 echo " option specifies a file to save the ps to."
76 echo " Usually the pl script is generated in a temporary"
77 echo " directoriy that is wiped as the script exits. This"
78 echo " saves the script as 'file' instead."
80 echo " Label the tail of each RPC bar with the XID of the"
81 echo " RPC. This can be illegible with dense bars."
84 echo " $0 -l /tmp/my-log -o out.ps && gv -landscape out.ps"
89 [ ${#*} == 0 ] && usage
91 if ! which pl > /dev/null 2>&1 ; then
92 echo "The ploticus 'pl' binary isn't in the PATH."
94 echo " (cd /tmp && wget http://ploticus.sourceforge.net/download/pl220linux.tar.gz)"
95 echo " (mkdir ~/ploticus && cd ~/ploticus && tar -zxf /tmp/pl220linux.tar.gz)"
96 echo ' export PATH=$PATH:~/ploticus/pl220linux/bin'
97 echo " chmod +x ~/ploticus/pl220linux/bin/pl"
99 echo "is sufficient. There are also rpms near"
100 echo " http://ploticus.sourceforge.net/doc/download.html"
105 while getopts ":l:o:p:x" opt; do
109 p) pl_save_file=$OPTARG ;;
110 x) labelfield="labelfield: 5" ;;
115 [ -z "$log" ] && die "need to specify a log file with -l"
116 [ ! -f "$log" ] && die "$log needs to be a file"
118 pl_script="$tmpdir/ploticus.script"
120 echo "$*" >> $pl_script
123 awk_vars="$tmpdir/awk_vars"
125 BEGIN { num_xids = 0 }
132 # the y position of the rpc bar in the graph is determined
133 # by the category which we use the process name for. when
134 # a process has multiple rpcs concurrently we generate
135 # seperate categories by appending ___slot to the name
136 # and then hide these slot categories in the graph.
138 # find the next slot that is empty
139 for (slot = 0; (pname, slot) in pname_slots; slot++) {
143 pname_slots[pname, slot] = xid
147 xid_pname[xid] = pname
149 xid_pname[xid] = pname "_____" slot
151 xid_start[xid] = tvtime
152 xid_opcode[xid] = opc
154 num_xids = num_xids + 1
158 if (initialized != 1) {
175 ($11 == "Completed") {
185 xid_stop[xid] = tvtime
186 this_time = xid_stop[xid] - xid_start[xid]
187 total_rpc_time = total_rpc_time + this_time;
188 rpc_total_time[opc] = rpc_total_time[opc] + this_time
192 delete pname_slots[pname, slot]
195 for (ind = 0; ind < num_xids; ind++) {
197 print xid_pname[xid], xid_start[xid] - min, \
198 xid_stop[xid] - min, xid_opcode[xid], xid \
201 print "FIRST_XID=" first_xid >> "'$awk_vars'"
202 print "LAST_XID=" last_xid >> "'$awk_vars'"
203 print "MIN=" 0.0 >> "'$awk_vars'"
204 print "TOTAL_RPCS=" total_rpcs >> "'$awk_vars'"
205 print "TOTAL_RPC_TIME=" total_rpc_time >> "'$awk_vars'"
206 print "MAX=" max - min >> "'$awk_vars'"
208 for (op in opcodes) {
209 all_opcodes = all_opcodes " " op
210 print "rpc_total_time[" op "]=\"" \
211 rpc_total_time[op] "\"" \
213 print "rpc_count[" op "]=\"" \
217 print "OP_CODES=\"" all_opcodes "\"" >> "'$awk_vars'"
218 print "NUM_OP_CODES=" asort(opcodes) >> "'$awk_vars'"
220 ' $log || die "awk failed"
224 [ ! -e $tmpdir/data ] && die "no RPCS found in $log"
229 # it seems neccesary to batch by category, sadly.
230 sort -n $tmpdir/data >> $pl_script || die "sorting failed"
231 # jeez. without another newline at the end pl doesn't read the last data row.
234 # could be smarter here
235 # http://ploticus.sourceforge.net/doc/color.html
236 colors=("red" "orange" "green" "blue" "purple" "pink" "powderblue" "yellow" \
242 ops_per_pane=$(((NUM_OP_CODES + 2)/ 3))
245 for op in $OP_CODES; do
247 [ $name == "unknown" ] && die "unknown op code $op"
249 [ $i == $num_colors ] && die "ran out of colors"
251 label="$name "`pct ${rpc_count[$op]} $TOTAL_RPCS`
252 label="$label, "`pct ${rpc_total_time[$op]} $TOTAL_RPC_TIME`
254 # this "tag:" is also included in the data and is used by the
255 # bar plot to define the color of the bar
256 # http://ploticus.sourceforge.net/doc/bars.html
257 # http://ploticus.sourceforge.net/doc/legendentry.html#legenddriven
258 to_pl "#proc legendentry
261 details: ${colors[$i]}
264 # ploticus makes you construct seperage legends stacked next to each
265 # other if you want to have a legend with multiple rows _and_ multiple
267 # http://ploticus.sourceforge.net/doc/legend.html
268 # http://ploticus.sourceforge.net/gallery/propbars1.htm
269 # we put each op code in part of a legend pane and then emit them
270 # all later on at the end of the script
271 if [ $legend_index == 0 ]; then
272 # XXX this should be standard
273 loc="min+$(($legend_pane * 3)) min-.5"
274 # loc="$loc min-"`echo "($ops_per_pane * .3)" | bc`
281 # all but the last get noclear
282 if [ $legend_pane != 2 ]; then
293 legend_index=$(($legend_index + 1))
294 if [ $legend_index == $ops_per_pane ]; then
296 legend_pane=$(($legend_pane + 1))
305 xautorange datafields=2,3
307 yscaletype: categories
308 ycategories: datafield 1
309 title: $TOTAL_RPCS RPCs found in \"$log\"
310 titledetails: align=C
314 grid: color=gray(0.9)
322 grid: color=gray(0.9)
323 label: Elapsed seconds
332 // see the legendentry generation above
337 if [ ! -z "$pl_save_file" ]; then
338 mv $pl_script $pl_save_file || \
339 die "couldn't save pl script as $pl_save_file"
340 pl_script="$pl_save_file"
343 # pl is very excited about not doing dynamic allocation.
344 NURR=$((TOTAL_RPCS * 10))
346 pl -maxproclines $NURR -maxfields $NURR -landscape -ps $pl_script \
347 -o $tmpdir/ps || die "pl failed"
349 if [ -z "$output" ]; then
350 gv -landscape $tmpdir/ps || die "couldn't start gv"
352 mv $tmpdir/ps $output || die "couldn't save ps output as $output"