the backup failed to back up the requested files(6)

[msandrosov59]

Hi, Our enviroment we have master server version 8.1.1 in Windows Server 2012 R2 . Last week we are getting a error code 6 form NBU for one snapshot/backup operation with the following error:
Nov 25, 2023 12:58:26 PM - Info nbjm (pid=6644) starting backup job (jobid=32857) for client vcs, policy vcs, schedule vcs_full
Nov 25, 2023 12:58:26 PM - Info nbjm (pid=6644) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=32857, request id:{12AA4538-D7B1-4091-A24C-7CCEBB5B9ABC})
Nov 25, 2023 12:58:26 PM - requesting resource  cifs1-stu
Nov 25, 2023 12:58:26 PM - requesting resource  srv-nbu01i.msa.com.NBU_CLIENT.MAXJOBS.vcs
Nov 25, 2023 12:58:26 PM - requesting resource  srv-nbu01i.msa.com.NBU_POLICY.MAXJOBS.vcs
Nov 25, 2023 12:58:26 PM - granted resource  srv-nbu01i.msa.com.NBU_CLIENT.MAXJOBS.vcs
Nov 25, 2023 12:58:26 PM - granted resource  srv-nbu01i.msa.com.NBU_POLICY.MAXJOBS.vcs
Nov 25, 2023 12:58:26 PM - granted resource  MediaID=@aaaah;DiskVolume=\\192.168.140.169\cifs1;DiskPool=cifs1;Path=\\192.168.140.169\cifs1;StorageServer=srv-nbu01i.msa.com;MediaServer=srv-nbu01i.msa.com
Nov 25, 2023 12:58:26 PM - granted resource  cifs1-stu
Nov 25, 2023 12:58:26 PM - estimated 0 kbytes needed
Nov 25, 2023 12:58:26 PM - begin Parent Job
Nov 25, 2023 12:58:26 PM - begin VMware: Start Notify Script
Nov 25, 2023 12:58:27 PM - Info RUNCMD (pid=32432) started
Nov 25, 2023 12:58:27 PM - Info RUNCMD (pid=32432) exiting with status: 0
Operation Status: 0
Nov 25, 2023 12:58:27 PM - end VMware: Start Notify Script; elapsed time 0:00:01
Nov 25, 2023 12:58:27 PM - begin VMware: Step By Condition
Operation Status: 0
Nov 25, 2023 12:58:27 PM - end VMware: Step By Condition; elapsed time 0:00:00
Nov 25, 2023 12:58:27 PM - begin VMware: Read File List
Operation Status: 0
Nov 25, 2023 12:58:27 PM - end VMware: Read File List; elapsed time 0:00:00
Nov 25, 2023 12:58:27 PM - begin VMware: Create Snapshot
Nov 25, 2023 12:58:27 PM - Info bpbrm (pid=35140) vcs is the host to backup data from
Nov 25, 2023 12:58:27 PM - Info bpbrm (pid=35140) reading file list for client
Nov 25, 2023 12:58:27 PM - Info bpbrm (pid=35140) start bpfis on client
Nov 25, 2023 12:58:27 PM - Info bpbrm (pid=35140) Starting create snapshot processing
Nov 25, 2023 12:58:27 PM - started process bpbrm (pid=35140)
Nov 25, 2023 12:58:28 PM - Info bpfis (pid=40904) Backup started
Nov 25, 2023 12:58:28 PM - snapshot backup of client vcs using method VMware_v2
Nov 25, 2023 12:58:29 PM - Info bpbrm (pid=35140) INF - vmwareLogger:  Creating snapshot for vCenter server srv-vcenter02.dmzmsa.com, ESX host esx51.dmzmsa.com, BIOS UUID 4209005c-4ec2-29a8-b85b-64661575584b, Instance UUID 5009b489-ff24-bdce-eca6-95a8003f543a, Display Name vcs, Hostname trueconf.dmzmsa.com 
Nov 25, 2023 12:58:29 PM - Info bpbrm (pid=35140) INF - vmwareLogger:  Connection state of virtual machine: connected.
Nov 25, 2023 12:58:51 PM - end VMware: Create Snapshot; elapsed time 0:00:24
Nov 25, 2023 12:58:51 PM - Info bpfis (pid=40904) done. status: 0
Nov 25, 2023 12:58:51 PM - Info bpfis (pid=40904) done. status: 0: the requested operation was successfully completed
Nov 25, 2023 12:58:51 PM - end writing
Operation Status: 0
Nov 25, 2023 12:58:51 PM - end Parent Job; elapsed time 0:00:25
Nov 25, 2023 12:58:51 PM - Info nbjm (pid=6644) snapshotid=vcs_1700906306
Nov 25, 2023 12:58:51 PM - begin VMware: Policy Execution Manager Preprocessed
Operation Status: 6
Nov 25, 2023 1:25:15 PM - end VMware: Policy Execution Manager Preprocessed; elapsed time 0:26:24
Nov 25, 2023 1:25:15 PM - begin VMware: Stop On Error
Operation Status: 0
Nov 25, 2023 1:25:15 PM - end VMware: Stop On Error; elapsed time 0:00:00
Nov 25, 2023 1:25:15 PM - begin VMware: Delete Snapshot
Nov 25, 2023 1:25:15 PM - started process bpbrm (pid=40192)
Nov 25, 2023 1:25:16 PM - Info bpbrm (pid=40192) Starting delete snapshot processing
Nov 25, 2023 1:25:16 PM - Info bpfis (pid=40116) Backup started
Nov 25, 2023 1:25:24 PM - Info bpfis (pid=40116) done. status: 0
Nov 25, 2023 1:25:24 PM - end VMware: Delete Snapshot; elapsed time 0:00:09
Nov 25, 2023 1:25:24 PM - Info bpfis (pid=40116) done. status: 0: the requested operation was successfully completed
Nov 25, 2023 1:25:24 PM - end writing
Operation Status: 0
Nov 25, 2023 1:25:24 PM - begin VMware: End Notify Script
Nov 25, 2023 1:25:24 PM - Info RUNCMD (pid=40884) started
Nov 25, 2023 1:25:24 PM - Info RUNCMD (pid=40884) exiting with status: 0
Operation Status: 0
Nov 25, 2023 1:25:24 PM - end VMware: End Notify Script; elapsed time 0:00:00
Operation Status: 6
the backup failed to back up the requested files  (6)

