Thursday, December 12, 2013

Enabling, Monitoring and Disabling Dedup

dedup info:
http://nutanix.blogspot.com/2013/08/introducing-nede-nutanix-elastic-dedup.html

Enabling Dedup

1.
- it can be done per container
ncli ctr edit name=xyz fingerprint-on-write=on
- it can be done per vdisk
ncli vdisk edit name NFS:2389 fingerprint-on-write=on


2. When you upgrade to 3.5.1, enable dedup right away if needed, as FP is done on write, we may not
get the benefit of dedup if enable later ( unless you vdisk manipulator tool is used).

Why it works on upgrade is curator converts 16 MB extent group to 4 MB extentgroup, so there
will be a lot write activities which will be used for Finger printing.

3. Increase  medusa_extent_group_id_map_cache_size_mb=2048 (stargate gflag) to reduce evictions. Make sure of 24G CVM

4. Content cache and extent cache are allocated based on CVM memory (ENG-10798)


 Monitoring Dedup example: - 3.5.2 prism GUI has dedup stats.



have to look around in 2009 page and Curator master logs.)
#0. Overall container usage & amount of data which is fingerprinted:

On master curator (data/logs/curator.INFO)
I1203 12:27:53.777602  curator_execute_job_op.cc:2452] ContainerEgroupFileSizeBytes[912] = 4168785526784
I1203 12:27:53.777606  curator_execute_job_op.cc:2452] ContainerEgroupFileSizeBytes[107907] = 1100420612096
I1203 12:27:53.777609  curator_execute_job_op.cc:2452] ContainerUntransformedSizeBytes[912] = 4136075722752
I1203 12:27:53.777613  curator_execute_job_op.cc:2452] ContainerUntransformedSizeBytes[107907] = 1100301139968
I1203 12:27:53.777616  curator_execute_job_op.cc:2452] ContainerInternalGarbageBytes[912] = 32709804032
I1203 12:27:53.777621  curator_execute_job_op.cc:2452] ContainerInternalGarbageBytes[107907] = 119472128
I1203 12:27:53.777623  curator_execute_job_op.cc:2452] ContainerFingerprintedBytes[912] =  3699631161344
From above, looks like customer has two containers (912 & 107907) and 912 is the one for which fingerprint on write has been turned on. Almost 90% of it is fingerprinted (3.6T out of 4.1T).
#1. Read Path Live (30sec) Metrics
wget -O- 'http://localhost:2009/h/vars?regex=stargate.content&format=text'
stargate/content_cache_adds 2921
stargate/content_cache_dedup_ref_count 2.4583     <--- effective RAM/Flash savings right now is ~2.5x
stargate/content_cache_evictions_flash 9815
stargate/content_cache_evictions_memory 15969
stargate/content_cache_flash_page_in_pct 4
stargate/content_cache_flash_spills 9815
stargate/content_cache_hits_pct 98                         <---- good
stargate/content_cache_lookups 261701
stargate/content_cache_multi_touch_flash_max 21474836480
stargate/content_cache_multi_touch_flash_usage 21474836480
stargate/content_cache_multi_touch_memory_max 1899180856
stargate/content_cache_multi_touch_memory_usage 1900703744
stargate/content_cache_page_in_from_flash 13062
stargate/content_cache_single_touch_flash_max 0
stargate/content_cache_single_touch_flash_usage 0
stargate/content_cache_single_touch_memory_max 474795208
stargate/content_cache_single_touch_memory_usage 473272320
stargate/content_cache_usage_flash_mb 20480               <---- 20G flash
stargate/content_cache_usage_memory_mb 2264            <---- 2.2G RAM

#2. Medusa ExtentGroupId Map (where SHA1s are kept) hit/miss info:
wget -O- 'http://localhost:2009/h/vars?regex=medusa.cache.extent_group_id_map&format=text'
medusa/cache/extent_group_id_map/current_size_bytes 268430856
medusa/cache/extent_group_id_map/entries 9496
medusa/cache/extent_group_id_map/evictions 293020 <<< to reduce evictions increase the extent_group_id cache.
medusa/cache/extent_group_id_map/hits   28665029
medusa/cache/extent_group_id_map/misses 923660
medusa/cache/extent_group_id_map/insertions 9417038
medusa/cache/extent_group_id_map/max_size_bytes 268435456  ---> 256MB cache size for this map
Medusa Extent ID map hit ratio is 96.8% (28665029/(28665029+923660)). 
After increasing medusa extent id cache to 2G:

