Monitoring virtual FC Client Traffic

With the LPAR tool, statistics for all virtual FC clients can be displayed at any time using the “vios fcstat” command. This allows you to determine at any time which client LPARs have which I/O throughput (when using NPIV).

Which NPIV-capable FC adapters are available on a virtual I/O server can easily be found out with “vios lsnports“:

$ vios lsnports ms15-vio1
NAME  PHYSLOC                     FABRIC  TPORTS  APORTS  SWWPNS  AWWPNS
fcs0  U78CB.001.XXXXXXX-P1-C5-T1  1       64      62      2032    2012
fcs1  U78CB.001.XXXXXXX-P1-C5-T2  1       64      62      2032    2012
fcs2  U78CB.001.XXXXXXX-P1-C5-T3  1       64      61      2032    1979
fcs3  U78CB.001.XXXXXXX-P1-C5-T4  1       64      61      2032    1979
fcs4  U78CB.001.XXXXXXX-P1-C3-T1  1       64      50      3088    3000
fcs5  U78CB.001.XXXXXXX-P1-C3-T2  1       64      63      3088    3077
$

We display the FC client statistics with the command “vios fcstat”. By default, the data for all virtual FC clients of the specified virtual I/O server are shown every 10 seconds:

$ vios fcstat ms15-vio1
HOSTNAME   PHYSDEV  WWPN                DEV    INREQS    INBYTES      OUTREQS    OUTBYTES     CTRLREQS
ms15-vio1  fcs1     0x210000XXXXX56EC5  fcs1   774.75/s  129.51 MB/s  1332.71/s   92.96 MB/s  20
aixtsmp1   fcs2     0xC050760XXXXX0058  fcs6   318.10/s   83.39 MB/s  481.34/s   126.18 MB/s  0
ms15-vio1  fcs2     0x210000XXXXX56EC6  fcs2   318.10/s   83.39 MB/s  480.78/s   126.03 MB/s  0
aixtsmp1   fcs5     0xC050760XXXXX003E  fcs0   583.98/s   60.35 MB/s  1835.17/s  124.86 MB/s  0
ms15-vio1  fcs5     0x10000090XXXXX12D  fcs5   583.70/s   60.27 MB/s  1836.21/s  124.92 MB/s  0
ms15-vio1  fcs0     0x21000024XXXXXEC4  fcs0   923.19/s  165.08 MB/s  1032.81/s   17.25 MB/s  46
aixtsmp3   fcs1     0xC050760XXXXX00E4  fcs0   775.12/s  129.48 MB/s  1047.32/s   17.15 MB/s  20
aixtsmp3   fcs0     0xC050760XXXXX00DE  fcs1   775.78/s  128.99 MB/s  1037.99/s   17.39 MB/s  20
aixtsmp1   fcs1     0xC050760XXXXX0056  fcs5     0.00/s    0.00 B/s   290.39/s    76.12 MB/s  0
aixtsmp1   fcs0     0xC050760XXXXX0052  fcs4   142.89/s   36.12 MB/s    0.00/s     0.00 B/s   26
ms15-vio1  fcs4     0x10000090XXXXX12C  fcs4   234.97/s    4.58 MB/s  621.78/s    11.12 MB/s  40
cus1dbp01  fcs4     0xC050760XXXXX0047  fcs0   243.55/s    5.05 MB/s  432.33/s     9.95 MB/s  0
cus1dbi01  fcs4     0xC050760XXXXX0044  fcs1     0.94/s   10.42 KB/s   87.28/s   459.26 KB/s  0
...
HOSTNAME   PHYSDEV  WWPN                DEV    INREQS     INBYTES      OUTREQS    OUTBYTES     CTRLREQS
aixtsmp1   fcs5     0xC050760XXXXX003E  fcs0   1772.84/s  162.24 MB/s  1309.30/s   70.60 MB/s  68
ms15-vio1  fcs5     0x10000090XXXXX12D  fcs5   1769.13/s  161.95 MB/s  1305.60/s   70.54 MB/s  68
ms15-vio1  fcs1     0x21000024XXXXXEC5  fcs1   883.55/s   118.97 MB/s  1551.97/s  108.78 MB/s  43
ms15-vio1  fcs2     0x21000024XXXXXEC6  fcs2   201.09/s    52.72 MB/s  497.26/s   130.35 MB/s  0
aixtsmp1   fcs2     0xC050760XXXXX0058  fcs6   201.09/s    52.72 MB/s  495.40/s   129.87 MB/s  0
ms15-vio1  fcs0     0x21000024XXXXXEC4  fcs0   923.54/s   128.89 MB/s  1234.98/s   23.31 MB/s  65
aixtsmp3   fcs0     0xC050760XXXXX00DE  fcs1   876.93/s   118.93 MB/s  1234.98/s   23.32 MB/s  44
aixtsmp3   fcs1     0xC050760XXXXX00E4  fcs0   884.17/s   119.07 MB/s  1223.50/s   23.00 MB/s  43
aixtsmp1   fcs1     0xC050760XXXXX0056  fcs5     0.00/s     0.00 B/s   325.83/s    85.41 MB/s  0
...
^C
$

