Enabling and configuring Tracing/Logging for the SFCB CIMOM on ESXi 5.x machines

It has been my constant experience that VMware creates excellent software and deplorable documentation. Ever since my first tryst with VMware around 2008 or so when I was given the task of working with the VMware VI-SDK (for the ESX platform, and later on for the ESXi platform as well), it has been a wonderful experience seeing those APIs work beautifully, simply, and powerfully. Working on the SDK also led me to explore the internals of the ESX platform itself, and it was quite an enriching experience in and of itself. However, that was also the first time that I experienced the horrendous cesspool of detritus that VMware calls its documentation.  Finding anything of use on its website is an exercise in futility, and the forums don’t fare much better. The best way I found to work my way through this mess was to read the SDK code itself, explore the ESXi console, and try out lots of small prototype programs to see if the data was indeed correct. One saving grace was the availability of the MOB (Managed Object Browser) which arguably taught me more than anything else.

Recently I had a need to set up logging/tracing on the SFCB CIMOM used by the ESXi 4.x and 5.x series, and it was déjà vu all over again. Granted that SFCB is not a VMware product, but since it comes pre-installed on every ESXi box, I would have expected some basic guides explaining the configuration and workings of the CIMOM vis-à-vis the ESXi kernel. Absolutely none whatsoever. So in order to spare people the trouble of not finding any relevant results, let me share my experience in setting up the logging mechanism for SFCB specifically in reference to ESXi.

SFCB (Small Footprint CIM Broker) is an excellent CIMOM that is lightweight, and has a very nice pluggable interface for third-party CIM Providers. An added benefit is that a Provider crash is isolated, and is not allowed to crash the CIMOM itself. No wonder then that it is already the de facto CIMOM for a wide variety of platforms – various Linux flavors, and ESXi of course (which used to depend on the unwieldy gargoyle that is OpenPegasus till Common Sense won out). Now, with ESXi in mind, here are the three simple steps needed to configure the SFCB CIMOM for logging/tracing (especially useful when an errant CIM Provider needs to be checked for anomalous behavior):

1. Log on to the ESXi shell (you need to have SSH enabled through the vSphere Client before you can open a console through a tool such as PuTTY) and check the contents of the /etc/sfcb/sfcb.cfg file (showing the default configuration here):

~ # cat etc/sfcb/sfcb.cfg.new
# Do not modify this header
# VMware ESXi 5.5.0 build-1106514
#
# set logLevel using advanced config: CIMLogLevel
httpPort:       5988
enableHttp:     true
httpProcs:      2
httpsPort:      5989
enableHttps:    true
httpsProcs:     4
provProcs:      16
httpLocalOnly:  true
doBasicAuth:    true
basicAuthLib:   sfcBasicPAMAuthentication
useChunking:    true
keepaliveTimeout: 1
keepaliveMaxRequest: 10
providerTimeoutInterval: 120
sslKeyFilePath: /etc/vmware/ssl/rui.key
sslCertificateFilePath: /etc/vmware/ssl/rui.crt
sslClientTrustStore: /etc/sfcb/client.pem
sslClientCertificate: ignore
certificateAuthLib:   sfcCertificateAuthentication
registrationDir: /var/lib/sfcb/registration
providerDirs: /usr/lib /usr/lib/cmpi /usr/lib/cim
enableInterOp:  true
threadStackSize:     524288
rcvSocketTimeOut: 0
requestQueueSize: 10
threadPoolSize: 5
intSockTimeout: 600
maxSemInitRetries: 5
maxFailureThreshold: 3
cimXmlFdSoftLimit: 512
cimXmlFdHardLimit: 1024

You can see above the default values for various parameters as present on my local ESXi 5.5 machine. The contents should not be too different, if at all, for other versions of ESXi. This file, /etc/sfcb/sfcb.cfg is the main configuration file for the SFCB CIMOM. You can change various parameters by reading up the general documentation of the SFCB CIMOM for other Operating Systems.

2. Now, add the following lines to the /etc/sfcb/sfcb.cfg file:

traceLevel: 1
traceMask: 0x0000103
traceFile: /vmfs/volumes/50cb7c7d-30e72dbe-a165-ac162d8be508/timmy/z0ltan.log

So your new file might look something like the following:

