cancel
Showing results forΒ 
Search instead forΒ 
Did you mean:Β 

VM Instant Recovery fails with an error 5

Andrew_Madsen
Level 6
Partner

I am trying to do an instant recovery of a VM from one NBU domain to another. The backup image was replicated through AIR. The comand I use is this:

nbrestorevm -vmw -ir_activate -C mspwksv20 -vmproxy mspnbuv01 -temp_location LOCAL_MSPESCH31 -R "E:\Program Files\Veritas\NetBackup\bin\change.txt" -vmserver mspvicv30.datalinklabs.local -L "E:\Program Files\Veritas\NetBackup\bin\progress.log" -vmpo

I get an error 5 in the details:

12/04/2014 17:27:03 - Info bprd (pid=6772) Waiting for Instant Recovery job to end
12/04/2014 17:27:03 - Info bprd (pid=6772) Starting to export a backup image on the media server mspnbu5230
12/04/2014 17:27:05 - Info bprd (pid=6772) Backup image has been successfully exported on the media server mspnbu5230
12/04/2014 17:27:12 - Info bprd (pid=6772) Backup image has been successfully mounted  on the server mspesch31.datalinklabs.local
12/04/2014 17:27:12 - Info bprd (pid=6772) Starting to activate a virtual machine on the server mspesch31.datalinklabs.local
12/04/2014 17:27:19 - Error bprd (pid=6772) Failed to activate a virtual machine on the server mspesch31.datalinklabs.local
12/04/2014 17:27:19 - Info bprd (pid=6772) Starting to unmount a backup image on the server mspesch31.datalinklabs.local
the restore failed to recover the requested files  (5)

In the bpVMutil log