medusa/cache/extent_group_id_map/current_size_bytes 1644951348
medusa/cache/extent_group_id_map/entries 75678 (increased)
medusa/cache/extent_group_id_map/evictions 0 ( zero evictions)
medusa/cache/extent_group_id_map/hits 71550917
medusa/cache/extent_group_id_map/insertions 24404990
medusa/cache/extent_group_id_map/max_size_bytes 2147483648
medusa/cache/extent_group_id_map/misses 875467    (reduced)
#3. Write Path Live (30sec) Metrics
wget -O- 'http://localhost:2009/h/vars?regex=stargate.dedup&format=text'
stargate/dedup_fingerprint_added_bytes 8355840
stargate/dedup_fingerprint_cleared_bytes 8290304



III. Disable Dedup:
ncli ctr edit name=xyz fingerprint-on-write=off

stargate.gflags: stargate_disable_dedup_on_read=true

Monday, October 28, 2013

No SAN, No Cry

"No SAN No Cry"

No, SAN, no cry;
No, SAN , no cry;
No, SAN, no cry;
No, SAN, no cry.

'Cause - 'cause - 'cause I remember when we used to sit
In a dark server room in Trenchtown,
Oba - obaserving the bad pWWN  - yeah! -
Zoned with the good pWWN , yeah!
Storage Admins we have, oh, SAN Admins we have lost
Along the way, yeah!
In this great Nutanix converged future, you can forget your pLOGI;
So dismantle your Storage Array, I seh. Yeah!

No, SAN, no cry;
No, SAN, no cry. Eh, yeah!
Storage admin', don't shed no tears:
No, SAN, no cry. Eh!

Said - said - said I remember when we used to sit
In the dark server room in Trenchtown, yeah!
And then SAN Admin would make the Fiber Channel no shut,
I seh, PRLI crashing all through the nights, yeah!
Then SAN admin would reassign the LUN, say,
Of which to a proper  server pwwn, yeah!
Now,Your compute is your storage
And so I've got  Nutanix Converged Architecture.
Oh, while SAN is gone,
Everything's gonna be all right!
Everything's gonna be all right!
Everything's gonna be all right, yeah!
Everything's gonna be all right!
Everything's gonna be all right-a!
Everything's gonna be all right!
Everything's gonna be all right, yeah!
Everything's gonna be all right!

So no, SAN, no cry;
No, SAN, no cry.
I seh, O Server Admin - O Storage Admin', don't shed no tears;
No, SAN, no cry, eh.

No, SAN - no, SAN - no, SAN, no cry;
No, SAN, no cry.
One more time I got to say:
O Server Admin - Storage Admin', please don't shed no tears;
No, SAN, no cry.

Wednesday, October 23, 2013

vmware: Unidesk VM on NFS taking about a minute to start booting up.

Here we look at traces (NFS) to find few inefficiencies of VMware NFS client
unidesk config:

 




there is Workaround available: (from nutanix/unidesk support)

The workaround is to follow these guidelines:
1. Ensure the root of the datastore has as few directories as possible. 
2. The desktop VM's files need to be two directories below the root of the data store.

Assuming a greenfield setup, this is how to setup the directory structure.

1. Create one directory for the desktop VMs.
2. Create one directory for all the CPs and the rest of the infrastructure VMs.
3. If VMs were automatically deployed, unregister VMs, move into the appropriate subdirectory, register VMs.
4. Use the "synchronize infrastructure" in the Unidesk Management Appliance UI to discover the new VM ids which change after re-registering.

Example of a 3 desktop setup:
/vmfs/volumes/ctr1/DesktopVMs/VM1
/vmfs/volumes/ctr1/DesktopVMs/VM2
/vmfs/volumes/ctr1/DesktopVMs/VM3

