After upgrading our test IBM SAN Volume Controller (SVC) systems from version 7.3.0.7 to 7.3.0.8 or later, the previously described Nagios monitoring plugin (Nagios Monitoring - IBM SVC and Storwize) ceased to work. A quick check revealed that the “wbemcli” command line tool from the Standards Based Linux Instrumentation project, which is used in the Nagios plugin to query the CIMOM server on the SVC or Storwize systems, would fail with the following error message:

$ /opt/sblim-wbemcli/bin/wbemcli -dx -noverify ecn https://user:pass@svc-test:5989/root/ibm
*
* /opt/sblim-wbemcli/bin/wbemcli: Http Exception: SSL connect error
*

Re-checking the release notes, this sudden change in behaviour seemed to be explained by the fix:

SSL vulnerability CVE-2014-3566

Not really being that verbose a description, a quick look at the CVE-2014-3566 showed that this is a fix for the “POODLE” issue. So IBM probably switched off the support for the SSLv3 protocol in the SVC and Storwize code. But why would this cause the “wbemcli” command line tool to fail? Here are the steps taken in an analysis of the issue:

1. First, i was trying to get the “wbemcli” command line tool to be a tad more verbose about what it is actually doing:

   $ /opt/sblim-wbemcli/bin/wbemcli -dx -noverify ecn https://user:pass@svc-test:5989/root/ibm
   To server: <?xml version="1.0" encoding="utf-8" ?>
   <CIM CIMVERSION="2.0" DTDVERSION="2.0">
   <MESSAGE ID="4711" PROTOCOLVERSION="1.0"><SIMPLEREQ><IMETHODCALL NAME="EnumerateClassNames"><LOCALNAMESPACEPATH><NAMESPACE NAME="root"></NAMESPACE><NAMESPACE NAME="ibm"></NAMESPACE></LOCALNAMESPACEPATH>
   <IPARAMVALUE NAME="DeepInheritance"><VALUE>TRUE</VALUE></IPARAMVALUE>
   </IMETHODCALL></SIMPLEREQ>
   </MESSAGE></CIM>
   *
   * /opt/sblim-wbemcli/bin/wbemcli: Http Exception: SSL connect error
   *

   Not really an abundance of information in here too.

