Symptoms

The NetWorker VMware Protection (NVP) integration is configured with the vProxy Appliance. The backups intermittently fail with a resource not found message in the NetWorker Management Console. A subsequent backup completes for the virtual machine, but it may affect other virtual machines.The virtual machine backup log and the NetWorker Management Console message show: {"Text":"Resource not found: 44ab916f-7519-40f9-9d2e-e90394782ed9","Code":-404} The Backup action log shows: MM/DD/YY HH:MM:SS [VM_NAME]: Unable to obtain backup status from vProxy after 5 attempts, failing the backup: Received an HTTP code: 404, libCURL message: "", vProxy message: "Error received from vProxy ="-404: Resource not found: 44ab916f-7519-40f9-9d2e-e90394782ed9". ", url: "https://ii170-vproxy01.fastenal.com:9090/api/v1/BackupVmSessions/44ab916f-7519-40f9-9d2e-e90394782ed9", body: " ". MM/DD/YY HH:MM:SS [VM_NAME]: Unable to download vProxy Session log into file '/nsr/logs/policy/VMWare Protection/[WORKFLOW]/461300-[VM_NAME]-YYYY-MM-DD-HH-MM-SS.log': Possible wrong vProxy hostname or port, resource path not found. Received an HTTP code: 404, libCURL message: "", url: "https://[VPROXY_NAME]:9090/api/v1/BackupVmSessions/44ab916f-7519-40f9-9d2e-e90394782ed9/log". MM/DD/YY HH:MM:SS [VM_NAME]: Backup failed. MM/DD/YY HH:MM:SS The size of proxied data written has not been set. MM/DD/YY HH:MM:SS Save-set ID '849786629' (client '[VCENTER_NAME]': save-set 'vm:50308677-bf8b-c786-0140-6a9c4409b90f:[VCENTER_NAME]') is aborted. The vProxy vbackupd-engine.log shows: YYYY/MM/DD HH:MM:SS TRACE: Ending go routine of main session loop for *resources.BackupVmSessions (vm-29424) [VM_NAME]. YYYY/MM/DD HH:MM:SS NOTICE: 44ab916f-7519-40f9-9d2e-e90394782ed9:vm-29424:[VM_NAME]: Backup session is exiting YYYY/MM/DD HH:MM:SS TRACE: Resource Update 44ab916f-7519-40f9-9d2e-e90394782ed9:externalId=[VCENTER_NAME]:vm-29424:state=Success:deletable=true. YYYY/MM/DD HH:MM:SS INFO: Saved resource map to "/opt/emc/vproxy/runtime/state/vbackupd/BackupVmSessions.gob". YYYY/MM/DD HH:MM:SS NOTICE: Aging out inactive session BackupVmSessions - 44ab916f-7519-40f9-9d2e-e90394782ed9 ([VCENTER_NAME]:vm-29424) last accessed YYYY-MM-DD HH:MM:SS -0500 CDT. YYYY/MM/DD HH:MM:SS TRACE: Deleting logfiles of session '44ab916f-7519-40f9-9d2e-e90394782ed9'... YYYY/MM/DD HH:MM:SS TRACE: Deleting log file "/opt/emc/vproxy/runtime/logs/vbackupd/44ab916f-7519-40f9-9d2e-e90394782ed9.log" while deleting session "44ab916f-7519-40f9-9d2e-e90394782ed9"... YYYY/MM/DD HH:MM:SS INFO: File '/opt/emc/vproxy/runtime/logs/vbackupd/44ab916f-7519-40f9-9d2e-e90394782ed9.log' is moved to '/opt/emc/vproxy/runtime/logs/recycle/vbackupd/44ab916f-7519-40f9-9d2e-e90394782ed9.log'. YYYY/MM/DD HH:MM:SS INFO: Deleted log file "/opt/emc/vproxy/runtime/logs/vbackupd/44ab916f-7519-40f9-9d2e-e90394782ed9.log" while deleting session "44ab916f-7519-40f9-9d2e-e90394782ed9". YYYY/MM/DD HH:MM:SS TRACE: Deleting resource: [VCENTER_NAME]:vm-29424 - 44ab916f-7519-40f9-9d2e-e90394782ed9 ... YYYY/MM/DD HH:MM:SS INFO: Deleted resource: [VCENTER_NAME]:vm-29424 - 44ab916f-7519-40f9-9d2e-e90394782ed9. YYYY/MM/DD HH:MM:SS INFO: Saved resource map to "/opt/emc/vproxy/runtime/state/vbackupd/BackupVmSessions.gob". YYYY/MM/DD HH:MM:SS INFO: Aged out 1 'BackupVmSessions' sessions, 0 remaining YYYY/MM/DD HH:MM:SS ERROR: Resource not found: 44ab916f-7519-40f9-9d2e-e90394782ed9 YYYY/MM/DD HH:MM:SS ERROR: Resource not found: 44ab916f-7519-40f9-9d2e-e90394782ed9 YYYY/MM/DD HH:MM:SS ERROR: Resource not found: 44ab916f-7519-40f9-9d2e-e90394782ed9 YYYY/MM/DD HH:MM:SS ERROR: Resource not found: 44ab916f-7519-40f9-9d2e-e90394782ed9 YYYY/MM/DD HH:MM:SS ERROR: Resource not found: 44ab916f-7519-40f9-9d2e-e90394782ed9 YYYY/MM/DD HH:MM:SS ERROR: Resource not found: 44ab916f-7519-40f9-9d2e-e90394782ed9 YYYY/MM/DD HH:MM:SS TRACE: Handling Action GetLog for 44ab916f-7519-40f9-9d2e-e90394782ed9 ... YYYY/MM/DD HH:MM:SS ERROR: Resource not found: 44ab916f-7519-40f9-9d2e-e90394782ed9 YYYY/MM/DD HH:MM:SS TRACE: Reply sent successfully for "GetLog".

Cause

The NetWorker server continuously checks the status for the backup session and requests the logs once the backup session is complete. The vProxy completes the backup and ages the session after the NetWorker server does not request an update for a couple of minutes. As the session is aged, the vProxy is no longer able to give the NetWorker server a status update or logs and it fails with the resource not found error. The NetWorker Server status request delays are typically due to high latency between the NetWorker Storage node and the Data Domain communication.

Resolution

The NetWorker Storage node to Data Domain latency should be reduced to less than 50 ms during the backup execution. This guideline is documented in the "TCP window size and network latency considerations" section of the Dell NetWorker Performance Optimization Planning Guide. If the latency cannot be reduced, then it is suggested to configure a NetWorker Storage node at the remote site to manage the Data Domain devices.The following article details how to perform some network troubleshooting: NetWorker: How To Troubleshoot Network Related Issues.The above article details how to perform timestamped ping from the NetWorker storage node and Data Domain. Confirm the time zones match and leave the ping operation running in the background and outputting to a file. When the backup issue is reproduced, check the ping output file's time range for high latency during the time period the backup issue was observed. 

Support Cases