The LPAR name, the physical FC port (PHYSDEV) on the virtual I/O server, the WWPN of the client adapter, the virtual FC client port (DEV), as well as the number of requests (INREQS and OUTREQS) and thereby transferred bytes (INBYTES and OUTBYTES). The transfer rates are output in KB/s, MB/s or GB/s. The output can be very long on larger systems! The output is sorted according to throughput, i.e. the most active virtual client adapters are output first. With the option ‘-t‘ (top) the output can be restricted to a desired number of data records: e.g. with ‘-t 10‘ only the top ten adapters with the highest throughput are shown. In addition, the interval length (in seconds) can be specified via a further argument, here is a short example:

$ vios fcstat -t 10 ms15-vio1 2
HOSTNAME   PHYSDEV  WWPN                DEV   INREQS     INBYTES      OUTREQS    OUTBYTES     CTRLREQS
ms15-vio1  fcs1     0x21000024XXXXXEC5  fcs1  1034.58/s   86.56 MB/s  2052.23/s  160.11 MB/s  20
ms15-vio1  fcs5     0x10000090XXXXX12D  fcs5  1532.63/s  115.60 MB/s  1235.72/s  118.32 MB/s  40
aixtsmp1   fcs5     0xC050760XXXXX003E  fcs0  1510.33/s  114.88 MB/s  1236.49/s  118.27 MB/s  40
aixtsmp3   fcs1     0xC050760XXXXX00E4  fcs0  1036.11/s   86.67 MB/s  1612.25/s   44.86 MB/s  20
aixtsmp3   fcs0     0xC050760XXXXX00DE  fcs1  1031.50/s   86.29 MB/s  1588.02/s   44.27 MB/s  20
ms15-vio1  fcs0     0x21000024XXXXXEC4  fcs0  1029.58/s   86.31 MB/s  1567.63/s   43.65 MB/s  20
aixtsmp1   fcs1     0xC050760XXXXX0056  fcs5    0.00/s     0.00 B/s   436.52/s   114.43 MB/s  0
ms15-vio1  fcs2     0x21000024XXXXXEC6  fcs2    0.00/s     0.00 B/s   435.75/s   114.23 MB/s  0
aixtsmp1   fcs2     0xC050760XXXXX0058  fcs6    0.00/s     0.00 B/s   432.68/s   113.42 MB/s  0
ms15-vio1  fcs4     0x10000090XXXXX12C  fcs4  144.99/s     0.78 MB/s  478.83/s     2.22 MB/s  46
HOSTNAME   PHYSDEV  WWPN                DEV   INREQS    INBYTES      OUTREQS    OUTBYTES     CTRLREQS
aixtsmp1   fcs5     0xC050760XXXXX003E  fcs0  758.14/s   35.55 MB/s  1822.99/s  112.60 MB/s  0
ms15-vio1  fcs5     0x10000090XXXXX12D  fcs5  757.38/s   35.52 MB/s  1821.46/s  112.59 MB/s  0
ms15-vio1  fcs0     0x21000024XXXXXEC4  fcs0  944.23/s   85.09 MB/s  1657.58/s   41.40 MB/s  2
aixtsmp3   fcs0     0xC050760XXXXX00DE  fcs1  943.47/s   85.15 MB/s  1636.90/s   40.68 MB/s  2
ms15-vio1  fcs1     0x21000024XXXXXEC5  fcs1  949.21/s   84.88 MB/s  1586.74/s   39.41 MB/s  2
aixtsmp3   fcs1     0xC050760XXXXX00E4  fcs0  946.53/s   84.64 MB/s  1584.83/s   39.40 MB/s  2
ms15-vio1  fcs4     0x10000090XXXXX12C  fcs4   39.44/s  449.92 KB/s  676.97/s     3.63 MB/s  10
cus1dbp01  fcs4     0xC050760XXXXX0047  fcs0   29.10/s  471.69 KB/s  310.92/s     1.28 MB/s  4
cus1mqp01  fcs4     0xC050760XXXXX002C  fcs0    1.91/s    4.71 KB/s  230.12/s     1.66 MB/s  0
cus2orap01 fcs4     0xC050760XXXXX000F  fcs0    0.77/s    4.31 KB/s   48.25/s   263.49 KB/s  0
^C
$

