cancel
Showing results for 
Search instead for 
Did you mean: 

GUI Restore Works, CLI Restore Fails

jwithamwellcome
Level 3

Hi,

We are running a restore in the GUI and it works perfect and then tried to script this restore, see script below but every time it throws this error - EXIT STATUS 2808: MS-windows policy restore error

 

 

cd "D:\Program Files\Veritas\NetBackup\bin"


.\bprestore.exe -B -w -C FileServer01 -D NBserver01.companyX.com -L "D:\Program Files\Veritas\NetBackup\logs\bprd\test.log" -s 26/04/2019 05:13:12 -e 26/04/2019 23:15:28 -R "D:\Program Files\Veritas\NetBackup\logs\user_ops\test03a_rename.txt" -f "D:\Program Files\Veritas\NetBackup\logs\user_ops\test03a_list.txt"

 

D:\Program Files\Veritas\NetBackup\logs\user_ops\test03a_rename.txt =

rename 142 "/Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/Doc.docx" 171 "D:\doc.docx"

 

 

D:\Program Files\Veritas\NetBackup\logs\user_ops\test03a_list.txt =

142 /Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/doc.docx

 

 

 

When I run the script, I see in the activity controller.....

 

 

 

17-Apr-2020 14:08:00 - begin Restore
17-Apr-2020 14:08:02 - Info bprd (pid=12996) Found (3,467,191) files in (10) images for Restore Job ID 75697.xxx
17-Apr-2020 14:08:02 - restoring from image fileserver01_1556305208
17-Apr-2020 14:08:02 - requesting resource  @aaaaS
17-Apr-2020 14:08:02 - granted resource  MediaID=@aaaaS;DiskVolume=_PhysicalLSU;DiskPool=dxi-qcloudprotect;Path=_PhysicalLSU;StorageServer=aws-qcloudprotect_172.31.23.33;MediaServer=nbserver01.companyx.com
17-Apr-2020 14:08:03 - Info bprd (pid=12996) Searched (        2) files of (3,467,191) files for Restore Job ID 75697.xxx
17-Apr-2020 14:08:03 - Info bprd (pid=12996) Restoring from copy 2 of image created 04/26/19 20:00:08 from policy AA-FS01_Weekly
17-Apr-2020 14:08:03 - Info bpbrm (pid=10536) nbserver01.companyx.com is the host to restore to
17-Apr-2020 14:08:03 - Info bpbrm (pid=10536) reading file list for client
17-Apr-2020 14:08:03 - Info bpbrm (pid=10536) connecting to bprd to get file list
17-Apr-2020 14:08:03 - connecting
17-Apr-2020 14:08:03 - Info bpbrm (pid=10536) starting bptm
17-Apr-2020 14:08:07 - Info tar32 (pid=7288) Restore started
17-Apr-2020 14:08:07 - connected; connect time: 0:00:00
17-Apr-2020 14:08:07 - Info bptm (pid=13688) start
17-Apr-2020 14:08:07 - started process bptm (pid=13688)
17-Apr-2020 14:08:07 - Info bptm (pid=13688) reading backup image
17-Apr-2020 14:08:07 - Info bptm (pid=13688) using 64 data buffers
17-Apr-2020 14:08:08 - begin reading
17-Apr-2020 14:08:11 - Info bptm (pid=13688) waited for empty buffer 0 times, delayed 0 times
17-Apr-2020 14:08:11 - Info tar32 (pid=7288) done. status: 5
17-Apr-2020 14:08:11 - end reading; read time: 0:00:03
17-Apr-2020 14:08:17 - Info bptm (pid=13688) completed reading backup image
17-Apr-2020 14:08:17 - Info bptm (pid=13688) EXITING with status 0 <----------
17-Apr-2020 14:08:17 - Info tar32 (pid=7288) done. status: 5: the restore failed to recover the requested files
17-Apr-2020 14:08:17 - Error bpbrm (pid=10536) client restore EXIT STATUS 5: the restore failed to recover the requested files
17-Apr-2020 14:08:17 - restored from image fileserver01_1556305208; restore time: 0:00:15
17-Apr-2020 14:08:17 - Warning bprd (pid=12996) Restore must be resumed prior to first image expiration on 25/04/2020 20:00:08
17-Apr-2020 14:08:17 - end Restore; elapsed time 0:00:17
Windows File System policy restore error  (2808)

1 ACCEPTED SOLUTION

Accepted Solutions

Look at the rename file again - I think you may be missing a new line. From the commands reference guide (the emphasis is mine). 

