Whamcloud - gitweb
- add a cute script that uses 'ploticus' to graph the rpcs from a D_RPCTRACE
authorzab <zab>
Sat, 17 Apr 2004 04:11:08 +0000 (04:11 +0000)
committerzab <zab>
Sat, 17 Apr 2004 04:11:08 +0000 (04:11 +0000)
  log.  the script should be easy to use and has pointers to ploticus.

http://tetsuo.zabbo.net/~zab/rpc-graph.ps

is an example.

lustre/scripts/graph-rpcs.sh [new file with mode: 0755]

diff --git a/lustre/scripts/graph-rpcs.sh b/lustre/scripts/graph-rpcs.sh
new file mode 100755 (executable)
index 0000000..08a2d24
--- /dev/null
@@ -0,0 +1,351 @@
+#!/bin/bash
+
+# I'm sure this could be one cleaner perl script instead of a weird combination
+# of awk and shell.  This was the fastest path to feeding 'pl' for me. I'm
+# all for improvements.  Let me know.  -- zab
+
+die() {
+        echo $* 1>&2
+        exit 1
+}
+pct() {
+       echo "$1 "'('`echo "($1 * 100) / $2" | bc`'%)'
+}
+
+tmpdir=`mktemp -d /tmp/.tmpdirXXXXXX` || die "couldn't create tmp dir"
+cleanup() {
+        [ ${#tmpdir} == 18 ] && [ -d $tmpdir ] && rm -rf $tmpdir
+}
+trap cleanup EXIT
+
+rpc_name() {
+       case "$1" in
+               0) echo "OST_REPLY" ;;
+               1) echo "OST_GETATTR" ;;
+               2) echo "OST_SETATTR" ;;
+               3) echo "OST_READ" ;;
+               4) echo "OST_WRITE" ;;
+               5) echo "OST_CREATE" ;;
+               6) echo "OST_DESTROY" ;;
+               7) echo "OST_GET_INFO" ;;
+               8) echo "OST_CONNECT" ;;
+               9) echo "OST_DISCONNECT" ;;
+               10) echo "OST_PUNCH" ;;
+               11) echo "OST_OPEN" ;;
+               12) echo "OST_CLOSE" ;;
+               13) echo "OST_STATFS" ;;
+               14) echo "OST_SAN_READ" ;;
+               15) echo "OST_SAN_WRITE" ;;
+               16) echo "OST_SYNC" ;;
+               17) echo "OST_SET_INFO" ;;
+               33) echo "MDS_GETATTR" ;;
+               34) echo "MDS_GETATTR_NAME" ;;
+               35) echo "MDS_CLOSE" ;;
+               36) echo "MDS_REINT" ;;
+               37) echo "MDS_READPAGE" ;;
+               38) echo "MDS_CONNECT" ;;
+               39) echo "MDS_DISCONNECT" ;;
+               40) echo "MDS_GETSTATUS" ;;
+               41) echo "MDS_STATFS" ;;
+               42) echo "MDS_PIN" ;;
+               43) echo "MDS_UNPIN" ;;
+               44) echo "MDS_SYNC" ;;
+               45) echo "MDS_DONE_WRITING" ;;
+               101) echo "LDLM_ENQUEUE" ;;
+               102) echo "LDLM_CONVERT" ;;
+               103) echo "LDLM_CANCEL" ;;
+               104) echo "LDLM_BL_CALLBACK" ;;
+               105) echo "LDLM_CP_CALLBACK" ;;
+               106) echo "LDLM_GL_CALLBACK" ;;
+               400) echo "OBD_PING" ;;
+               401) echo "OBD_LOG_CANCEL" ;;
+
+               *) echo "unknown" ;;
+       esac
+}
+
+usage() {
+        echo " -l file (required)"
+        echo "         Specifies a debug log that contains RPC 'Sending' and"
+        echo "         'Completed' entries generated by D_RPCTRACE."
+        echo " -o file"
+        echo "         Usually the PostScript output is temporary and only" 
+        echo "         used for the gv instance during the script.  This"
+        echo "         option specifies a file to save the ps to."
+        echo " -p file"
+        echo "         Usually the pl script is generated in a temporary" 
+        echo "         directoriy that is wiped as the script exits.  This"
+        echo "         saves the script as 'file' instead."
+        echo " -x"
+        echo "         Label the tail of each RPC bar with the XID of the"
+        echo "         RPC.  This can be illegible with dense bars."
+        echo
+        echo "Example:"
+        echo " $0 -l /tmp/my-log -o out.ps && gv -landscape out.ps"
+       echo
+        exit;
+}
+
+[ ${#*} == 0 ] && usage
+
+if ! which pl > /dev/null 2>&1 ; then
+       echo "The ploticus 'pl' binary isn't in the PATH."
+       echo " ----"
+       echo " (cd /tmp && wget http://ploticus.sourceforge.net/download/pl220linux.tar.gz)"
+       echo " (mkdir ~/ploticus && cd ~/ploticus && tar -zxf /tmp/pl220linux.tar.gz)"
+       echo ' export PATH=$PATH:~/ploticus/pl220linux/bin'
+       echo " chmod +x ~/ploticus/pl220linux/bin/pl"
+       echo " ----"
+       echo "is sufficient.  There are also rpms near"
+       echo "  http://ploticus.sourceforge.net/doc/download.html"
+       exit 1;
+fi
+
+labelfield="//"
+while getopts ":l:o:p:x" opt; do
+        case $opt in
+                l) log=$OPTARG                 ;;
+                o) output=$OPTARG                 ;;
+                p) pl_save_file=$OPTARG                 ;;
+                x) labelfield="labelfield: 5"                 ;;
+                \?) usage
+        esac
+done
+
+[ -z "$log" ] && die "need to specify a log file with -l"
+[ ! -f "$log" ] && die "$log needs to be a file"
+
+pl_script="$tmpdir/ploticus.script"
+to_pl() {
+       echo "$*" >> $pl_script
+}
+
+awk_vars="$tmpdir/awk_vars"
+awk -F"[$IFS:]" '
+       BEGIN { num_xids = 0 }
+       ($11 == "Sending") { 
+               tvtime = $4
+               pname = $20
+               xid = $23
+               opc = $26
+
+               # the y position of the rpc bar in the graph is determined
+               # by the category which we use the process name for.  when
+               # a process has multiple rpcs concurrently we generate
+               # seperate categories by appending ___slot to the name
+               # and then hide these slot categories in the graph.
+               # find the next slot that is empty
+               for (slot = 0; (pname, slot) in pname_slots; slot++) {
+                       ;
+               }
+
+               pname_slots[pname, slot] = xid
+               xid_slot[xid] = slot
+
+               if (slot == 0) {
+                       xid_pname[xid] = pname
+               } else {
+                       xid_pname[xid] = pname "_____" slot
+               }
+               xid_start[xid] = tvtime
+               xid_opcode[xid] = opc
+               xids[num_xids] = xid
+               num_xids = num_xids + 1
+               opcodes[opc] = 1
+
+
+               if (initialized != 1) {
+                       min = tvtime
+                       max = tvtime
+                       first_xid = xid
+                       last_xid = xid
+                       initialized = 1
+                       
+               }
+               if (tvtime < min) {
+                       min = tvtime
+                       first_xid = xid
+               }
+               if (tvtime > max) {
+                       max = tvtime
+                       last_xid = xid
+               }
+       }
+       ($11 == "Completed") { 
+               tvtime = $4
+               pname = $20
+               xid = $23
+               opc = $26
+
+
+               total_rpcs++;
+               rpc_count[opc]++;
+
+               xid_stop[xid] = tvtime
+               this_time = xid_stop[xid] - xid_start[xid]
+               total_rpc_time = total_rpc_time + this_time;
+               rpc_total_time[opc] = rpc_total_time[opc] + this_time
+
+               slot = xid_slot[xid]
+               delete xid_slot[xid]
+               delete pname_slots[pname, slot]
+       }
+       END {
+               for (ind = 0; ind < num_xids; ind++) {
+                       xid = xids[ind]
+                       print xid_pname[xid], xid_start[xid] - min, \
+                               xid_stop[xid] - min, xid_opcode[xid], xid \
+                                       >> "'$tmpdir/data'"
+               }
+               print "FIRST_XID=" first_xid >> "'$awk_vars'"
+               print "LAST_XID=" last_xid >> "'$awk_vars'"
+               print "MIN=" 0.0 >> "'$awk_vars'"
+               print "TOTAL_RPCS=" total_rpcs >> "'$awk_vars'"
+               print "TOTAL_RPC_TIME=" total_rpc_time >> "'$awk_vars'"
+               print "MAX=" max - min >> "'$awk_vars'"
+
+               for (op in opcodes) {
+                       all_opcodes = all_opcodes " " op
+                       print "rpc_total_time[" op "]=\"" \
+                               rpc_total_time[op] "\"" \
+                                       >> "'$awk_vars'"
+                       print "rpc_count[" op "]=\"" \
+                               rpc_count[op] "\"" \
+                                       >> "'$awk_vars'"
+               }
+               print "OP_CODES=\"" all_opcodes "\"" >> "'$awk_vars'"
+               print "NUM_OP_CODES=" asort(opcodes) >> "'$awk_vars'"
+       }
+       ' $log || die "awk failed"
+
+. $awk_vars
+
+to_pl  '#proc getdata
+       data:'
+
+# it seems neccesary to batch by category, sadly.
+sort -n $tmpdir/data >> $pl_script || die "sorting failed"
+# jeez. without another newline at the end pl doesn't read the last data row.
+echo >> $pl_script
+
+# could be smarter here
+# http://ploticus.sourceforge.net/doc/color.html
+colors=("red" "orange" "green" "blue" "purple" "pink" "powderblue" "yellow" \
+       "brown")
+num_colors=9
+
+legend_index=0
+legend_pane=0
+ops_per_pane=$(((NUM_OP_CODES  + 2)/ 3))
+
+i=0
+for op in $OP_CODES; do
+       name=`rpc_name $op`
+       [ $name == "unknown" ] && die "unknown op code $op"
+
+       [ $i == $num_colors ] && die "ran out of colors"
+
+       label="$name "`pct ${rpc_count[$op]} $TOTAL_RPCS`
+       label="$label, "`pct ${rpc_total_time[$op]} $TOTAL_RPC_TIME`
+
+       # this "tag:" is also included in the data and is used by the
+       # bar plot to define the color of the bar
+       #  http://ploticus.sourceforge.net/doc/bars.html
+       #  http://ploticus.sourceforge.net/doc/legendentry.html#legenddriven
+       to_pl "#proc legendentry
+               sampletype: color
+               label: $label
+               details: ${colors[$i]}
+               tag: $op"
+
+       # ploticus makes you construct seperage legends stacked next to each
+       # other if you want to have a legend with multiple rows _and_ multiple
+       # columns.
+       #       http://ploticus.sourceforge.net/doc/legend.html
+       #       http://ploticus.sourceforge.net/gallery/propbars1.htm
+       # we put each op code in part of a legend pane and then emit them
+       # all later on at the end of the script
+       if [ $legend_index == 0 ]; then
+               # XXX this should be standard
+               loc="min+$(($legend_pane * 3)) min-.5"
+#              loc="$loc min-"`echo "($ops_per_pane * .3)" | bc`
+
+               leg=" $leg
+
+                       #proc legend
+                               location: $loc"
+
+               # all but the last get noclear
+               if [ $legend_pane != 2 ]; then
+                       leg="$leg
+                               noclear: yes"
+               fi
+               leg="$leg
+                               specifyorder: $name"
+       else
+               leg="$leg
+                                               $name"
+       fi
+
+       legend_index=$(($legend_index + 1))
+       if [ $legend_index == $ops_per_pane ]; then
+               legend_index=0
+               legend_pane=$(($legend_pane + 1))
+       fi
+
+       i=$(($i + 1))
+done
+
+to_pl  "
+#proc areadef
+       rectangle: 1 1 9.5 8
+       xautorange datafields=2,3
+          xrange:    $MIN $MAX
+       yscaletype: categories
+       ycategories: datafield 1
+       title: $TOTAL_RPCS RPCs found in \"$log\"
+       titledetails: align=C
+
+#proc yaxis
+       stubs: categories
+       grid: color=gray(0.9)
+       labeldistance: 1
+       label: Process name
+       stubomit: *_____*
+#proc xaxis
+       stubs: inc
+       stubformat: %.3f
+       grid: color=gray(0.9)
+       label: Elapsed seconds
+                                                                                
+#proc bars
+       axis: x
+       locfield: 1
+       segmentfields: 2 3
+       barwidth: 0.06
+       outline: no
+       $labelfield
+// see the legendentry generation above
+       colorfield 4
+
+$leg"
+
+if [ ! -z "$pl_save_file" ]; then
+       mv $pl_script $pl_save_file || \
+               die "couldn't save pl script as $pl_save_file"
+       pl_script="$pl_save_file"
+fi
+
+# pl is very excited about not doing dynamic allocation.
+NURR=$((TOTAL_RPCS * 10))
+
+pl -maxproclines $NURR -maxfields $NURR -landscape -ps $pl_script \
+       -o $tmpdir/ps || die "pl failed"
+
+if [ -z "$output" ]; then
+       gv -landscape $tmpdir/ps || die "couldn't start gv"
+else
+       mv $tmpdir/ps $output || die "couldn't save ps output as $output"
+fi