1 #!/usr/bin/ksh
   2 #
   3 # iscsisvrtop - display top iSCSI I/O events on a server.
   4 #
   5 # This is measuring the response time between an incoming iSCSI operation
   6 # and its response. In general, this measures the servers view of how
   7 # quickly it can respond to requests. By default, the list shows responses
   8 # to each client.
   9 #
  10 # Top-level fields:
  11 #       load    1 min load average
  12 #       read    total KB read during sample
  13 #       write   total KB sync writes during sample
  14 #
  15 # The following per-client and "all" clients fields are shown
  16 #       Client  IP addr of client
  17 #       OPS     iSCSI operations per second
  18 #       Reads   Read operations per second
  19 #       Writes  Sync write operations per second
  20 #       NOPS    NOP operations per second
  21 #       Rd_bw   Read KB/sec
  22 #       Wr_bw   Sync write KB/sec
  23 #       ARd_sz  Average read size (KB)
  24 #       AWr_sz  Average write size (KB)
  25 #       Rd_t    Average read time in microseconds
  26 #       Wr_t    Average sync write time in microseconds
  27 #       Align%  Percentage of read/write operations that have LBA aligned to
  28 #               blocksize (default=4096 bytes)
  29 #
  30 # INSPIRATION:  top(1) by William LeFebvre and iotop by Brendan Gregg
  31 #
  32 # Copyright 2012, Richard Elling, All rights reserved.
  33 # Copyright 2011, Nexenta Systems, Inc. All rights reserved.
  34 #
  35 # CDDL HEADER START
  36 #
  37 #  The contents of this file are subject to the terms of the
  38 #  Common Development and Distribution License, Version 1.0 only
  39 #  (the "License").  You may not use this file except in compliance
  40 #  with the License.
  41 #
  42 #  You can obtain a copy of the license at Docs/cddl1.txt
  43 #  or http://www.opensolaris.org/os/licensing.
  44 #  See the License for the specific language governing permissions
  45 #  and limitations under the License.
  46 #
  47 # CDDL HEADER END
  48 #
  49 # Author: Richard.Elling@RichardElling.com
  50 #
  51 # Revision:
  52 #   1.9  29-Nov-2012
  53 #
  54 PATH=/usr/sbin:/usr/bin
  55 
  56 ##############################
  57 # check to see if the NFS server module is loaded
  58 # if not, then the dtrace probes will fail ungracefully
  59 if [ "$(uname -s)" = "SunOS" ]; then
  60         modinfo | awk '{print $6}' | grep -q iscsit
  61         if [ $? != 0 ]; then
  62                 echo "error: iSCSI target module is not loaded, are you serving iSCSI?"
  63                 exit 1
  64         fi
  65 fi
  66 
  67 ##############################
  68 # --- Process Arguments ---
  69 #
  70 
  71 ### default variables
  72 opt_blocksize=4096      # blocksize for alignment measurements
  73 sys_blocksize=512       # default system blocksize
  74 opt_client=0            # set if -c option set
  75 opt_clear=1             # set if screen to be cleared
  76 opt_json=0              # print in JSON format
  77 opt_top=0               # set if list trimmed to top
  78 top=0                   # number of lines trimmed
  79 interval=10             # default interval
  80 count=-1                # number of intervals to show
  81 
  82 ### process options
  83 while getopts b:c:Cjm:t: name
  84 do
  85     case $name in
  86         b)  opt_blocksize=$OPTARG ;;
  87         c)      opt_client=1; client_IP=$OPTARG ;;
  88         C)      opt_clear=0 ;;
  89         j)      opt_json=1 ;;
  90         t)      opt_top=1; top=$OPTARG ;;
  91         h|?)    cat <<END >&2
  92 USAGE: iscsisvrtop [-b blocksize] [-Cj] [-c client_IP] [-t top] 
  93                    [interval [count]]
  94         -b blocksize   # alignment blocksize (default=4096)
  95         -c client_IP   # trace for this client only
  96         -C             # don't clear the screen
  97         -j             # print output in JSON format
  98         -t top         # print top number of entries only
  99 examples:
 100     iscsisvrtop         # default output, 10 second samples
 101     iscsisvrtop 1       # 1 second samples
 102     iscsisvrtop -b 1024 # check alignment on 1KB boundary
 103     iscsisvrtop -C 60   # 60 second samples, do not clear screen
 104     iscsisvrtop -t 20   # print top 20 lines only
 105     iscsisvrtop 5 12    # print 12 x 5 second samples
 106 END
 107                 exit 1
 108         esac
 109 done
 110 
 111 shift $(( $OPTIND - 1 ))
 112 
 113 ### option logic
 114 if [[ "$1" > 0 ]]; then
 115     interval=$1; shift
 116 fi
 117 if [[ "$1" > 0 ]]; then
 118     count=$1; shift
 119 fi
 120 if (( opt_clear )); then
 121     clearstr=$(clear)
 122 else
 123     clearstr=""
 124 fi
 125 
 126 
 127 
 128 #################################
 129 # --- Main Program, DTrace ---
 130 #
 131 /usr/sbin/dtrace -n '
 132 /*
 133  * iscsisvrtop - Command line arguments
 134  */
 135 inline int OPT_blocksize = '$opt_blocksize' / '$sys_blocksize';
 136 inline int OPT_client   = '$opt_client';
 137 inline int OPT_clear    = '$opt_clear';
 138 inline int OPT_json     = '$opt_json';
 139 inline int OPT_top      = '$opt_top';
 140 inline int INTERVAL     = '$interval';
 141 inline int COUNTER      = '$count';
 142 inline int TOP  = '$top';
 143 inline string CLIENT    = "'$client_IP'";
 144 inline string CLEAR     = "'$clearstr'";
 145 
 146 #pragma D option quiet
 147 
 148 /* increase dynvarsize if you get "dynamic variable drops" */
 149 #pragma D option dynvarsize=8m
 150 
 151 /*
 152  * Print header
 153  */
 154 dtrace:::BEGIN 
 155 {
 156     /* starting values */
 157     counts = COUNTER;
 158     secs = INTERVAL;
 159     total_bytes_read = 0;
 160     total_bytes_write = 0;
 161 
 162     printf("Tracing... Please wait.\n");
 163 }
 164 
 165 /*
 166  * Filter as needed, based on starts
 167  */
 168 iscsi:::xfer-start,
 169 iscsi:::nop-receive
 170 /OPT_client == 0 || CLIENT == args[0]->ci_remote/
 171 { 
 172     @count_iops[args[0]->ci_remote] = count();
 173     OPT_client == 0 ? @count_iops["all"] = count() : 1;
 174     ts[arg1] = timestamp;
 175 }
 176 
 177 /* 
 178  * read operations 
 179  */
 180 iscsi:::xfer-done 
 181 /ts[arg1] != 0 && args[2]->xfer_type == 0/
 182 {
 183     t = timestamp - ts[arg1];
 184     @count_read[args[0]->ci_remote] = count();
 185     OPT_client == 0 ? @count_read["all"] = count() : 1;
 186     @avgtime_read[args[0]->ci_remote] = avg(t);
 187     OPT_client == 0 ? @avgtime_read["all"] = avg(t) : 1;
 188     @bytes_read[args[0]->ci_remote] = sum(args[2]->xfer_len);
 189     OPT_client == 0 ? @bytes_read["all"] = sum(args[2]->xfer_len) : 1;
 190     @avg_bytes_read[args[0]->ci_remote] = avg(args[2]->xfer_len);
 191     OPT_client == 0 ? @avg_bytes_read["all"] = avg(args[2]->xfer_len) : 1;
 192     total_bytes_read += args[2]->xfer_len;
 193     ts[arg1] = 0;
 194 }
 195 
 196 /*
 197  * write operations
 198  */
 199 iscsi:::xfer-done 
 200 /ts[arg1] != 0 && args[2]->xfer_type == 1/
 201 {
 202     t = timestamp - ts[arg1];
 203     @count_write[args[0]->ci_remote] = count();
 204     OPT_client == 0 ? @count_write["all"] = count() : 1;
 205     @avgtime_write[args[0]->ci_remote] = avg(t);
 206     OPT_client == 0 ? @avgtime_write["all"] = avg(t) : 1;
 207     @bytes_write[args[0]->ci_remote] = sum(args[2]->xfer_len);
 208     OPT_client == 0 ? @bytes_write["all"] = sum(args[2]->xfer_len) : 1;
 209     @avg_bytes_write[args[0]->ci_remote] = avg(args[2]->xfer_len);
 210     OPT_client == 0 ? @avg_bytes_write["all"] = avg(args[2]->xfer_len) : 1;
 211     total_bytes_write += args[2]->xfer_len;
 212     @avg_aligned[args[0]->ci_remote] = 
 213     avg((args[2]->xfer_loffset % OPT_blocksize) ? 0 : 100);
 214     ts[arg1] = 0;
 215 }
 216 
 217 /*
 218  * nops are ops too!
 219  */
 220 iscsi:::nop-send
 221 /ts[arg1] != 0/
 222 {
 223     t = timestamp - ts[arg1];
 224     @count_nop[args[0]->ci_remote] = count();
 225     OPT_client == 0 ? @count_nop["all"] = count() : 1;
 226     @avgtime_nop[args[0]->ci_remote] = avg(t);
 227     OPT_client == 0 ? @avgtime_nop["all"] = avg(t) : 1;
 228     ts[arg1] = 0;
 229 } 
 230 
 231 /*
 232  * timer
 233  */
 234 profile:::tick-1sec
 235 {
 236     secs--;
 237 }
 238 
 239 /*
 240  * Print report
 241  */
 242 profile:::tick-1sec
 243 /secs == 0/
 244 {       
 245     /* fetch 1 min load average */
 246     self->load1a  = `hp_avenrun[0] / 65536;
 247     self->load1b  = ((`hp_avenrun[0] % 65536) * 100) / 65536;
 248 
 249     /* convert counters to Kbytes */
 250     total_bytes_read /= 1024;
 251     total_bytes_write /= 1024;
 252 
 253     /* normalize to seconds giving a rate */
 254     /* todo: this should be measured, not based on the INTERVAL */
 255     normalize(@count_iops, INTERVAL);
 256     normalize(@count_read, INTERVAL);
 257     normalize(@count_write, INTERVAL);
 258     normalize(@count_nop, INTERVAL);
 259 
 260     /* normalize to KB per second */
 261     normalize(@bytes_read, 1024 * INTERVAL);
 262     normalize(@avg_bytes_read, 1024 * INTERVAL);
 263     normalize(@bytes_write, 1024 * INTERVAL);
 264     normalize(@avg_bytes_write, 1024 * INTERVAL);
 265 
 266     /* normalize average to microseconds */
 267     normalize(@avgtime_read, 1000);
 268     normalize(@avgtime_write, 1000);
 269     normalize(@avgtime_nop, 1000);
 270 
 271     /* print status */
 272     OPT_clear && !OPT_json ? printf("%s", CLEAR) : 1;
 273 
 274     OPT_json ?
 275         printf("{ \"collector\": \"iscsisvrtop\", \"time\": \"%Y\", \"timestamp\": %d, \"interval\": %d, \"load\": %d.%02d, \"read_KB_int\": %d, \"write_KB_int\": %d, \n \"clientdata\": [",
 276             walltimestamp, walltimestamp, INTERVAL, 
 277             self->load1a, self->load1b, 
 278             total_bytes_read, total_bytes_write)
 279     :
 280         printf("%Y load: %d.%02d read_KB: %d write_KB: %d\n",
 281             walltimestamp, self->load1a, self->load1b, 
 282             total_bytes_read, total_bytes_write);
 283 
 284     /* print headers */
 285     OPT_json ? 1 :
 286         printf("%-15s\t%7s\t%7s\t%7s\t%7s\t%7s\t%7s\t%7s\t%7s\t%7s\t%7s\t%7s\t%7s\n",
 287             "client", "ops", "reads", "writes", "nops", "rd_bw", "wr_bw",
 288             "ard_sz", "awr_sz", "rd_t", "wr_t", "nop_t", "align%");
 289 
 290     /* truncate to top lines if needed */
 291     OPT_top ? trunc(@count_iops, TOP) : 1;
 292 
 293     OPT_json ?
 294         printa("{\"address\": \"%s\", \"iops\": %@d, \"reads\": %@d, \"writes\": %@d, \"nops\": %@d, \"read_bw\": %@d, \"write_bw\": %@d, \"avg_read_size\": %@d, \"avg_write_size\": %@d, \"avg_read_t\": %@d, \"avg_write_t\": %@d, \"avg_nop_t\": %@d, \"aligned_pct\": %@d},",
 295             @count_iops, @count_read, @count_write, @count_nop,
 296             @bytes_read, @bytes_write, @avg_bytes_read, @avg_bytes_write,
 297             @avgtime_read, @avgtime_write, @avgtime_nop, @avg_aligned)
 298     :
 299         printa("%-15s\t%7@d\t%7@d\t%7@d\t%7@d\t%7@d\t%7@d\t%7@d\t%7@d\t%7@d\t%7@d\t%7@d\t%7@d\n",
 300             @count_iops, @count_read, @count_write, @count_nop,
 301             @bytes_read, @bytes_write, @avg_bytes_read, @avg_bytes_write,
 302             @avgtime_read, @avgtime_write, @avgtime_nop, @avg_aligned);
 303 
 304     OPT_json ? printf("{}]}\n") : 1;
 305 
 306     /* clear data */
 307     trunc(@count_iops); trunc(@count_read); trunc(@count_write); 
 308     trunc(@count_nop); trunc(@bytes_read); trunc(@bytes_write);
 309     trunc(@avg_bytes_read); trunc(@avg_bytes_write);
 310     trunc(@avgtime_read); trunc(@avgtime_write); trunc(@avgtime_nop);
 311     trunc(@avg_aligned);
 312     total_bytes_read = 0;
 313     total_bytes_write = 0;
 314     secs = INTERVAL;
 315     counts--;
 316 }
 317 
 318 /*
 319  * end of program 
 320  */
 321 profile:::tick-1sec
 322 /counts == 0/
 323 {
 324     exit(0);
 325 }
 326 
 327 /*
 328  * clean up when interrupted
 329  */
 330 dtrace:::END
 331 {
 332     trunc(@count_iops); trunc(@count_read); trunc(@count_write); 
 333     trunc(@count_nop); trunc(@bytes_read); trunc(@bytes_write);
 334     trunc(@avg_bytes_read); trunc(@avg_bytes_write);
 335     trunc(@avgtime_read); trunc(@avgtime_write); trunc(@avgtime_nop);
 336     trunc(@avg_aligned);
 337 }
 338 '