lustre/scripts/graph-rpcs.sh

   1 #!/bin/bash
   2
   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
   6
   7 die() {
   8         echo $* 1>&2
   9         exit 1
  10 }
  11 pct() {
  12         echo "$1 "'('`echo "($1 * 100) / $2" | bc`'%)'
  13 }
  14
  15 tmpdir=`mktemp -d /tmp/.tmpdirXXXXXX` || die "couldn't create tmp dir"
  16 cleanup() {
  17         [ ${#tmpdir} == 18 ] && [ -d $tmpdir ] && rm -rf $tmpdir
  18 }
  19 trap cleanup EXIT
  20
  21 rpc_name() {
  22         case "$1" in
  23                 0) echo "OST_REPLY" ;;
  24                 1) echo "OST_GETATTR" ;;
  25                 2) echo "OST_SETATTR" ;;
  26                 3) echo "OST_READ" ;;
  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" ;;
  50                 42) echo "MDS_PIN" ;;
  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" ;;
  62
  63                 *) echo "unknown" ;;
  64         esac
  65 }
  66
  67 usage() {
  68         echo "  -l file (required)"
  69         echo "          Specifies a debug log that contains RPC 'Sending' and"
  70         echo "          'Completed' entries generated by D_RPCTRACE."
  71         echo "  -o file"
  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."
  75         echo "  -p file"
  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."
  79         echo "  -x"
  80         echo "          Label the tail of each RPC bar with the XID of the"
  81         echo "          RPC.  This can be illegible with dense bars."
  82         echo
  83         echo "Example:"
  84         echo " $0 -l /tmp/my-log -o out.ps && gv -landscape out.ps"
  85         echo
  86         exit;
  87 }
  88
  89 [ ${#*} == 0 ] && usage
  90
  91 if ! which pl > /dev/null 2>&1 ; then
  92         echo "The ploticus 'pl' binary isn't in the PATH."
  93         echo " ----"
  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"
  98         echo " ----"
  99         echo "is sufficient.  There are also rpms near"
 100         echo "  http://ploticus.sourceforge.net/doc/download.html"
 101         exit 1;
 102 fi
 103
 104 labelfield="//"
 105 while getopts ":l:o:p:x" opt; do
 106         case $opt in
 107                 l) log=$OPTARG                 ;;
 108                 o) output=$OPTARG                 ;;
 109                 p) pl_save_file=$OPTARG                 ;;
 110                 x) labelfield="labelfield: 5"                 ;;
 111                 \?) usage
 112         esac
 113 done
 114
 115 [ -z "$log" ] && die "need to specify a log file with -l"
 116 [ ! -f "$log" ] && die "$log needs to be a file"
 117
 118 pl_script="$tmpdir/ploticus.script"
 119 to_pl() {
 120         echo "$*" >> $pl_script
 121 }
 122
 123 awk_vars="$tmpdir/awk_vars"
 124 awk -F"[$IFS:]" '
 125         BEGIN { num_xids = 0 }
 126         ($11 == "Sending") {
 127                 tvtime = $4
 128                 pname = $20
 129                 xid = $23
 130                 opc = $26
 131
 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.
 137
 138                 # find the next slot that is empty
 139                 for (slot = 0; (pname, slot) in pname_slots; slot++) {
 140                         ;
 141                 }
 142
 143                 pname_slots[pname, slot] = xid
 144                 xid_slot[xid] = slot
 145
 146                 if (slot == 0) {
 147                         xid_pname[xid] = pname
 148                 } else {
 149                         xid_pname[xid] = pname "_____" slot
 150                 }
 151                 xid_start[xid] = tvtime
 152                 xid_opcode[xid] = opc
 153                 xids[num_xids] = xid
 154                 num_xids = num_xids + 1
 155                 opcodes[opc] = 1
 156
 157
 158                 if (initialized != 1) {
 159                         min = tvtime
 160                         max = tvtime
 161                         first_xid = xid
 162                         last_xid = xid
 163                         initialized = 1
 164
 165                 }
 166                 if (tvtime < min) {
 167                         min = tvtime
 168                         first_xid = xid
 169                 }
 170                 if (tvtime > max) {
 171                         max = tvtime
 172                         last_xid = xid
 173                 }
 174         }
 175         ($11 == "Completed") {
 176                 tvtime = $4
 177                 pname = $20
 178                 xid = $23
 179                 opc = $26
 180
 181
 182                 total_rpcs++;
 183                 rpc_count[opc]++;
 184
 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
 189
 190                 slot = xid_slot[xid]
 191                 delete xid_slot[xid]
 192                 delete pname_slots[pname, slot]
 193         }
 194         END {
 195                 for (ind = 0; ind < num_xids; ind++) {
 196                         xid = xids[ind]
 197                         print xid_pname[xid], xid_start[xid] - min, \
 198                                 xid_stop[xid] - min, xid_opcode[xid], xid \
 199                                         >> "'$tmpdir/data'"
 200                 }
 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'"
 207
 208                 for (op in opcodes) {
 209                         all_opcodes = all_opcodes " " op
 210                         print "rpc_total_time[" op "]=\"" \
 211                                 rpc_total_time[op] "\"" \
 212                                         >> "'$awk_vars'"
 213                         print "rpc_count[" op "]=\"" \
 214                                 rpc_count[op] "\"" \
 215                                         >> "'$awk_vars'"
 216                 }
 217                 print "OP_CODES=\"" all_opcodes "\"" >> "'$awk_vars'"
 218                 print "NUM_OP_CODES=" asort(opcodes) >> "'$awk_vars'"
 219         }
 220         ' $log || die "awk failed"
 221
 222 . $awk_vars
 223
 224 to_pl   '#proc getdata
 225         data:'
 226
 227 # it seems neccesary to batch by category, sadly.
 228 sort -n $tmpdir/data >> $pl_script || die "sorting failed"
 229 # jeez. without another newline at the end pl doesn't read the last data row.
 230 echo >> $pl_script
 231
 232 # could be smarter here
 233 # http://ploticus.sourceforge.net/doc/color.html
 234 colors=("red" "orange" "green" "blue" "purple" "pink" "powderblue" "yellow" \
 235         "brown")
 236 num_colors=9
 237
 238 legend_index=0
 239 legend_pane=0
 240 ops_per_pane=$(((NUM_OP_CODES  + 2)/ 3))
 241
 242 i=0
 243 for op in $OP_CODES; do
 244         name=`rpc_name $op`
 245         [ $name == "unknown" ] && die "unknown op code $op"
 246
 247         [ $i == $num_colors ] && die "ran out of colors"
 248
 249         label="$name "`pct ${rpc_count[$op]} $TOTAL_RPCS`
 250         label="$label, "`pct ${rpc_total_time[$op]} $TOTAL_RPC_TIME`
 251
 252         # this "tag:" is also included in the data and is used by the
 253         # bar plot to define the color of the bar
 254         #  http://ploticus.sourceforge.net/doc/bars.html
 255         #  http://ploticus.sourceforge.net/doc/legendentry.html#legenddriven
 256         to_pl "#proc legendentry
 257                 sampletype: color
 258                 label: $label
 259                 details: ${colors[$i]}
 260                 tag: $op"
 261
 262         # ploticus makes you construct seperage legends stacked next to each
 263         # other if you want to have a legend with multiple rows _and_ multiple
 264         # columns.
 265         #       http://ploticus.sourceforge.net/doc/legend.html
 266         #       http://ploticus.sourceforge.net/gallery/propbars1.htm
 267         # we put each op code in part of a legend pane and then emit them
 268         # all later on at the end of the script
 269         if [ $legend_index == 0 ]; then
 270                 # XXX this should be standard
 271                 loc="min+$(($legend_pane * 3)) min-.5"
 272 #               loc="$loc min-"`echo "($ops_per_pane * .3)" | bc`
 273
 274                 leg=" $leg
 275
 276                         #proc legend
 277                                 location: $loc"
 278
 279                 # all but the last get noclear
 280                 if [ $legend_pane != 2 ]; then
 281                         leg="$leg
 282                                 noclear: yes"
 283                 fi
 284                 leg="$leg
 285                                 specifyorder: $name"
 286         else
 287                 leg="$leg
 288                                                 $name"
 289         fi
 290
 291         legend_index=$(($legend_index + 1))
 292         if [ $legend_index == $ops_per_pane ]; then
 293                 legend_index=0
 294                 legend_pane=$(($legend_pane + 1))
 295         fi
 296
 297         i=$(($i + 1))
 298 done
 299
 300 to_pl   "
 301 #proc areadef
 302         rectangle: 1 1 9.5 8
 303         xautorange datafields=2,3
 304            xrange:    $MIN $MAX
 305         yscaletype: categories
 306         ycategories: datafield 1
 307         title: $TOTAL_RPCS RPCs found in \"$log\"
 308         titledetails: align=C
 309
 310 #proc yaxis
 311         stubs: categories
 312         grid: color=gray(0.9)
 313         labeldistance: 1
 314         label: Process name
 315         stubomit: *_____*
 316
 317 #proc xaxis
 318         stubs: inc
 319         stubformat: %.3f
 320         grid: color=gray(0.9)
 321         label: Elapsed seconds
 322
 323 #proc bars
 324         axis: x
 325         locfield: 1
 326         segmentfields: 2 3
 327         barwidth: 0.06
 328         outline: no
 329         $labelfield
 330 // see the legendentry generation above
 331         colorfield 4
 332
 333 $leg"
 334
 335 if [ ! -z "$pl_save_file" ]; then
 336         mv $pl_script $pl_save_file || \
 337                 die "couldn't save pl script as $pl_save_file"
 338         pl_script="$pl_save_file"
 339 fi
 340
 341 # pl is very excited about not doing dynamic allocation.
 342 NURR=$((TOTAL_RPCS * 10))
 343
 344 pl -maxproclines $NURR -maxfields $NURR -landscape -ps $pl_script \
 345         -o $tmpdir/ps || die "pl failed"
 346
 347 if [ -z "$output" ]; then
 348         gv -landscape $tmpdir/ps || die "couldn't start gv"
 349 else
 350         mv $tmpdir/ps $output || die "couldn't save ps output as $output"
 351 fi