The option ‘-s‘ (select) can be used to select and show only data records from a specific client (‘-s hostname = aixtsmp1‘) or only data records from a specific physical port (‘-s physdev = fcs1‘):

$ vios fcstat -s hostname=aixtsmp1 ms15-vio1 2
HOSTNAME  PHYSDEV  WWPN                DEV   INREQS     INBYTES      OUTREQS    OUTBYTES     CTRLREQS
aixtsmp1  fcs5     0xC050760XXXXX003E  fcs0  1858.72/s   51.14 MB/s  1231.82/s  104.20 MB/s  0
aixtsmp1  fcs2     0xC050760XXXXX0058  fcs6    6.94/s     1.82 MB/s    6.94/s     1.82 MB/s  0
aixtsmp1  fcs4     0xC050760XXXXX0042  fcs2    0.39/s     1.19 KB/s    0.39/s   395.05 B/s   0
aixtsmp1  fcs1     0xC050760XXXXX0056  fcs5    0.39/s     7.72 B/s     0.00/s     0.00 B/s   1
aixtsmp1  fcs0     0xC050760XXXXX0052  fcs4    0.00/s     0.00 B/s     0.00/s     0.00 B/s   0
aixtsmp1  fcs3     0xC050760XXXXX005A  fcs7    0.00/s     0.00 B/s     0.00/s     0.00 B/s   0
HOSTNAME  PHYSDEV  WWPN                DEV   INREQS     INBYTES      OUTREQS    OUTBYTES     CTRLREQS
aixtsmp1  fcs5     0xC050760XXXXX003E  fcs0  1760.48/s  111.48 MB/s  1125.70/s   95.20 MB/s  0
aixtsmp1  fcs2     0xC050760XXXXX0058  fcs6    8.53/s     2.24 MB/s  484.61/s   127.04 MB/s  0
aixtsmp1  fcs1     0xC050760XXXXX0056  fcs5    0.00/s     0.00 B/s   469.04/s   122.96 MB/s  0
aixtsmp1  fcs4     0xC050760XXXXX0042  fcs2    0.37/s     1.14 KB/s    0.00/s     0.00 B/s   0
aixtsmp1  fcs0     0xC050760XXXXX0052  fcs4    0.00/s     0.00 B/s     0.00/s     0.00 B/s   0
aixtsmp1  fcs3     0xC050760XXXXX005A  fcs7    0.00/s     0.00 B/s     0.00/s     0.00 B/s   0
^C
$

With the “vios fcstat” command, FC throughput of any LPAR can be shown at any time in an extremely simple way, at the push of a button, so to speak.

If the intervals are smaller, the accuracy of the displayed values suffers. At 2 second intervals the inaccuracy is approx. 10%. However, the relationship between the displayed values is still correct.

nmon_printer: quick view into NMON files

Many administrators use NMON to collect performance data on AIX systems. The collected data can then be visualized graphically with the NMON analyzer for example. Alternatively, one can of course also use njmon. Sometimes you want to take a quick look into an NMON file on the AIX system itself. Of course, this can be done with grep, awk, and other standard UNIX utilities. However, the appropriate command line must always be considered and typed in and the output is not always very readable.

For such a quick look into an NMON file, we have provided the script nmon_printer in our download area. With the nmon_printer you can easily list which data records have been collected in the NMON file:

