NVP-vProxy: Backups fail with resource not found code -404 "Aging out inactive session"
Summary: Virtual machine (VM) backups performed with the NetWorker VMware Protection (NVP) vProxy appliance fail intermittently with a "Resource not found" error (code ‑404) because the vProxy ages out a completed backup session before the NetWorker server retrieves the final status. High network latency between the NetWorker storage node and the Data Domain causes the NetWorker server to delay its status‑polling requests, which allows the vProxy session to expire. Reducing the storage‑node‑to‑Data‑Domain latency to below 50 ms resolves the issue. ...
Symptoms
The NetWorker VMware Protection (NVP) integration uses a vProxy appliance to perform VM backups. VM backups fail intermittently with a Resource not found message in the NetWorker Management Console (NMC). A subsequent retry backup for the same VM may succeed, but the failure can affect other VMs in the same backup window. The NMC displays the following error (session ID varies per occurrence):
{"Text":"Resource not found: 44ab916f-7519-40f9-9d2e-e90394782ed9","Code":-404}
The backup action log shows the NetWorker server's unsuccessful attempts to retrieve the backup status from the vProxy, followed by the backup failure:
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://[VPROXY_NAME]: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 the complete session lifecycle — the backup completes successfully on the vProxy side, but the session is subsequently aged out and deleted before the NetWorker server retrieves the status:
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 polls the vProxy for backup session status and requests the session logs once the backup completes. 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
- Measure the storage‑node‑to‑Data‑Domain latency:
- Run a timestamped continuous ping from the NetWorker storage node to the Data Domain and output the results to a file. Ensure the time zones on both systems match.
- Windows:
ping -t [DATA_DOMAIN_IP] > ping_output.txt - Linux:
ping [DATA_DOMAIN_IP] | while read line; do echo "$(date): $line"; done > ping_output.txt
- Windows:
- Leave the ping running in the background during a backup window.
- When the backup failure recurs, review the ping_output.txt file and check the time range corresponding to the failure for latency spikes.
- Run a timestamped continuous ping from the NetWorker storage node to the Data Domain and output the results to a file. Ensure the time zones on both systems match.
- Reduce latency to below 50 ms:
- Identify and resolve the source of high latency between the NetWorker storage node and the Data Domain. Common causes include network congestion, WAN links, routing inefficiencies, or overloaded network equipment.
- Ensure that the round‑trip latency between the NetWorker storage node and the Data Domain remains below 50 ms during backup execution. This threshold is documented in the "TCP window size and network latency considerations" section of the Dell NetWorker Performance Optimization Planning Guide.
- Deploy a remote storage node (if latency cannot be reduced):
- If the storage‑node‑to‑Data‑Domain latency cannot be reduced below 50 ms (for example, due to geographic separation), configure a NetWorker storage node at the remote site where the Data Domain resides. This storage node manages the Data Domain devices locally, eliminating the high‑latency path.
- Verify resolution:
- After reducing latency or deploying a remote storage node, trigger backup jobs for the previously affected VMs.
- Confirm that the backups complete successfully without Resource not found (code ‑404) errors in the NMC, backup action log, or vProxy vbackupd-engine.log.
- Monitor backup jobs over 3 consecutive backup windows to confirm the intermittent failures no longer occur.
- If the session‑aging failures persist after reducing latency below 50 ms, contact Dell Support for further investigation and reference this KB article.
Additional Information
The following article details how to perform some network troubleshooting: NetWorker: How To Troubleshoot Network Related Issues.