For example, the following entry renames C:\fred.txt to C:\fred2.txt:
rename 11 /C/fred.txt 12 /C/fred2.txt
(Be sure to end the entry with a return.)

Your rename file doesn't appear to to have a new line at the end. I think what may be happening is it is attempting to restore the file to the original location on the destination server hence the strange error (as I assume the destination server doesn't have DFSR running). 

View solution in original post

22 REPLIES 22

sdo
Moderator
Moderator
Partner    VIP    Certified

Oddly the rename file for Windows files needs to be specified in a Unix/Linux like format, and note the numbers are lengths of the part not positions.  Don't use quotes in the contents of the rename file.

For example, the following entry renames C:\fred.txt to C:\fred2.txt:
rename 11 /C/fred.txt 12 /C/fred2.txt

davidmoline
Level 6
Employee

Following on from @sdo advice, your rename file is incorrect. It should read something like the following:

rename 142 /Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/Doc.docx 11 /D/doc.docx

Three changes from what you had - no quotes; the second length was incorrect, and the rename location needs to be specified using linux/unix syntax

A big thank you to @davidmoline  & @sdo , the unix format was something I had indeed overlooked.

Here is the updated script:

 

---

cd "D:\Program Files\Veritas\NetBackup\bin"


.\bprestore.exe -B -w -C FileServer01 -D NBserver01.companyX.com -L "D:\Program Files\Veritas\NetBackup\logs\bprd\test.log" -s 26/04/2019 05:13:12 -e 26/04/2019 23:15:28 -R "D:\Program Files\Veritas\NetBackup\logs\user_ops\test03a_rename.txt" -f "D:\Program Files\Veritas\NetBackup\logs\user_ops\test03a_list.txt"

 

D:\Program Files\Veritas\NetBackup\logs\user_ops\test03a_rename.txt =

rename 142 /Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/Doc.docx 11 /D/doc.docx

 

 

D:\Program Files\Veritas\NetBackup\logs\user_ops\test03a_list.txt =

142 /Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/doc.docx

 

---

 

When I run this script is still fails with EXIT STATUS 2808, the activity monitor reads:

 

20-Apr-2020 08:43:18 - begin Restore
20-Apr-2020 08:43:20 - Info bprd (pid=11696) Found (3,467,191) files in (10) images for Restore Job ID 75707.xxx
20-Apr-2020 08:43:20 - restoring from image wt-fs01_1556305208
20-Apr-2020 08:43:20 - requesting resource  @aaaaS
20-Apr-2020 08:43:20 - granted resource  MediaID=@aaaaS;DiskVolume=_PhysicalLSU;DiskPool=dxi-qcloudprotect;Path=_PhysicalLSU;StorageServer=aws-qcloudprotect_172.31.23.33;MediaServer=wt-netbackupa.wellcomeit.com
20-Apr-2020 08:43:21 - Info bprd (pid=11696) Searched (        2) files of (3,467,191) files for Restore Job ID 75707.xxx
20-Apr-2020 08:43:21 - Info bprd (pid=11696) Restoring from copy 2 of image created 04/26/19 20:00:08 from policy WT-FS01_Weekly
20-Apr-2020 08:43:21 - Info bpbrm (pid=3152) wt-aws-nb02 is the host to restore to
20-Apr-2020 08:43:21 - Info bpbrm (pid=3152) reading file list for client
20-Apr-2020 08:43:23 - connecting
20-Apr-2020 08:43:23 - Info bpbrm (pid=3152) starting bptm
20-Apr-2020 08:43:26 - Info tar32 (pid=1472) Restore started
20-Apr-2020 08:43:26 - connected; connect time: 0:00:00
20-Apr-2020 08:43:26 - Info bptm (pid=11280) start
20-Apr-2020 08:43:26 - started process bptm (pid=11280)
20-Apr-2020 08:43:26 - Info bptm (pid=11280) reading backup image
20-Apr-2020 08:43:27 - Info bptm (pid=11280) using 64 data buffers
20-Apr-2020 08:43:27 - Info bptm (pid=11280) spawning a child process
20-Apr-2020 08:43:27 - Info bptm (pid=11280) child pid: 14104
20-Apr-2020 08:43:27 - Info bptm (pid=14104) start
20-Apr-2020 08:43:27 - started process bptm (pid=14104)
20-Apr-2020 08:43:28 - begin reading
20-Apr-2020 08:43:29 - Warning bpbrm (pid=3152) from client wt-aws-nb02: WRN - can't create file:  (WIN32 3: The system cannot find the path specified. )
20-Apr-2020 08:43:29 - Info tar32 (pid=1472) done. status 0
20-Apr-2020 08:43:29 - Info tar32 (pid=1472) done. status: 5
20-Apr-2020 08:43:45 - Info bptm (pid=11280) waited for empty buffer 1 times, delayed 1 times
20-Apr-2020 08:43:45 - end reading; read time: 0:00:17
20-Apr-2020 08:43:53 - Info bptm (pid=11280) completed reading backup image
20-Apr-2020 08:43:53 - Info bptm (pid=11280) EXITING with status 0 <----------
20-Apr-2020 08:43:53 - Info tar32 (pid=1472) done. status: 5: the restore failed to recover the requested files
20-Apr-2020 08:43:53 - Error bpbrm (pid=3152) client restore EXIT STATUS 5: the restore failed to recover the requested files
20-Apr-2020 08:43:53 - restored from image wt-fs01_1556305208; restore time: 0:00:33
20-Apr-2020 08:43:53 - Warning bprd (pid=11696) Restore must be resumed prior to first image expiration on 25/04/2020 20:00:08
20-Apr-2020 08:43:53 - end Restore; elapsed time 0:00:35
Windows File System policy restore error  (2808)

