NVP vProxy: Backups intermittently fail "VDDK Error: 18000: Cannot connect to the host"

The NetWorker VMware Protection (NVP) solution is configured with the vProxy Appliance. The vProxy backups intermittently fail with "VDDK Error: 18000: Cannot connect to the host" during the Virtual Disk Development Kit (VDDK) disk connection or storage migration step. The manual execution or subsequent scheduled execution may complete successfully in the environment.

The VDDK disk connection error shows the following in the /opt/emc/vproxy/runtime/logs/vbackupd/vbackupd-engine.log:

MM/DD/YYYY HH:MM:SS INFO:   [99] Data Mover: Hard disk 1: Preparing for data movement.
MM/DD/YYYY HH:MM:SS ERROR:  [99] Data Mover: Hard disk 1: VDDK: Failed to open source VMDK "[DATASTORE_NAME] VM_NAME/VM_NAME.vmdk": VDDK Error: 18000: Cannot connect to the host.
MM/DD/YYYY HH:MM:SS ERROR:  [99] Data Mover: Hard disk 1: Failed to initialize Block Reader.

The /opt/emc/vproxy/runtime/logs/vbackupd/vbackupd-vddk.log shows:

MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLib: VixDiskLib_OpenEx: Open a disk.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLibVim: VixDiskLibVim_GetNfcTicket: Get NFC ticket for [DATASTORE_NAME] VM_NAME/VM_NAME.vmdk.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLibVim: Error 18000 (listener error GVmomiFaultInvalidResponse).

The storage migration failure shows:

MM/DD/YYYY HH:MM:SS INFO:   [99] Disabling storage migration of virtual machine ...
MM/DD/YYYY HH:MM:SS WARN:   [99] Error disabling storage migration:  VDDK Error: 18000: Cannot connect to the host., retrying.
MM/DD/YYYY HH:MM:SS INFO:   [99] There are 3 certificates available at VCENTER_NAME. First one will be used.
MM/DD/YYYY HH:MM:SS ERROR:  [99] Failed to disable storage migration for virtual machine "vm-###": VDDK Error: 18000: Cannot connect to the host.
MM/DD/YYYY HH:MM:SS ERROR:  [99] Error disabling storage migration for virtual machine "VM_NAME".

The vProxy's vbackupd-vddk.log shows:

MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLib: VixDiskLib_PrepareForAccess: Prepare to access disk.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLib: VixDiskLib_Connect: Establish connection.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLib: Resolve host.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLibVim: VixDiskLibVim_AllowVMotion: Disable VMotion.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLibVim: Error 18000 (listener error GVmomiFaultInvalidResponse).

Increasing the VDDK debug ("vixDiskLib.transport.LogLevel = 4") in the /opt/emc/vproxy/conf/VixDiskLib.config file provides further insight in the vbackup-vddk.log.

NetWorker VMware Protection (NVP)-vProxy: How to Enable Debug Logging

The VDDK debug output shows:

MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLib: VixDiskLib_OpenEx: Open a disk.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLibVim: VixDiskLibVim_GetNfcTicket: Get NFC ticket for [DATASTORE_NAME] VM_NAME/VM_NAME.vmdk.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO 2019-10-24T13:19:20.348Z info -[7FF30C87D700] [Originator@6876 sub=Libs] GVmomi: Instantiating VMOMI session at https://VCENTER_IP:443/sdk
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO 2019-10-24T13:19:20.348Z info -[7FF30C87D700] [Originator@6876 sub=Libs] GVmomi: Verifying SSL certificate with thumbprint AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO 2019-10-24T13:19:20.348Z info -[7FF30C87D700] [Originator@6876 sub=Libs] GVmomi: Certificate accepted
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO 2019-10-24T13:19:20.453Z info -[7FF30C87D700] [Originator@6876 sub=Libs] BasicHttpOnSent: xmlReadMemory (NULL == xmlDoc) errorCode 0 responseCode 503 message 
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLibVim: Error 18000 (listener error GVmomiFaultInvalidResponse).

The storage migration failure debug shows:

MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLib: VixDiskLib_Connect: Establish connection.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLib: Resolve host.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLibVim: VixDiskLibVim_AllowVMotion: Enable VMotion.
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO 2019-10-24T13:20:11.512Z info -[7FF2CE7AE700] [Originator@6876 sub=Libs] GVmomi: Instantiating VMOMI session at https://VCENTER_IP:443/sdk
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO 2019-10-24T13:20:11.512Z info -[7FF2CE7AE700] [Originator@6876 sub=Libs] GVmomi: Verifying SSL certificate with thumbprint AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB:AB
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO 2019-10-24T13:20:11.512Z info -[7FF2CE7AE700] [Originator@6876 sub=Libs] GVmomi: Certificate accepted
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO 2019-10-24T13:20:11.612Z info -[7FF2CE7AE700] [Originator@6876 sub=Libs] BasicHttpOnSent: xmlReadMemory (NULL == xmlDoc) errorCode 0 responseCode 503 message 
MM/DD/YYYY HH:MM:SS NOTICE: VDDK INFO VixDiskLibVim: Error 18000 (listener error GVmomiFaultInvalidResponse).

The vProxy backup workflow is sending a vSphere Application Programming Interface (API) call using a vCenter Simple Object Access Protocol (SOAP) request over HTTP (https://VCENTER_IP:443/sdk). The VDDK debug output shows the vCenter verifies and accepts the SSL Certificate, but then the request returns an HTTP 503 Status Code.  
 

503 Service Unavailable 
The server cannot handle the request (because it is overloaded or down for maintenance). Generally, this is a temporary state.

The vCenter vpxd.log shows the vCenter is consistently reaching the limit of HTTP sessions for the configuration during the backup window.

YYYY-MM-DD HH:MM:SS error vpxd[7FBB590AC700] [Originator@6876 sub=HTTP session map] Out of HTTP sessions: Limited to 2000

The NetWorker vProxy backup appliance requires vCenter HTTP session connectivity during the backup to perform the vCenter functions. The HTTP sessions are being exhausted on the vCenter server and preventing the vProxy backup from initiating the required HTTP connections.   

Evaluate the vpxd.log to determine what is causing a high number of HTTP sessions and if they occur during certain times. The vProxy backups can be scheduled to run outside the time where HTTP sessions may not be available. If required, contact VMware Support to help evaluate the vCenter Server HTTP usage.