$ nmon_printer -l aix01_200718.nmon
CPU_ALL -     CPU Total aix01
CPU01 -       CPU 1 aix01
CPU02 -       CPU 2 aix01
CPU03 -       CPU 3 aix01
CPU04 -       CPU 4 aix01
CPU05 -       CPU 5 aix01
CPU06 -       CPU 6 aix01
CPU07 -       CPU 7 aix01
CPU08 -       CPU 8 aix01
MEM -         Memory aix01
MEMNEW -      Memory New aix01
MEMUSE -      Memory Use aix01
PAGE -        Paging aix01
...
$

To display the data records, in addition to the NMON file, you must also specify the desired data record to be displayed, upper or lower case is irrelevant. Here is an example of CPU_ALL:

$ nmon_printer aix01_200718.nmon cpu_all
  CPU_ALL             Timestamp  User%  Sys%  Wait%  Idle%  Busy  PhysicalCPUs 
  CPU_ALL  00:05:15 17-JUL-2020    1.2   3.0    0.1   95.7   4.2              8
  CPU_ALL  00:10:15 17-JUL-2020    1.3   2.7    0.0   96.0   3.9              8
  CPU_ALL  00:15:15 17-JUL-2020    1.0   2.3    0.1   96.7   3.3              8
  CPU_ALL  00:20:16 17-JUL-2020    5.1   3.0    0.1   91.8   8.2              8
  CPU_ALL  00:25:16 17-JUL-2020    1.2   2.7    0.0   96.0   3.9              8
  CPU_ALL  00:30:16 17-JUL-2020    1.1  17.5    0.1   81.3  18.5              8
  CPU_ALL  00:35:16 17-JUL-2020    1.1   5.8    0.0   93.1   6.9              8
...
$

In some cases, a data record has so many fields that long lines have to be broken and the output becomes somewhat confusing. The data record LPAR has e.g. 23 fields! In such cases, or if you are only interested in certain fields, you can specify the desired fields with the ‘-f‘ option. You can either specify the desired fields separated by commas:

$ nmon_printer -f 0,1,2,13,14,15 aix01_200718.nmon lpar
  LPAR             Timestamp  PhysicalCPU  EC_User%  EC_Sys%  EC_Wait%
  LPAR  00:05:15 17-JUL-2020        0.037      1.23     2.95      0.00
  LPAR  00:10:15 17-JUL-2020        0.034      1.28     2.66      0.00
  LPAR  00:15:15 17-JUL-2020        0.029      1.03     2.25      0.00
  LPAR  00:20:16 17-JUL-2020        0.064      5.14     3.01      0.00
  LPAR  00:25:16 17-JUL-2020        0.035      1.21     2.69      0.00
  LPAR  00:30:16 17-JUL-2020        0.150      1.08    17.46      0.02
  LPAR  00:35:16 17-JUL-2020        0.063      1.13     5.77      0.00
  LPAR  00:40:16 17-JUL-2020        0.030      1.13     2.24      0.00
  LPAR  00:45:16 17-JUL-2020        0.030      1.06     2.34      0.00
...
$

Or you can also specify ranges (e.g. 0-2 or 13-15):

$ nmon_printer -f 1,5-7 aix01_200718.nmon ioadapt
             Timestamp  fcs1_read-KB/s  fcs1_write-KB/s  fcs1_xfer-tps
  00:05:15 17-JUL-2020             0.0             27.3            3.0
  00:10:15 17-JUL-2020             0.0              0.0            2.6
  00:15:15 17-JUL-2020             0.0             13.6            2.8
  00:20:16 17-JUL-2020             0.0             13.6            2.3
  00:25:16 17-JUL-2020             0.0             13.7            2.3
  00:30:16 17-JUL-2020            27.3           4982.5           89.4
  00:35:16 17-JUL-2020            13.7             27.3            4.1
  00:40:16 17-JUL-2020             0.0             13.6            2.6
  00:45:16 17-JUL-2020             0.0             13.6            2.6
...
$

The fields are counted starting from 0.

ProbeVue in Action: Monitoring the Queue Depth of Disks

Disk and storage systems support Tagged Command Queuing, i.e. connected servers can send multiple I/O jobs to the disk or storage system without waiting for older I/O jobs to finish. The number of I/O requests you can send to a disk before you have to wait for older I/O requests to complete can be configured using the hdisk queue_depth attribute on AIX. For many hdisk types, the value 20 for the queue_depth is the default value. In general, most storage systems allow even greater values for the queue depth.

