Unsolved
This post is more than 5 years old
2 Intern
•
202 Posts
0
3971
VADP error DiskLib error 802 (NBD_ERR_INSUFFICIENT_RESOURCES)
Dear Experts!
Our customer is using a quite older networker 8.2.3.1.build1109.
It is working fine (no plan to upgrade), however we met an error yesterday.
Vmware backup is running fine, however once a day it is stopped
for the specific virtual machines with this error:
VADP: VixDiskLib - WARNING: [NFC ERROR] NfcFssrvrProcessErrorMsg: received NFC error 5 from server: Failed to allocate the requested 16777216 bytes
VADP: VixDiskLib - Log: DISKLIB-LIB : RWv failed ioId: #1 (802) (34) .
VADP: VixDiskLib - Log: VixDiskLib: Detected DiskLib error 802 (NBD_ERR_INSUFFICIENT_RESOURCES).
90268:nsrvadp_save: The save operation of the non-NTFS image completed with errors.
Vmware is running at 6.0u3 level.
We experienced the following:
- Before backup specific vm says: Disk consolidation is needed
- We consolidate vm disks
- After the backup stops with this error: we got the following: Disk consolidation is needed
I try to remove tmp folders and try to remove the log directories too.
I increased the VADP_MAX_BACKOFF_TIME too.(360)
The vmx file versions is from vmx6-11 no change.
Questions:
-----------
1. How can i fix this problem?
2. Any advices and suggestions are accepted.
Thanks again.
BR:
Pal Szabo
SurajPujari
155 Posts
1
January 17th, 2018 10:00
It appears from the logs that it is doing NBD method. Will you be able to upload session logs for the backup which is getting failed. Which should bring up the error through which it fails.
paulo3
2 Intern
2 Intern
•
202 Posts
0
January 17th, 2018 11:00
Thanks for the quick answer!
For me according to logs it seems that nsr process cannot read data from vcenter.
But if you can help additional comments or suggestions it will be a helpful for me.
Here are the logs:
1/16/18 16:06:13.853830 can't get my primary domain controller info, Could not find domain controller for this domain. (Win32 error 0x995)
01/16/18 16:06:13.869430 lgto_auth for `nsrd' succeeded
01/16/18 16:06:13.885030 Install path for NetWorker: C:\Program Files\EMC NetWorker\nsr.
Initializing VADP Configuration.
01/16/18 16:06:13.900630 lgto_auth for `nsrd' succeeded
Using srv-bkp-ucs.domain.loc as the VADP proxy server host for client srv-client1.
Application information attribute VADP_HOST for client srv-client1 is set to "srv-vcenter1".
Application information attribute VADP_DISABLE_FLR for client srv-client1 is set to default value of "No".
81095:nsrvadp_save: Failed to obtain "VADP_DISABLE_CBT" application information attribute for client srv-client1. Default value of "No" is taken.
Application information attribute 'VADP_QUIESCE_SNAPSHOT' for client 'srv-client1' is set to default value of "Yes".
Application information attribute VADP_BACKUPROOT for client srv-client1 is set to "c:\mnt".
Application information attribute VADP_TRANSPORT_MODE for client srv-client1 is set to "nbd".
Application information attribute VADP_MAX_RETRIES for client srv-client1 is set to "3".
Application information attribute VADP_MAX_BACKOFF_TIME for client srv-client1 is set to "360".
Trying to reset the client resource application information attributes.
Application information attribute VADP_HYPERVISOR for client srv-client1 is set to "srv-vcenter1".
Application information attribute VADP_DISABLE_FLR for client srv-client1 is set to 'Yes'.
80419:nsrvadp_save: Failed to get VADP_DISABLE_CBT in application information attribute of client srv-client1.
VC\ESX Host Name : x.y.z.e
VC\ESX Port : 443
VC\ESX Username : domain\_svc_networkervdap
Mount point : c:\mnt\srv-client1
Flavor : fullvm
Transport Mode : nbd
Max retry : 3
Max backoff time : 360
VDDK Install Directory: C:\Program Files\EMC NetWorker\nsr\plugins\VDDK.
VADP VM-TMP Directory Location: c:\mnt\srv-client1\srv-client1\srv-client1-tmp\letters\1.
01/16/18 16:06:13.931830 lgwstat: Failed to open file/directory: \01/16/18 16:06:13.931830 lgwstat: Failed to open file/directory: \01/16/18 16:06:13.931830 lgwstat: Failed to open file/directory: \01/16/18 16:06:13.931830 lgwstat: Failed to open file/directory: \01/16/18 16:06:13.931830 lgwstat: Failed to open file/directory: \01/16/18 16:06:13.931830 lgwstat: Failed to open file/directory: \Temporary Directory for VM created.
VADP TMP Directory Location: c:\mnt\srv-client1\srv-client1\tmp.
01/16/18 16:06:13.947430 lgwstat: Failed to open file/directory: \01/16/18 16:06:13.947430 lgwstat: Failed to open file/directory: \Temporary Directory for VADP created.
01/16/18 16:06:13.947430 lgwstat: Failed to open file/directory: \01/16/18 16:06:13.947430 lgwstat: Failed to open file/directory: \01/16/18 16:06:13.947430 lgwstat: Failed to open file/directory: \Temporary vmMntLoc Directory for VADP created.
01/16/18 16:06:13.947430 Intializing LibVADP Context.
VADP: Requesting transport modes: nbd.
VADP: Initializing VCB...
01/16/18 16:06:13.963030 C:\Program Files\EMC NetWorker\nsr\plugins\VDDK\bin\nsrvddk.exe started, pid 6100
VADP: nsrvddk: Ready.
VADP: NsrVDDK - Log: Debug Level = 3
VADP: NsrVDDK - Log: VixDiskLib_InitEx: Major Version = 1
VADP: NsrVDDK - Log: Minor Version = 1
VADP: NsrVDDK - Log: VDDK Dir = C:\Program Files\EMC NetWorker\nsr\plugins\VDDK
VADP: NsrVDDK - Log: Config File = C:\Program Files\EMC NetWorker\nsr\plugins\VDDK\VixDiskLib.config
VADP: VixDiskLib - Log: OBJLIB-LIB: Objlib initialized.
VADP: VixDiskLib - Log: VixDiskLib: Attempting to locate advanced transport module in "C:\Program Files\EMC NetWorker\nsr\plugins\VDDK".
VADP: VixDiskLib - Log: VixDiskLib: Advanced transport plugin was successfully loaded into vixDiskLib.
VADP: VixDiskLib - Log: VixDiskLib: Enabling advanced transport modes.
VADP: VixDiskLib - Log: OBJLIB-LIB: Objlib initialized.
VADP: VixDiskLib - Log: VixDiskLib: Initialize transport modes.
VADP: VixDiskLib - Log: VixDiskLib: Available transport modes: file:san:hotadd:nbdssl:nbd.
VADP: VixDiskLib - Log: VMware VixDiskLib (5.5) Release build-2962804
VADP: VixDiskLib - Log: PREF early PreferenceGet(poll.forceSelect), using default
VADP: VixDiskLib - Log: POLL Using the WSAPoll API Implementation for PollDefault
VADP: VixDiskLib - Log: VixDiskLibVim: VixDiskLibVim_Init: Initialization is completed.
VADP: NsrVDDK - Log: VixMntapi_Init: major version = 1
VADP: NsrVDDK - Log: minor version = 0
VADP: NsrVDDK - Log: VDDK Dir = C:\Program Files\EMC NetWorker\nsr\plugins\VDDK
VADP: NsrVDDK - Log: Config File = C:\Program Files\EMC NetWorker\nsr\plugins\VDDK\VixMountApi.config
VADP: VixMntApi - Log: `anonymous-namespace'::VixMntapiReadTmpDirPath: Using tempDirectory C:\Program Files\EMC NetWorker\nsr\plugins\VDDK\tmp.
VADP: VixMntApi - Log: Mntapi_Init Asked - 2.0 Served - 2.0 was successful,TempDirectory: C:\Program Files\EMC NetWorker\nsr\plugins\VDDK\tmp.
VADP: NsrVDDK - Log: Available Transport Modes: file:san:hotadd:nbdssl:nbd
VADP: nsrvddk.exe initialized: available transport modes: file:san:hotadd:nbdssl:nbd.
VADP: Parsed NBD mode
VADP: NsrVDDK - Trace: Received command 'cleanup'.
VADP: VixDiskLib - Log: VixDiskLib: VixDiskLib_Cleanup: Remove previous mount points and clean up .
VADP: VixDiskLib - Log: VixDiskLib: VixDiskLib_Connect: Establish connection.
VADP: VixDiskLib - Log: VixDiskLib: VixDiskLib_Disconnect: Disconnect.
VADP: Initializing VimService 'https://x.y.z.e/sdk' ...
VADP: Logging into VimService as 'domain\_svc_networkervdap' ...
01/16/18 16:06:14.243830 Intialized LibVADP context successfully.
Performing the backup via the Virtual Center.
Application information attribute VADP_VM_NAME for client srv-client1 is set to "srv-client1".
Trying to connect to the VM using VM name 'srv-client1'.
Performing a FULL Image level backup.
Creating a quiesced snapshot for 'srv-client1'.
01/16/18 16:06:14.290630 Creating snapshot for 'vm-2966' ...
01/16/18 16:06:14.321831 Task is 0% complete
01/16/18 16:06:14.321831 Task is 0% complete
01/16/18 16:06:16.755435 Task is 33% complete
01/16/18 16:06:18.923839 Task is 33% complete
01/16/18 16:06:19.267039 Task is -1% complete
VADP: Destructing VirtualDisk '[DSL_MGM01_CLU01_AVAYA01] srv-client1/srv-client1-000013.vmdk'.
VADP: Destructing VirtualDisk '[DSL_MGM01_CLU01_AVAYA01] srv-client1/srv-client1_1.vmdk'.
VADP: Destructing VirtualDisk '[DSL_MGM01_CLU01_AVAYA01] srv-client1/srv-client1_2.vmdk'.
VADP: Found snapshot: '_NETWORKER-VADP-BACKUP_'
The snapshot was created successfully for VM 'srv-client1'.
Downloading VM configuration for srv-client1.
VADP: Destructing Folder (vm, group-v3)
VADP: Destructing Folder (Datacenters, group-d1)
VADP: Destructing DataStore (DSL_MGM01_CLU01_AVAYA01, datastore-2878)
VADP: Destructing DataStore (DSL_MGM01_CLU01_AVAYA01, datastore-2878)
VADP: Destructing DataStore (DSL_MGM01_CLU01_AVAYA01, datastore-2878)
VADP: Destructing HostSystem (esx43, host-2911)
VADP: Destructing ResourcePool (AVAYA, resgroup-17502)
VADP: Destructing DataCenter (domain, datacenter-2)
Configuration downloaded successfully for VM 'srv-client1'.
Following are the details of the client srv-client1:
VirtualCenter : x.y.z.e
ESX Server : esx43
DataCenter Name : domain
ConfigDatastore Name : DSL_MGM01_CLU01_AVAYA01
Resourcepool Name : /AVAYA
Following is the disk information of the client srv-client1:
Disk 1 Label : Hard disk 1
Disk 1 Size : 14,0 GB
Disk 1 Datastore name : DSL_MGM01_CLU01_AVAYA01
Disk 2 Label : Hard disk 2
Disk 2 Size : 50,0 GB
Disk 2 Datastore name : DSL_MGM01_CLU01_AVAYA01
Disk 3 Label : Hard disk 3
Disk 3 Size : 25,0 GB
Disk 3 Datastore name : DSL_MGM01_CLU01_AVAYA01
Total Number of Disks : 3
Obtained the virtual disks for the VM.
Change block tracking is disabled for VM: srv-client1
VADP: Logging out of VIM Server from 'x.y.z.e' ...
File level Recovery from Image level backup is disabled.
01/16/18 16:06:21.856644 Checking for the de-duplication / directive attributes for client srv-client1.
01/16/18 16:06:21.856644 Failed to bind socket to port 10633: Only one usage of each socket address (protocol/network address/port) is normally permitted.
01/16/18 16:06:21.856644 Bind attempt 1 failed, retrying...
01/16/18 16:06:21.872244 lgto_parms for `nsrmmd' succeeded
01/16/18 16:06:21.872244 setting `store index entries' value to `No'
01/16/18 16:06:21.872244 lgto_auth for `nsrmmd' succeeded
01/16/18 16:06:21.872244 rpc/lib/c_tcp.c:334 Failed to create connection to ::1 on port 8035 for RPC client handle: Only one usage of each socket address (protocol/network address/port) is normally permitted.
01/16/18 16:06:21.887844 Waiting up to 60 seconds for a session to become available for nsrmmd on srv-bkp-ucs.domain.loc, vers 605, volume , pool
01/16/18 16:06:21.887844 device_host(), devfull: \\.\Tape4801118
01/16/18 16:06:21.887844 device_host(), devfull: \\.\Tape4801115
01/16/18 16:06:21.887844 device_host(), devfull: \\.\Tape4801121
01/16/18 16:06:21.887844 device_host(), devfull: \\.\Tape4801124
01/16/18 16:06:21.887844 device_host(), devfull: adv_vmbackup
01/16/18 16:06:21.887844 Found available session on srv-bkp-ucs.domain.loc after waiting for 0 secs
01/16/18 16:06:21.950244 lgwstat: Failed to open file/directory: \01/16/18 16:06:21.950244 Default DFA handling by client is 'Fallback'
01/16/18 16:06:21.950244 DIRECT_ACCESS=No: Client direct set to 'No'
01/16/18 16:06:21.950244 Using immediate backup for save-set ID '660477165' (srv-client1:FULLVM).
01/16/18 16:06:21.950244 ssid 660477165 using immediate save to `srv-bkp-ucs.domain.loc'
01/16/18 16:06:21.950244 Successfully setup direct saves
80459:nsrvadp_save: Starting save operation of the non-NTFS Image.
01/16/18 16:06:21.965844 ichunk[0] recidx 3 off 196, len 2324
01/16/18 16:06:21.981444 got a gap of 312 bytes to handle
01/16/18 16:06:21.981444 cut off ichunk[1] recidx 3 off 2552, len 196
01/16/18 16:06:21.981444 `1:\vm_config.xml' final f->offset = 45141.
off 0 len 45364 file #1 1:\vm_config.xml
01/16/18 16:06:21.981444 nsrvadp_save: MORef is Obtained for the given VM.
01/16/18 16:06:21.981444 nsrvadp_save: Obtained Virtual Disks.
VADP: NsrVDDK - Trace: Received command 'connect'.
VADP: NsrVDDK - Trace: Calling VixDiskLib_ConnectEx: Host = x.y.z.e
VADP: NsrVDDK - Trace: TCP Port = 0
VADP: NsrVDDK - Trace: Transport Mode = nbd
VADP: NsrVDDK - Trace: Read Only = TRUE
VADP: VixDiskLib - Log: VixDiskLib: VixDiskLib_ConnectEx: Establish connection using nbd.
VADP: VixDiskLib - Log: VixDiskLib: VixDiskLib_Connect: Establish connection.
VADP: VixDiskLib - Log: VixDiskLib: Advanced transport modes not available for opening moref=vm-2966.
VADP: NsrVDDK - Trace: Received command 'open-disk'.
VADP: NsrVDDK - Trace: Calling VixDiskLib_Open: Connection ID = 1
VADP: NsrVDDK - Trace: Disk Name = [DSL_MGM01_CLU01_AVAYA01] srv-client1/srv-client1-000013.vmdk
VADP: NsrVDDK - Trace: Open Flag = VIXDISKLIB_FLAG_OPEN_READ_ONLY
VADP: VixDiskLib - Log: VixDiskLib: VixDiskLib_OpenEx: Open a disk.
VADP: VixDiskLib - Log: VixDiskLibVim: VixDiskLibVim_GetNfcTicket: Get NFC ticket for [DSL_MGM01_CLU01_AVAYA01] srv-client1/srv-client1-000013.vmdk.
VADP: VixDiskLib - Log: HOSTINFO 2202607880212 @ 2050810Hz -> 0 @ 1000000000Hz
VADP: VixDiskLib - Log: HOSTINFO ((x * 4090387700) >> 23) + -1074018499987392
VADP: VixDiskLib - Log: VThreadBase detected multiple threads.
VADP: VixDiskLib - Log: VixDiskLibVim: Request RandomAccessRO diskKey = 2000, readOnly = 1, openSnapshot = 0.
VADP: VixDiskLib - Log: HOSTINFO 2202611952126 @ 2050810Hz -> 0 @ 1000000000Hz
VADP: VixDiskLib - Log: HOSTINFO ((x * 4090387700) >> 23) + -1074020485502383
VADP: VixDiskLib - Log: VixDiskLibVim: VixDiskLibVim_FreeNfcTicket: Free NFC ticket.
VADP: VixDiskLib - Log: NBD_ClientOpen: attempting to create connection to vpxa-nfc://[DSL_MGM01_CLU01_AVAYA01] srv-client1/srv-client1-000013.vmdk@esx43:902
VADP: VixDiskLib - Log: Started up WSA
VADP: VixDiskLib - Log: Opening file [DSL_MGM01_CLU01_AVAYA01] srv-client1/srv-client1-000013.vmdk (vpxa-nfc://[DSL_MGM01_CLU01_AVAYA01] srv-client1/srv-client1-000013.vmdk@esx43:902)
VADP: VixDiskLib - Log: DISKLIB-LINK : Opened 'vpxa-nfc://[DSL_MGM01_CLU01_AVAYA01] srv-client1/srv-client1-000013.vmdk@esx43:902' (0x1e): custom, 29360128 sectors / 14 GB.
VADP: VixDiskLib - Log: DISKLIB-LIB : Opened "vpxa-nfc://[DSL_MGM01_CLU01_AVAYA01] srv-client1/srv-client1-000013.vmdk@esx43:902" (flags 0x1e, type custom).
VADP: NsrVDDK - Trace: New disk handle id = 1
VADP: VixDiskLib - Log: VixDiskLib: VixDiskLib_GetInfo: Retrieve disk info.
VADP: VixDiskLib - Log: VixDiskLib: VixDiskLib_FreeInfo: Clean up VixDiskLib.
VADP: VixDiskLib - Log: VixDiskLib: VixDiskLib_GetTransportMode: Retrieve transport mode.
VADP: NsrVDDK - Trace: Opened with transport mode = nbd
VADP: VDDK capacity = 2147483648
VADP: VI SDK capacity = 2147483648
VADP: Transport Mode = nbd
VADP: Disk opened.
VADP: Logging into VimService as 'domain\_svc_networkervdap' ...
VADP: VixDiskLib - WARNING: [NFC ERROR] NfcFssrvrProcessErrorMsg: received NFC error 5 from server: Failed to allocate the requested 16777216 bytes
VADP: VixDiskLib - Log: DISKLIB-LIB : RWv failed ioId: #1 (802) (34) .
VADP: VixDiskLib - Log: VixDiskLib: Detected DiskLib error 802 (NBD_ERR_INSUFFICIENT_RESOURCES).
83065:nsrvadp_save: The following internal error occurred: An error was returned from nsrvddk.exe: Error reading from disk: VDDK Error: NBD_ERR_INSUFFICIENT_RESOURCES
VADP: Logging out of VIM Server from 'x.y.z.e' ...
The following internal error occurred: An error was returned from nsrvddk.exe: Error reading from disk: VDDK Error: NBD_ERR_INSUFFICIENT_RESOURCES
01/16/18 16:06:25.631850 nsrvadp_save: Over all Save time is 4 secs
90268:nsrvadp_save: The save operation of the non-NTFS image completed with errors.
90269:nsrvadp_save: Cannot create the client index entries.
01/16/18 16:06:25.631850 Raw data could not be sent and saved. Exiting.
01/16/18 16:06:25.631850 srv-client1:FULLVM size 45 KB, 1 file(s), took 0 min 4 sec
85194:nsrmmd: Chunking ssid 660477165 failed, because saveset was aborted
Total number of files backed up: -1.
Total backup size: 0 MB.
Completion time: 2018.01.16. 16:06:25
Total time taken: 0 hr(s) 00 min(s) 04 sec(s)
90255:nsrvadp_save: The backup of the non-NTFS volume failed.
Cleaningup VADP mount operation.
VADP: NsrVDDK - Trace: Received command 'Disconnect'.
VADP: NsrVDDK - Trace: Calling VixDiskLib_Disconnect: Connection ID = 1
VADP: VixDiskLib - Log: VixDiskLib: VixDiskLib_Disconnect: Disconnect.
VADP: Logging into VimService as 'domain\_svc_networkervdap' ...
01/16/18 16:06:25.772251 Deleting snapshot for 'snapshot-21439' ...
01/16/18 16:06:25.803451 Task is 0% complete
01/16/18 16:06:25.819051 Task is 0% complete
01/16/18 16:06:25.834651 Task is 0% complete
01/16/18 16:06:27.815854 Task is 33% complete
01/16/18 16:06:28.049855 Task is 66% complete
01/16/18 16:06:28.408655 Task is 66% complete
01/16/18 16:06:28.408655 Task is -1% complete
Snapshot for VM srv-client1 is deleted.
VADP: Logging out of VIM Server from 'x.y.z.e' ...
Temporary directory 'c:\mnt\srv-client1' for VADP deleted.
crazyrov
4 Operator
4 Operator
•
1.3K Posts
1
January 17th, 2018 23:00
Hello @Pal Szabo,
Can you try and vMotion this off of the current ESX host to a different one and retry the backup ?
paulo3
2 Intern
2 Intern
•
202 Posts
0
January 18th, 2018 00:00
Hi!
Thanks a lot!
We will try it to move another host.
Do you think it is an error of the Vmware side?
BR:
Pal
SurajPujari
155 Posts
1
January 23rd, 2018 03:00
Sorry about the delay in response. Did you trying migrating the VM to a different ESX host and then taking a backup.
below are the trouble making lines in your backup:
VADP: VixDiskLib - WARNING: [NFC ERROR] NfcFssrvrProcessErrorMsg: received NFC error 5 from server: Failed to allocate the requested 16777216 bytes
VADP: VixDiskLib - Log: DISKLIB-LIB : RWv failed ioId: #1 (802) (34) .
VADP: VixDiskLib - Log: VixDiskLib: Detected DiskLib error 802 (NBD_ERR_INSUFFICIENT_RESOURCES).
Before you do migration it will also make sense to consolidate VM and try a backup.
Check this:https://support.unitrends.com/UnitrendsBackup/s/article/000004086
paulo3
2 Intern
2 Intern
•
202 Posts
0
January 28th, 2018 14:00
Hi!
Thanks a lot! Migrating to another esx is helped us!
BR: Pal
SurajPujari
155 Posts
0
January 29th, 2018 04:00
Happy to know that....It was more of a ESX host issue than being VM client issue.