Could you please help me to resolve this?

and the error occurs for many time.

Thank you,
Mike Androsov

[Hamza_H]

Hi, please share detailled status of the backup job (child) also try to enable logs for more details (bpbkar & vxms on backup host)

[msandrosov59]

All the time that has passed, backups have been running normally. An error occurred again today.

This errors see on backup stage:

13.04.2024 12:46:13 - Info nbjm (pid=6784) starting backup job (jobid=39911) for client vcs, policy vcs, schedule vcs_full

13.04.2024 12:46:13 - Info nbjm (pid=6784) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=39911, request id:{49225851-F948-4675-87D6-56407DC8D472})

13.04.2024 12:46:13 - requesting resource  cifs1-stu

13.04.2024 12:46:13 - requesting resource  srv-nbu01i.dmzmsa.com.NBU_CLIENT.MAXJOBS.vcs

13.04.2024 12:46:13 - requesting resource  srv-nbu01i.dmzmsa.com.NBU_POLICY.MAXJOBS.vcs

13.04.2024 12:46:13 - granted resource  srv-nbu01i.dmzmsa.com.NBU_CLIENT.MAXJOBS.vcs

13.04.2024 12:46:13 - granted resource  srv-nbu01i.dmzmsa.com.NBU_POLICY.MAXJOBS.vcs

13.04.2024 12:46:13 - granted resource  MediaID=@aaaah;DiskVolume=\\192.168.140.169\cifs1;DiskPool=cifs1;Path=\\192.168.140.169\cifs1;StorageServer=srv-nbu01i.dmzmsa.com;MediaServer=srv-nbu01i.dmzmsa.com