With the help of ProbeVue, the utilization of the disk queue can be monitored very easily.

Starting with AIX 7.1 TL4 or AIX 7.2 TL0, AIX supports the I/O Probe Manager. This makes it easy to trace events in AIX’s I/O stack. If an I/O is started by the disk driver, this is done via the iostart function in the kernel, the request is forwarded to the adapter driver and then passed to the storage system via the host bus adapter. Handling the response is done by the iodone function in the kernel. The I/O Probe Manager supports (among others) probe events at these locations:

@@io:disk:iostart:read:<filter>
@@io::disk:iostart:write:<filter>
@@io:disk:iodone:read:<filter>
@@io::disk:iodone:write:<filter>

As a filter, e.g. a hdisk name like hdisk2 can be specified. The probe points then only trigger events for the disk hdisk2. This allows to perform an action whenever an I/O for a hdisk begins or ends. This would allow to measure how long an I/O operation takes or just to count how many I/Os are executed. In our example, we were interested in the utilization of the disk queue, i.e. the number of I/Os sent to the disk which are not yet completed. The I/O Probe Manager has a built-in variable __diskinfo for the iostart and iodone I/O probe events with the following fields (https://www.ibm.com/support/knowledgecenter/en/ssw_aix_72/com.ibm.aix .genprogc / probevue_man_io.htm):

name          char*     Name of the disk.
…
queue_depth   int       The queue depth of the disk (value from ODM)
cmds_out      int       Number of outstanding I/Os
…

The cmds_out field indicates how many I/Os have already been sent to the disk for which the I/O has not yet been completed (response has not yet arrived at the server).

The following section of code determines the minimum, maximum, and average number of entries in the disk queue:

@@io:disk:iostart:*:hdisk0     // Only I/Os for hdisk0 are considered
{
   queue = __iopath->cmds_out; // Store number of outstanding I/Os in variable queue
   ++numIO;                    // Number of I/Os (used for calculating the average)
   avg += queue;               // Add number of outstanding I/Os to variable avg
   if ( queue < min )
      min = queue;             // Check if minimum
   if ( queue > max )
      max = queue;             // Check if maximum
}

The calculated values are then printed once per second using the interval probe manager:

@@interval:*:clock:1000
{
   if ( numIO == 0 )
      numIO = 1;    // Prevent division by 0 when calculating the average
   if ( min > max )
      min = max;
   printf( "%5d  %5d  %5d\n" , min , avg/numIO , max );
   min = 100000;   // Reset variables for the next interval
   avg = 0;
   max = 0;
   numIO = 0;
}

The full script is available for download on our website: ioqueue.e.

Here is a sample run of the script for the disk hdisk13:

# ./ioqueue.e hdisk13
  min    avg    max
    1      1      2
    1      1      9
    1      1      2
    1      1      8
    1      1      2
    1      1      2
    1      1      8
    1      1     10
    1      1      2
    1      1      1
    1      1     10
    1      1      2
    1      1     11
...

The script expects an hdisk as an argument, and then outputs once per second the values determined for the specified hdisk.

In the example output you can see that the maximum number of entries in the disk queue is 11. An increase of the attribute queue_depth therefore makes no sense from a performance perspective.

Here’s another example:

# ./ioqueue.e hdisk21
  min    avg    max
    9     15     20
   11     17     20
   15     19     20
   13     19     20
   14     19     20
   17     18     20
   18     18     19
   16     19     20
   13     18     20
   18     19     19
   17     19     20
   18     19     20
   17     19     19
...

In this case, the maximum value of 20 (the hdisk21 has a queue_depth of 20) is reached on a regular basis. Increasing the queue_depth can improve throughput in this case.

Of course, the sample script can be expanded in various ways; to determine the throughput in addition, or the waiting time of I/Os in the wait queue, or even the position and size of each I/O on the disk. This example just shows how easy it is to get information about I/Os using ProbeVue.

More Articles on ProbeVue

ProbeVue: Practical Introduction

ProbeVue: Practical Introduction II

ProbeVue in Action: Identifying a crashing Process

ProbeVue in Action: Monitoring the Queue Depth of Disks