sdo
Moderator
Moderator
Partner    VIP    Certified

The first error seems to be:

Warning bpbrm (pid=3152) from client wt-aws-nb02: WRN - can't create file:  (WIN32 3: The system cannot find the path specified. )

NetBackup should create a folder if it doesn't exist.  Is a D: drive present and writable on the client: wt-aws-nb02 ?

Hi @sdo ,

 

I can access remote SMB share of wt-aws-nb02 D Drive, using the right account, it has full controll over the drive and folders too.

 

I then re-ran the script against the master server itself, of which the script is being run on and here were the Activity job results....



 

---

20-Apr-2020 10:21:44 - begin Restore
20-Apr-2020 10:21:46 - Info bprd (pid=13200) Found (3,467,191) files in (10) images for Restore Job ID 75710.xxx
20-Apr-2020 10:21:47 - restoring from image wt-fs01_1556305208
20-Apr-2020 10:21:47 - Info bprd (pid=13200) Searched (        2) files of (3,467,191) files for Restore Job ID 75710.xxx
20-Apr-2020 10:21:47 - Info bprd (pid=13200) Restoring from copy 2 of image created 04/26/19 20:00:08 from policy WT-FS01_Weekly
20-Apr-2020 10:21:47 - requesting resource  @aaaaS
20-Apr-2020 10:21:47 - granted resource  MediaID=@aaaaS;DiskVolume=_PhysicalLSU;DiskPool=dxi-qcloudprotect;Path=_PhysicalLSU;StorageServer=aws-qcloudprotect_172.31.23.33;MediaServer=wt-netbackupa.wellcomeit.com
20-Apr-2020 10:21:47 - Info bpbrm (pid=1476) wt-netbackupA is the host to restore to
20-Apr-2020 10:21:47 - Info bpbrm (pid=1476) reading file list for client
20-Apr-2020 10:21:47 - Info bpbrm (pid=1476) connecting to bprd to get file list
20-Apr-2020 10:21:47 - connecting
20-Apr-2020 10:21:47 - Info bpbrm (pid=1476) starting bptm
20-Apr-2020 10:21:51 - Info tar32 (pid=1204) Restore started
20-Apr-2020 10:21:51 - connected; connect time: 0:00:00
20-Apr-2020 10:21:51 - Info bptm (pid=9904) start
20-Apr-2020 10:21:51 - started process bptm (pid=9904)
20-Apr-2020 10:21:51 - Info bptm (pid=9904) reading backup image
20-Apr-2020 10:21:51 - Info bptm (pid=9904) using 64 data buffers
20-Apr-2020 10:21:53 - begin reading
20-Apr-2020 10:21:55 - Info bptm (pid=9904) waited for empty buffer 0 times, delayed 0 times
20-Apr-2020 10:21:55 - Info tar32 (pid=1204) done. status: 5
20-Apr-2020 10:21:55 - end reading; read time: 0:00:02
20-Apr-2020 10:22:00 - Info bptm (pid=9904) completed reading backup image
20-Apr-2020 10:22:00 - Info bptm (pid=9904) EXITING with status 0 <----------
20-Apr-2020 10:22:00 - Info tar32 (pid=1204) done. status: 5: the restore failed to recover the requested files
20-Apr-2020 10:22:00 - Error bpbrm (pid=1476) client restore EXIT STATUS 5: the restore failed to recover the requested files
20-Apr-2020 10:22:01 - restored from image wt-fs01_1556305208; restore time: 0:00:14
20-Apr-2020 10:22:01 - Warning bprd (pid=13200) Restore must be resumed prior to first image expiration on 25/04/2020 20:00:08
20-Apr-2020 10:22:01 - end Restore; elapsed time 0:00:17
Windows File System policy restore error  (2808)

 

 

