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 hex2float() {
  22         echo "ibase=16;scale=2;$*/FF" | bc
  23 }
  24 make_color() {
  25         local md5=`echo "$*" | md5sum - | awk '{print $1}' | \
  26                         tr '[a-z]' '[A-Z]'`;
  27         local r=`echo $md5 | cut -b 1,2`
  28         local g=`echo $md5 | cut -b 3,4`
  29         local b=`echo $md5 | cut -b 5,6`
  30         echo "rgb(`hex2float $r`,`hex2float $g`,`hex2float $b`)"
  31 }
  32
  33 rpc_name() {
  34         case "$1" in
  35                 0) echo "OST_REPLY" ;;
  36                 1) echo "OST_GETATTR" ;;
  37                 2) echo "OST_SETATTR" ;;
  38                 3) echo "OST_READ" ;;
  39                 4) echo "OST_WRITE" ;;
  40                 5) echo "OST_CREATE" ;;
  41                 6) echo "OST_DESTROY" ;;
  42                 7) echo "OST_GET_INFO" ;;
  43                 8) echo "OST_CONNECT" ;;
  44                 9) echo "OST_DISCONNECT" ;;
  45                 10) echo "OST_PUNCH" ;;
  46                 11) echo "OST_OPEN" ;;
  47                 12) echo "OST_CLOSE" ;;
  48                 13) echo "OST_STATFS" ;;
  49                 14) echo "OST_SAN_READ" ;;
  50                 15) echo "OST_SAN_WRITE" ;;
  51                 16) echo "OST_SYNC" ;;
  52                 17) echo "OST_SET_INFO" ;;
  53                 33) echo "MDS_GETATTR" ;;
  54                 34) echo "MDS_GETATTR_NAME" ;;
  55                 35) echo "MDS_CLOSE" ;;
  56                 36) echo "MDS_REINT" ;;
  57                 37) echo "MDS_READPAGE" ;;
  58                 38) echo "MDS_CONNECT" ;;
  59                 39) echo "MDS_DISCONNECT" ;;
  60                 40) echo "MDS_GETSTATUS" ;;
  61                 41) echo "MDS_STATFS" ;;
  62                 42) echo "MDS_PIN" ;;
  63                 43) echo "MDS_UNPIN" ;;
  64                 44) echo "MDS_SYNC" ;;
  65                 45) echo "MDS_DONE_WRITING" ;;
  66                 101) echo "LDLM_ENQUEUE" ;;
  67                 102) echo "LDLM_CONVERT" ;;
  68                 103) echo "LDLM_CANCEL" ;;
  69                 104) echo "LDLM_BL_CALLBACK" ;;
  70                 105) echo "LDLM_CP_CALLBACK" ;;
  71                 106) echo "LDLM_GL_CALLBACK" ;;
  72                 400) echo "OBD_PING" ;;
  73                 401) echo "OBD_LOG_CANCEL" ;;
  74
  75                 *) echo "unknown" ;;
  76         esac
  77 }
  78
  79 usage() {
  80         echo "  -l file (required)"
  81         echo "          Specifies a debug log that contains RPC 'Sending' and"
  82         echo "          'Completed' entries generated by D_RPCTRACE."
  83         echo "  -o file"
  84         echo "          Usually the PostScript output is temporary and only"
  85         echo "          used for the gv instance during the script.  This"
  86         echo "          option specifies a file to save the ps to."
  87         echo "  -p file"
  88         echo "          Usually the pl script is generated in a temporary"
  89         echo "          directoriy that is wiped as the script exits.  This"
  90         echo "          saves the script as 'file' instead."
  91         echo "  -x"
  92         echo "          Label the tail of each RPC bar with the XID of the"
  93         echo "          RPC.  This can be illegible with dense bars."
  94         echo
  95         echo "Example:"
  96         echo " $0 -l /tmp/my-log -o out.ps && gv -landscape out.ps"
  97         echo
  98         exit;
  99 }
 100
 101 [ ${#*} == 0 ] && usage
 102
 103 if ! which pl > /dev/null 2>&1 ; then
 104         echo "The ploticus 'pl' binary isn't in the PATH."
 105         echo " ----"
 106         echo " (cd /tmp && wget http://ploticus.sourceforge.net/download/pl220linux.tar.gz)"
 107         echo " (mkdir ~/ploticus && cd ~/ploticus && tar -zxf /tmp/pl220linux.tar.gz)"
 108         echo ' export PATH=$PATH:~/ploticus/pl220linux/bin'
 109         echo " chmod +x ~/ploticus/pl220linux/bin/pl"
 110         echo " ----"
 111         echo "is sufficient.  There are also rpms near"
 112         echo "  http://ploticus.sourceforge.net/doc/download.html"
 113         exit 1;
 114 fi
 115
 116 labelfield="//"
 117 while getopts ":l:o:p:x" opt; do
 118         case $opt in
 119                 l) log=$OPTARG                 ;;
 120                 o) output=$OPTARG                 ;;
 121                 p) pl_save_file=$OPTARG                 ;;
 122                 x) labelfield="labelfield: 5"                 ;;
 123                 \?) usage
 124         esac
 125 done
 126
 127 [ -z "$log" ] && die "need to specify a log file with -l"
 128 [ ! -f "$log" ] && die "$log needs to be a file"
 129
 130 pl_script="$tmpdir/ploticus.script"
 131 to_pl() {
 132         echo "$*" >> $pl_script
 133 }
 134
 135 awk_vars="$tmpdir/awk_vars"
 136 awk -F"[$IFS:]" '
 137         BEGIN { num_xids = 0 }
 138         ($11 == "Sending") {
 139                 tvtime = $4
 140                 pname = $20
 141                 xid = $23
 142                 # sometimes the nid has our seperators
 143                 # in it, so we hope the last field is the op code
 144                 opc = $NF
 145
 146                 # the y position of the rpc bar in the graph is determined
 147                 # by the category which we use the process name for.  when
 148                 # a process has multiple rpcs concurrently we generate
 149                 # seperate categories by appending ___slot to the name
 150                 # and then hide these slot categories in the graph.
 151
 152                 # find the next slot that is empty
 153                 for (slot = 0; (pname, slot) in pname_slots; slot++) {
 154                         ;
 155                 }
 156
 157                 pname_slots[pname, slot] = xid
 158                 xid_slot[xid] = slot
 159
 160                 if (slot == 0) {
 161                         xid_pname[xid] = pname
 162                 } else {
 163                         xid_pname[xid] = pname "_____" slot
 164                 }
 165                 xid_start[xid] = tvtime
 166                 xid_opcode[xid] = opc
 167                 xids[num_xids] = xid
 168                 num_xids = num_xids + 1
 169                 opcodes[opc] = 1
 170
 171
 172                 if (initialized != 1) {
 173                         min = tvtime
 174                         max = tvtime
 175                         first_xid = xid
 176                         last_xid = xid
 177                         initialized = 1
 178
 179                 }
 180                 if (tvtime < min) {
 181                         min = tvtime
 182                         first_xid = xid
 183                 }
 184                 if (tvtime > max) {
 185                         max = tvtime
 186                         last_xid = xid
 187                 }
 188         }
 189         ($11 == "Completed") {
 190                 tvtime = $4
 191                 pname = $20
 192                 xid = $23
 193                 opc = $NF
 194
 195
 196                 total_rpcs++;
 197                 rpc_count[opc]++;
 198
 199                 xid_stop[xid] = tvtime
 200                 this_time = xid_stop[xid] - xid_start[xid]
 201                 total_rpc_time = total_rpc_time + this_time;
 202                 rpc_total_time[opc] = rpc_total_time[opc] + this_time
 203
 204                 slot = xid_slot[xid]
 205                 delete xid_slot[xid]
 206                 delete pname_slots[pname, slot]
 207         }
 208         END {
 209                 for (ind = 0; ind < num_xids; ind++) {
 210                         xid = xids[ind]
 211                         print xid_pname[xid], xid_start[xid] - min, \
 212                                 xid_stop[xid] - min, xid_opcode[xid], xid \
 213                                         >> "'$tmpdir/data'"
 214                 }
 215                 print "FIRST_XID=" first_xid >> "'$awk_vars'"
 216                 print "LAST_XID=" last_xid >> "'$awk_vars'"
 217                 print "MIN=" 0.0 >> "'$awk_vars'"
 218                 print "TOTAL_RPCS=" total_rpcs >> "'$awk_vars'"
 219                 print "TOTAL_RPC_TIME=" total_rpc_time >> "'$awk_vars'"
 220                 print "MAX=" max - min >> "'$awk_vars'"
 221
 222                 for (op in opcodes) {
 223                         all_opcodes = all_opcodes " " op
 224                         print "rpc_total_time[" op "]=\"" \
 225                                 rpc_total_time[op] "\"" \
 226                                         >> "'$awk_vars'"
 227                         print "rpc_count[" op "]=\"" \
 228                                 rpc_count[op] "\"" \
 229                                         >> "'$awk_vars'"
 230                 }
 231                 print "OP_CODES=\"" all_opcodes "\"" >> "'$awk_vars'"
 232                 print "NUM_OP_CODES=" asort(opcodes) >> "'$awk_vars'"
 233         }
 234         ' $log || die "awk failed"
 235
 236 . $awk_vars
 237
 238 [ ! -e $tmpdir/data ] && die "no RPCS found in $log"
 239
 240 to_pl   '#proc getdata
 241         data:'
 242
 243 # it seems neccesary to batch by category, sadly.
 244 sort -n $tmpdir/data >> $pl_script || die "sorting failed"
 245 # jeez. without another newline at the end pl doesn't read the last data row.
 246 echo >> $pl_script
 247
 248 legend_index=0
 249 legend_pane=0
 250 ops_per_pane=$(((NUM_OP_CODES  + 2)/ 3))
 251
 252 i=0
 253 for op in $OP_CODES; do
 254         name=`rpc_name $op`
 255         [ $name == "unknown" ] && die "unknown op code $op"
 256
 257         label="$name "`pct ${rpc_count[$op]} $TOTAL_RPCS`
 258         label="$label, "`pct ${rpc_total_time[$op]} $TOTAL_RPC_TIME`
 259
 260         # this "tag:" is also included in the data and is used by the
 261         # bar plot to define the color of the bar
 262         #  http://ploticus.sourceforge.net/doc/bars.html
 263         #  http://ploticus.sourceforge.net/doc/legendentry.html#legenddriven
 264         to_pl "#proc legendentry
 265                 sampletype: color
 266                 label: $label
 267                 details: `make_color $name`
 268                 tag: $op"
 269
 270         # ploticus makes you construct seperage legends stacked next to each
 271         # other if you want to have a legend with multiple rows _and_ multiple
 272         # columns.
 273         #       http://ploticus.sourceforge.net/doc/legend.html
 274         #       http://ploticus.sourceforge.net/gallery/propbars1.htm
 275         # we put each op code in part of a legend pane and then emit them
 276         # all later on at the end of the script
 277         if [ $legend_index == 0 ]; then
 278                 # XXX this should be standard
 279                 loc="min+$(($legend_pane * 3)) min-.5"
 280 #               loc="$loc min-"`echo "($ops_per_pane * .3)" | bc`
 281
 282                 leg=" $leg
 283
 284                         #proc legend
 285                                 location: $loc"
 286
 287                 # all but the last get noclear
 288                 if [ $legend_pane != 2 ]; then
 289                         leg="$leg
 290                                 noclear: yes"
 291                 fi
 292                 leg="$leg
 293                                 specifyorder: $name"
 294         else
 295                 leg="$leg
 296                                                 $name"
 297         fi
 298
 299         legend_index=$(($legend_index + 1))
 300         if [ $legend_index == $ops_per_pane ]; then
 301                 legend_index=0
 302                 legend_pane=$(($legend_pane + 1))
 303         fi
 304
 305         i=$(($i + 1))
 306 done
 307
 308 to_pl   "
 309 #proc areadef
 310         rectangle: 1 2 9.5 8
 311         xautorange datafields=2,3
 312            xrange:    $MIN $MAX
 313         yscaletype: categories
 314         ycategories: datafield 1
 315         title: $TOTAL_RPCS RPCs found in \"$log\"
 316         titledetails: align=C
 317
 318 #proc yaxis
 319         stubs: categories
 320         grid: color=gray(0.9)
 321         labeldistance: 1
 322         label: Process name
 323         stubomit: *_____*
 324
 325 #proc xaxis
 326         stubs: inc
 327         stubformat: %.3f
 328         grid: color=gray(0.9)
 329         label: Elapsed seconds
 330
 331 #proc bars
 332         axis: x
 333         locfield: 1
 334         segmentfields: 2 3
 335         barwidth: 0.06
 336         outline: no
 337         $labelfield
 338 // see the legendentry generation above
 339         colorfield 4
 340
 341 $leg"
 342
 343 if [ ! -z "$pl_save_file" ]; then
 344         mv $pl_script $pl_save_file || \
 345                 die "couldn't save pl script as $pl_save_file"
 346         pl_script="$pl_save_file"
 347 fi
 348
 349 # pl is very excited about not doing dynamic allocation.
 350 NURR=$((TOTAL_RPCS * 10))
 351
 352 pl -maxproclines $NURR -maxfields $NURR -landscape -ps $pl_script \
 353         -o $tmpdir/ps || die "pl failed"
 354
 355 if [ -z "$output" ]; then
 356         gv -landscape $tmpdir/ps || die "couldn't start gv"
 357 else
 358         mv $tmpdir/ps $output || die "couldn't save ps output as $output"
 359 fi