~ # cat /etc/sfcb/sfcb.cfg
# Do not modify this header
# VMware ESXi 5.5.0 build-1106514
#
# set logLevel using advanced config: CIMLogLevel
httpPort:       5988
enableHttp:     true
httpProcs:      2
httpsPort:      5989
enableHttps:    true
httpsProcs:     4
provProcs:      16
httpLocalOnly:  true
doBasicAuth:    true
basicAuthLib:   sfcBasicPAMAuthentication
useChunking:    true
keepaliveTimeout: 1
keepaliveMaxRequest: 10
providerTimeoutInterval: 120
sslKeyFilePath: /etc/vmware/ssl/rui.key
sslCertificateFilePath: /etc/vmware/ssl/rui.crt
sslClientTrustStore: /etc/sfcb/client.pem
sslClientCertificate: ignore
certificateAuthLib:   sfcCertificateAuthentication
registrationDir: /var/lib/sfcb/registration
providerDirs: /usr/lib /usr/lib/cmpi /usr/lib/cim
enableInterOp:  true
threadStackSize:     524288
rcvSocketTimeOut: 0
requestQueueSize: 10
threadPoolSize: 5
intSockTimeout: 600
maxSemInitRetries: 5
maxFailureThreshold: 3
cimXmlFdSoftLimit: 512
cimXmlFdHardLimit: 1024
traceLevel: 1
traceMask: 0x0000103
traceFile: /vmfs/volumes/50cb7c7d-30e72dbe-a165-ac162d8be508/timmy/z0ltan.log

Explanation:

traceLevel dictates the level of logging that you wish to generate (in my experience, a level of ‘1’ should suffice for most cases, but levels 2, 3, or even 4 can be tried out depending on your requirements. The higher the level, the finer the level of logging). However, beware that increasing the level of logging also increases the memory and CPU overheads on the ESXi box, so set the level of logging with a discriminating approach.