/vmfs/volumes/ctr1/InfraVMs/CachePoint1
/vmfs/volumes/ctr1/InfraVMs/CachePoint2
/vmfs/volumes/ctr1/InfraVMs/CachePoint3
/vmfs/volumes/ctr1/InfraVMs/MA
/vmfs/volumes/ctr1/InfraVMs/MasterCachePoint
/vmfs/volumes/ctr1/InfraVMs/InstallationMachine1


More details on the issue:
 

How to capture NFS traffic on Nutanix, so that we can review through the wireshark.

1. Power off all the VMs other than CVM and Unidesk VM, so that we get clean trace.


sudo tcpdump -i eth1 port 2049 -w nfs.cap

 


 Bootup time in Vcenter:
 ~Unidesk-TESTVM   Completed  Administrator  pax-vCenter
start time:10/21/2013 1:53:19 PM
Bootup complete as per Vcenter: 10/21/2013 1:54:13 PM ( it still needs to boot the OS), It waits for more than
40 seconds at 95%)
 
Four things I can see that are odd :

1. NFS client is looking for entire / directory rather than focussing on the files .
(Unidesk KB specifically addresses how to reduce this issue this : http://www.unidesk.com/support/kb/unidesk-configuration-considerations-nfs-based-storage-including-nutanix-your-boot-images)


and looking  UP sre-theos2,sretheos1 which are not part of ~Unidesk directory.



2. It is creating too many vmBigTestFile ( it should be enough to create one).
3. REDO logs - looking up and then verifying and then creating the files (
so it will take while before sending create files)

repeated create and remove of redo logs ( not sure why ESXi nfs client has to do that)


4. Workers (4 workers) do not work parallely, they seem to work serially. - deduced
from wireshark and vmware.log file. During the Pause I see other worker is active.


On our system, it took about 56seconds. It is a 2400 system.
It took about 37 seconds for opening and closing of the vmdks. ( of which 13-15 seconds was ESXi waiting after open successful to close).
It is same as your system.


/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM # grep vmfs vmware.log|head -1
2013-10-21T20:28:03.795Z| vmx| I120: Command line: "/bin/vmx" "-ssched.group=host/user" "-#" "product=4;name=VMware ESX;version=5.1.0;buildnumber=1065491;licensename=VMware ESX Server;licenseversion=5.0;" "-@" "duplex=3;msgs=ui" "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM.vmx"
/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM # grep vmfs vmware.log|tail -1
2013-10-21T20:28:40.674Z| Worker#3| I120: DISKLIB-LIB   : Opened "./~Unidesk-TESTVM_13.vmdk.REDO_6uPnSb" (flags 0x8, type vmfsSparse).




/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM # grep Worker#3 vmware.log
2013-10-21T20:28:04.503Z| Worker#3| I120: DISK: OPEN scsi0:3 '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_17.vmdk' independent-nonpersistent R[]
2013-10-21T20:28:04.870Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:04.877Z| Worker#3| I120: DISKLIB-VMFS  : "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_17-flat.vmdk" : open successful (14) size = 10737418240, hd = 157193863. Type 3
2013-10-21T20:28:04.877Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_17-flat.vmdk" (0xe)
2013-10-21T20:28:04.877Z| Worker#3| I120: DISKLIB-LINK  : Opened '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_17.vmdk' (0xe): vmfs, 20971520 sectors / 10 GB.
2013-10-21T20:28:04.922Z| Worker#3| I120: DISKLIB-LIB   : Opened "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_17.vmdk" (flags 0xe, type vmfs).
2013-10-21T20:28:05.847Z| Worker#3| I120: DISKLIB-LIB   : DiskLibCreateCreateParam: vmfssparse grain size set to : 1
2013-10-21T20:28:06.030Z| Worker#3| I120: DISKLIB-LIB   : CREATE CHILD: "./~Unidesk-TESTVM_17.vmdk.REDO_grMSJ6" -- vmfsSparse cowGran=0 allocType=0
2013-10-21T20:28:06.033Z| Worker#3| I120: CREATE-CHILD: Creating disk backed by 'default'
2013-10-21T20:28:06.656Z| Worker#3| I120: DISKLIB-VMFS_SPARSE : VmfsSparseExtentCreate: "./~Unidesk-TESTVM_17.vmdk-delta.REDO_grMSJ6" : success
2013-10-21T20:28:06.706Z| Worker#3| I120: DISKLIB-DSCPTR: "./~Unidesk-TESTVM_17.vmdk.REDO_grMSJ6" : creation successful.
2013-10-21T20:28:07.304Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:07.310Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_17.vmdk-delta.REDO_grMSJ6" : open successful (17) size = 24576, hd = 0. Type 8

--   2 seconds

2013-10-21T20:28:09.704Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_17.vmdk-delta.REDO_grMSJ6" : closed.
2013-10-21T20:28:10.088Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:10.100Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_17.vmdk-delta.REDO_grMSJ6" : open successful (8) size = 24576, hd = 152606383. Type 8
2013-10-21T20:28:10.100Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_17.vmdk-delta.REDO_grMSJ6" (0x8)
2013-10-21T20:28:10.100Z| Worker#3| I120: DISKLIB-LINK  : Opened './~Unidesk-TESTVM_17.vmdk.REDO_grMSJ6' (0x8): vmfsSparse, 20971520 sectors / 10 GB.
2013-10-21T20:28:10.100Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2013-10-21T20:28:10.100Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 152606383, extentType = 0
2013-10-21T20:28:10.123Z| Worker#3| I120: DISKLIB-LIB   : Opened "./~Unidesk-TESTVM_17.vmdk.REDO_grMSJ6" (flags 0x8, type vmfsSparse).
2013-10-21T20:28:10.123Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 2, numSubChains = 1
2013-10-21T20:28:10.123Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 157193863, extentType = 2
2013-10-21T20:28:10.124Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 152606383, extentType = 0
2013-10-21T20:28:10.149Z| Worker#3| I120: DISK: Disk './~Unidesk-TESTVM_17.vmdk.REDO_grMSJ6' has UUID '60 00 c2 95 e9 99 ac 11-ff da ee ef 7d d0 cc 3d'
2013-10-21T20:28:10.149Z| Worker#3| I120: DISK: OPEN './~Unidesk-TESTVM_17.vmdk.REDO_grMSJ6' Geo (1305/255/63) BIOS Geo (0/0/0)


2013-10-21T20:28:10.196Z| Worker#3| I120: DISK: OPEN scsi0:8 '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_21.vmdk' independent-nonpersistent R[]
2013-10-21T20:28:10.386Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:10.495Z| Worker#3| I120: DISKLIB-VMFS  : "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_21-flat.vmdk" : open successful (14) size = 10737418240, hd = 158897845. Type 3
2013-10-21T20:28:10.495Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_21-flat.vmdk" (0xe)
2013-10-21T20:28:10.495Z| Worker#3| I120: DISKLIB-LINK  : Opened '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_21.vmdk' (0xe): vmfs, 20971520 sectors / 10 GB.
2013-10-21T20:28:10.498Z| Worker#3| I120: DISKLIB-LIB   : Opened "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_21.vmdk" (flags 0xe, type vmfs).
2013-10-21T20:28:11.418Z| Worker#3| I120: DISKLIB-LIB   : DiskLibCreateCreateParam: vmfssparse grain size set to : 1
2013-10-21T20:28:11.514Z| Worker#3| I120: DISKLIB-LIB   : CREATE CHILD: "./~Unidesk-TESTVM_21.vmdk.REDO_QnAph7" -- vmfsSparse cowGran=0 allocType=0
2013-10-21T20:28:11.523Z| Worker#3| I120: CREATE-CHILD: Creating disk backed by 'default'
2013-10-21T20:28:12.114Z| Worker#3| I120: DISKLIB-VMFS_SPARSE : VmfsSparseExtentCreate: "./~Unidesk-TESTVM_21.vmdk-delta.REDO_QnAph7" : success
2013-10-21T20:28:12.258Z| Worker#3| I120: DISKLIB-DSCPTR: "./~Unidesk-TESTVM_21.vmdk.REDO_QnAph7" : creation successful.
2013-10-21T20:28:13.161Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:13.168Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_21.vmdk-delta.REDO_QnAph7" : open successful (17) size = 24576, hd = 0. Type 8

 2 seconds

2013-10-21T20:28:15.207Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_21.vmdk-delta.REDO_QnAph7" : closed.
2013-10-21T20:28:15.775Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:15.819Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_21.vmdk-delta.REDO_QnAph7" : open successful (8) size = 24576, hd = 141858511. Type 8
2013-10-21T20:28:15.819Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_21.vmdk-delta.REDO_QnAph7" (0x8)
2013-10-21T20:28:15.819Z| Worker#3| I120: DISKLIB-LINK  : Opened './~Unidesk-TESTVM_21.vmdk.REDO_QnAph7' (0x8): vmfsSparse, 20971520 sectors / 10 GB.
2013-10-21T20:28:15.819Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2013-10-21T20:28:15.819Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 141858511, extentType = 0
2013-10-21T20:28:15.837Z| Worker#3| I120: DISKLIB-LIB   : Opened "./~Unidesk-TESTVM_21.vmdk.REDO_QnAph7" (flags 0x8, type vmfsSparse).
2013-10-21T20:28:15.838Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 2, numSubChains = 1
2013-10-21T20:28:15.838Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 158897845, extentType = 2
2013-10-21T20:28:15.838Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 141858511, extentType = 0
2013-10-21T20:28:15.876Z| Worker#3| I120: DISK: Disk './~Unidesk-TESTVM_21.vmdk.REDO_QnAph7' has UUID '60 00 c2 95 84 24 a5 34-e5 25 bc b7 82 0f f9 35'
2013-10-21T20:28:15.876Z| Worker#3| I120: DISK: OPEN './~Unidesk-TESTVM_21.vmdk.REDO_QnAph7' Geo (1305/255/63) BIOS Geo (0/0/0)



2013-10-21T20:28:15.957Z| Worker#3| I120: DISK: OPEN scsi0:12 '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_25.vmdk' independent-nonpersistent R[]
2013-10-21T20:28:16.235Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:16.255Z| Worker#3| I120: DISKLIB-VMFS  : "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_25-flat.vmdk" : open successful (14) size = 10737418240, hd = 154441437. Type 3
2013-10-21T20:28:16.255Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_25-flat.vmdk" (0xe)
2013-10-21T20:28:16.255Z| Worker#3| I120: DISKLIB-LINK  : Opened '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_25.vmdk' (0xe): vmfs, 20971520 sectors / 10 GB.
2013-10-21T20:28:16.380Z| Worker#3| I120: DISKLIB-LIB   : Opened "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_25.vmdk" (flags 0xe, type vmfs).
2013-10-21T20:28:17.299Z| Worker#3| I120: DISKLIB-LIB   : DiskLibCreateCreateParam: vmfssparse grain size set to : 1
2013-10-21T20:28:17.497Z| Worker#3| I120: DISKLIB-LIB   : CREATE CHILD: "./~Unidesk-TESTVM_25.vmdk.REDO_4Isqws" -- vmfsSparse cowGran=0 allocType=0
2013-10-21T20:28:17.500Z| Worker#3| I120: CREATE-CHILD: Creating disk backed by 'default'
2013-10-21T20:28:18.249Z| Worker#3| I120: DISKLIB-VMFS_SPARSE : VmfsSparseExtentCreate: "./~Unidesk-TESTVM_25.vmdk-delta.REDO_4Isqws" : success
2013-10-21T20:28:18.423Z| Worker#3| I120: DISKLIB-DSCPTR: "./~Unidesk-TESTVM_25.vmdk.REDO_4Isqws" : creation successful.
2013-10-21T20:28:19.280Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:19.304Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_25.vmdk-delta.REDO_4Isqws" : open successful (17) size = 24576, hd = 0. Type 8

 2 seconds

2013-10-21T20:28:21.714Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_25.vmdk-delta.REDO_4Isqws" : closed.
2013-10-21T20:28:22.184Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:22.189Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_25.vmdk-delta.REDO_4Isqws" : open successful (8) size = 24576, hd = 155686649. Type 8
2013-10-21T20:28:22.189Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_25.vmdk-delta.REDO_4Isqws" (0x8)
2013-10-21T20:28:22.189Z| Worker#3| I120: DISKLIB-LINK  : Opened './~Unidesk-TESTVM_25.vmdk.REDO_4Isqws' (0x8): vmfsSparse, 20971520 sectors / 10 GB.
2013-10-21T20:28:22.189Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2013-10-21T20:28:22.189Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 155686649, extentType = 0
2013-10-21T20:28:22.222Z| Worker#3| I120: DISKLIB-LIB   : Opened "./~Unidesk-TESTVM_25.vmdk.REDO_4Isqws" (flags 0x8, type vmfsSparse).
2013-10-21T20:28:22.222Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 2, numSubChains = 1
2013-10-21T20:28:22.222Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 154441437, extentType = 2
2013-10-21T20:28:22.222Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 155686649, extentType = 0
2013-10-21T20:28:22.253Z| Worker#3| I120: DISK: Disk './~Unidesk-TESTVM_25.vmdk.REDO_4Isqws' has UUID '60 00 c2 96 68 ce 90 d3-83 68 6b 87 bc a4 a7 f6'
2013-10-21T20:28:22.253Z| Worker#3| I120: DISK: OPEN './~Unidesk-TESTVM_25.vmdk.REDO_4Isqws' Geo (1305/255/63) BIOS Geo (0/0/0)



2013-10-21T20:28:22.297Z| Worker#3| I120: DISK: OPEN scsi1:2 '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_2.vmdk' independent-nonpersistent R[]
2013-10-21T20:28:22.868Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:23.843Z| Worker#3| I120: DISKLIB-VMFS  : "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_2-flat.vmdk" : open successful (14) size = 10737418240, hd = 151295754. Type 3
2013-10-21T20:28:23.843Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_2-flat.vmdk" (0xe)
2013-10-21T20:28:23.843Z| Worker#3| I120: DISKLIB-LINK  : Opened '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_2.vmdk' (0xe): vmfs, 20971520 sectors / 10 GB.
2013-10-21T20:28:23.907Z| Worker#3| I120: DISKLIB-LIB   : Opened "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_2.vmdk" (flags 0xe, type vmfs).
2013-10-21T20:28:24.402Z| Worker#3| I120: DISKLIB-LIB   : DiskLibCreateCreateParam: vmfssparse grain size set to : 1
2013-10-21T20:28:24.483Z| Worker#3| I120: DISKLIB-LIB   : CREATE CHILD: "./~Unidesk-TESTVM_2.vmdk.REDO_yXB1Cf" -- vmfsSparse cowGran=0 allocType=0
2013-10-21T20:28:24.532Z| Worker#3| I120: CREATE-CHILD: Creating disk backed by 'default'
2013-10-21T20:28:25.310Z| Worker#3| I120: DISKLIB-VMFS_SPARSE : VmfsSparseExtentCreate: "./~Unidesk-TESTVM_2.vmdk-delta.REDO_yXB1Cf" : success
2013-10-21T20:28:25.352Z| Worker#3| I120: DISKLIB-DSCPTR: "./~Unidesk-TESTVM_2.vmdk.REDO_yXB1Cf" : creation successful.
2013-10-21T20:28:26.020Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:26.026Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_2.vmdk-delta.REDO_yXB1Cf" : open successful (17) size = 24576, hd = 0. Type 8

 2 seconds
2013-10-21T20:28:28.685Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_2.vmdk-delta.REDO_yXB1Cf" : closed.
2013-10-21T20:28:29.066Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:29.097Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_2.vmdk-delta.REDO_yXB1Cf" : open successful (8) size = 24576, hd = 140744474. Type 8
2013-10-21T20:28:29.097Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_2.vmdk-delta.REDO_yXB1Cf" (0x8)
2013-10-21T20:28:29.097Z| Worker#3| I120: DISKLIB-LINK  : Opened './~Unidesk-TESTVM_2.vmdk.REDO_yXB1Cf' (0x8): vmfsSparse, 20971520 sectors / 10 GB.
2013-10-21T20:28:29.097Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2013-10-21T20:28:29.097Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 140744474, extentType = 0
2013-10-21T20:28:29.116Z| Worker#3| I120: DISKLIB-LIB   : Opened "./~Unidesk-TESTVM_2.vmdk.REDO_yXB1Cf" (flags 0x8, type vmfsSparse).
2013-10-21T20:28:29.116Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 2, numSubChains = 1
2013-10-21T20:28:29.116Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 151295754, extentType = 2
2013-10-21T20:28:29.116Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 140744474, extentType = 0
2013-10-21T20:28:29.139Z| Worker#3| I120: DISK: Disk './~Unidesk-TESTVM_2.vmdk.REDO_yXB1Cf' has UUID '60 00 c2 9a 23 51 be 1d-8c 5a 0e c8 72 31 85 d2'
2013-10-21T20:28:29.139Z| Worker#3| I120: DISK: OPEN './~Unidesk-TESTVM_2.vmdk.REDO_yXB1Cf' Geo (1305/255/63) BIOS Geo (0/0/0)
2013-10-21T20:28:29.235Z| Worker#3| I120: DISK: OPEN scsi1:6 '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_6.vmdk' independent-nonpersistent R[]
2013-10-21T20:28:29.644Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:29.651Z| Worker#3| I120: DISKLIB-VMFS  : "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_6-flat.vmdk" : open successful (14) size = 10737418240, hd = 199005995. Type 3
2013-10-21T20:28:29.651Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_6-flat.vmdk" (0xe)
2013-10-21T20:28:29.651Z| Worker#3| I120: DISKLIB-LINK  : Opened '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_6.vmdk' (0xe): vmfs, 20971520 sectors / 10 GB.
2013-10-21T20:28:29.656Z| Worker#3| I120: DISKLIB-LIB   : Opened "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_6.vmdk" (flags 0xe, type vmfs).
2013-10-21T20:28:30.684Z| Worker#3| I120: DISKLIB-LIB   : DiskLibCreateCreateParam: vmfssparse grain size set to : 1
2013-10-21T20:28:30.766Z| Worker#3| I120: DISKLIB-LIB   : CREATE CHILD: "./~Unidesk-TESTVM_6.vmdk.REDO_oUoy4b" -- vmfsSparse cowGran=0 allocType=0
2013-10-21T20:28:30.777Z| Worker#3| I120: CREATE-CHILD: Creating disk backed by 'default'
2013-10-21T20:28:31.230Z| Worker#3| I120: DISKLIB-VMFS_SPARSE : VmfsSparseExtentCreate: "./~Unidesk-TESTVM_6.vmdk-delta.REDO_oUoy4b" : success
2013-10-21T20:28:31.423Z| Worker#3| I120: DISKLIB-DSCPTR: "./~Unidesk-TESTVM_6.vmdk.REDO_oUoy4b" : creation successful.
2013-10-21T20:28:32.308Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:32.341Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_6.vmdk-delta.REDO_oUoy4b" : open successful (17) size = 24576, hd = 0. Type 8

 --- 2 seconds 
2013-10-21T20:28:34.457Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_6.vmdk-delta.REDO_oUoy4b" : closed.
2013-10-21T20:28:34.717Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:34.722Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_6.vmdk-delta.REDO_oUoy4b" : open successful (8) size = 24576, hd = 181901123. Type 8
2013-10-21T20:28:34.722Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_6.vmdk-delta.REDO_oUoy4b" (0x8)
2013-10-21T20:28:34.722Z| Worker#3| I120: DISKLIB-LINK  : Opened './~Unidesk-TESTVM_6.vmdk.REDO_oUoy4b' (0x8): vmfsSparse, 20971520 sectors / 10 GB.
2013-10-21T20:28:34.722Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2013-10-21T20:28:34.722Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 181901123, extentType = 0
2013-10-21T20:28:34.769Z| Worker#3| I120: DISKLIB-LIB   : Opened "./~Unidesk-TESTVM_6.vmdk.REDO_oUoy4b" (flags 0x8, type vmfsSparse).
2013-10-21T20:28:34.769Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 2, numSubChains = 1
2013-10-21T20:28:34.769Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 199005995, extentType = 2
2013-10-21T20:28:34.769Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 181901123, extentType = 0
2013-10-21T20:28:34.805Z| Worker#3| I120: DISK: Disk './~Unidesk-TESTVM_6.vmdk.REDO_oUoy4b' has UUID '60 00 c2 9c 9e 2d 8c 87-b7 d5 50 37 2a 7d 39 e7'
2013-10-21T20:28:34.805Z| Worker#3| I120: DISK: OPEN './~Unidesk-TESTVM_6.vmdk.REDO_oUoy4b' Geo (1305/255/63) BIOS Geo (0/0/0)


2013-10-21T20:28:34.897Z| Worker#3| I120: DISK: OPEN scsi1:14 '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_13.vmdk' independent-nonpersistent R[]
2013-10-21T20:28:35.334Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:35.348Z| Worker#3| I120: DISKLIB-VMFS  : "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_13-flat.vmdk" : open successful (14) size = 3758096384, hd = 146904906. Type 3
2013-10-21T20:28:35.348Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_13-flat.vmdk" (0xe)
2013-10-21T20:28:35.348Z| Worker#3| I120: DISKLIB-LINK  : Opened '/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_13.vmdk' (0xe): vmfs, 7340032 sectors / 3.5 GB.
2013-10-21T20:28:35.438Z| Worker#3| I120: DISKLIB-LIB   : Opened "/vmfs/volumes/2fbb0409-ee3410bd/~Unidesk-TESTVM/~Unidesk-TESTVM_13.vmdk" (flags 0xe, type vmfs).
2013-10-21T20:28:35.876Z| Worker#3| I120: DISKLIB-LIB   : DiskLibCreateCreateParam: vmfssparse grain size set to : 1
2013-10-21T20:28:35.954Z| Worker#3| I120: DISKLIB-LIB   : CREATE CHILD: "./~Unidesk-TESTVM_13.vmdk.REDO_6uPnSb" -- vmfsSparse cowGran=0 allocType=0
2013-10-21T20:28:36.002Z| Worker#3| I120: CREATE-CHILD: Creating disk backed by 'default'
2013-10-21T20:28:36.632Z| Worker#3| I120: DISKLIB-VMFS_SPARSE : VmfsSparseExtentCreate: "./~Unidesk-TESTVM_13.vmdk-delta.REDO_6uPnSb" : success
2013-10-21T20:28:36.780Z| Worker#3| I120: DISKLIB-DSCPTR: "./~Unidesk-TESTVM_13.vmdk.REDO_6uPnSb" : creation successful.
2013-10-21T20:28:37.618Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:37.655Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_13.vmdk-delta.REDO_6uPnSb" : open successful (17) size = 12288, hd = 0. Type 8

3 seconds

2013-10-21T20:28:40.221Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_13.vmdk-delta.REDO_6uPnSb" : closed.
2013-10-21T20:28:40.562Z| Worker#3| I120: nutanix_nfs_plugin: Established VAAI session with NFS server 192.168.5.2
2013-10-21T20:28:40.594Z| Worker#3| I120: DISKLIB-VMFS  : "./~Unidesk-TESTVM_13.vmdk-delta.REDO_6uPnSb" : open successful (8) size = 12288, hd = 157652962. Type 8
2013-10-21T20:28:40.594Z| Worker#3| I120: DISKLIB-DSCPTR: Opened [0]: "~Unidesk-TESTVM_13.vmdk-delta.REDO_6uPnSb" (0x8)
2013-10-21T20:28:40.594Z| Worker#3| I120: DISKLIB-LINK  : Opened './~Unidesk-TESTVM_13.vmdk.REDO_6uPnSb' (0x8): vmfsSparse, 7340032 sectors / 3.5 GB.
2013-10-21T20:28:40.594Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2013-10-21T20:28:40.594Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 157652962, extentType = 0
2013-10-21T20:28:40.674Z| Worker#3| I120: DISKLIB-LIB   : Opened "./~Unidesk-TESTVM_13.vmdk.REDO_6uPnSb" (flags 0x8, type vmfsSparse).
2013-10-21T20:28:40.674Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 2, numSubChains = 1
2013-10-21T20:28:40.674Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 146904906, extentType = 2
2013-10-21T20:28:40.674Z| Worker#3| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 157652962, extentType = 0
2013-10-21T20:28:40.757Z| Worker#3| I120: DISK: Disk './~Unidesk-TESTVM_13.vmdk.REDO_6uPnSb' has UUID '60 00 c2 96 78 0e 37 cd-a2 10 ae b7 8f 64 f0 68'
2013-10-21T20:28:40.757Z| Worker#3| I120: DISK: OPEN './~Unidesk-TESTVM_13.vmdk.REDO_6uPnSb' Geo (456/255/63) BIOS Geo (0/0/0)