2. Getting the source code for and, while we're at it, updating the “wbemcli” command line tool from version 1.6.0 to 1.6.3. Spent some time looking through the source code and with the “gdb” debugger to get a feeling for the general program flow and functions/methods being called. While looking through the source code i noticed the cURL debugging options are being set if a environment variable named “CURLDEBUG” is set to “true”. Later also found this mentioned in the ChangeLog file:

   $ CURLDEBUG=true /opt/sblim-wbemcli/bin/wbemcli -dx -noverify ecn https://user:pass@svc-test:5989/root/ibm
   To server: <?xml version="1.0" encoding="utf-8" ?>
   <CIM CIMVERSION="2.0" DTDVERSION="2.0">
   <MESSAGE ID="4711" PROTOCOLVERSION="1.0"><SIMPLEREQ><IMETHODCALL NAME="EnumerateClassNames"><LOCALNAMESPACEPATH><NAMESPACE NAME="root"></NAMESPACE><NAMESPACE NAME="ibm"></NAMESPACE></LOCALNAMESPACEPATH>
   <IPARAMVALUE NAME="DeepInheritance"><VALUE>TRUE</VALUE></IPARAMVALUE>
   </IMETHODCALL></SIMPLEREQ>
   </MESSAGE></CIM>
   * About to connect() to svc-test port 5989 (#0)
   *   Trying 192.168.x.x...
   * connected
   * Connected to svc-test (192.168.x.x) port 5989 (#0)
   * successfully set certificate verify locations:
   *   CAfile: none
     CApath: /etc/ssl/certs
   * Unknown SSL protocol error in connection to svc-test:5989
   * Closing connection #0
   * SSL connect error
   *
   * /opt/sblim-wbemcli/bin/wbemcli: Http Exception: SSL connect error
   *

   Now we know that we're encountering a “Unknown SSL protocol error” – not that helpful either.

3. Searched the web for further information on how to debug the cURL library and found the debug.c example source code, which was very helpful. Incorperated it into the file “CimCurl.cpp”:

   sblim-wbemcli-1.6.3_debug.patch

   --- sblim-wbemcli-1.6.3_orig/CimCurl.cpp    2013-09-21 01:26:32.000000000 +0200
   +++ sblim-wbemcli-1.6.3_new/CimCurl.cpp     2014-11-26 16:30:19.000000000 +0100
   @@ -37,6 +37,100 @@
    extern int waitTime;
    extern int expect100;
    
   +// Trace Begin
   +struct data {
   +  char trace_ascii; /* 1 or 0 */ 
   +};
   +
   +static
   +void dump(const char *text,
   +          FILE *stream, unsigned char *ptr, size_t size,
   +          char nohex)
   +{ 
   +  size_t i;
   +  size_t c;
   +  
   +  unsigned int width=0x10;
   +  
   +  if(nohex)
   +    /* without the hex output, we can fit more on screen */
   +    width = 0x40;
   +
   +  fprintf(stream, "%s, %010.10ld bytes (0x%08.8lx)\n",
   +          text, (long)size, (long)size);
   +
   +  for(i=0; i<size; i+= width) {
   +
   +    fprintf(stream, "%04.4lx: ", (long)i);
   +
   +    if(!nohex) {
   +      /* hex not disabled, show it */
   +      for(c = 0; c < width; c++)
   +        if(i+c < size)
   +          fprintf(stream, "%02x ", ptr[i+c]);
   +        else
   +          fputs("   ", stream);
   +    }
   +
   +    for(c = 0; (c < width) && (i+c < size); c++) {
   +      /* check for 0D0A; if found, skip past and start a new line of output */
   +      if (nohex && (i+c+1 < size) && ptr[i+c]==0x0D && ptr[i+c+1]==0x0A) {
   +        i+=(c+2-width);
   +        break;
   +      }
   +      fprintf(stream, "%c",
   +              (ptr[i+c]>=0x20) && (ptr[i+c]<0x80)?ptr[i+c]:'.');
   +      /* check again for 0D0A, to avoid an extra \n if it's at width */
   +      if (nohex && (i+c+2 < size) && ptr[i+c+1]==0x0D && ptr[i+c+2]==0x0A) {
   +        i+=(c+3-width);
   +        break;
   +      }
   +    }
   +    fputc('\n', stream); /* newline */
   +  }
   +  fflush(stream);
   +}
   +
   +static
   +int my_trace(CURL *handle, curl_infotype type,
   +             char *data, size_t size,
   +             void *userp)
   +{
   +  struct data *config = (struct data *)userp;
   +  const char *text;
   +  (void)handle; /* prevent compiler warning */
   +
   +  switch (type) {
   +  case CURLINFO_TEXT:
   +    fprintf(stderr, "== Info: %s", data);
   +  default: /* in case a new one is introduced to shock us */
   +    return 0;
   +
   +  case CURLINFO_HEADER_OUT:
   +    text = "=> Send header";
   +    break;
   +  case CURLINFO_DATA_OUT:
   +    text = "=> Send data";
   +    break;
   +  case CURLINFO_SSL_DATA_OUT:
   +    text = "=> Send SSL data";
   +    break;
   +  case CURLINFO_HEADER_IN:
   +    text = "<= Recv header";
   +    break;
   +  case CURLINFO_DATA_IN:
   +    text = "<= Recv data";
   +    break;
   +  case CURLINFO_SSL_DATA_IN:
   +    text = "<= Recv SSL data";
   +    break;
   +  }
   +
   +  dump(text, stderr, (unsigned char *)data, size, config->trace_ascii);
   +  return 0;
   +}
   +// Trace End
   +
    // These are the constant headers added to all requests
    static const char *headers[] = {
        "Content-Type: application/xml; charset=\"utf-8\"",
   @@ -152,6 +246,11 @@
        CURLcode rv;
        string sb;
    
   +// Trace Begin
   +struct data config;
   +config.trace_ascii = 1;
   +// Trace End
   +
        mUri = url.scheme + "://" + url.host + ":" + url.port + "/cimom";
        url.ns.toStringBuffer(sb,"%2F");
    
   @@ -248,6 +347,11 @@
    
        rv = curl_easy_setopt(mHandle, CURLOPT_WRITEHEADER, &mErrorData);
        rv = curl_easy_setopt(mHandle, CURLOPT_HEADERFUNCTION, headerCb);
   +
   +// Trace Begin
   +    rv = curl_easy_setopt(mHandle, CURLOPT_DEBUGFUNCTION, my_trace);
   +    rv = curl_easy_setopt(mHandle, CURLOPT_DEBUGDATA, &config);
   +// Trace End
    }
    
    static string getErrorMessage(CURLcode err)

   rebuild the “wbemcli” command line tool and tried again:

   $ CURLDEBUG=true /opt/sblim-wbemcli/bin/wbemcli -dx -noverify ecn https://user:pass@svc-test:5989/root/ibm
   To server: <?xml version="1.0" encoding="utf-8" ?>
   <CIM CIMVERSION="2.0" DTDVERSION="2.0">
   <MESSAGE ID="4711" PROTOCOLVERSION="1.0"><SIMPLEREQ><IMETHODCALL NAME="EnumerateClassNames"><LOCALNAMESPACEPATH><NAMESPACE NAME="root"></NAMESPACE><NAMESPACE NAME="ibm"></NAMESPACE></LOCALNAMESPACEPATH>
   <IPARAMVALUE NAME="DeepInheritance"><VALUE>TRUE</VALUE></IPARAMVALUE>
   </IMETHODCALL></SIMPLEREQ>
   </MESSAGE></CIM>
   == Info: About to connect() to svc-test port 5989 (#0)
   == Info:   Trying 192.168.x.x...
   == Info: connected
   == Info: Connected to svc-test (192.168.x.x) port 5989 (#0)
   == Info: found 172 certificates in /etc/ssl/certs/ca-certificates.crt
   == Info: gnutls_handshake() failed: A TLS packet with unexpected length was received.
   == Info: Closing connection #0
   == Info: SSL connect error
   *
   * /opt/sblim-wbemcli/bin/wbemcli: Http Exception: SSL connect error
   *

   Now we know there is an issue in the way the GnuTLS library used by libcURL interacts with the CIMOM server on the SVC or Storwize systems.

4. Again, searching the web for similar issues with the error message “gnutls_handshake() failed: A TLS packet with unexpected length was received.”, we find a rebuild against the OpenSSL library instead of the GnuTLS library could solve this issue:

   $ dpkg -l | grep curl
   ii  curl                        7.26.0-1+wheezy11   powerpc     command line tool for transferring data with URL syntax
   ii  libcurl3:powerpc            7.26.0-1+wheezy11   powerpc     easy-to-use client-side URL transfer library (OpenSSL flavour)
   ii  libcurl3-gnutls:powerpc     7.26.0-1+wheezy11   powerpc     easy-to-use client-side URL transfer library (GnuTLS flavour)
   ii  libcurl4-gnutls-dev         7.26.0-1+wheezy11   powerpc     development files and documentation for libcurl (GnuTLS flavour)
   
   $ apt-get install libcurl4-openssl-dev
   Reading package lists... Done
   Building dependency tree
   Reading state information... Done
   Suggested packages:
     libcurl3-dbg
   The following packages will be REMOVED:
     libcurl4-gnutls-dev
   The following NEW packages will be installed:
     libcurl4-openssl-dev
   0 upgraded, 1 newly installed, 1 to remove and 0 not upgraded.
   Need to get 0 B/1,259 kB of archives.
   After this operation, 28.7 kB of additional disk space will be used.
   Do you want to continue [Y/n]? y
   (Reading database ... 65717 files and directories currently installed.)
   Removing libcurl4-gnutls-dev ...
   Processing triggers for man-db ...
   Selecting previously unselected package libcurl4-openssl-dev.
   (Reading database ... 65463 files and directories currently installed.)
   Unpacking libcurl4-openssl-dev (from .../libcurl4-openssl-dev_7.26.0-1+wheezy11_powerpc.deb) ...
   Processing triggers for man-db ...
   Setting up libcurl4-openssl-dev (7.26.0-1+wheezy11) ...
   
   $ dpkg -l | grep curl
   ii  curl                        7.26.0-1+wheezy11   powerpc     command line tool for transferring data with URL syntax
   ii  libcurl3:powerpc            7.26.0-1+wheezy11   powerpc     easy-to-use client-side URL transfer library (OpenSSL flavour)
   ii  libcurl3-gnutls:powerpc     7.26.0-1+wheezy11   powerpc     easy-to-use client-side URL transfer library (GnuTLS flavour)
   ii  libcurl4-openssl-dev        7.26.0-1+wheezy11   powerpc     development files and documentation for libcurl (OpenSSL flavour)

   Rebuild the “wbemcli” command line tool and tried again:

   $ CURLDEBUG=true /opt/sblim-wbemcli/bin/wbemcli -dx -noverify ecn https://user:pass@svc-test:5989/root/ibm
   To server: <?xml version="1.0" encoding="utf-8" ?>
   <CIM CIMVERSION="2.0" DTDVERSION="2.0">
   <MESSAGE ID="4711" PROTOCOLVERSION="1.0"><SIMPLEREQ><IMETHODCALL NAME="EnumerateClassNames"><LOCALNAMESPACEPATH><NAMESPACE NAME="root"></NAMESPACE><NAMESPACE NAME="ibm"></NAMESPACE></LOCALNAMESPACEPATH>
   <IPARAMVALUE NAME="DeepInheritance"><VALUE>TRUE</VALUE></IPARAMVALUE>
   </IMETHODCALL></SIMPLEREQ>
   </MESSAGE></CIM>
   == Info: About to connect() to svc-test port 5989 (#0)
   == Info:   Trying 192.168.x.x...
   == Info: connected
   == Info: Connected to svc-test (192.168.x.x) port 5989 (#0)
   == Info: successfully set certificate verify locations:
   == Info:   CAfile: none
     CApath: /etc/ssl/certs
   == Info: SSLv3, TLS handshake, Client hello (1):
   => Send SSL data, 0000000134 bytes (0x00000086)
   0000: ......T.."\.~....`...K4.......p..7"&4...Z.....9.8.........5.....
   0040: ................3.2.....E.D...../...A...........................
   0080: ......
   == Info: Unknown SSL protocol error in connection to svc-test:5989
   == Info: Closing connection #0
   == Info: SSL connect error
   *
   * /opt/sblim-wbemcli/bin/wbemcli: Http Exception: SSL connect error
   *

   Now we know that the “wbemcli” command line tool is actually – as already suspected – trying to initiate a SSLv3 connection.

5. In order to confirm we're on the right track, try to first verify manually that we're unable to connct with a SSLv3 secured connection:

   $ openssl s_client -host svc-test -port 5989 -ssl3
   CONNECTED(00000003)
   write:errno=104
   ---
   no peer certificate available
   ---
   No client certificate CA names sent
   ---
   SSL handshake has read 0 bytes and written 0 bytes
   ---
   New, (NONE), Cipher is (NONE)
   Secure Renegotiation IS NOT supported
   Compression: NONE
   Expansion: NONE
   SSL-Session:
       Protocol  : SSLv3
       Cipher    : 0000
       Session-ID:
       Session-ID-ctx:
       Master-Key:
       Key-Arg   : None
       PSK identity: None
       PSK identity hint: None
       SRP username: None
       Start Time: 1418397594
       Timeout   : 7200 (sec)
       Verify return code: 0 (ok)
   ---
   quit

   And that we're instead able to connect with a TLS secured connection:

   $ openssl s_client -host svc-test -port 5989
   CONNECTED(00000003)
   depth=0 C = GB, L = Hursley, O = IBM, OU = SSG, CN = 2145, emailAddress = support@ibm.com
   verify error:num=18:self signed certificate
   verify return:1
   depth=0 C = GB, L = Hursley, O = IBM, OU = SSG, CN = 2145, emailAddress = support@ibm.com
   verify return:1
   ---
   Certificate chain
    0 s:/C=GB/L=Hursley/O=IBM/OU=SSG/CN=2145/emailAddress=support@ibm.com
      i:/C=GB/L=Hursley/O=IBM/OU=SSG/CN=2145/emailAddress=support@ibm.com
   ---
   Server certificate
   -----BEGIN CERTIFICATE-----
   MIICyDCCAjGgAwIBAgIEUAPzmTANBgkqhkiG9w0BAQUFADBqMQswCQYDVQQGEwJH
   QjEQMA4GA1UEBxMHSHVyc2xleTEMMAoGA1UEChMDSUJNMQwwCgYDVQQLEwNTU0cx
   DTALBgNVBAMTBDIxNDUxHjAcBgkqhkiG9w0BCQEWD3N1cHBvcnRAaWJtLmNvbTAe
   Fw0xMjA3MTYxMDU3MjlaFw0yNzA3MTMxMDU3MjlaMGoxCzAJBgNVBAYTAkdCMRAw
   DgYDVQQHEwdIdXJzbGV5MQwwCgYDVQQKEwNJQk0xDDAKBgNVBAsTA1NTRzENMAsG
   A1UEAxMEMjE0NTEeMBwGCSqGSIb3DQEJARYPc3VwcG9ydEBpYm0uY29tMIGfMA0G
   CSqGSIb3DQEBAQUAA4GNADCBiQKBgQC3E7+7mE2GAID/35o5/s7cnzoqu9PQdOGB
   ryGMa8adD4Wd9hpmTkrsgyNvkUB6sPIifbFstGooOkQtK9ZNgP5OHOorZmqINSxM
   9goCkSCQG9xRKAvNt2tA8gujaV+p42oVEhIH6naJUul96qZI31y3GffUu2CRrJL7
   4wG/8cv0BQIDAQABo3sweTAJBgNVHRMEAjAAMCwGCWCGSAGG+EIBDQQfFh1PcGVu
   U1NMIEdlbmVyYXRlZCBDZXJ0aWZpY2F0ZTAdBgNVHQ4EFgQUkPMkXUjn0YHlfQW8
   TJiRC5jWQO4wHwYDVR0jBBgwFoAUkPMkXUjn0YHlfQW8TJiRC5jWQO4wDQYJKoZI
   hvcNAQEFBQADgYEAKqu7KpVxnOXonQE3unC1O7qUHKoyQUEWqcKsM/4tPI+lsBMZ
   jvoPwn8yQRWiLehFmVc8VSZfdFPLzshNabXp5qbZo/EFberXrgI2CbtPiULYyyyH
   DUhWF+vhwb6uqwfBbGncvTvI2ewU8+0oTXsuTkSjumJ7+chpaHFWWyj2cJA=
   -----END CERTIFICATE-----
   subject=/C=GB/L=Hursley/O=IBM/OU=SSG/CN=2145/emailAddress=support@ibm.com
   issuer=/C=GB/L=Hursley/O=IBM/OU=SSG/CN=2145/emailAddress=support@ibm.com
   ---
   No client certificate CA names sent
   ---
   SSL handshake has read 1029 bytes and written 498 bytes
   ---
   New, TLSv1/SSLv3, Cipher is AES256-GCM-SHA384
   Server public key is 1024 bit
   Secure Renegotiation IS supported
   Compression: NONE
   Expansion: NONE
   SSL-Session:
       Protocol  : TLSv1.2
       Cipher    : AES256-GCM-SHA384
       Session-ID: 48291D368E0A8584A8DFA00A9881B8979BDE370FC6C9439294C670695D031239
       Session-ID-ctx:
       Master-Key: 71BD12A161FC595CD056DA8E6D6E27420F37468E47498B7591A403A86844C55F61FF02B2FEC7739FAAEDCE3DFEA0F217
       Key-Arg   : None
       PSK identity: None
       PSK identity hint: None
       SRP username: None
       TLS session ticket lifetime hint: 300 (seconds)
       TLS session ticket:
       0000 - a0 e0 b1 9b c2 37 9a ca-49 1c 54 f5 26 4b d6 24   .....7..I.T.&K.$
       0010 - af 6a 7d cc 5e 4a 97 a8-b3 6d b7 66 0b b7 0a 65   .j}.^J...m.f...e
       0020 - 47 af ef 47 76 fc c7 e9-38 ff 84 28 ca 8e 73 25   G..Gv...8..(..s%
       0030 - 47 25 f6 0d 36 01 04 f1-f9 f7 0c b6 42 ef cf 09   G%..6.......B...
       0040 - 64 8f df ff 89 38 ed 7c-ae 1d 0e 25 d1 c1 77 86   d....8.|...%..w.
       0050 - b6 61 88 15 cf fe 9f 20-86 0d 17 74 18 da ea c0   .a..... ...t....
       0060 - 33 3a 47 f5 f9 51 24 ae-48 37 8a 3f 19 dd c6 04   3:G..Q$.H7.?....
       0070 - 7e d1 20 78 35 99 0b 9f-3b 1f ce 7c bc 11 93 e4   ~. x5...;..|....
       0080 - 0f 94 de 94 f1 0d 0c da-64 ca 0d f6 10 2a c8 fa   ........d....*..
       0090 - dc 3e e4 1a 97 d1 34 7a-9c f5 c3 00 e8 1b 10 d7   .>....4z........
   
       Start Time: 1418397614
       Timeout   : 300 (sec)
       Verify return code: 18 (self signed certificate)
   ---
   quit

   The secured connection negotiated to TLS succeeded, so we're on the right track!

6. Now we need to find the spot in the source code, where the “wbemcli” command line tool is forced to initiate a SSLv3 connection. We know this is probably done in a cURL related function call, since libcURL is used for the network connection. So lets first look into the cURL code for all the lines showing any sign of SSL related operations:

   $ grep -n curl CimCurl.cpp | grep -i ssl
   185:    // Assume we support SSL if we don't have the curl_version_info API
   276:    rv = curl_easy_setopt(mHandle, CURLOPT_SSL_VERIFYHOST, 0);
   277:    //    rv = curl_easy_setopt(mHandle, CURLOPT_SSL_VERIFYPEER, 0);
   280:    rv = curl_easy_setopt(mHandle, CURLOPT_SSLVERSION, 3);
   441:     if ((rv=curl_easy_setopt(mHandle,CURLOPT_SSL_VERIFYPEER,0))) {
   448:       if ((rv=curl_easy_setopt(mHandle,CURLOPT_SSL_VERIFYPEER,1))) {
   466:     if ((rv=curl_easy_setopt(mHandle,CURLOPT_SSLCERT,certificate))) {
   470:     if ((rv=curl_easy_setopt(mHandle,CURLOPT_SSLKEY,key))) {

   Looks like a perfect match in line 280 of the file “CimCurl.cpp”. The line numbers are a bit off from the original source code, since the file “CimCurl.cpp” was patched with our above debugging code. The code in the original, unpatched source file “CimCurl.cpp”, within the function “CimomCurl::genRequest” looks like this:

   CimCurl.cpp

   175     [...]
   176     /* Disable SSL host verification */
   177     rv = curl_easy_setopt(mHandle, CURLOPT_SSL_VERIFYHOST, 0);
   178     //    rv = curl_easy_setopt(mHandle, CURLOPT_SSL_VERIFYPEER, 0);
   179
   180     /* Force using SSL V3 */
   181     rv = curl_easy_setopt(mHandle, CURLOPT_SSLVERSION, 3);
   182
   183     /* Set username and password */
   184     if (url.user.length() > 0 && url.password.length() > 0) {
   185         mUserPass = url.user + ":" + url.password;
   186         rv = curl_easy_setopt(mHandle, CURLOPT_USERPWD, mUserPass.c_str());
   187     }
   188     [...]

   In line 181 the cURL option “CURLOPT_SSLVERSION” is indiscriminately set to use SSLv3 and nothing else, which we know from the above deduction is bound to fail on systems adressing the “POODLE” issues.

7. With the knowledge where the issue is actually caused, an easy quick'n'dirty fix can be implemented:

   sblim-wbemcli-1.6.3_debug.patch

   --- sblim-wbemcli-1.6.3_orig/CimCurl.cpp    2013-09-21 01:26:32.000000000 +0200
   +++ sblim-wbemcli-1.6.3/CimCurl.cpp         2014-11-26 16:46:09.000000000 +0100
   @@ -178,7 +178,7 @@
        //    rv = curl_easy_setopt(mHandle, CURLOPT_SSL_VERIFYPEER, 0);
    
        /* Force using SSL V3 */
   -    rv = curl_easy_setopt(mHandle, CURLOPT_SSLVERSION, 3);
   +    //rv = curl_easy_setopt(mHandle, CURLOPT_SSLVERSION, 3);
    
        /* Set username and password */
        if (url.user.length() > 0 && url.password.length() > 0) {

   Inserting the comment at the line where the cURL option “CURLOPT_SSLVERSION” is forced to SSLv3 causes libcURL to fall back to its default value, which is now TLS.

   Rebuild the “wbemcli” command line tool and tried again:

   $ CURLDEBUG=true /opt/sblim-wbemcli/bin/wbemcli -dx -noverify ecn https://user:pass@svc-test:5989/root/ibm
   To server: <?xml version="1.0" encoding="utf-8" ?>
   <CIM CIMVERSION="2.0" DTDVERSION="2.0">
   <MESSAGE ID="4711" PROTOCOLVERSION="1.0"><SIMPLEREQ><IMETHODCALL NAME="EnumerateClassNames"><LOCALNAMESPACEPATH><NAMESPACE NAME="root"></NAMESPACE><NAMESPACE NAME="ibm"></NAMESPACE></LOCALNAMESPACEPATH>
   <IPARAMVALUE NAME="DeepInheritance"><VALUE>TRUE</VALUE></IPARAMVALUE>
   </IMETHODCALL></SIMPLEREQ>
   </MESSAGE></CIM>
   * About to connect() to svc-test port 5989 (#0)
   *   Trying 192.168.x.x...
   * connected
   * Connected to svc-test (192.168.x.x) port 5989 (#0)
   * found 172 certificates in /etc/ssl/certs/ca-certificates.crt
   *    server certificate verification SKIPPED
   *    common name: 2145 (does not match 'svc-test')
   *    server certificate expiration date OK
   *    server certificate activation date OK
   *    certificate public key: RSA
   *    certificate version: #3
   *    subject: C=GB,L=Hursley,O=IBM,OU=SSG,CN=2145,EMAIL=support@ibm.com
   *    start date: Mon, 16 Jul 2012 10:57:29 GMT
   
   *    expire date: Tue, 13 Jul 2027 10:57:29 GMT
   
   *    issuer: C=GB,L=Hursley,O=IBM,OU=SSG,CN=2145,EMAIL=support@ibm.com
   *    compression: NULL
   *    cipher: AES-128-CBC
   *    MAC: SHA1
   * Server auth using Basic with user 'user'
   > POST /cimom HTTP/1.1
   Authorization: Basic enp6bmFnaW9zOm5hZ2lvcw==
   Host: svc-test:5989
   Content-Type: application/xml; charset="utf-8"
   Connection: Keep-Alive, TE
   CIMProtocolVersion: 1.0
   CIMOperation: MethodCall
   CIMMethod: EnumerateClassNames
   CIMObject: root%2Fibm
   Content-Length: 396
   
   * upload completely sent off: 396 out of 396 bytes
   * additional stuff not fine transfer.c:1037: 0 0
   * HTTP 1.1 or later with persistent connection, pipelining supported
   < HTTP/1.1 200 OK
   < Content-Type: application/xml; charset="utf-8"
   From server: Content-Type: application/xml; charset="utf-8"
   < content-length: 0000072284
   From server: content-length: 0000072284
   < CIMOperation: MethodResponse
   From server: CIMOperation: MethodResponse
   <
   * Connection #0 to host svc-test left intact
   From server: <?xml version="1.0" encoding="utf-8" ?>
   <CIM CIMVERSION="2.0" DTDVERSION="2.0">
   <MESSAGE ID="4711" PROTOCOLVERSION="1.0">
   <SIMPLERSP>
   <IMETHODRESPONSE NAME="EnumerateClassNames">
   <IRETURNVALUE>
   <CLASSNAME NAME="CIM_ConcreteIdentity"/>
   <CLASSNAME NAME="CIM_NetworkPacketAction"/>
   <CLASSNAME NAME="CIM_CollectionInSystem"/>
   [...]
   
   $ /opt/sblim-wbemcli/bin/wbemcli -noverify ecn https://user:pass@svc-test:5989/root/ibm
   svc-test:5989/root/ibm:CIM_ConcreteIdentity
   svc-test:5989/root/ibm:CIM_NetworkPacketAction
   svc-test:5989/root/ibm:CIM_CollectionInSystem
   svc-test:5989/root/ibm:CIM_DeviceSAPImplementation
   svc-test:5989/root/ibm:CIM_ProtocolControllerAccessesUnit
   svc-test:5989/root/ibm:CIM_ControlledBy
   [...]

   Great, now we're finally able to query and monitor the IBM SVC or Storwize systems again with the Nagios monitoring plugin (Nagios Monitoring - IBM SVC and Storwize)!

Between first noticing and researching the issue and creating the quick'n'dirty fix shown above, an official bug report has been filed on the issue and a patch has already been submitted to the source code repository in order to adress the issue more thoroughly. Hopefully an updated official source code package will be released soon.

Nonetheless, the process of researching and debugging this issue was an excellent hands on exercise for me, which i enjoyed very much. Hopefully the steps taken and described here, will turn out to be of use for others as well.

Like before with HMC Update to 7.7.5.0, HMC Update to 7.7.7.0 SP1 and HMC Update to 7.7.8.0, the recent HMC update to v7.7.9.0 was again not installable directly from the ISO images via the HMC GUI. Along with the HMC network installation images which are now mentioned in the release notes, there is now also an official documentation of the update procedure using the HMC network installation images. It's called “HMC network installation” and provides a more remote admin friendly way of performing the update. Since it's only a slightly shortened version of the procedure i already tested and used in HMC Update to 7.7.7.0 SP1, i decided to stick with my own procedure.

Also a turn for the better is, that now the release notes as well as FixCentral clearly point out the dependencies between the fixpacks that are supposed to go on top of the update release and the order they are supposed to be applied in. In case of MH01405 (aka V7R7.9.0.0) this is currently only MH01428 (aka V7R7.9.0.1 or v7.7.9.0 SP1.

As always, be sure to study the release notes thoroughly before an update attempt. Depending on your environment and HMC hardware there might be a road block in there. Special attention deserves item 2 in the “upgrade notes” section of the release notes of MH01405. Due to a bug in certain Power Systems firmware levels, there is a dependency between the usable HMC version and the firmware version on the managed system. Be sure to check if your managed systems firmware levels fall in the affected version ranges. For me this meant first upgrading certain managed systems to firmware levels not affected by the above bug. Then upgrading the HMCs to v7.7.9.0 SP1. And finally upgrading certain other managed systems to firmware levels depending on HMC version v7.7.9.0 or later. The latter dependency was - besides the fixed security issues - the main reason to upgrade the HMC in the first place.

For reference purposes, here are some example screen shots from a KVM session to the HMC during a update to MH01405:

After the upgrade to v7.7.9.0 (MH01405) was complete and the HMC had rebooted, the following errors showed up:

There are not a lot of resources on this particular error, but it seems to occationally have occurred on earlier HMC upgrades as well. Up to now there seems to be no negative effect resulting from this error.

After the upgrade to V7R7.9.0.0 (MH01405) is complete, you can apply the service pack V7R7.9.0.1 (MH01428) in the usual way via the HMC GUI. For me the service pack showed the following output during the update process:

• MH01428:

  Management console corrective service installation in progress. Please wait...
  Corrective service file offload from remote server in progress...
  The corrective service file offload was successful. Continuing with HMC service installation...
  Verifying Certificate Information
  Authenticating Install Packages
  Installing Packages
  --- Installing ptf-req ....
  --- Installing RSCT ....
  src-3.1.4.10-14056
  rsct.core.utils-3.1.4.10-14056
  rsct.core-3.1.4.10-14056
  rsct.service-3.5.0.0-1
  rsct.basic-3.1.4.10-14056
  --- Installing CSM ....
  csm.core-1.7.1.20-1
  csm.deploy-1.7.1.20-1
  csm_hmc.server-1.7.1.20-1
  csm_hmc.hdwr_svr-7.0-3.4.0
  csm_hmc.client-1.7.1.20-1
  csm.server.hsc-1.7.1.20-1
  --- Installing LPARCMD ....
  hsc.lparcmd-3.3.0.1-3
  ln: creating symbolic link `/usr/hmcrbin/lsnodeid': File exists
  ln: creating symbolic link `/usr/hmcrbin/lsrsrc-api': File exists
  ln: creating symbolic link `/usr/hmcrbin/mkrsrc-api': File exists
  ln: creating symbolic link `/usr/hmcrbin/rmrsrc-api': File exists
  --- Installing Pegasus ....
  --- Updating baseOS ....
  cp: cannot stat `.dev': No such file or directory
  PreInstalling HMC REST Web Services ...
  Installing HMC REST Web Services ...
  pmc.core-7.7.9.0-20140312T2001
  pmc.soliddb-7.7.9.0-20140312T2001
  pmc.wlp-7.7.9.0-20140312T2001
  pmc.wlp.soliddriver-7.7.9.0-20140312T2001
  pmc.wlp.log4j-7.7.9.0-20140312T2010
  pmc.wlp.guava-7.7.9.0-20140312T2010
  pmc.wlp.jaxb2.runtime-7.7.9.0-20140312T2010
  pmc.wlp.slf4j.api-7.7.9.0-20140312T2002
  pmc.wlp.quartz-7.7.9.0-20140312T2015
  pmc.wlp.commons-7.7.9.0-20140312T2013
  pmc.war.rest-7.7.9.0-20140312T2002
  pmc.soliddb.rest.sql-7.7.9.0-20140312T2010
  pmc.soliddb.pcm.sql-7.7.9.0-20140312T2015
  pmc.pcm.rest-7.7.9.0-20140312T2010
  pmc.ui.developer-7.7.9.0-20140312T2015
  D: opening db environment /var/lib/rpm/Packages create:cdb:mpool:private
  D: opening db index /var/lib/rpm/Packages rdonly mode=0x0
  D: locked db index /var/lib/rpm/Packages
  D: opening db index /var/lib/rpm/Name rdonly:nofsync mode=0x0
  D: read h# 849 Header SHA1 digest: OK (f280a38b206c3192103a5f4050991e1690ed43ea)
  D: ========== recording tsort relations
  D: ========== tsorting packages (order, #predecessors, #succesors, tree, depth, breadth)
  D: 0 0 0 0 1 0 -pmc.sem.war-7.7.9.0-20140312T2009.i386
  D: closed db index /var/lib/rpm/Name
  D: closed db index /var/lib/rpm/Packages
  D: closed db environment /var/lib/rpm/Packages
  D: opening db environment /var/lib/rpm/Packages create:cdb:mpool:private
  D: opening db index /var/lib/rpm/Packages create mode=0x42
  D: locked db index /var/lib/rpm/Packages
  D: sanity checking 1 elements
  D: running pre-transaction scripts
  D: computing 95 file fingerprints
  D: computing file dispositions
  D: opening db index /var/lib/rpm/Basenames create:nofsync mode=0x42
  D: read h# 931 Header SHA1 digest: OK (91c4128792b6b1d92318612e35f0d99c2b09bc41)
  D: read h# 932 Header SHA1 digest: OK (28745eb2d1d7a376c9cd9b457d024887849da559)
  D: read h# 933 Header SHA1 digest: OK (37f012c206c4a6cf6335be71d34ff09c0538d5b5)
  D: read h# 934 Header SHA1 digest: OK (9561ea0f53cff788ccf4a3f58655aff9a4d63bf3)
  D: read h# 935 Header SHA1 digest: OK (5718f74492d5e0af6858146bb5b72f588b0da4ab)
  D: read h# 936 Header SHA1 digest: OK (3a41ff5853613da4930e18097f657efb3a3b296f)
  D: read h# 937 Header SHA1 digest: OK (473cf0fe9c2b6f3458c180f1a8b206ed12f97536)
  D: read h# 938 Header SHA1 digest: OK (8b83dc36fa9ba3ee8a3454f00c0c1d3456794463)
  D: read h# 939 Header SHA1 digest: OK (76e2814d26d19030ca280e3a87c64a63f6db4939)
  D: read h# 940 Header SHA1 digest: OK (0bbd68866852e41a9813d4e95ae6f4af33316ad8)
  D: read h# 941 Header SHA1 digest: OK (88ca29e0d1812cccfd2a8729a9ae474366840cd0)
  D: read h# 942 Header SHA1 digest: OK (11fb71feb49795a55b8d4775dd3a87efa23ae085)
  D: read h# 943 Header SHA1 digest: OK (a65291baf06e105125843c7d9345284a4d036225)
  D: read h# 944 Header SHA1 digest: OK (fcf30711bf354a554a7a639bf634865a4a07dc35)
  D: read h# 945 Header SHA1 digest: OK (29769b20afd49242a01ba84d069521dac74bcb99)
  D: ========== --- pmc.sem.war-7.7.9.0-20140312T2009 i386-linux 0x0
  D: erase: pmc.sem.war-7.7.9.0-20140312T2009 has 95 files, test = 0
  D: opening db index /var/lib/rpm/Name create:nofsync mode=0x42
  D: read h# 849 Header SHA1 digest: OK (f280a38b206c3192103a5f4050991e1690ed43ea)
  D: opening db index /var/lib/rpm/Triggername create:nofsync mode=0x42
  D: erase: %preun(pmc.sem.war-7.7.9.0-20140312T2009.i386) asynchronous scriptlet start
  D: erase: %preun(pmc.sem.war-7.7.9.0-20140312T2009.i386) execv(/bin/sh) pid 16142
  D: erase: waitpid(16142) rc 16142 status 0 secs 0.001
  D: fini 100755 1 ( 504,1004) 662 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/theme/feed.css
  D: fini 100755 1 ( 504,1004) 625 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/theme/Master.css
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/theme
  D: fini 100755 1 ( 504,1004) 2121 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/feed.xsl
  D: fini 100755 1 ( 504,1004) 1704 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/web.xml
  D: fini 100755 1 ( 504,1004) 57211 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/wink-client-1.2.0-incubating.jar
  D: fini 100755 1 ( 504,1004) 679719 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.workhorse.templates-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 404664 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.workhorse.templates-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 35865 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.servlet.templates-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 29188 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.servlet.templates-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 26675 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.servlet.jdbc-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 128797 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.servlet.common-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 92119 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.servlet.common-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 41062 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.schema.web.src-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 93348 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.schema.web-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 349323 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.schema.vios-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 182187 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.schema.uom.src-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 509804 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.schema.uom-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 120510 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.schema.templates.src-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 415957 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.schema.templates-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 90846 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.schema.serviceableeventmanager.src-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 62845 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.schema.serviceableeventmanager-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 613724 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.westbound-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 643149 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.viosapi.rmc.handler-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 343001 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.viosapi.rmc.handler-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 55846 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.servlet.utils-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 31166 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.servlet.utils-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 1812 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.servlet.uom.vios-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 1787 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.servlet.uom.vios-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 399799 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.servlet.uom.phyp-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 247481 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.servlet.uom.phyp-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 15743 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.servlet.spi-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 10126 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.servlet.spi-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 22369 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.servlet.sem-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 13576 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.servlet.sem-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 62648 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.rest.provider-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 14607 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.resources-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 12268 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.resources-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 32880 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.logging.log4j-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 13132 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.logging-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 10638 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.logging-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 877816 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.web-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 294774 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.web-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 762319 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.vios-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 582466 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.vios-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 11266109 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.uom-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 2401072 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.uom-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 5042339 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.templates-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 1587400 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.templates-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 581709 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.serviceableeventmanager-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 197153 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.serviceableeventmanager-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 472045 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.reflection-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 145769 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.reflection-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 493817 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.api.server-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 280894 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.api.server-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 76060 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.api.common-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 41833 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.jaxb.api.common-7.7.9.0-src.jar
  D: fini 100755 1 ( 504,1004) 368989 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.cli.adapter-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 2061 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/pmc.annotations-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 1078246 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/dpsmapi-7.7.9.0.jar
  D: fini 100755 1 ( 504,1004) 243016 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/commons-lang-2.2.jar
  D: fini 100755 1 ( 504,1004) 65621 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/commons-io-1.2.jar
  D: fini 100755 1 ( 504,1004) 232771 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/commons-codec-1.6.jar
  D: fini 100755 1 ( 504,1004) 713 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib/.jazzignore
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/lib
  D: fini 100755 1 ( 504,1004) 4892 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/geronimo-web.xml
  D: fini 100755 1 ( 504,1004) 5963 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/log4j2.xml
  D: fini 100755 1 ( 504,1004) 1378 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/com/ibm/pmc/war/servlet/applications/sem/SemServletApplication.class
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/com/ibm/pmc/war/servlet/applications/sem
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/com/ibm/pmc/war/servlet/applications
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/com/ibm/pmc/war/servlet
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/com/ibm/pmc/war
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/com/ibm/pmc
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/com/ibm
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/com
  D: fini 100755 1 ( 504,1004) 764 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/ServletDaemonClassnames.properties
  D: fini 100755 1 ( 504,1004) 771 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/REST_Servlet.properties.SAMPLE
  D: fini 100755 1 ( 504,1004) 967 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/META-INF/wink-alternate-shortcuts.properties
  D: fini 100755 1 ( 504,1004) 0 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/META-INF/server/wink-providers
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/META-INF/server
  D: fini 100755 1 ( 504,1004) 363 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/META-INF/persistence.xml
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes/META-INF
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF/classes
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/WEB-INF
  D: fini 100755 1 ( 504,1004) 275 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/META-INF/MANIFEST.MF
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war/META-INF
  D: fini 040755 2 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps/PMC_SEM.war
  D: fini 040755 7 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc/apps skip
  D: fini 040755 8 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers/pmc skip
  D: fini 040755 6 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr/servers skip
  D: fini 040755 4 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5/usr skip
  D: fini 040755 9 ( 504,1004) 4096 /opt/pmc/lib/share/wlp-8.5.5 skip
  D: fini 040755 4 ( 504,1004) 4096 /opt/pmc/lib/share skip
  D: fini 040755 3 ( 504,1004) 4096 /opt/pmc/lib skip
  D: fini 040755 8 ( 504,1004) 4096 /opt/pmc skip
  D: erase: %postun(pmc.sem.war-7.7.9.0-20140312T2009.i386) asynchronous scriptlet start
  D: erase: %postun(pmc.sem.war-7.7.9.0-20140312T2009.i386) execv(/bin/sh) pid 16145
  + . /opt/pmc/bin/rpmScripts.include
  ++ EZLOG=/var/hsc/log/EZBuild.rpm.log
  ++ BASENAME=/usr/bin/basename
  ++ CAT=/bin/cat
  ++ CHMOD=/bin/chmod
  ++ CHOWN=/bin/chown
  ++ CP=/bin/cp
  ++ DATE='/bin/date --rfc-3339=seconds'
  ++ DIRNAME=/usr/bin/dirname
  ++ ECHO=/bin/echo
  ++ FIND=/usr/bin/find
  ++ GREP=/usr/bin/grep
  ++ LN=/bin/ln
  ++ MKDIR=/bin/mkdir
  ++ RM='/bin/rm -v'
  ++ RUNASROOT=/opt/ccfw/bin/framework/runAsRoot
  ++ TAR=/bin/tar
  ++ WC=/usr/bin/wc
  ++ UNZIP=/usr/bin/unzip
  ++ MV=/bin/mv
  + setupPMC
  + PMC_ROOT=/opt/pmc
  + PMC_BIN=/opt/pmc/bin
  + PMC_CONFIG=/opt/pmc/config
  + PMC_LIB=/opt/pmc/lib
  + PMC_LIB_SHARE=/opt/pmc/lib/share
  + PMC_LIB_WLP=/opt/pmc/lib/wlp
  + PMC_LIB_SOLIDDB=/opt/pmc/lib/soliddb
  + PMC_LOG=/opt/pmc/log
  + PMC_TMP=/opt/pmc/tmp
  + setupWLP
  + WLP_ROOT=/opt/pmc/lib/wlp
  + WLP_CONFIG_DIR=/opt/pmc/config/wlp
  + WLP_LOG_DIR=/opt/pmc/log/wlp
  + WLP_CONFIG_DIR=/opt/pmc/config/wlp
  + WLP_VERSION=8.5.5
  + WLP_SHARE_ROOT=/opt/pmc/lib/share/wlp-8.5.5
  + WLP_SERVER_ROOT=/opt/pmc/lib/wlp/usr/servers/pmc
  + WLP_PMC_CONTRIB=/opt/pmc/lib/wlp/usr/servers/pmc/libs/pmc-contrib/
  + WLP_SERVER_LOGS=/var/hsc/log/wlp
  + WLP_SERVER_APPS=/opt/pmc/lib/wlp/usr/servers/pmcapps/
  + HMC_PLUGINJARS_DIR=/usr/websm/codebase/pluginjars
  + RPM_NAME=pmc.sem.war
  + write_to_log START: RPM postUnInstall for pmc.sem.war
  ++ /bin/date --rfc-3339=seconds
  + echo '2014-12-04 22:24:13+01:00 START: RPM postUnInstall for pmc.sem.war'
  + /opt/pmc/bin/removeWARfromWLPserverxml.sh PMC_SEM_WAR
  + write_to_log removing of REST war is done
  ++ /bin/date --rfc-3339=seconds
  + echo '2014-12-04 22:24:13+01:00 removing of REST war is done'
  + write_to_log STOP: RPM postUnInstall for pmc.sem.war
  ++ /bin/date --rfc-3339=seconds
  + echo '2014-12-04 22:24:13+01:00 STOP: RPM postUnInstall for pmc.sem.war'
  D: erase: waitpid(16145) rc 16145 status 0 secs 0.016
  D: --- h# 849 pmc.sem.war-7.7.9.0-20140312T2009
  D: removing "pmc.sem.war" from Name index.
  D: removing 95 entries from Basenames index.
  D: opening db index /var/lib/rpm/Group create:nofsync mode=0x42
  D: removing "pmc" from Group index.
  D: opening db index /var/lib/rpm/Requirename create:nofsync mode=0x42
  D: removing 5 entries from Requirename index.
  D: opening db index /var/lib/rpm/Providename create:nofsync mode=0x42
  D: removing "pmc.sem.war" from Providename index.
  D: opening db index /var/lib/rpm/Dirnames create:nofsync mode=0x42
  D: removing 24 entries from Dirnames index.
  D: opening db index /var/lib/rpm/Requireversion create:nofsync mode=0x42
  D: removing 5 entries from Requireversion index.
  D: opening db index /var/lib/rpm/Provideversion create:nofsync mode=0x42
  D: removing "0:7.7.9.0-20140312T2009" from Provideversion index.
  D: opening db index /var/lib/rpm/Installtid create:nofsync mode=0x42
  D: removing 1 entries from Installtid index.
  D: opening db index /var/lib/rpm/Sigmd5 create:nofsync mode=0x42
  D: removing 1 entries from Sigmd5 index.
  D: opening db index /var/lib/rpm/Sha1header create:nofsync mode=0x42
  D: removing "f280a38b206c3192103a5f4050991e1690ed43ea" from Sha1header index.
  D: opening db index /var/lib/rpm/Filemd5s create:nofsync mode=0x42
  D: removing 95 entries from Filemd5s index.
  D: running post-transaction scripts
  D: closed db index /var/lib/rpm/Filemd5s
  D: closed db index /var/lib/rpm/Sha1header
  D: closed db index /var/lib/rpm/Sigmd5
  D: closed db index /var/lib/rpm/Installtid
  D: closed db index /var/lib/rpm/Provideversion
  D: closed db index /var/lib/rpm/Requireversion
  D: closed db index /var/lib/rpm/Dirnames
  D: closed db index /var/lib/rpm/Triggername
  D: closed db index /var/lib/rpm/Providename
  D: closed db index /var/lib/rpm/Requirename
  D: closed db index /var/lib/rpm/Group
  D: closed db index /var/lib/rpm/Basenames
  D: closed db index /var/lib/rpm/Name
  D: closed db index /var/lib/rpm/Packages
  D: closed db environment /var/lib/rpm/Packages
  D: May free Score board((nil))
  package pmc.sem.war is not installed
  Corrective service installation was successful.

  For reference purposes, here are some example screen shots from a KVM session to the HMC during a update to MH01428:

  

  

The MH01428 update still shows error messages with regard to symlink creation appearing during the update process, which can be savely ignored. The error message “cp: cannot stat `.dev': No such file or directory” is also becoming an old friend and originates from the shell script /images/installImages inside the MH01428 installation ISO image, where non-existing files are attempted to be copied.

The strange output lines starting with “D:”, “+” and “++” characters seemed awfully familiar, just like the output of a “rpm -vv” command. From tracing down the call order of /images/installImages inside the MH01428 installation ISO image:

/images/installImages

448
449 if [ -f $image/installK2Payloads.sh ]
450 then
451     echo "Installing HMC REST Web Services ..."
452     $image/./installK2Payloads.sh $image
453 fi
454

to:

/images/installK2Payloads.sh

  4
  5 LogFile=/tmp/K2Install.log
  6 IndexFile=K2Payloads.txt
  7
[...]
 73     while read line
 74     do
 75     rpmToInstall=`echo $line | cut -d '/' -f 4`
 76     rpmToUpdate=`echo $line | cut -d '/' -f 4 | cut -d '-' -f 1`
 77 
 78     #   pmc.sem.war needs to be uninstalled and then installed
 79     if [ "$rpmToUpdate" == "pmc.sem.war" ]; then
 80         /bin/rpm -evv $rpmToUpdate --nodeps --allmatches
 81     fi
 82 
 83     /bin/rpm -q $rpmToUpdate
 84     if [ $? -eq 0 ]; then
 85         /bin/rpm -vvh -U $rpmToInstall >> $LogFile 2>&1
 86     else
 87         /bin/rpm -vv -i $rpmToInstall >> $LogFile 2>&1
 88     fi
 89     done < $IndexFile

it seems the dubious output is due to a missing output redirection at the “rpm -evv pmc.sem.war” command in line 80 in the above code snippet of “/images/installK2Payloads.sh”. Since the uninstall of pmc.sem.war is mentioned in the comment in line 78 and the uninstall process apparently finished successfully it can be savely ignored. Although from the above output and without privileged access to the HMCs OS its hard to verify, whether the RPM “pmc.sem.war-7.7.9.1-20140905T1656.i386.rpm” was subsequently successfully re-installed. It can indirectly be verified by looking at the log entries written to the file “/tmp/K2Install.log” in line 87 of the above code snippet. The contents of the log file “/var/hsc/log/EZBuild.rpm.log” written from within the RPM install-/erase-time scriptlets could also be interesting in order to verify everything was re-installed properly.

Aside from the error and dubious messages mentioned above, we're currently not experiencing any issues with the new HMC version v7.7.9.0 SP1 (V7R7.9.0.1).

We've been using the IBM SAN Volume Controller (SVC) for several years now (since about 2006). While the technological progress was a tad slow in the early years, development – probably along with popularity and more widespread use – of the SVC fortunately picked up considerable pace in recent years. For us the most interesting new features that emerged over time are the:

• stretched cluster configuration, which seems to be far more popular in europe with its traditionally shorter distances between datacenters. It allows us to provide active-active access to host LUNs and thus considerably simplifying a resilient VMware environment.

• synchronous VDisk mirroring, which allows us to provide mirrored LUNs that are independent of the storage vendor in the backend.

• EasyTier, which allows us to utilize our TMS RamSan (now IBM Flash System) flash storage much more efficiently.

• Real-time compression (RTC), which as well allows us to utilize our overall backend storage much more efficiently.

We also went through several cycles of node hardware, starting with our initial 2145-4F2 via the 2145-8F2 and the 2145-8G4 to our current 2145-CG8. Currently our overall environment looks like this:

• Six 2145-CG8 nodes in three I/O groups.

• A stretched cluster configuration covering two datacenters which are within a distance of about 300 meters of single-mode fibre length. A quorum storage on a third location on the same campus.

• Dual fabric 8GB FC SAN consisting of four Brocade DCX-4S directors.

• A total of six disk based storage systems from different vendors (HDS AMS2300, Fujitsu DX90, IBM V3700), one of each vendor in each datacenter, with a total capacity of about 260TB. The systems are typically sized and configured for multiple 4+1 or 8+1 RAID-5 arrays. The arrays are subsequently mapped entirely as LUNs to the SVC. All the LUNs from one disk storage system are pooled together into one MDiskGroup, forming a single, striped failure group.

• A total of six flash based storage systems (TMS RamSan-630, TMS RamSan-810, IBM Flashsystem 820), one of each model in each datacenter, with a total capacity of about 34TB. The systems LUNs are also mapped to the SVC and all the LUNs from one flash storage are added to one disk based MDiskGroup for use as a SSD tier with EasyTier.

• 65 host systems (IBM xSeries, IBM BladeCenter and IBM Power), running either non-virtualized or virtualized (VMware, Xen, PowerVM) workloads.

• 291 VDisks, ranging from sizes of 1GB up to 4TB. Almost all VDisks are mirrored, exceptions are made where the application on the host prefers to do the mirroring or the replication itself (e.g. MS Exchange).

For about seven months – since the end of april 2014 – we've now been using Real-time compression (RTC). We started by implementing RPQ 8S1296 on all of our nodes. This added an additional 6-core CPU and 24GB memory to each node. As a result the “normal” SVC operation still uses four of the CPU-cores on the initially installed CPU and the RTC algorithm is dedicated eight CPU-cores – two on the initially and six on the additionally installed CPU. The SVC code version was v7.1.0.3 when we initially started testing and implementing RTC (see the screenshots below). After gradually converting more and more VDisks to compressed volumes, the CPU load of the RTC algorithm became quite noticable (30-60%). Along with that, a substancially increased latency (>10ms) could be observed. After updating the SVC code to v7.2.0.7, the CPU utilization dropped noticably to 10% and below. The latency also went back to the values (<2ms) usually observed before implementing RTC. There must have been quite an improvement in the RTC code, unfortunately IBM does not publish any such interesting details.

Over the course of implementing RTC, i took four series of screenshots from the SVC WebUI showing the compression allocation view at that particular point in time. They have been combined into the four following images showing all information at once, with the last one being a representation of the current situation:

One thing about the visual representation in the compression allocation view and the volume of RTC licensed storage – which confused me too at first – has to be noted. It seems that with regard to RTC licensing only the storage space allocated to primary VDisk volumes i.e. the unmirrored storage capacity is considered. From the information available on the matter at the time, both the corresponding sections from the “IBM EMEA Software Announcement ZP12-0235”:

The license entitles users for the quantity of terabytes of SVC volumes created with real-time compression enabled. The volume size (and not necessarily the amount of data you are able to store on that volume compressed) is the measure used to determine how many terabytes of 5641-CP1 to license.

and from the “Real-time Compression in SAN Volume Controller and Storwize V7000” redpaper:

In SAN Volume Controller, real-time compression is licensed by the total number of terabytes of virtual capacity, which is the amount of storage that the host sees.

are a bit ambiguous. At first the emphasis seems to be on the matter of uncompressed vs. compressed storage size. But on second thought, the key words “[…] the amount of storage that the host sees.” from the second quote come into play. Those basically say, that enabling RTC on secondary VDisk copies is free, since a host only sees the unmirrored amount of storage.

Example: In our setup each VDisk compressed with RTC has also a secondary copy, also compressed with RTC. There is currently only one exception in the form of a flash copy volume of 2750GB which is compressed, but not mirrored. The currently compressed virtual capacity is 62.67TB. The currently used RTC licenses is being reported as 32.68TB. The calculation is: ( 62.67TB - 2750GB ) / 2 + 2750GB = 32.68TB. Makes sense, doesn't it?

For the four cases shown in the images above, the average RTC+TP and RTC-only compression ratio, relative storage size after compression and relative storage saving have been calculated and are shown in the following table:

Although thin provisioning (TP) alone would amount to 16-20% storage saving on the overall average, the larger and quiet substancial effect of 64-67% of storage saving on the overall average can only be achieved with RTC. Needless to say, we're currently only using RTC on VDisks that promise to yield rather good compression results. This is done in order to save valueable licensed compression volume and to minimize the number of CPU cycles wasted on uncompressible data. For guidelines please see the recommendations in the redbook referenced below in the “Links & Resources” section. The VDisks have either been chosen by estimating the compressability with the comprestimator utility or by knowing the application data very well. VDisks which contain data with an inherent high entropy, like e.g. encrypted and compressed MS Exchange DAGs, repositories of already compressed installation media, compressed Windows system images or compressed AIX mksysb images, page compressed MS SQL data files or fileserver volumes with user data (docx, xlsx, pptx, zip, jpeg, mpeg, etc.) have been excluded from RTC for now. We're still investigating which way to ultimately go on the topic of MS SQL page compression vs. IBM SVC RTC. We're also still sorting out the “mess” of compressible and uncompressible data being mixed together within the same VMware datastores before converting some of them into RTC enabled VDisks. We'll probably end up with a mix of RTC enabled VDisks backing VMware datastores containing compression-friendly VMs and regular VDisks backing datastores containing high-entropy, less compressible VMs. It'll be interesting to see what the ratio between the two will be and which VM will fall into which category.

A detailed compilation of storage saving with RTC on a per VDisk basis is shown in the section Detailed per VDisk RTC data. The columns are pretty self-explainatory, with the most interesting columns being “Application Type”, “Size (%)” and “Saving (%)”. To get a better overview, a condensed view aggregated by “Application Type” was compliled. The following table shows the values aggregated by “Application Type”. The columns “Avg. Size (GB)” and “Avg. Compressed Size (GB)” show the arithmetic average for the VDisk size and compressed size. To be able to compare the different application types against each other, relative arithmetic averages were calculated (columns “Avg. Size (%)” and “vg. Saving (%)”). The columns “Min./Max. Size/Saving (%)” and “Samples” are provided to get an impression about the variability and the significance of the arithmetic averages.

A graphical representation of the above aggregated data is shown in the following graph:

The values “Avg. Size (%)” and “Avg. Saving (%)” are shown as colored bars, the error bars are their respective relative minimum and maximum values, the numbers at the bottom of the colored bars are the number of samples per application type.

The “AIX rootvg” and “Database” application types show rather good compression results, but also a high range of variability. For the case of “AIX rootvg” the compression results depend mainly on the amount of paging space being used, since on all systems the paging space is part of the rootvg. Systems with very low compressed VDisk size also show no or almost no paging space usage. For the case of “Database” the compression results obviously depend on the data stored within the database tablespaces, unfortunately i have no further information on what kind of data is stored in the less compressible cases. In the most compressible cases (5.38% and 7.32% of the original VDisk size) though, the databases contain large amounts of text data and fulltext search indexes, which explains the extraordinary compression results. The “ERP” application type shows equally good compression results, but with a much lower variability, which seems to be largely caused by the current amount of free unused database space. The sample from the “MS SQL” application type is unfortunately the only VDisk directly allocated to a MS SQL Server instance, so it's not really a representative sample. All other MS SQL Server instance in our environment run on VMware and the VDisks there are currently not RTC enabled due to the application and use case mixture described above. The “Code Server” and “Fileserver” application types show good compression results, considering the data usually associated with those. The low sample number indicated that they have specifically been chosen as candidates for RTC enabled VDisks. Especially the other available fileserver VDisks showed much worse results in the preliminary comprestimator runs. Only the the fileserver VDisk containing the Windows server saved user profiles showed good enough results to justify enabling RTC. The “Linux Package” and “Windows Package” application types show the expected worst compression results, since the data on those VDisks is already stored in compressed formats. Still, compression savings of approximately 40% on this kind of data is still pretty good. The “Apache & MySQL” application type is by its compression behaviour kind of a mixture between the “AIX rootvg” and “Fileserver” application types, since it has the same paging space configuration and has large amounts of already compressed data (bz2, gz, docx, xlsx, pptx, zip, jpeg, mpeg, etc.) stored on the VDisks. The “VMware ESX” and “Xen Server” also show average compression results, considering that those are run by 3rd parties where there is currently no distinction between and seperation of compression-friendly from compression-unfriendly VM data being made.

Overall, we're up to now quite happy with the SVCs RTC feature, since it gives us some breathing room and on the overall takes off the pressure to evaluate, purchase, implement and maintain additional storage units for the foreseeable future. On the downside, there is a pretty hefty price tag to the RTC volume licenses. Especially compared to other vendors (e.g. Pure Storage) where the compression functionality is part of the systems base package. One is advised to do a thorough TCO calculation to determine whether the investment in SVC RTC licenses outways the benefits of operating storage systems with actually allocateable space. In the end this boils down to a bet about the current and future compressability of the data actually stored. Besides licensing terms another issue for us was, that we unfortunately pretty quickly reached the limit for the allowed number of compressed VDisks per I/O group on our current 2145-CG8 hardware (max. 200 RTC enabled VDisks). This limit is put in place by SVC development as a safeguard, supposedly in order to keep the nodes from being overloaded with RTC workload. While understandable from a technical point of view, this limit can be reached pretty quickly if you're for example using a lot RTC enabled rootvgs or if you're following the SAP or Oracle disk layout guidelines pretty closely. For the rootvgs and possibly test and development SAP or Oracle systems a consolidation of the system and data disks into fewer VDisks using AIX/VIOS shared storage pools could be an option. But then again, the same downsides for e.g. VMware datastores apply to shared storage pools as well.

Real-time Compression in SAN Volume Controller and Storwize V7000
Implementing IBM Real-time Compression in SAN Volume Controller and IBM Storwize V7000
IBM System Storage SAN Volume Controller software V6.4.0 improves storage efficiency - IBM Europe, Middle East, and Africa Software Announcement ZP12-0235 - June 4, 2012

Detailed compilation of storage saving with RTC on a per VDisk basis. If JavaScript is enabled in your browser, click on a column headers to sort by that particular column.

After gaining some operational experience with the previously introduced Nagios plugin for Infortrend EonStor and EonStor DS storage arrays, some issues became apparent which needed to be addressed in an update. The updated version of the Nagios plugin check_infortrend.sh fixes the following issues:

1. Newer array firmware versions use different severity strings for event log entries. The Nagios plugin has been adapted to be able to cope with these.

2. Due to a limitation in the array firmware, event log entries available via SNMP are not cleared when the corresponding event log entries are cleared via RAIDWatch or SANWatch. They are only cleared during a controller reboot. A support case with Infortrend confirmed this and it is currently under investigation whether this feature could be added for future releases of the array firmware.

   In the meantime a workaround to address this behaviour has been added to the Nagios plugin. In order to not constantly get alarms about already addressed events, the date of the event will now – along with the already used severity of the event – be taken into consideration. By default only events within the past 60 minutes will be evaluated. The extent of time to look into the past can be overridden from the default with the new “-t <minutes>” command line option of the Nagios plugin. E.g. “-t 120” will evaluate events within the past 2 hours. You might need to adjust the definition of the check_infortrend_events command to suite your environment, e.g.:

   # check Infortrend ESDS cache status
   define command {
       command_name    check_infortrend_events
       command_line    $USER1$/check_infortrend.sh -H $HOSTNAME$ -C events -t <minutes>
   }

   There are several pitfalls here though:

   • Make sure the timeframe aligns with your Nagios configuration options max_check_attempts, normal_check_interval and retry_check_interval to actually allow non-normal events to trigger an alarm. Generally speaking, the cumulated timeframe of the three Nagios configuration options of your Check_IFT_Events service check must be smaller than the timeframe given in the definition of the check_infortrend_events command.

   • Make sure you set the date and time on the array to the correct values or preferably use a SNTP server. Also, make sure the Nagios server and the array use the same timezone, preferably UTC in both cases.

3. Not exactly an issue with the Nagios plugin per se, but related to the monitoring of Infortrend storage arrays in general, is an adapted SNMPTT configuration. Since all SNMP traps generated from events of Infortrend arrays are indiscriminately reported with the same OID, a bit more extensive parsing of the SNMP traps needs to occur. In order to achieve this, the following entries should be used in the snmptt.conf.infortrend SNMPTT configuration file:

   /opt/snmptt/conf/snmptt.conf.infortrend

   EVENT iftEventText .1.3.6.1.4.1.1714.0.1 "Status Events" Critical
   FORMAT The description of the event $*
   MATCH $*: ( \[Alert Condition\])
   MATCH $*: ( \[Critical\])
   MATCH $*: ( \[Critical Error\])
   MATCH $*: ( \[Error\])
   SDESC
   The description of the event
   Variables:
   EDESC
    
   EVENT iftEventText .1.3.6.1.4.1.1714.0.1 "Status Events" Warning
   FORMAT The description of the event $*
   MATCH $*: ( \[Warning Condition\])
   MATCH $*: ( \[Warning\])
   SDESC
   The description of the event
   Variables:
   EDESC
    
   EVENT iftEventText .1.3.6.1.4.1.1714.0.1 "Status Events" Normal
   FORMAT The description of the event $*
   MATCH $*: ( \[Information\])
   MATCH $*: ( \[Notification\])
   SDESC
   The description of the event
   Variables:
   EDESC

   and the SNMPTT daemon should be restarted.

If you happen to find any additional issues with monitoring your Infortrend systems with this Nagios plugin, please feel free to leave a comment or drop me a note via email.