traceMask is a bitmask that allows SFCB to enable logging for specific components (a very useful feature that produces smaller and more relevant logs). The various components are listed below along with their bitmasks. Either the int or the hex mask can be used. Also, in order to generate logs for multiple components, their bitmasks may be ORed together to generate a single bitmask to be set as the traceMask. (For instance, I have my bitmask set to: 0x0000103 (providerMgr | providerDrv | providers).

      Traceable Components:     Int        Hex
 	       providerMgr:          1	0x0000001
 	       providerDrv:          2	0x0000002
 	        cimxmlProc:          4	0x0000004
 	        httpDaemon:          8	0x0000008
 	           upCalls:         16	0x0000010
 	          encCalls:         32	0x0000020
 	   ProviderInstMgr:         64	0x0000040
 	  providerAssocMgr:        128	0x0000080
 	         providers:        256	0x0000100
 	       indProvider:        512	0x0000200
 	  internalProvider:       1024	0x0000400
 	        objectImpl:       2048	0x0000800
 	             xmlIn:       4096	0x0001000
 	            xmlOut:       8192	0x0002000
 	           sockets:      16384	0x0004000
 	         memoryMgr:      32768	0x0008000
 	          msgQueue:      65536	0x0010000
 	        xmlParsing:     131072	0x0020000
 	    responseTiming:     262144	0x0040000
 	         dbpdaemon:     524288	0x0080000
 	               slp:    1048576	0x0100000

traceFile, as the name suggests, refers to the location where you want the trace outputs to be logger. By default this is stderr (console), but this can be made to point to a file location (as seen in the sample config file shown previously). I would suggest setting this file in a persistent location with enough space availability (such as on an available datastore). The reason is that if you should choose a location within the root folder (say, /mylogs/test.log), it can quickly overwhelm your ESXi machine. Remember that everything under the root folder in ESXi is necessarily in volatile memory with size restrictions, and from my experience, these logs can quickly grown to hundreds of MBs in size.

3. Restart the SFCB CIMOM in order to reflect the changes to the config file:

~# /etc/init.d/sfcbd-watchdog restart

Note: If you want to go about in a cleaner way, I would recommend that you stop the SFCB CIMOM as the first step (before modifying the config file):

~# /etc/init.d/sfcbd-watchdog stop

Confirm that the SFCB CIMOM has indeed shutdown:

~# /etc/init.d/sfcbd-watchdog status

And then proceed with the steps mentioned before, and when the config file has been updated with the changes, start the SFCB CIMOM again:

~# /etc/init.d/sfcbd-watchdog start

Followed by a final confirmation that the SFCB CIMOM is up and running:

~# /etc/init.d/sfcbd-watchdog status

And that’s all there is to it! Now you should be able to see the log file being populated with log messages as the SFCB CIMOM starts running, and you can then trigger your own CIM operations (such as querying for specific CIM classes on your CIM provider), and those operations should be logged in the log file as well.

Enabling and configuring Tracing/Logging for the SFCB CIMOM on ESXi 5.x machines

How the finnegan does one regenerate a VMDK file’s UUID programmatically?

As promised in my last post, here it is – the real deal on the generation and re-generation of UUIDs for VMDK files on an ESX Server platform. A bit of background on this topic might be of interest and possibly of use to the reader.

It was around six months ago that I became involved in some work requiring me to dabble with VMDK files at an intimate level. One of the steps necessitated the re-generation and assignment of UUID for a VMDK file (of course, the base VMDK file and not the ‘flat’ or ‘rdmp’ file). As much as I tried searching online, I could not find any constructive approach to actually generating these UUIDs. This made sense to the extent that VMware had vested interest in preserving the cloud of secrecy to its UUID generation algorithms. At this juncture, I must clarify that the UUID generation scheme for a VMDK is different from that of a Virtual Machine and other ESX Server platform components. For instance, a Virtual Machine (whose metadata is represented in the form of a .vmx file) may have the following UUID information:

uuid.location = “56 4d 3e 6b 50 fe 21 4c-e6 9d 74 44 da ac de 23”
uuid.bios = “56 4d 3e 6b 50 fe 21 4c-e6 9d 74 44 da ac de 23”

The algorithm (or at least the basic methodology) by which these are generated is more or less documented in existing VMware documents. This will not be discussed in the blog. Digressing no more, in brief, I found absolutely no information on how to generate a VMDK UUID for the ESX Server environment. The VI-SDK (and the vSphere SDK) documentation provides information on an API that is used to change the UUID of a VMDK. The API is:

SetVirtualDiskUUID with four parameters described in order as

_this (Managed Object Reference to the VirtualDiskManager

name (String) // referring to the Datastore path or URL of the VirtualDisk

datacenter(Managed Object Reference to the Datacenter) // not required for ESX Server

uuid(String) // The new UUID to update the VMDK file with.

Now the interesting part is that the ‘uuid’ component is a necessary parameter to this API call. This absolutely makes no sense for my requirements of course, as I need the system to generate me a new UUID just like the ‘vmkfstools’ command can generate on the fly. In case you are not familiar with this method, consider the following representative example:

Suppose we want to regenerate the UUID of a VirtualDisk named New_W2K3_3.vmdk then follow the following steps:

1. Locate the ‘vmkfstools’ binary (in case it has not been already set in the PATH enviroment variable) using

[root@z0ltanik]# whereis vmkfstools

You should see a response such as

vmkfstools: /usr/sbin/vmkfstools /usr/man/man1/vmkfstools.1.gz

2. Suppose that vmfkstools resides in /usr/sbin, traverse to the directory where the VMDK file exists (or use relative/absolute paths) and invoke

[root@z0ltanik New_W2k3]# /usr/sbin/vmkfstools -J getuuid New_W2k3_3.vmdk

The output will be something like the following

UUID is 60 00 C2 95 78 96 04 68-53 cb d0 5e 0f a7 d0 32

This is the current UUID of the VMDK file.

3. To regenerate (and assign) a new UUID to the aforementioned VMDK file, simply invoke the following command. The response follows suit, displaying the
new UUID

[root@z0ltanik New_W2k3]# /usr/sbin/vmkfstools -J setuuid New_W2k3_3.vmdk

UUID is 60 00 C2 97 5e 42 fd 6f-bc ee 83 c5 51 c6 40 34

Et voila! You are all done. I had been hoping for a similar behavior from the SetVirtualDiskUUID API. Perhaps the VMware SDK engineers should have attended Joshua Bloch’s API design sessions eh? Just kidding of course – for the most part the vSphere (and its older avatar, the VI-SDK) SDK is impeccably designed. Enough digression already mates! Let’s get down to the meat of a simple Java example of how to read UUIDs from a file and translate them into new valid and perfectly acceptable UUIDs subject of course to the following caveats:

1. The user is responsible for writing the business logic to ensure the unique-ness of the new UUID in the Virtual Machine namespace (yes, NOT the ESX Server namespace). A trivial task indeed.

2. This code represents a representative example and suited to my requirements of retrieving a VMDK file’s existing VMDK and modifying it. However, this can be easily modified to generate UUIDs from scratch ad infinitum. The moot point here is that the first 7 characters of the UUID must always be “60 00 C2 9“. There you go – a revelation for you lads!

3. No major error condition checks, boundary condition checks etc. Feel free to add them yourself.

The code:

     /**
      * Program to read UUIDs from 'uuid.txt', generate valid UUIDs and display them on the console.
      *
      * @author Timmy z0ltan Jose
      */

      import java.util.Random;
      import java.io.BufferedReader;
      import java.io.FileReader;
      import java.io.IOException;

      public class SetUuid {

      public static void main(String args[]) {

            String oldUuid = null;
            BufferedReader myReader = null;

           try {
                    myReader = new BufferedReader(new FileReader("uuid.txt"));

                    while( (oldUuid = myReader.readLine()) != null) {

                            System.out.println("\nOld Uuid = " + oldUuid);

                            System.out.println("New Uuid = " + getNewUuid(oldUuid));
                     }

                } catch (IOException ex) {
                        ex.printStackTrace();
                } finally {
                      if (myReader != null) {
                          try {
                                 myReader.close();
                               } catch ( IOException ioex) {
                                      ioex.printStackTrace();
                                  }
                      }
                }
      }

      private static String getNewUuid(String oldUuid) {

            String fixed = null;
            String toggle = null;
            String randomOne = null;
            String randomTwo = null;
            String timestamp = null;
            String newUuid = " ";

            StringBuffer origUuid = new StringBuffer(oldUuid);

            for (int i = 0; i < origUuid.length(); i++) {

               if (origUuid.charAt(i) == ' ' || origUuid.charAt(i) == '-') {
                      origUuid.deleteCharAt(i);
               }
             }

            fixed = origUuid.substring(0, 7);

            toggle = Integer.toHexString(new Random().nextInt(16));

            byte[] randBytes = new byte[4];

            new Random().nextBytes(randBytes);
            String result = "";
           
            for (int i=0; i < randBytes.length; i++) {
                 result += Integer.toString( ( randBytes[i] & 0xff ) + 0x100, 16).substring( 1 );
            }

            randomOne = result;

            byte[] b = new byte[2];
            randomTwo = "";

            new Random().nextBytes(b);

            for (int j = 0; j < b.length; j++) {

                  randomTwo += Integer.toHexString( (b[j] & 0xff) + 0x100).substring(1);
            }

             timestamp = toggle + Long.toHexString(System.nanoTime());

             String firstHalf = fixed + toggle + randomOne;

             for (int j = 1; j < firstHalf.length(); j+=2) {

                    newUuid += " " + firstHalf.charAt(j-1) + firstHalf.charAt(j);
             }

              newUuid += "-";

              String secondHalf = randomTwo + timestamp.substring(0, 12);
              String newerUuid = (" " + secondHalf.charAt(0) + secondHalf.charAt(1)).trim();

              for (int k = 3; k < secondHalf.length(); k+=2) {

                     newerUuid += " " + secondHalf.charAt(k-1) + secondHalf.charAt(k);
               }

              return (newUuid + newerUuid.trim()).trim();

      }
    }

And here, of course, is the uuid.txt file:

60 00 C2 97 50 b3 99 57-47 b9 2b fd fb 45 ed 5f
60 00 C2 9f f0 04 aa 90-0f 6e 94 0a b0 33 fa f3
60 00 C2 93 54 19 90 f8-f1 8f 7b 25 7b 72 e2 3a
60 00 C2 97 c1 57 ca e4-a2 24 98 3f c2 0d 55 c2
60 00 C2 9e b1 00 fb 5e-a2 45 99 09 7f 0d fd 00

Sample output from a single run of the above code:

Old Uuid = 60 00 C2 97 50 b3 99 57-47 b9 2b fd fb 45 ed 5f
New Uuid = 60 00 C2 90 bb dd a8 31-b3 a8 0c 67 37 cc 6a f0

Old Uuid = 60 00 C2 9f f0 04 aa 90-0f 6e 94 0a b0 33 fa f3
New Uuid = 60 00 C2 93 16 22 c0 93-76 1d 3c 67 37 e5 b2 2c

Old Uuid = 60 00 C2 93 54 19 90 f8-f1 8f 7b 25 7b 72 e2 3a
New Uuid = 60 00 C2 9e 2f 80 ad 29-53 aa ec 67 37 fd 55 43

Old Uuid = 60 00 C2 97 c1 57 ca e4-a2 24 98 3f c2 0d 55 c2
New Uuid = 60 00 C2 95 24 ba 3b b4-17 18 5c 67 38 27 7b bd

Old Uuid = 60 00 C2 9e b1 00 fb 5e-a2 45 99 09 7f 0d fd 00
New Uuid = 60 00 C2 9c 69 24 b2 49-44 f2 cc 67 38 3e 81 b0

The code is simple enough as to not necessitate the presence of comments. However, if needed, I will explain the modus operandi in a separate blog. Right now I have to go get my power meal done. So long! 😉

P.S: Some screwy issues with the code formatter. Well, que sera sera….. for now!

P.P.S: Fixed the formatting issue – should have used the <pre> tag instead of <code>….. duh!

How the finnegan does one regenerate a VMDK file’s UUID programmatically?