13.04.2024 12:46:13 - granted resource  cifs1-stu

13.04.2024 12:46:13 - estimated 0 kbytes needed

13.04.2024 12:46:13 - Info nbjm (pid=6784) started backup (backupid=vcs_1713001573) job for client vcs, policy vcs, schedule vcs_full on storage unit cifs1-stu using backup host srv-nbu01i.dmzmsa.com

13.04.2024 12:46:13 - started process bpbrm (pid=11112)

13.04.2024 12:46:13 - Info bpbrm (pid=11112) vcs is the host to backup data from

13.04.2024 12:46:13 - Info bpbrm (pid=11112) reading file list for client

13.04.2024 12:46:14 - connecting

13.04.2024 12:46:14 - connected; connect time: 0:00:00

13.04.2024 12:46:14 - Info bpbrm (pid=11112) starting bpbkar32 on client

13.04.2024 12:46:16 - Info bpbkar32 (pid=7216) Backup started

13.04.2024 12:46:16 - Info bpbkar32 (pid=7216) archive bit processing:<enabled>

13.04.2024 12:46:16 - Info bptm (pid=11768) start

13.04.2024 12:46:16 - Info bptm (pid=11768) using 262144 data buffer size

13.04.2024 12:46:16 - Info bptm (pid=11768) using 256 data buffers

13.04.2024 12:46:16 - Info bptm (pid=11768) start backup

13.04.2024 12:46:17 - begin writing

13.04.2024 12:46:19 - Info bpbkar32 (pid=7216) INF - Backing up vCenter server srv-vcenter02.dmzmsa.com, ESX host esx51.dmzminfin.ru, BIOS UUID 4209005c-4ec2-29a8-b85b-64661575584b, Instance UUID 5009b489-ff24-bdce-eca6-95a8003f543a, Display Name vcs, Hostname trueconf.dmzmsa.com

13.04.2024 12:55:29 - Error bpbrm (pid=11112) from client vcs: ERR - Error opening the snapshot disks using given transport mode: san:hotadd:nbd:nbdssl Status 23

13.04.2024 12:55:30 - Info bpbkar32 (pid=7216) bpbkar waited 0 times for empty buffer, delayed 0 times.

13.04.2024 12:55:38 - Error bpbrm (pid=11112) could not send server status message to client

13.04.2024 12:55:39 - Critical bpbrm (pid=11112) unexpected termination of client vcs

13.04.2024 12:55:39 - Info bpbkar32 (pid=0) done. status: 6: the backup failed to back up the requested files

13.04.2024 12:55:39 - end writing; write time: 0:09:22

the backup failed to back up the requested files  (6)

[L_BR]

Why have you got all options selected for the transport method? Which one are you trying to use?

If you are using SAN, check the VxMS logs on the media server. Search for this line:

Transport mode in effect =

I've had issues in the past where despite my transport method being set to 'san' only. In the background, the policy tries to use NBD instead and fails.

Additionally, check the for the following in the same log:

Error:

   11:25:16.0448 : g_vixInterfaceLogger:libvix.cpp:1800 <DEBUG> : [VFM_ESINFO] FILE: FileRemoveDirectoryRetry: Non-retriable error encountered (C:\Windows\TEMP\vmware-SYSTEM\42133551-573f-235f-c7dd-1ba8cfd1bfb2-vm-731\LOCK.lck): The directory is not empty (145)

   11:25:16.0448 : g_vixInterfaceLogger:libvix.cpp:1800 <DEBUG> : [VFM_ESINFO] 2020-03-13T11:25:16.448+02:00 info -[15932] [Originator@6876 sub=cleanup] Cannot lock directory C:\Windows\TEMP\vmware-SYSTEM\42133551-573f-235f-c7dd-1ba8cfd1bfb2-vm-731\LOCK.

Under C:\Windows\Temp will be a file called 'vmware-SYSTEM'. Rename it and retry the backup again.