---

sdo
Moderator
Moderator
Partner    VIP    Certified

Can you collect a detailed tar log?  So that we can see why tar32 is generating a status 5.

 

Hi @sdo , 

 

is the attached log file enough detail? Many thanks :)

Looking at the log file I see the following problem:

WinMain: INF - No existing DFSR metadata, attempting to create a copy.
GetDFSMetadata: INF - Expected DFSR metadata file does not exist "D:\Program Files\Veritas\\NetBackup\logs\beds\{2707761B-2324-473D-88EB-EB007A359533} - DFS Replication service writer.xml" .
GetDFSMetadata: INF - The DFS Replication writer service is not running on this machine.
tar_base::V_vTarMsgW: WRN - can't create file: (WIN32 3: The system cannot find the path specified. )
tar_base::V_vTarMsgM: CKP - 75712.001 1587375073 0 0 105 1 0 T 142 /Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/BED Communications List.docx

I'm not familiar enough with DFSR restores to know if this is a problem, but can you try the restore back to the same client (or does that defeat the purpos of what you are testing).
Also when you have tested via the GUI, is the restore to the same alternate destination client? If so, can you run again and provide the logs from that session please?

Hi @davidmoline , Thank you for helping me one this!

Unfortuntately not an option to restore to the same client, very interesting DFSR error!

I attempt the same restore via the GUI and here are in the log from the Activity Log:

---

21-Apr-2020 08:29:02 - Info bpbrm (pid=1772) wt-aws-nb02.companyx.com is the host to restore to
21-Apr-2020 08:29:02 - Info bpbrm (pid=1772) reading file list for client
21-Apr-2020 08:29:03 - Info bpbrm (pid=1772) connecting to bprd to get file list
21-Apr-2020 08:29:04 - connecting
21-Apr-2020 08:29:04 - Info bpbrm (pid=1772) starting bptm
21-Apr-2020 08:29:07 - Info tar32 (pid=1340) Restore started
21-Apr-2020 08:29:07 - connected; connect time: 0:00:00
21-Apr-2020 08:29:07 - Info bptm (pid=3440) start
21-Apr-2020 08:29:08 - started process bptm (pid=3440)
21-Apr-2020 08:29:08 - Info bptm (pid=3440) reading backup image
21-Apr-2020 08:29:08 - Info bptm (pid=3440) using 30 data buffers
21-Apr-2020 08:29:11 - begin reading
21-Apr-2020 08:29:13 - Info bptm (pid=3440) waited for empty buffer 1 times, delayed 31 times
21-Apr-2020 08:29:13 - end reading; read time: 0:00:02
21-Apr-2020 08:29:13 - Info bptm (pid=3440) completed reading backup image
21-Apr-2020 08:29:13 - Info tar32 (pid=1340) done. status 0
21-Apr-2020 08:29:13 - Info bptm (pid=3440) EXITING with status 0 <----------
21-Apr-2020 08:29:13 - Info tar32 (pid=1340) done. status: 0
21-Apr-2020 08:29:13 - Info tar32 (pid=1340) done. status: 0: the requested operation was successfully completed
21-Apr-2020 08:30:20 - begin Restore
21-Apr-2020 08:30:22 - Info bprd (pid=11148) Found (250,186) files in (1) images for Restore Job ID 75714.xxx
21-Apr-2020 08:30:22 - restoring from image wt-fs01_1556305208
21-Apr-2020 08:30:22 - requesting resource  @aaaaS
21-Apr-2020 08:30:22 - granted resource  MediaID=@aaaaS;DiskVolume=_PhysicalLSU;DiskPool=dxi-qcloudprotect;Path=_PhysicalLSU;StorageServer=aws-qcloudprotect_172.31.23.33;MediaServer=wt-aws-nb02.companyx.com
21-Apr-2020 08:30:22 - Info bprd (pid=11148) Searched (      1) files of (250,186) files for Restore Job ID 75714.xxx
21-Apr-2020 08:30:22 - Info bprd (pid=11148) Restoring from copy 2 of image created 04/26/19 20:00:08 from policy WT-FS01_Weekly
21-Apr-2020 08:30:35 - restored from image wt-fs01_1556305208; restore time: 0:00:13
21-Apr-2020 08:30:35 - end Restore; elapsed time 0:00:15
the requested operation was successfully completed  (0)

