2 Replies Latest reply on Mar 7, 2019 6:51 AM by daphnissov

    VDP backup error, failed to download VM metadata, request help!!! ...

    Main19832101 Lurker

      VDP configuration and installation are normal, but backup error, backup can not continue, although you see            Fail to download VM metadata, try later, but I don't know what the problem is.            The error log is as follows. Ask for help:

       

      --------------------------------------------------------------------------------------------------------

      -----  START avvcbimage log 2019-03-07 11:38:09 CST  [7.2.180-167 Linux-x86_64]

      --------------------------------------------------------------------------------------------------------

      2019-03-07T11:38:09.033-08:00 avvcbimage Info <5008>: Logging to /usr/local/avamarclient/var/test2-1551929879509-3306f8eb7116f7c3e2b9e9e59a4c3a0c591e4e98-1016-vmimagel.log

      2019-03-07T11:38:09.033-08:00 avvcbimage Info <5174>: - Reading /root/.avamar

      2019-03-07T11:38:09.033-08:00 avvcbimage Info <5174>: - Reading /usr/local/avamar/etc/usersettings.cfg

      2019-03-07T11:38:09.034-08:00 avvcbimage Info <5174>: - Reading /usr/local/avamarclient/var/avvcbimage.cmd

      2019-03-07T11:38:09.034-08:00 avvcbimage Info <5174>: - Reading /usr/local/avamarclient/var/avvcbimageAll.cmd

      2019-03-07T11:38:09.038-08:00 avvcbimage Info <6673>: CTL listening on port 52565

      2019-03-07T11:38:09.040-08:00 avvcbimage Info <10684>: Setting ctl message version to 3 (from 1)

      2019-03-07T11:38:09.040-08:00 avvcbimage Info <16136>: Setting ctl max message size to 268435456

      2019-03-07T11:38:09.043-08:00 avvcbimage Info <40636>: SSL Certificate Thumbprint: 58:92:C8:7E:11:CE:AB:36:92:8A:60:40:30:CE:D8:CC:53:F1:40:1C

      2019-03-07T11:38:09.043-08:00 avvcbimage Info <0000>: job type = 4

      2019-03-07T11:38:09.064-08:00 avvcbimage Info <18664>: Login(https://vcsa01.lntmh.com:443/sdk) Datacenter: 'New Core Business'

      2019-03-07T11:38:09.064-08:00 avvcbimage Info <19728>:      - connected to 'VirtualCenter' - version: 'VMware vCenter Server 6.7.0 build-10244857',  apiVersion:'6.7.1'

      2019-03-07T11:38:09.130-08:00 avvcbimage Info <14692>: Login test is OK.

      2019-03-07T11:38:09.236-08:00 avvcbimage Info <40726>: VM Config Info: VMX version 4(F), ctk enabled(T), fault tolerant (F), Guest OS Red Hat Enterprise Linux 6 (64-bit), Cloud UUID = NoUUID. version=13

      2019-03-07T11:38:09.255-08:00 avvcbimage Info <40727>: VM Guest Info: GuestOS Family = linuxGuest, Guest Full Name = CentOS 4/5 or later (64-bit), Guest OS State = running, Tools Running = guestToolsRunning,  Tools Version Status = guestToolsUnmanaged

      2019-03-07T11:38:09.324-08:00 avvcbimage Info <14625>: WorkOrder Disk Info:

         Prior Disk '2000': file(base):'[Macrosan_AutoTier_Lun03] ZYLWEB01/ZYLWEB01.vmdk', backItUp=1

                      snapshot file:'[Macrosan_AutoTier_Lun03] ZYLWEB01/ZYLWEB01.vmdk'

                      prior size(KB):0, current size(KB):367001600, match=0

                      prior change block ID:''

                      Datastore:'Macrosan_AutoTier_Lun03' Directly Accessible=1

      2019-03-07T11:38:09.424-08:00 avvcbimage Info <40637>: Proxy Host Name=esxi29.lntmh.com(6.7.1 build-10302608)

      2019-03-07T11:38:09.507-08:00 avvcbimage Info <40638>: VM Host Name=esxi30.lntmh.com(6.7.1 build-10302608)

      2019-03-07T11:38:09.507-08:00 avvcbimage Info <19547>: Using Simultaneous Workorders method

      2019-03-07T11:38:09.507-08:00 avvcbimage Info <19652>: Updated cache lookup

      2019-03-07T11:38:09.507-08:00 avvcbimage Info <19587>: Create cache lock file succeeded

      2019-03-07T11:38:09.507-08:00 avvcbimage Info <19588>: usLockFile: /usr/local/avamarclient/bin/var1.lck

      2019-03-07T11:38:09.508-08:00 avvcbimage Info <11979>: proxy VM DNS name is: 127.0.0.2,vdp01.lntmh.com,vdp01,192.168.101.126

      2019-03-07T11:38:09.508-08:00 avvcbimage Info <18672>: proxy VM Instance name is: vdp01.lntmh.com-proxy-1

      2019-03-07T11:38:09.508-08:00 avvcbimage Info <17793>: proxy VM Moref is: vm-5063

      2019-03-07T11:38:09.508-08:00 avvcbimage Info <16010>: vCenter 'New Core Business' is vcsa01.lntmh.com

      2019-03-07T11:38:09.508-08:00 avvcbimage Info <11981>: VM's host is esxi30.lntmh.com

      2019-03-07T11:38:09.508-08:00 avvcbimage Info <11982>: VM's primary storage location is [Macrosan_AutoTier_Lun03] ZYLWEB01/ZYLWEB01.vmx

      2019-03-07T11:38:09.508-08:00 avvcbimage Info <11983>: VM's vCenter ID is vm-3973

      2019-03-07T11:38:09.508-08:00 avvcbimage Info <19658>: change block file: VmImage1_changefilemap.tmp

      2019-03-07T11:38:09.541-08:00 avvcbimage Info <11984>: VM's backup account on vdp01.lntmh.com is /vcsa01.lntmh.com/VirtualMachines/ZYLWEB01_UBfzB1oMmAggk1yC18TNtA

      2019-03-07T11:38:09.541-08:00 avvcbimage Info <11986>: Changed block tracking is engaged for this VM

      2019-03-07T11:38:09.541-08:00 avvcbimage Info <11988>: A reference to a valid prior backup is not available so this will be a full level zero backup.

      2019-03-07T11:38:09.610-08:00 avvcbimage Info <19549>: metadata tmp dir: /usr/local/avamarclient/var/vmware/1/temp

      2019-03-07T11:38:09.610-08:00 avvcbimage Info <40640>: create tmpDir: /usr, failed (-1)

      2019-03-07T11:38:09.610-08:00 avvcbimage Info <40640>: create tmpDir: /usr/local, failed (-1)

      2019-03-07T11:38:09.610-08:00 avvcbimage Info <40640>: create tmpDir: /usr/local/avamarclient, failed (-1)

      2019-03-07T11:38:09.610-08:00 avvcbimage Info <40640>: create tmpDir: /usr/local/avamarclient/var, failed (-1)

      2019-03-07T11:38:09.610-08:00 avvcbimage Info <40640>: create tmpDir: /usr/local/avamarclient/var/vmware, failed (-1)

      2019-03-07T11:38:09.610-08:00 avvcbimage Info <40640>: create tmpDir: /usr/local/avamarclient/var/vmware/1, failed (-1)

      2019-03-07T11:38:09.610-08:00 avvcbimage Info <40640>: create tmpDir: /usr/local/avamarclient/var/vmware/1/temp, failed (-1)

      2019-03-07T11:38:09.611-08:00 avvcbimage Info <40654>: isExitOK()=0

      2019-03-07T11:38:09.611-08:00 avvcbimage Info <17823>: Body- abortrecommended(f)

      2019-03-07T11:38:09.613-08:00 avvcbimage Info <19660>: targetlist contains <path backup="true" name="[Macrosan_AutoTier_Lun03] ZYLWEB01/ZYLWEB01.vmdk" diskCapacity="375809638400" />

      2019-03-07T11:38:09.613-08:00 avvcbimage Info <5174>: - Reading /usr/local/avamarclient/var/avvcbimage.cmd

      2019-03-07T11:38:09.613-08:00 avvcbimage Info <5174>: - Reading /usr/local/avamarclient/var/avvcbimageAll.cmd

      2019-03-07T11:38:09.613-08:00 avvcbimage Info <7084>: target[0]=[Macrosan_AutoTier_Lun03] ZYLWEB01/ZYLWEB01.vmdk

      2019-03-07T11:38:09.613-08:00 avvcbimage Info <40658>: vmparams (vcsa01.lntmh.com)

      2019-03-07T11:38:09.613-08:00 avvcbimage Info <40654>: isExitOK()=0

      2019-03-07T11:38:09.628-08:00 avvcbimage Info <18664>: Login(https://vcsa01.lntmh.com:443/sdk) Datacenter: 'New Core Business'

      2019-03-07T11:38:09.628-08:00 avvcbimage Info <19728>:      - connected to 'VirtualCenter' - version: 'VMware vCenter Server 6.7.0 build-10244857',  apiVersion:'6.7.1'

      2019-03-07T11:38:09.657-08:00 avvcbimage Info <14692>: Login test is OK.

      2019-03-07T11:38:09.746-08:00 avvcbimage Info <18664>: Login(https://vcsa01.lntmh.com:443/sdk) Datacenter: 'New Core Business'

      2019-03-07T11:38:09.746-08:00 avvcbimage Info <19728>:      - connected to 'VirtualCenter' - version: 'VMware vCenter Server 6.7.0 build-10244857',  apiVersion:'6.7.1'

      2019-03-07T11:38:09.772-08:00 avvcbimage Info <14692>: Login test is OK.

      2019-03-07T11:38:09.773-08:00 avvcbimage Info <16041>: VDDK:OBJLIB-LIB: Objlib initialized.

      2019-03-07T11:38:09.773-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Attempting to locate advanced transport module in "/usr/lib/vmware-vix-disklib".

      2019-03-07T11:38:09.966-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Advanced transport plugin /usr/lib/vmware-vix-disklib/lib64/libdiskLibPlugin.so was successfully loaded into vixDiskLib.

      2019-03-07T11:38:09.966-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Enabling advanced transport modes.

      2019-03-07T11:38:09.967-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Initialize transport modes.

      2019-03-07T11:38:09.967-08:00 avvcbimage Info <16041>: VDDK:2019-03-07T11:38:09.967+08:00 info -[7F239E879700] [Originator@6876 sub=vm:DictionaryLoad: Cannot open file "/etc/vmware/vsphereFeatures/vsphereFeatures.cfg] : No such file or directory.

      2019-03-07T11:38:09.967-08:00 avvcbimage Info <16041>: VDDK:2019-03-07T11:38:09.967+08:00 info -[7F239E879700] [Originator@6876 sub=vm:[msg.dictionary.load.openFailed] Cannot open file "/etc/vmware/vsphereFeatures/vsphereFeatures.cfg] : No such file or directory.

      2019-03-07T11:38:09.967-08:00 avvcbimage Info <16041>: VDDK:2019-03-07T11:38:09.967+08:00 info -[7F239E879700] [Originator@6876 sub=vm:FeatureStateLib: Error while loading feature config file: /etc/vmware/vsphereFeatures/vsphereFeatures.cfg]  using default feature state values.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Available transport modes: file:san:hotadd:nbdssl:nbd.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:VMware VixDiskLib (6.5) Release build-5993564

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:DictionaryLoad: Cannot open file "/usr/lib/vmware/settings": No such file or directory.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:[msg.dictionary.load.openFailed] Cannot open file "/usr/lib/vmware/settings": No such file or directory.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:PREF Optional preferences file not found at /usr/lib/vmware/settings. Using default values.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:DictionaryLoad: Cannot open file "/usr/lib/vmware/config": No such file or directory.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:[msg.dictionary.load.openFailed] Cannot open file "/usr/lib/vmware/config": No such file or directory.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:PREF Optional preferences file not found at /usr/lib/vmware/config. Using default values.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:DictionaryLoad: Cannot open file "/root/.vmware/config": No such file or directory.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:[msg.dictionary.load.openFailed] Cannot open file "/root/.vmware/config": No such file or directory.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:PREF Optional preferences file not found at /root/.vmware/config. Using default values.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:DictionaryLoad: Cannot open file "/root/.vmware/preferences": No such file or directory.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:[msg.dictionary.load.openFailed] Cannot open file "/root/.vmware/preferences": No such file or directory.

      2019-03-07T11:38:09.991-08:00 avvcbimage Info <16041>: VDDK:PREF Optional preferences file not found at /root/.vmware/preferences. Using default values.

      2019-03-07T11:38:09.992-08:00 avvcbimage Info <16041>: VDDK:lib/ssl: OpenSSL using FIPS_drbg for RAND

      2019-03-07T11:38:09.992-08:00 avvcbimage Info <16041>: VDDK:lib/ssl: protocol list tls1.2

      2019-03-07T11:38:09.992-08:00 avvcbimage Info <16041>: VDDK:lib/ssl: protocol list tls1.2 (openssl flags 0x17000000)

      2019-03-07T11:38:09.992-08:00 avvcbimage Info <16041>: VDDK:lib/ssl: cipher list !aNULL:kECDH+AESGCM:ECDH+AESGCM:RSA+AESGCM:kECDH+AES:ECDH+AES:RSA+AES

      2019-03-07T11:38:10.008-08:00 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVim_Init: Initialization is completed.

      2019-03-07T11:38:10.008-08:00 avvcbimage Info <9666>: Available transport modes are file:san:hotadd:nbdssl:nbd

      2019-03-07T11:38:10.008-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_PrepareForAccess: Prepare to access disk.

      2019-03-07T11:38:10.008-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_Connect: Establish connection.

      2019-03-07T11:38:10.008-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Resolve host.

      2019-03-07T11:38:10.008-08:00 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVim_AllowVMotion: Disable VMotion.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:DictionaryLoad: Cannot open file "/usr/lib/vmware/settings": No such file or directory.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:[msg.dictionary.load.openFailed] Cannot open file "/usr/lib/vmware/settings": No such file or directory.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:PREF Optional preferences file not found at /usr/lib/vmware/settings. Using default values.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:DictionaryLoad: Cannot open file "/usr/lib/vmware/config": No such file or directory.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:[msg.dictionary.load.openFailed] Cannot open file "/usr/lib/vmware/config": No such file or directory.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:PREF Optional preferences file not found at /usr/lib/vmware/config. Using default values.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:DictionaryLoad: Cannot open file "/root/.vmware/config": No such file or directory.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:[msg.dictionary.load.openFailed] Cannot open file "/root/.vmware/config": No such file or directory.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:PREF Optional preferences file not found at /root/.vmware/config. Using default values.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:DictionaryLoad: Cannot open file "/root/.vmware/preferences": No such file or directory.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:[msg.dictionary.load.openFailed] Cannot open file "/root/.vmware/preferences": No such file or directory.

      2019-03-07T11:38:10.009-08:00 avvcbimage Info <16041>: VDDK:PREF Optional preferences file not found at /root/.vmware/preferences. Using default values.

      2019-03-07T11:38:10.010-08:00 avvcbimage Info <16041>: VDDK:lib/ssl: OpenSSL using FIPS_drbg for RAND

      2019-03-07T11:38:10.010-08:00 avvcbimage Info <16041>: VDDK:lib/ssl: protocol list tls1.2

      2019-03-07T11:38:10.010-08:00 avvcbimage Info <16041>: VDDK:lib/ssl: protocol list tls1.2 (openssl flags 0x17000000)

      2019-03-07T11:38:10.010-08:00 avvcbimage Info <16041>: VDDK:lib/ssl: cipher list !aNULL:kECDH+AESGCM:ECDH+AESGCM:RSA+AESGCM:kECDH+AES:ECDH+AES:RSA+AES

      2019-03-07T11:38:10.549-08:00 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVim_FreeNfcTicket: Free NFC ticket.

      2019-03-07T11:38:10.549-08:00 avvcbimage Info <17818>: VixDiskLib vMotion reservation successfully enabled by 'vSphere Data Protection'

      2019-03-07T11:38:10.549-08:00 avvcbimage Info <16011>: Running cleanup of old backups.

      2019-03-07T11:38:10.549-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_Cleanup: Remove previous mount points and clean up .

      2019-03-07T11:38:10.549-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_Connect: Establish connection.

      2019-03-07T11:38:10.549-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Resolve host.

      2019-03-07T11:38:10.550-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_Disconnect: Disconnect.

      2019-03-07T11:38:10.550-08:00 avvcbimage Info <16048>: VixDiskLib_Cleanup() found no prior mounts to cleanup.

      2019-03-07T11:38:10.562-08:00 avvcbimage Info <18664>: Login(https://vcsa01.lntmh.com:443/sdk) Datacenter: 'New Core Business'

      2019-03-07T11:38:10.562-08:00 avvcbimage Info <19728>:      - connected to 'VirtualCenter' - version: 'VMware vCenter Server 6.7.0 build-10244857',  apiVersion:'6.7.1'

      2019-03-07T11:38:10.587-08:00 avvcbimage Info <14692>: Login test is OK.

      2019-03-07T11:38:10.620-08:00 avvcbimage Info <0000>: SnapshotManager: initializing at 127.0.0.1:8543, vCenter vcsa01.lntmh.com(administrator@vsphere.local), datacenter(/New Core Business), httpsTimeout_ms(60000), maxDeleteRetries(-1)

      2019-03-07T11:38:10.696-08:00 avvcbimage Info <0000>: GET: curl_easy_getinfo succeeded with httpcode(200)

      2019-03-07T11:38:10.701-08:00 avvcbimage Info <0000>: AvSnapMgr::getData Succeeded httpCode: 200

      2019-03-07T11:38:10.701-08:00 avvcbimage Info <0000>: SnapshotManager version:7.2.80.167

      2019-03-07T11:38:10.701-08:00 avvcbimage Info <40642>: Using SnapShot Manager - with fallback to proxy calling vSphere API functions.

      2019-03-07T11:38:10.768-08:00 avvcbimage Info <18648>: The snapshot '' could not be removed.

      2019-03-07T11:38:10.811-08:00 avvcbimage Info <40751>:  Datastore Macrosan_AutoTier_Lun03

      2019-03-07T11:38:10.828-08:00 avvcbimage Info <14664>: no snapshots are present on this VM.

      2019-03-07T11:38:10.862-08:00 avvcbimage Info <0000>: (CURL) Logging into datacenter path of 'folder?dcPath=New%2520Core%2520Business', New Core Business => New%2520Core%2520Business

      2019-03-07T11:38:10.862-08:00 avvcbimage Info <0000>: (Legacy) Logging into datacenter path of 'folder?dcPath=New%2520Core%2520Business', New Core Business => New%2520Core%2520Business

      2019-03-07T11:38:10.862-08:00 avvcbimage Info <41153>: Using CURL Method

      2019-03-07T11:38:10.862-08:00 avvcbimage Info <41154>: Re-using vCS Session Cookie

      2019-03-07T11:38:20.872-08:00 avvcbimage Info <41153>: Using CURL Method

      2019-03-07T11:38:20.872-08:00 avvcbimage Info <41154>: Re-using vCS Session Cookie

      2019-03-07T11:38:30.882-08:00 avvcbimage Info <41153>: Using CURL Method

      2019-03-07T11:38:30.882-08:00 avvcbimage Info <41154>: Re-using vCS Session Cookie

      2019-03-07T11:38:40.894-08:00 avvcbimage Info <41155>: Using Legacy Method

      2019-03-07T11:38:40.904-08:00 avvcbimage Warning <15995>: HTTP fault detected, Problem with returning page from HTTP, Msg:'SOAP 1.1 fault: SOAP-ENV:Server [no subcode]

      "HTTP Error"

      Detail: HTTP/1.1 404 Not Found

      '

      2019-03-07T11:38:50.912-08:00 avvcbimage Info <41155>: Using Legacy Method

      2019-03-07T11:38:50.932-08:00 avvcbimage Warning <15995>: HTTP fault detected, Problem with returning page from HTTP, Msg:'SOAP 1.1 fault: SOAP-ENV:Server [no subcode]

      "HTTP Error"

      Detail: HTTP/1.1 404 Not Found

      '

      2019-03-07T11:39:00.932-08:00 avvcbimage Info <41155>: Using Legacy Method

      2019-03-07T11:39:00.942-08:00 avvcbimage Warning <15995>: HTTP fault detected, Problem with returning page from HTTP, Msg:'SOAP 1.1 fault: SOAP-ENV:Server [no subcode]

      "HTTP Error"

      Detail: HTTP/1.1 404 Not Found

      '

      2019-03-07T11:39:10.942-08:00 avvcbimage Warning <40648>: DataStore/VM Info download failed.

      2019-03-07T11:39:10.942-08:00 avvcbimage Warning <0000>: [IMG0016] The datastore from VMX '[Macrosan_AutoTier_Lun03] ZYLWEB01/ZYLWEB01.vmx' could not be fully inspected.

      2019-03-07T11:39:10.964-08:00 avvcbimage Info <0000>: (CURL) Logging into datacenter path of 'folder?dcPath=New%2520Core%2520Business', New Core Business => New%2520Core%2520Business

      2019-03-07T11:39:10.964-08:00 avvcbimage Info <0000>: (Legacy) Logging into datacenter path of 'folder?dcPath=New%2520Core%2520Business', New Core Business => New%2520Core%2520Business

      2019-03-07T11:39:10.964-08:00 avvcbimage Info <41153>: Using CURL Method

      2019-03-07T11:39:10.964-08:00 avvcbimage Info <14620>: Logging into datacenter 'vcsa01.lntmh.com' with user 'administrator@vsphere.local'

      2019-03-07T11:39:21.007-08:00 avvcbimage Info <41153>: Using CURL Method

      2019-03-07T11:39:21.007-08:00 avvcbimage Info <14620>: Logging into datacenter 'vcsa01.lntmh.com' with user 'administrator@vsphere.local'

      2019-03-07T11:39:31.018-08:00 avvcbimage Info <41153>: Using CURL Method

      2019-03-07T11:39:31.018-08:00 avvcbimage Info <14620>: Logging into datacenter 'vcsa01.lntmh.com' with user 'administrator@vsphere.local'

      2019-03-07T11:39:41.033-08:00 avvcbimage Info <41155>: Using Legacy Method

      2019-03-07T11:39:41.033-08:00 avvcbimage Info <14620>: Logging into datacenter 'vcsa01.lntmh.com' with user 'administrator@vsphere.local'

      2019-03-07T11:39:41.078-08:00 avvcbimage Warning <15995>: HTTP fault detected, Problem with returning page from HTTP, Msg:'SOAP 1.1 fault: SOAP-ENV:Server [no subcode]

      "HTTP Error"

      Detail: HTTP/1.1 404 Not Found

      '

      2019-03-07T11:39:51.084-08:00 avvcbimage Info <41155>: Using Legacy Method

      2019-03-07T11:39:51.084-08:00 avvcbimage Info <14620>: Logging into datacenter 'vcsa01.lntmh.com' with user 'administrator@vsphere.local'

      2019-03-07T11:39:51.192-08:00 avvcbimage Warning <15995>: HTTP fault detected, Problem with returning page from HTTP, Msg:'SOAP 1.1 fault: SOAP-ENV:Server [no subcode]

      "HTTP Error"

      Detail: HTTP/1.1 404 Not Found

      '

      2019-03-07T11:40:01.193-08:00 avvcbimage Info <41155>: Using Legacy Method

      2019-03-07T11:40:01.193-08:00 avvcbimage Info <14620>: Logging into datacenter 'vcsa01.lntmh.com' with user 'administrator@vsphere.local'

      2019-03-07T11:40:01.228-08:00 avvcbimage Warning <15995>: HTTP fault detected, Problem with returning page from HTTP, Msg:'SOAP 1.1 fault: SOAP-ENV:Server [no subcode]

      "HTTP Error"

      Detail: HTTP/1.1 404 Not Found

      '

      2019-03-07T11:40:11.229-08:00 avvcbimage Info <0000>: initial attempt at downloading VM file failed, now trying by re-creating the HREF, (CURL) /folder/ZYLWEB01%2fZYLWEB01.vmx?dcPath=%252fNew%2520Core%2520Business&dsName=Macrosan_AutoTier_Lun03, (LEGACY) /folder/ZYLWEB01%2FZYLWEB01.vmx?dcPath=%252FNew%2520Core%2520Business&dsName=Macrosan%255FAutoTier%255FLun03.

      2019-03-07T11:40:11.229-08:00 avvcbimage Info <41153>: Using CURL Method

      2019-03-07T11:40:11.229-08:00 avvcbimage Info <41154>: Re-using vCS Session Cookie

      2019-03-07T11:40:21.239-08:00 avvcbimage Info <41153>: Using CURL Method

      2019-03-07T11:40:21.239-08:00 avvcbimage Info <41154>: Re-using vCS Session Cookie

      2019-03-07T11:40:31.252-08:00 avvcbimage Info <41153>: Using CURL Method

      2019-03-07T11:40:31.252-08:00 avvcbimage Info <41154>: Re-using vCS Session Cookie

      2019-03-07T11:40:41.263-08:00 avvcbimage Info <41155>: Using Legacy Method

      2019-03-07T11:40:41.263-08:00 avvcbimage Info <40756>: Attempting to Download file:/folder/ZYLWEB01%2FZYLWEB01.vmx?dcPath=%252FNew%2520Core%2520Business&dsName=Macrosan%255FAutoTier%255FLun03

      2019-03-07T11:40:41.278-08:00 avvcbimage Warning <15995>: HTTP fault detected, Problem with returning page from HTTP, Msg:'SOAP 1.1 fault: SOAP-ENV:Server [no subcode]

      "HTTP Error"

      Detail: HTTP/1.1 404 Not Found

      '

      2019-03-07T11:40:51.280-08:00 avvcbimage Info <41155>: Using Legacy Method

      2019-03-07T11:40:51.280-08:00 avvcbimage Info <40756>: Attempting to Download file:/folder/ZYLWEB01%2FZYLWEB01.vmx?dcPath=%252FNew%2520Core%2520Business&dsName=Macrosan%255FAutoTier%255FLun03

      2019-03-07T11:40:51.298-08:00 avvcbimage Warning <15995>: HTTP fault detected, Problem with returning page from HTTP, Msg:'SOAP 1.1 fault: SOAP-ENV:Server [no subcode]

      "HTTP Error"

      Detail: HTTP/1.1 404 Not Found

      '

      2019-03-07T11:41:01.299-08:00 avvcbimage Info <41155>: Using Legacy Method

      2019-03-07T11:41:01.299-08:00 avvcbimage Info <40756>: Attempting to Download file:/folder/ZYLWEB01%2FZYLWEB01.vmx?dcPath=%252FNew%2520Core%2520Business&dsName=Macrosan%255FAutoTier%255FLun03

      2019-03-07T11:41:01.317-08:00 avvcbimage Warning <15995>: HTTP fault detected, Problem with returning page from HTTP, Msg:'SOAP 1.1 fault: SOAP-ENV:Server [no subcode]

      "HTTP Error"

      Detail: HTTP/1.1 404 Not Found

      '

      2019-03-07T11:41:11.317-08:00 avvcbimage Warning <40650>: Download VM .vmx file failed.

      2019-03-07T11:41:11.317-08:00 avvcbimage Error <17821>: failed to download vm metadata, try later

      2019-03-07T11:41:11.317-08:00 avvcbimage Info <9772>: Starting graceful (staged) termination, failed to download vm metadata (wrap-up stage)

      2019-03-07T11:41:11.318-08:00 avvcbimage Error <0000>: [IMG0009] createSnapshot: snapshot creation  or pre/post snapshot script failed

      2019-03-07T11:41:11.318-08:00 avvcbimage Error <0000>: [IMG0009] createSnapshot: snapshot creation/pre-script/post-script failed

      2019-03-07T11:41:11.318-08:00 avvcbimage Info <40654>: isExitOK()=157

      2019-03-07T11:41:11.318-08:00 avvcbimage Info <40659>: snapshot created:false NOMC:false ChangeBlTrackingAvail:true UsingChBl:true, ExitOK:false, cancelled:false, fatal: true

      2019-03-07T11:41:11.318-08:00 avvcbimage Info <40654>: isExitOK()=157

      2019-03-07T11:41:11.318-08:00 avvcbimage Info <40660>: vcbimage_progress::terminate

      2019-03-07T11:41:11.319-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_EndAccess: Disk access completed.

      2019-03-07T11:41:11.319-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: VixDiskLib_Connect: Establish connection.

      2019-03-07T11:41:11.319-08:00 avvcbimage Info <16041>: VDDK:VixDiskLib: Resolve host.

      2019-03-07T11:41:11.320-08:00 avvcbimage Info <16038>: Final summary, cancelled/aborted 0, snapview 0, exitcode 157: miscellaneous error

      2019-03-07T11:41:11.320-08:00 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVim_AllowVMotion: Enable VMotion.

      2019-03-07T11:41:11.704-08:00 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVim_FreeNfcTicket: Free NFC ticket.

      2019-03-07T11:41:11.704-08:00 avvcbimage Info <17819>: VixDiskLib vMotion reservation successfully released

      --------------------------------------------------------------------------------------------------------

      ----- END avvcbimage log 2019-03-07 11:41:16 CST  (12 warnings, 3 errors, 0 fatal errors)

      --------------------------------------------------------------------------------------------------------