17:27:18.451 [33072.34212] <4> nbfs_log_msg: (nbfs_mount()  INF - waiting for mount mutex
17:27:18.451 [33072.34212] <4> nbfs_log_msg: (nbfs_mount()  INF - running command - "E:\Program Files\Veritas\NetBackup\bin\nbfs" mount -server mspnbu5230 -port 7394 -timeout 60  -cred EBF3AC5801...
17:27:18.591 [33072.34212] <4> nbfs_log_msg: (nbfs_mount()  INF - response - BASEDIR=
17:27:18.591 [33072.34212] <4> nbfs_log_msg: (nbfs_mount()  INF - response - MNTPATH=/NBUFS_A_1F4F6B14C4352574_003
17:27:18.591 [33072.34212] <4> nbfs_log_msg: (nbfs_mount()  INF - response - MOUNTPOINT=
17:27:18.591 [33072.34212] <4> nbfs_log_msg: (nbfs_mount()  INF - response - Z: is now successfully connected to mspnbu5230:/NBUFS_A_1F4F6B14C4352574_003
17:27:18.591 [33072.34212] <4> nbfs_log_msg: (nbfs_mount()  INF - response - EXIT_STATUS=0
17:27:18.607 [33072.34212] <4> nbfs_log_msg: (nbfs_mount()  INF - looking for mount path: NBUFS_A_1F4F6B14C4352574_003
17:27:18.607 [33072.34212] <4> nbfs_log_msg: (_nbfs_connection_process()  INF - local name: Z:
17:27:18.607 [33072.34212] <4> nbfs_log_msg: (_nbfs_connection_process()  INF - remote name: \\mspnbu5230\NBUFS_A_1F4F6B14C4352574_003
17:27:18.607 [33072.34212] <4> nbfs_log_msg: (_nbfs_connection_process()  INF - successfully processed connection: Z:
17:27:18.607 [33072.34212] <4> nbfs_log_msg: (nbfs_mount()  INF - mount point - Z:
17:27:18.607 [33072.34212] <4> nbfs_log_msg: (makeClientAndBackupTime  INF - Finding client and backup time from bid: mspwksv20_1417703802
17:27:18.607 [33072.34212] <4> nbfs_log_msg: (buildPathToXml  INF - Reading VM Config file from: Z:\backups\mspwksv20\allusers\full\1417703802\^^.^VIRTUAL_FILE_FSMAP
17:27:18.622 [33072.34212] <4> nbfs_log_msg: (_nbfs_file_exists()  INF - FindFirstFile(Z:\backups\mspwksv20\allusers\full\1417703802\^^.^VIRTUAL_FILE_FSMAP) indicates that the file exists
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (readXml  INF - Size reported by stat: 22016 bytes
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (readXml  INF - Found xml file of size: 22016 bytes, Z:\backups\mspwksv20\allusers\full\1417703802\^^.^VIRTUAL_FILE_FSMAP
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (readXml  INF - Read file size: 22015
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (readXml  INF - Size after striping padding: 21837
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (_nbfs_file_exists()  INF - FindFirstFile(Z:\backups\mspwksv20\allusers\full\1417703802\_vmir) indicates that the file exists
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (makeViewFolder  INF - Using existing folder for view: Z:\backups\mspwksv20\allusers\full\1417703802\_vmir
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (_nbfs_file_exists()  INF - FindFirstFile(Z:\backups\mspwksv20\allusers\full\1417703802\VMSTORAGE-v03-mspesch1x_vmware_nfs01_ds\mspwksv20\mspwksv20-000001.vmdk.desc) indicates that the file exists
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (_nbfs_file_exists()  INF - FindFirstFile(Z:\backups\mspwksv20\allusers\full\1417703802\_vmir\mspwksv20.vmdk) indicates that the file exists
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (copyOrLinkPath  INF - File already exists, reusing: Z:\backups\mspwksv20\allusers\full\1417703802\_vmir\mspwksv20.vmdk
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (_nbfs_file_exists()  INF - FindFirstFile(Z:\backups\mspwksv20\allusers\full\1417703802\VMSTORAGE-v03-mspesch1x_vmware_nfs01_ds\mspwksv20\mspwksv20-000001.vmdk) indicates that the file exists
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (_nbfs_file_exists()  INF - FindFirstFile(Z:\backups\mspwksv20\allusers\full\1417703802\_vmir\mspwksv20-flat.vmdk) indicates that the file exists
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (copyOrLinkPath  INF - File already exists, reusing: Z:\backups\mspwksv20\allusers\full\1417703802\_vmir\mspwksv20-flat.vmdk
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (nbfs_unmount()  INF - waiting for mount mutex
17:27:18.950 [33072.34212] <4> nbfs_log_msg: (nbfs_unmount()  INF - running command - "E:\Program Files\Veritas\NetBackup\bin\nbfs" umount -f -server mspnbu5230 -port 7394 -cred E838350D16D...
17:27:19.106 [33072.34212] <4> nbfs_log_msg: (nbfs_unmount()  INF - response - EXIT_STATUS=0
17:27:19.106 [33072.34212] <4> nbfs_log_msg: (nbfs_unmount()  INF - looking for mount path: NBUFS_A_1F4F6B14C4352574_003
17:27:19.122 [33072.34212] <4> nbfs_log_msg: (nbfs_unmount()  INF - unmounted mount path: NBUFS_A_1F4F6B14C4352574_003
17:27:19.699 [33072.34212] <16> publishVM: Create virtual machine failed for mspvicv30.datalinklabs.local with 16
17:27:19.730 [33072.34212] <16> bpVMutil main: publish VM failed

17:27:19.730 [33072.34212] <2> virtlogcallback: checkBackupRegEntry: searching configuration for KeepVMXmlFiles
17:27:19.730 [33072.34212] <2> virtlogcallback: get_string_value failed
17:27:19.730 [33072.34212] <2> bpVMutil main: EXIT STATUS 5: the restore failed to recover the requested files

I filtered a big load of stuff out. Important thing (in my mind) is "FindFirstFile(Z:\backups\mspwksv20\allusers\full\1417703802\_vmir\mspwksv20-flat.vmdk) indicates that the file exists" and yet we get a cannot find the files eror.

vCenter shows the NFS mount and then dismount. 

Has anyione seen this before?

 

 

1 ACCEPTED SOLUTION

Accepted Solutions

Andrew_Madsen
Level 6
Partner

Fixed this. It was a typo in the changes file I had "resource pool" not "resourcepool"

View solution in original post

3 REPLIES 3

Michael_G_Ander
Level 6
Certified

Have experienced a similar issue under the 7.6 Beta, where the problem was the name of the temp datastore name started with a number, maybe the underscore in your temp datastore name is the issue. If I remember correctly it could be seen in the bpVMutil log at verbose 2.

Our first workaround was to use a temp datastore named NBUREST, then we created a case at Symantec to get the bug fixed. The case number was 04522819

Hope this helps

The standard questions: Have you checked: 1) What has changed. 2) The manual 3) If there are any tech notes or VOX posts regarding the issue

Andrew_Madsen
Level 6
Partner

I performed a backup of a VM on the target VM farm. I then ran IR using the same volume for temp files as I did in the previous attempt with an AIR'd image. That restore worked fine. Not the datastore name. Thanks for the information tho it eliminates one more thing.

Andrew_Madsen
Level 6
Partner

Fixed this. It was a typo in the changes file I had "resource pool" not "resourcepool"