Start a Conversation

Unsolved

This post is more than 5 years old

3937

January 17th, 2018 07:00

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

155 Posts

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.

202 Posts

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.

4 Operator

 • 

1.3K Posts

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 ?

202 Posts

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

155 Posts

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

202 Posts

January 28th, 2018 14:00

Hi!

Thanks a lot! Migrating to another esx is helped us!

BR: Pal

155 Posts

January 29th, 2018 04:00

Happy to know that....It was more of a ESX host issue than being VM client issue.

No Events found!

Top