--

Is there any other log file that would help reveal more on this?

 

Many thanks

 

 

sdo
Moderator
Moderator
Partner    VIP    Certified

Let's collect a detailed level 5 tar log for the GUI based restore that works.  Then also collect a detailed level 5 log for the CLI based restore that fails.  Let's see if we can spot what's different, i.e. why the GUI method works, or why the CLI method fails.

davidmoline
Level 6
Employee

Other than what @sdo is suggesting, can you see if there are log files in the beds log directory from the time of the restores - they may also prove useful. Finally - can you attach any log files from the time of the restore(s) from the user_ops directory for the user perfroming these restores (GUI and CLI).

Thank you @DA @sdo .

I have changed the log settings to 5 and re-ran the CLI restore first (started 09:12AM, job id 75727, which failed), and then the GUI restore which completed sucessfully (started 09:22AM, job id 75729).

Kindly find attached the tar & user_ops logs directory as a .zip file. Let me know if you'd like additonal logs Hopefully this holds the answer :)

 

Many many thanks

I think I see the problem. The list file does not match the rename file (a simple error, but annoying). 

In the list file "tes03a_list.txt" - you are restoring the file "..BlueEarth\BED Communications List.docx"
142 /Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/BED Communications List.docx

In the test03a_rename.txt - you are renaming the file "..\BlueEarth\Doc.docx" to "D/Doc.docx"
rename 142 /Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/Doc.docx 11 /D/doc.docx

As the files don't match, although it can find the file to restore, there is nothing to rename this file to - so the restore fails. The critical lines from the tar log file are:
09:13:59.792 [8984.10556] <2> tar_base::V_vTarMsgM: TAR - Shadow Copy Components:\User Data\Distributed File System Replication\DfsrReplicatedFolders\Departments\BlueEarth\BED Communications List.docx
09:13:59.792 [8984.10556] <4> base_restore::chooseName: INF - existing name ="\\?\Shadow Copy Components:\User Data\Distributed File System Replication\DfsrReplicatedFolders\Departments\BlueEarth\BED Communications List.docx", new name = "", ""
09:13:59.792 [8984.10556] <2> tar_base::V_vTarMsgW: WRN - can't create file: (WIN32 3: The system cannot find the path specified. )

Your the first file path in the rename file needs to match one of the lines in the restore file list (and when you update the rename file don't forget to update the length as required). SO the rename file should have this:
rename 142 /Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/BED Communications List.docx 11 /D/doc.docx

Hi @davidmoline ,

The rename file being named differently would have been my fault when I was trying to troubleshoot.

The files are now:

test03a_rename:

rename 142 /Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/BED Communications List.docx 11 /D/doc.docx

test03a_list:

142 /Shadow Copy Components/User Data/Distributed File System Replication/DfsrReplicatedFolders/Departments/BlueEarth/BED Communications List.docx

 

 

Unfortunately the job still fails with error: EXIT STATUS 2808: MS-Windows policy restore error 

 

The job ran at 07:55AM and the job ID was 75733. 

 

I have attached the log files again, would uploading any others be helpful ? (log verbose set to level 5)

Look at the rename file again - I think you may be missing a new line. From the commands reference guide (the emphasis is mine). 

For example, the following entry renames C:\fred.txt to C:\fred2.txt:
rename 11 /C/fred.txt 12 /C/fred2.txt
(Be sure to end the entry with a return.)

Your rename file doesn't appear to to have a new line at the end. I think what may be happening is it is attempting to restore the file to the original location on the destination server hence the strange error (as I assume the destination server doesn't have DFSR running). 

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

@jwithamwellcome 

Could you please show us screenshots of the successful GUI restore? 

Please start with initial setup where you specify source and destination client, then where you drill down to the file name, and lastly the restore options where you specify the restore path and other restore options. 

These screenshots should enable us to compare with the CLI restore options. 

Hey @jwithamwellcome 

Did you resolve the issue? Or do you need more help?

Cheers

Thank you @davidmoline - the extra line indeed solved it, I am quite flabbergasted that this is required the script to run.

If only I could buy you a coffee, or something stronger to say thank you.

In the future, capture the good rename file that the GUI creates. It's not deleted at the end of the restore. You can get its name from the tar log.