Begin VxMS Session... Logmask set to 0x90007780 Current Environment Variables VFM_ROOT = NULL VFM_PRIVATE_ROOT = NULL VFM_MAP_API_LIB = NULL VFM_MAP_DIR = NULL VFM_UTIL_LIB = NULL 11:02:14.0691 : vhd_map_init:../libvhd.cpp:828 : Entered 11:02:14.0691 : vhd_map_init:../libvhd.cpp:847 : Exited 11:02:14.0691 : vhdMapInit:../VhdCoordinator.cpp:626 : Entered 11:02:14.0691 : vhdMapInit:../VhdCoordinator.cpp:665 : Exited 11:02:14.0691 : vhd_map_init:../libvhd.cpp:860 : Exited 11:02:14.0692 : vhd_map_claim_id:../libvhd.cpp:217 : Entered:: Objid: C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.spm4.domain.com_1447660908.1.0.NBU_DATA.xml 11:02:14.0692 : vhd_map_claim_id:../libvhd.cpp:237 : Exited 11:02:14.0692 : vhdMapClaimId:../VhdCoordinator.cpp:146 : Entered: Objid: C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.spm4.domain.com_1447660908.1.0.NBU_DATA.xml 11:02:14.0692 : claimId:../VhdManager.cpp:174 : Entered 11:02:14.0692 : claimId:../VhdManager.cpp:221 : Exited 11:02:14.0692 : claimHyperVGuestId:../VhdManager.cpp:282 : Entered 11:02:14.0692 : claimHyperVGuestId:../VhdManager.cpp:301 : Allocating buffer of filesize 4254 and reading the file 11:02:14.0692 : claimHyperVGuestId:../VhdManager.cpp:313 : filesize = 4254 and bytesRead = 4254 11:02:14.0692 : claimHyperVGuestId:../VhdManager.cpp:382 : Exited with no claim 11:02:14.0692 : vhdMapClaimId:../VhdCoordinator.cpp:178 : Exited 11:02:14.0703 : vix_map_init:../libvix.cpp:1037 : Allocated VixCoordinator 11:02:14.0703 : vix_map_claim_id:../libvix.cpp:232 : Objid: C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.spm4.domain.com_1447660908.1.0.NBU_DATA.xml 11:02:14.0703 : vixMapClaimId:../VixCoordinator.cpp:187 : Objid: C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.spm4.domain.com_1447660908.1.0.NBU_DATA.xml 11:02:14.0703 : claimId:../VixManager.cpp:202 : Objid: C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.spm4.domain.com_1447660908.1.0.NBU_DATA.xml 11:02:14.0704 : claimId:../VixManager.cpp:280 : Returned: VF_CLAIM_SECONDARY 11:02:14.0704 : setEnvVar:VixInterface.h:245 : in 11:02:14.0704 : setEnvVar:VixInterface.h:256 : Existing key:PATH value: C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files\ActivIdentity\ActivClient\;C:\Program Files (x86)\ActivIdentity\ActivClient\;c:\Program Files\MIT\Kerberos\bin;C:\Program Files (x86)\HITACHI\D 11:02:14.0704 : setEnvVar:VixInterface.h:262 : Adding 'C:\Program Files\Common Files\VERITAS\VxMS\\Shared\VDDK\bin\' to 'PATH' 11:02:14.0704 : setEnvVar:VixInterface.h:245 : out 11:02:14.0704 : DynLoadDiskLib:VixInterface.h:346 : Loading: C:\Program Files\Common Files\VERITAS\VxMS\\Shared\VDDK\bin\vixDiskLibVim.dll 11:02:14.0712 : DynLoadDiskLib:VixInterface.h:353 : Loading: C:\Program Files\Common Files\VERITAS\VxMS\\Shared\VDDK\bin\vixDiskLib.dll 11:02:14.0713 : VixInterface:VixInterface.h:493 : m_libDir: C:\Program Files\Common Files\VERITAS\VxMS\\Shared\VDDK\ 11:02:14.0713 : getInstance:../VixInterface.cpp:1262 : Allocated VIX instance: 000000000157A090 11:02:14.0713 : getInstance:../VixInterface.cpp:1263 : Reference VIX instance: 1 11:02:14.0713 : vdInit:../VixInterface.cpp:290 : Registry key not found: 'createVDDKlog'. 2 11:02:14.0713 : vdInit:../VixInterface.cpp:369 : vixDiskLib directory: C:\Program Files\Common Files\VERITAS\VxMS\\Shared\VDDK\ 11:02:14.0713 : vdInit:../VixInterface.cpp:377 : Using existing vixDiskLib config file: C:\Program Files\Common Files\VERITAS\VxMS\\Shared\VDDK\bin\vixDiskLib.ini 11:02:14.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: config options: libdir 'C:\Program Files\Common Files\VERITAS\VxMS\\Shared\VDDK\', tmpDir 'C:\Users\NB_SER~1\AppData\Local\Temp\vmware-nb_service'. 11:02:14.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Initialize Disklib. 11:02:14.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] OBJLIB-LIB: Objlib initialized. 11:02:14.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Attempting to locate advanced transport module in "C:\Program Files\Common Files\VERITAS\VxMS\\Shared\VDDK\". 11:02:15.0247 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Advanced transport plugin was successfully loaded into vixDiskLib. 11:02:15.0247 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Enabling advanced transport modes. 11:02:15.0250 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] OBJLIB-LIB: Objlib initialized. 11:02:15.0270 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Available transport modes from DiskLib: file:nbdssl:nbd:san. 11:02:15.0270 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Initialize transport modes. 11:02:15.0271 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Available transport modes: file:san:hotadd:nbdssl:nbd. 11:02:15.0271 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VMware VixDiskLib (5.5) Release build-1601882 11:02:15.0271 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Initializing SSL. 11:02:15.0274 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Initializing NFC. 11:02:15.0275 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] PREF early PreferenceGet(poll.forceSelect), using default 11:02:15.0275 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] POLL Using the WSAPoll API Implementation for PollDefault 11:02:15.0277 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLibVim: VixDiskLibVim_Init: Initialization is completed. 11:02:15.0296 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.296+03:00 [10044 info 'ThreadPool'] Thread enlisted 11:02:15.0296 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.296+03:00 [09496 info 'ThreadPool'] Thread enlisted 11:02:15.0296 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.296+03:00 [12136 info 'ThreadPool'] Thread enlisted 11:02:15.0296 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.296+03:00 [11856 info 'ThreadPool'] Thread enlisted 11:02:15.0308 : vix_map_open_id:../libvix.cpp:1291 : Flags: 0x80003 11:02:15.0308 : vixMapOpenId:../VixCoordinator.cpp:1006 : Flags: 0x80003 11:02:15.0308 : claimId:../VixManager.cpp:202 : Objid: C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.spm4.domain.com_1447660908.1.0.NBU_DATA.xml 11:02:15.0308 : claimId:../VixManager.cpp:280 : Returned: VF_CLAIM_SECONDARY 11:02:15.0308 : openId:../VixManager.cpp:353 : Opening guest 11:02:15.0308 : openGuest:../VixManager.cpp:441 : Flags: 0x80003 11:02:15.0308 : vixMapOpenId:../VixCoordinator.cpp:1025 : rflags returned: 0x3f5685dc 11:02:15.0309 : vixMapObjCtl:../VixCoordinator.cpp:926 : cmd: -109 11:02:15.0309 : vixMapObjCtl:../VixCoordinator.cpp:954 : case RVP_OBJECT_TYPE_GUEST 11:02:15.0309 : vixMapObjCtl:../VixCoordinator.cpp:926 : cmd: -103 11:02:15.0309 : vixMapObjCtl:../VixCoordinator.cpp:954 : case RVP_OBJECT_TYPE_GUEST 11:02:15.0309 : loadVixConfiguration:../VixGuest.cpp:1311 : Successfully parsed vix xml file 11:02:15.0309 : parseAndLoadDrives:../VixGuest.cpp:1460 : SnapshotName = NBU_SNAPSHOT svs2.domain.com 1447660919 11:02:15.0309 : parseAndLoadDrives:../VixGuest.cpp:1467 : SnapshotMoref = snapshot-6933 11:02:15.0310 : parseAndLoadDrives:../VixGuest.cpp:1501 : Disk Key = 2000 11:02:15.0310 : parseAndLoadDrives:../VixGuest.cpp:1520 : DiskController = 2000 11:02:15.0310 : parseAndLoadDrives:../VixGuest.cpp:1541 : ChangeId = 11:02:15.0310 : parseAndLoadDrives:../VixGuest.cpp:1501 : Disk Key = 2001 11:02:15.0310 : parseAndLoadDrives:../VixGuest.cpp:1520 : DiskController = 2001 11:02:15.0310 : parseAndLoadDrives:../VixGuest.cpp:1541 : ChangeId = 11:02:15.0310 : parseAndLoadDrives:../VixGuest.cpp:1638 : Number of VirtualDisks (excluding Independent disks) = 2 11:02:15.0310 : parseAndLoadDrives:../VixGuest.cpp:1639 : Number of Independent disks = 0 11:02:15.0310 : setupVixDiskSnapshotChains:../VixGuest.cpp:1794 : Successfully setup disk snapshot chain 11:02:15.0310 : parseAndLoadDrives:../VixGuest.cpp:1654 : Successfully parsed and loaded drives 11:02:15.0310 : openVM:../VixGuest.cpp:798 : Successfully loaded Vix configuration 11:02:15.0310 : openLeafSnapshotDisks:../VixGuest.cpp:432 : Calling connectToHost(SnapMoRef: snapshot-6933, TransportMode: san) 11:02:15.0310 : connectToHost:../VixGuest.cpp:962 : TransportMode requested: san 11:02:15.0310 : connectToHost:../VixGuest.cpp:967 : Transport Modes available on this host: file:san:hotadd:nbdssl:nbd 11:02:15.0310 : vdCleanup:../VixInterface.cpp:1334 : Using non-standard port: svs2.domain.com:443 11:02:15.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: VixDiskLib_Cleanup: Remove previous mount points and clean up . 11:02:15.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: VixDiskLib_Connect: Establish connection. 11:02:15.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: VixDiskLib_Connect: Use remote connection. 11:02:15.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Allocate connection. 11:02:15.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Prepare remote connect. 11:02:15.0317 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: VixDiskLib_Disconnect: Disconnect. 11:02:15.0318 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Clean up connection. 11:02:15.0318 : vdConnect:../VixInterface.cpp:1172 : Using non-standard port: svs2.domain.com:443 11:02:15.0318 : vdConnect:../VixInterface.cpp:1192 : Calling VixDiskLib_ConnectEx() 11:02:15.0318 : vdConnect:../VixInterface.cpp:1193 : vmxSpec: moref=vm-2488 11:02:15.0318 : vdConnect:../VixInterface.cpp:1194 : serverName: svs2.domain.com:443 11:02:15.0318 : vdConnect:../VixInterface.cpp:1195 : thumbPrint: 11:02:15.0318 : vdConnect:../VixInterface.cpp:1196 : credType: 1 11:02:15.0318 : vdConnect:../VixInterface.cpp:1197 : userName: domain\vm_sphere 11:02:15.0318 : vdConnect:../VixInterface.cpp:1198 : port: 0 11:02:15.0318 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: VixDiskLib_ConnectEx: Establish connection using san. 11:02:15.0318 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: VixDiskLib_Connect: Establish connection. 11:02:15.0318 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: VixDiskLib_Connect: Use remote connection. 11:02:15.0318 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Allocate connection. 11:02:15.0318 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Prepare remote connect. 11:02:15.0318 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.318+03:00 [01716 trivia 'Default'] Get advanced transport modes. 11:02:15.0320 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.320+03:00 [01716 info 'Default'] Vmacore::InitSSL: handshakeTimeoutUs = 20000000 11:02:15.0322 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.322+03:00 [01716 verbose 'HttpConnectionPool-000000'] HttpConnectionPoolImpl created. maxPoolConnections = 20; idleTimeout = 900000000; maxOpenConnections = 20; maxConnectionAge = 0 11:02:15.0323 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.323+03:00 [01716 trivia 'HttpConnectionPool-000000'] [IncConnectionCount] Number of connections to incremented to 1 11:02:15.0323 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.323+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:15.0326 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.326+03:00 [11856 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t)>,class boost::_bi::list2,class boost::_bi::value > > >) 11:02:15.0327 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.327+03:00 [11856 trivia 'ThreadPool'] HandleWork() leaving 11:02:15.0328 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.328+03:00 [11856 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:15.0329 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:15.329+03:00 [11856 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0237 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.237+03:00 [11856 info 'Libs'] VThreadBase detected multiple threads. 11:02:20.0237 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.237+03:00 [11856 warning 'Libs'] SSL_VerifyCbHelper: Certificate verification is disabled, so connection will proceed despite the error 11:02:20.0240 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.240+03:00 [11856 warning 'Libs'] SSL_VerifyCbHelper: Certificate verification is disabled, so connection will proceed despite the error 11:02:20.0242 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.242+03:00 [11856 warning 'Libs'] SSL_VerifyCbHelper: Certificate verification is disabled, so connection will proceed despite the error 11:02:20.0252 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.252+03:00 [11856 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0253 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.253+03:00 [11856 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0254 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.254+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0254 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.254+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0256 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.256+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0256 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.256+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0256 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.256+03:00 [01716 warning 'Default'] Closing Response processing in unexpected state: 3 11:02:20.0256 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.256+03:00 [01716 trivia 'HttpConnectionPool-000000'] [DecConnectionCount] Number of connections to decremented to 0 11:02:20.0257 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.257+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 1, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0257 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.257+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0257 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.257+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0257 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.257+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0257 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.257+03:00 [01716 trivia 'transport'] Initializing SSL context 11:02:20.0257 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.257+03:00 [01716 info 'transport'] Connecting to host svs2.domain.com on port 443 using protocol https via vim.version.version9 --> 11:02:20.0257 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.257+03:00 [01716 trivia 'transport'] Retrieve SSL thumbprint. 11:02:20.0260 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.260+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: retrieveContent {} 11:02:20.0261 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.261+03:00 [01716 trivia 'HttpConnectionPool-000000'] [IncConnectionCount] Number of connections to incremented to 1 11:02:20.0261 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.261+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0261 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.261+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0262 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.262+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t)>,class boost::_bi::list2,class boost::_bi::value > > >) 11:02:20.0262 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.262+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0262 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.262+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0263 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.263+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0266 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.266+03:00 [12136 warning 'Libs'] SSL_VerifyCbHelper: Certificate verification is disabled, so connection will proceed despite the error 11:02:20.0268 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.268+03:00 [12136 warning 'Libs'] SSL_VerifyCbHelper: Certificate verification is disabled, so connection will proceed despite the error 11:02:20.0270 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.270+03:00 [12136 warning 'Libs'] SSL_VerifyCbHelper: Certificate verification is disabled, so connection will proceed despite the error 11:02:20.0276 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.276+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0276 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.276+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0276 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.276+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0276 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.276+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0276 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.276+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0276 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.276+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0291 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.291+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0292 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.292+03:00 [09496 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0292 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.292+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0292 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.292+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: retrieveContent 11:02:20.0304 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.304+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0304 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.304+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: retrieveContent {} 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [10044 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 1, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [01716 verbose 'HttpConnectionPool-000001'] HttpConnectionPoolImpl created. maxPoolConnections = 1; idleTimeout = 900000000; maxOpenConnections = 1; maxConnectionAge = 0 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [10044 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [01716 trivia 'HttpConnectionPool-000001'] [IncConnectionCount] Number of connections to incremented to 1 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [01716 trivia 'HttpConnectionPool-000001'] [PopPendingConnection] Found pending connection to 11:02:20.0305 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [10044 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0306 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.305+03:00 [10044 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0306 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.306+03:00 [01716 trivia 'vmomi.soapStub[0]'] service state request started 11:02:20.0307 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.307+03:00 [10044 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t)>,class boost::_bi::list2,class boost::_bi::value > > >) 11:02:20.0307 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.307+03:00 [10044 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0307 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.307+03:00 [10044 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0308 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.308+03:00 [10044 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0308 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.308+03:00 [10044 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0308 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.308+03:00 [10044 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0309 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.309+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0309 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.309+03:00 [12136 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0309 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.309+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: retrieveContent 11:02:20.0309 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.309+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.310+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.310+03:00 [01716 info 'transport'] Connected using API Namespace vim.version.version9. 11:02:20.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.310+03:00 [01716 info 'transport'] Authenticating user domain\vm_sphere 11:02:20.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.310+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: login {} 11:02:20.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.310+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0310 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.310+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0311 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.310+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0311 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.311+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0311 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.311+03:00 [10044 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0311 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.311+03:00 [10044 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0311 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.311+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0311 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.311+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0312 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.312+03:00 [09496 warning 'Libs'] SSL_VerifyCbHelper: Certificate verification is disabled, so connection will proceed despite the error 11:02:20.0314 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.314+03:00 [09496 warning 'Libs'] SSL_VerifyCbHelper: Certificate verification is disabled, so connection will proceed despite the error 11:02:20.0316 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.316+03:00 [09496 warning 'Libs'] SSL_VerifyCbHelper: Certificate verification is disabled, so connection will proceed despite the error 11:02:20.0326 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.326+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0326 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.326+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0326 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.326+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0326 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.326+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0328 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.328+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0329 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.329+03:00 [09496 trivia 'vmomi.soapStub[0]'] Got service state document --> [class Vmacore::Xml::DocumentImpl:0000000002C182E0], 11:02:20.0329 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.329+03:00 [09496 trivia 'vmomi.soapStub[0]'] service state setting instance id to 52 ec de 93 b2 90 4a 4b-03 2f 69 bd 4d f6 35 c8 11:02:20.0329 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.329+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:3, busy_io:1, busy_long:0] HandleWork(type: 1, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0329 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.329+03:00 [09496 trivia 'HttpConnectionPool-000001'] [PopPendingConnection] No pending connections to 11:02:20.0329 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.329+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0329 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.329+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0649 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.649+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0649 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.649+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0649 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.649+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0649 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.649+03:00 [12136 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0649 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.649+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0650 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.650+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: login 11:02:20.0650 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.650+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0650 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.650+03:00 [01716 info 'transport'] Logged in! 11:02:20.0650 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.650+03:00 [01716 info 'transport'] Performing SearchIndex find. 11:02:20.0650 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.650+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: retrieveContent {} 11:02:20.0651 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.651+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0651 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.651+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0651 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.651+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0651 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.651+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0652 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.652+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0652 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.652+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0652 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.652+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0652 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.651+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0654 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.654+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0654 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.654+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0655 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.655+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0655 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.655+03:00 [09496 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0655 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.655+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: retrieveContent 11:02:20.0655 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.655+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0656 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.656+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0656 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.656+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: GetConfig {} 11:02:20.0656 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.656+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0656 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.656+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0656 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.656+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0656 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.656+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0656 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.656+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0656 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.656+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0656 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.656+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0657 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.657+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0660 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.660+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0660 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.660+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0660 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.660+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0661 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.660+03:00 [12136 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0661 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.661+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: GetConfig 11:02:20.0661 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.661+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0661 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.661+03:00 [01716 trivia 'Default'] Looking in buffer (pos 0 len 8020) for chunk size 11:02:20.0661 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.661+03:00 [01716 trivia 'Default'] Found chunk size starting at 0 and ending at 6 11:02:20.0661 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.661+03:00 [01716 trivia 'Default'] Read chunk size: 15816 11:02:20.0661 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.661+03:00 [01716 trivia 'Default'] Asked to read 8172 chars 11:02:20.0661 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.661+03:00 [01716 trivia 'Default'] Found 8014 chars in buffer 11:02:20.0661 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.661+03:00 [01716 trivia 'Default'] Read 158 chars from stream 11:02:20.0661 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.661+03:00 [01716 trivia 'Default'] Returning 8172 chars read 11:02:20.0664 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.664+03:00 [01716 trivia 'Default'] Asked to read 8172 chars 11:02:20.0664 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.664+03:00 [01716 trivia 'Default'] Read 7646 chars from stream 11:02:20.0664 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.664+03:00 [01716 trivia 'Default'] Read 2 terminals so far 11:02:20.0664 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.664+03:00 [01716 trivia 'Default'] Returning 7644 chars read 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Looking in buffer (pos 8020 len 8020) for chunk size 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Read 669 bytes from stream 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Looking in buffer (pos 0 len 669) for chunk size 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Found chunk size starting at 0 and ending at 5 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Read chunk size: 657 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Asked to read 8172 chars 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Found 659 chars in buffer 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Read 2 terminals so far 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Found 0 terminals in cache 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Returning 657 chars read 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Looking in buffer (pos 664 len 669) for chunk size 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Found chunk size starting at 664 and ending at 667 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'Default'] Read chunk size: 0 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0666 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 info 'transport'] MoRef vm-2488 is a valid virtual machine. 11:02:20.0667 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.666+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: GetSummary {} 11:02:20.0667 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.667+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0667 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.667+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0667 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.667+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0667 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.667+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0667 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.667+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0667 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.667+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0667 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.667+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0667 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.667+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0671 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.671+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0671 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.671+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0671 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.671+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0671 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.671+03:00 [09496 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0671 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.671+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: GetSummary 11:02:20.0671 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.671+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [01716 trivia 'transport'] Found vm moref=vm-2488 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: GetConfig {} 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0673 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.673+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0677 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.677+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0677 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.677+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0677 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.677+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0678 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.678+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: GetConfig 11:02:20.0678 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.678+03:00 [12136 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0678 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.678+03:00 [01716 trivia 'Default'] Looking in buffer (pos 0 len 8020) for chunk size 11:02:20.0678 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.678+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0678 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.678+03:00 [01716 trivia 'Default'] Found chunk size starting at 0 and ending at 6 11:02:20.0678 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.678+03:00 [01716 trivia 'Default'] Read chunk size: 15816 11:02:20.0678 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.678+03:00 [01716 trivia 'Default'] Asked to read 8172 chars 11:02:20.0678 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.678+03:00 [01716 trivia 'Default'] Found 8014 chars in buffer 11:02:20.0678 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.678+03:00 [01716 trivia 'Default'] Read 158 chars from stream 11:02:20.0678 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.678+03:00 [01716 trivia 'Default'] Returning 8172 chars read 11:02:20.0679 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.679+03:00 [01716 trivia 'Default'] Asked to read 8172 chars 11:02:20.0679 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.679+03:00 [01716 trivia 'Default'] Read 7646 chars from stream 11:02:20.0679 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.679+03:00 [01716 trivia 'Default'] Read 2 terminals so far 11:02:20.0679 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.679+03:00 [01716 trivia 'Default'] Returning 7644 chars read 11:02:20.0679 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.679+03:00 [01716 trivia 'Default'] Looking in buffer (pos 8020 len 8020) for chunk size 11:02:20.0679 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.679+03:00 [01716 trivia 'Default'] Read 669 bytes from stream 11:02:20.0679 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.679+03:00 [01716 trivia 'Default'] Looking in buffer (pos 0 len 669) for chunk size 11:02:20.0679 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.679+03:00 [01716 trivia 'Default'] Found chunk size starting at 0 and ending at 5 11:02:20.0679 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.679+03:00 [01716 trivia 'Default'] Read chunk size: 657 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'Default'] Asked to read 8172 chars 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'Default'] Found 659 chars in buffer 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'Default'] Read 2 terminals so far 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'Default'] Found 0 terminals in cache 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'Default'] Returning 657 chars read 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'Default'] Looking in buffer (pos 664 len 669) for chunk size 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'Default'] Found chunk size starting at 664 and ending at 667 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'Default'] Read chunk size: 0 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: GetSnapshot {} 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0680 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.680+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0681 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.681+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0681 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.681+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0681 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.681+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0682 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.682+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0682 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.682+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0682 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.682+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0682 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.682+03:00 [09496 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0682 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.682+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: GetSnapshot 11:02:20.0682 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.682+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0683 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.683+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0683 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.683+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: GetConfig {} 11:02:20.0683 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.683+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0683 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.683+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0683 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.683+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0683 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.683+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0683 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.683+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0683 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.683+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0683 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.683+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0683 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.683+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0688 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.688+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0688 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.688+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0688 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.688+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0688 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.688+03:00 [12136 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0688 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.688+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: GetConfig 11:02:20.0688 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.688+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualIDEController 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualIDEController 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualPS2Controller 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualPCIController 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualSIOController 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualKeyboard 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualPointingDevice 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualVideoCard 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualVMCIDevice 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualLsiLogicSASController 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualE1000 11:02:20.0689 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.689+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualDisk 11:02:20.0690 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.690+03:00 [01716 verbose 'transport'] Found a device: vim.vm.device.VirtualDisk 11:02:20.0690 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] FILE: FileLockDynaLink: Further process validation tools are: available 11:02:20.0691 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.691+03:00 [01716 verbose 'transport'] Examining special transport modes. 11:02:20.0691 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.691+03:00 [01716 trivia 'transport'] Checking transport mode san. 11:02:20.0691 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.691+03:00 [01716 trivia 'transport'] BIOS UUID obtained: 4215e7f6-d909-c9aa-44f3-70fa2a068a2c 11:02:20.0691 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.691+03:00 [01716 info 'transport'] Performing SearchIndex find. 11:02:20.0692 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.692+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: retrieveContent {} 11:02:20.0692 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.692+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0692 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.692+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0692 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.692+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0692 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.692+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0692 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.692+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0692 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.692+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0692 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.692+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0692 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.692+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0694 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.694+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0694 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.694+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0694 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.694+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0694 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.694+03:00 [09496 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0694 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.694+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: retrieveContent 11:02:20.0694 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.694+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0695 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.695+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0695 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.695+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: findByUuid {} 11:02:20.0695 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.695+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0695 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.695+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0695 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.695+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0695 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.695+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0695 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.695+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0695 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.695+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0695 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.695+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0695 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.695+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0714 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.714+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0714 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.714+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0714 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.714+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0714 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.714+03:00 [12136 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0714 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.714+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: findByUuid 11:02:20.0714 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.714+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.714+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.715+03:00 [01716 trivia 'vmomi.soapStub[0]'] Sending soap request to []: GetSummary {} 11:02:20.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.715+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.715+03:00 [01716 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.715+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.715+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.715+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.715+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0715 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.715+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0716 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.716+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0718 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.718+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0718 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.718+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0719 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.719+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0719 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.719+03:00 [09496 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0719 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.719+03:00 [01716 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: GetSummary 11:02:20.0719 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.719+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'transport'] Running in VM: moref:vm-2378 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'transport'] Transport mode san failed pre-flight check. Ignoring. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'transport'] Checking transport mode hotadd. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'transport'] Transport mode hotadd passed pre-flight checks. Adding to list of available transports. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'transport'] Checking transport mode nbdssl. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'transport'] Transport mode nbdssl passed pre-flight checks. Adding to list of available transports. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'transport'] Checking transport mode nbd. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'transport'] Transport mode nbd passed pre-flight checks. Adding to list of available transports. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'transport'] Narrowing down applicable transport modes. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 trivia 'transport'] Disregarding transport mode san. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: VixDiskLib_ConnectEx: No transport modes available to access disks: Error 3 at 3343. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: VixDiskLib_Disconnect: Disconnect. 11:02:20.0720 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.720+03:00 [01716 info 'Default'] Successfully released all resources. 11:02:20.0721 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Clean up connection. 11:02:20.0721 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.721+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 1, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0721 : vdConnect:../VixInterface.cpp:1229 : Done with VixDiskLib_Connect(): 0 11:02:20.0721 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.721+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0721 : vdConnect:../VixInterface.cpp:1239 : VixDiskLib_Connect failed. 11:02:20.0721 : connectToHost:../VixGuest.cpp:1009 : vdConnect() Error = 3. 11:02:20.0721 : openLeafSnapshotDisks:../VixGuest.cpp:439 : connectToHost() failed. Calling closeLeafSnapshotDisks() 11:02:20.0721 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.721+03:00 [09496 trivia 'vmomi.soapStub[0]'] Sending soap request to []: logout {} 11:02:20.0721 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.721+03:00 [09496 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to 11:02:20.0721 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.721+03:00 [09496 trivia 'vmomi.soapStub[0]'] Request started [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0721 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.721+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0722 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.722+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0722 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.722+03:00 [10044 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0722 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.722+03:00 [10044 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0722 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.722+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0722 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.722+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0724 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.724+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0725 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.725+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0725 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.725+03:00 [10044 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list2,class boost::_bi::value > >) 11:02:20.0725 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.725+03:00 [10044 trivia 'vmomi.soapStub[0]'] Request completed [class Vmacore::Http::UserAgentImpl::AsyncSendRequestHelper:0000000002BC6858] 11:02:20.0725 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.725+03:00 [09496 trivia 'vmomi.soapStub[0]'] Received SOAP response from []: logout 11:02:20.0725 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.725+03:00 [10044 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0725 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.725+03:00 [09496 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to 11:02:20.0725 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.725+03:00 [09496 info 'vmomi.soapStub[0]'] Resetting stub adapter for server : Closed 11:02:20.0726 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.726+03:00 [09496 trivia 'transport'] Clean up SSPI. 11:02:20.0726 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.726+03:00 [12136 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0726 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.726+03:00 [12136 trivia 'HttpConnectionPool-000001'] [DecConnectionCount] Number of connections to decremented to 0 11:02:20.0726 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.726+03:00 [12136 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0726 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.726+03:00 [11856 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 1, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0726 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.726+03:00 [11856 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0726 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.726+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0727 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.727+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0727 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.726+03:00 [10044 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0727 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.727+03:00 [10044 trivia 'HttpConnectionPool-000000'] [DecConnectionCount] Number of connections to decremented to 0 11:02:20.0727 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.727+03:00 [10044 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0727 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.727+03:00 [09496 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 0, fun: class boost::_bi::bind_t const & __ptr64,int,class Vmacore::Functor const & __ptr64>,class boost::_bi::list4 >,class boost::_bi::value >,class boost::_bi::value,class boost::_bi::value > > >) 11:02:20.0727 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.727+03:00 [11856 trivia 'ThreadPool'] ThreadPool[idle:4, busy_io:0, busy_long:0] HandleWork(type: 1, fun: class boost::_bi::bind_t,class boost::_bi::list1 > >) 11:02:20.0727 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.727+03:00 [11856 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0727 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.727+03:00 [09496 trivia 'ThreadPool'] HandleWork() leaving 11:02:20.0732 : log:../Error.cpp:249 : Error: 0x00000017 occured in file ../VixGuest.cpp, at line 624 11:02:20.0732 : log:../Error.cpp:249 : Error: 0x00000017 occured in file ../VixGuest.cpp, at line 624 11:02:20.0732 : vixMapObjCtl:../VixCoordinator.cpp:990 : Returning: 23 11:02:20.0732 : vix_map_objctl:../libvix.cpp:1275 : Returning: 23 11:02:20.0732 : vixMapClose:../VixCoordinator.cpp:304 : case RVP_OBJECT_TYPE_GUEST 11:02:20.0732 : closeGuest:../VixManager.cpp:70 : Obj: C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.spm4.domain.com_1447660908.1.0.NBU_DATA.xml 11:02:20.0732 : closeGuest:../VixManager.cpp:103 : Guest has no open file systems hence deleting it 11:02:20.0734 : vix_map_fini:../libvix.cpp:615 : Released VixCoordinator 11:02:20.0734 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: VixDiskLib_Exit: Unmatched Init calls so far: 1. 11:02:20.0734 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Clean up VixDiskLib. 11:02:20.0734 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Exit disk lib. 11:02:20.0734 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Shut down transport mode. 11:02:20.0734 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] 2015-11-16T11:02:20.734+03:00 [01716 trivia 'Default'] Shutting down worker thread pool. 11:02:21.0734 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Clean up vim. 11:02:21.0734 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLibVim: VixDiskLibVim_Exit: Clean up. 11:02:21.0734 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Shut down SSL session. 11:02:21.0734 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Release socket. 11:02:21.0734 : g_vixInterfaceLogger:../libvix.cpp:1844 : [VFM_ESINFO] VixDiskLib: Clean up log. 11:02:21.0734 : destroyInstance:../VixInterface.cpp:1362 : Deleting VIX instance: 000000000157A090 11:02:21.0734 : ~VixInterface:VixInterface.h:501 : m_libDir: C:\Program Files\Common Files\VERITAS\VxMS\\Shared\VDDK\ 11:02:21.0734 : ~VixInterface:VixInterface.h:508 : m_vddkDependsHandle: 3899916288 11:02:21.0735 : ~VixInterface:VixInterface.h:515 : m_vddkHandle: 3842703360 11:02:21.0735 : vhd_map_fini:../libvhd.cpp:443 : Entered 11:02:21.0735 : vhdMapFini:../VhdCoordinator.cpp:338 : Entered 11:02:21.0735 : vhdMapFini:../VhdCoordinator.cpp:350 : Exited 11:02:21.0735 : vhd_map_fini:../libvhd.cpp:458 : Exited