Video Screencast Help

Windows 2008 Nebackup restore issue

Created: 06 Jun 2013 | 8 comments

I am starting to see this on all our 2008 Windows 64bit Servers.

I have tried to restore from 2 different ones now and get the same error.  If I restore on 2003 or older I am fine.  If I restore from the master/Media 2008 server running 7.5.0.5 I have no problem.  Just the clients.

error is

Restore not initiated: the restore failed to recover the requested file (5)  This happens as soon as I try to restore.  I can see the data on the Master/Medai fine.  I can ping the VTL, and Netbackup servers both ways with no issues.

Any thoughs?

Operating Systems:

Comments 8 CommentsJump to latest comment

RonCaplinger's picture

NBU status code 5 is one of the less informative codes, you will have to look in the bptm and bpcd logs on the media server to identify the problem. 

NathanNieman's picture

Ok I have 3 logs in each folder.  Some a very large..  No idea how to read these.

RonCaplinger's picture

We need to narrow down the point in the logs we should be looking at.  Can you post the contents of the Detailed Status tab from the NBU Activity Monitor for one of the failed restore attempts?  That might help determine if the problem is in the connection to the client or the transfer of the backup data.

NathanNieman's picture
20:00:00.657 [4492.3096] <2> process_requests: Duplicated vnetd socket on stderr
20:00:00.657 [4492.3096] <2> process_requests: <---- NetBackup 7.5 0 ------------initiated
20:00:00.657 [4492.3096] <2> process_requests: VERBOSE = 5
20:00:00.657 [4492.3096] <2> process_requests: Not using VxSS authentication with UNS40-88.americas.ad.nsk.com
20:00:00.688 [4492.3096] <2> process_requests: 
20:00:00.688 [4492.3096] <2> process_requests: BPCD_FORK_CMD_RQST
20:00:00.688 [4492.3096] <2> process_requests: fork cmd = /usr/openv/netbackup/bin/bpbrm bpbrm -backup -S uns40-88 -c uns4025-10 -ct 13 -ru root -cl Trans4m-BiQuery-weekday_backup -sched Default-Application-Backup -bt 1370476800 -dt 86697 -st 1 -b uns4025-10_1370476800 -mediasvr uns40-88 -jobid 9360 -jobgrpid 9360 -masterversion 750000 -maxfrag 1048576 -bpstart_time 1370477100 -reqid -1370021452 -mt 2 -to 0 -stunit uns40-88-hcart3-robot-tld-2 -rl 3 -rp 2678400 -eari 0 -cj 17 -D 20 -rt 8 -rn 2 -pool NetBackup -use_ofb -use_otm -WOFB_enabled 1 -nbu -jm -secure 1 -kl 28 -rg root -fso -keyword Trans4M������Bi��Query����Autoex����T.S.S -connect_options 16974338
20:00:00.688 [4492.3096] <2> process_requests: filter type = -1
20:00:00.688 [4492.3096] <2> process_requests: Convert args to CreateProcess format
20:00:00.703 [4492.3096] <2> process_requests: Done converting args to CreateProcess format
20:00:00.703 [4492.3096] <2> process_requests: new fork cmd = C:\Program Files\Veritas\NetBackup\bin\bpbrm.exe -backup -S uns40-88 -c uns4025-10 -ct 13 -ru root -cl Trans4m-BiQuery-weekday_backup -sched Default-Application-Backup -bt 1370476800 -dt 86697 -st 1 -b uns4025-10_1370476800 -mediasvr uns40-88 -jobid 9360 -jobgrpid 9360 -masterversion 750000 -maxfrag 1048576 -bpstart_time 1370477100 -reqid -1370021452 -mt 2 -to 0 -stunit uns40-88-hcart3-robot-tld-2 -rl 3 -rp 2678400 -eari 0 -cj 17 -D 20 -rt 8 -rn 2 -pool NetBackup -use_ofb -use_otm -WOFB_enabled 1 -nbu -jm -secure 1 -kl 28 -rg root -fso -keyword Trans4M������Bi��Query����Autoex����T.S.S -connect_options 16974338 
20:00:00.703 [4492.3096] <2> process_requests: Before CreateProcess
20:00:00.703 [4492.3096] <2> process_requests: StdOutput assigned the value STDOUTSOCK
20:00:00.703 [4492.3096] <2> process_requests: final fork cmd = "C:\Program Files\Veritas\NetBackup\bin\bpbrm.exe" -backup -S uns40-88 -c uns4025-10 -ct 13 -ru root -cl Trans4m-BiQuery-weekday_backup -sched Default-Application-Backup -bt 1370476800 -dt 86697 -st 1 -b uns4025-10_1370476800 -mediasvr uns40-88 -jobid 9360 -jobgrpid 9360 -masterversion 750000 -maxfrag 1048576 -bpstart_time 1370477100 -reqid -1370021452 -mt 2 -to 0 -stunit uns40-88-hcart3-robot-tld-2 -rl 3 -rp 2678400 -eari 0 -cj 17 -D 20 -rt 8 -rn 2 -pool NetBackup -use_ofb -use_otm -WOFB_enabled 1 -nbu -jm -secure 1 -kl 28 -rg root -fso -keyword Trans4M������Bi��Query����Autoex����T.S.S -connect_options 16974338 
20:00:00.703 [4492.3096] <2> process_requests: After CreateProcess, pid = 7836
20:00:00.703 [4492.3096] <2> bpcd exit_bpcd: exit status 0  ----------->exiting
20:00:01.936 [6912.6680] <2> vnet_pbxAcceptSocket: Accepted sock[556] from 131.40.10.88:50353
20:00:01.936 [6912.6680] <2> bpcd main: accept sock = 556
20:00:01.967 [4200.4372] <2> setup_debug_log: switched debug log file for bpcd
20:00:01.967 [4200.4372] <2> bpcd main: VERBOSE = 5
20:00:01.967 [4200.4372] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpcd.exe -standalone 
20:00:01.967 [4200.4372] <2> ReadKeyfile: keyfile C:\Program Files\Veritas\NetBackup\bin\keyfile.dat does not exist
 
RonCaplinger's picture

This appears to be the bpcd output from a job that ran at 8:00pm.  I don't see ay problem with this, but it looks like a backup, not a restore.Can you post the bpcd output from the restore attempt?  And just to be sure, do you have any "Restore Failover" or "Media Host Override" defined in your master server's properties that might be affecting restores?

NathanNieman's picture

What is strange is if I run this restore on the master it runs fine.

more this time the BPTM

14:01:53.233 [8176.8316] <2> initialize: fd values STDOUTSOCK=244 STDERRSOCK=508
14:01:53.249 [8176.8316] <2> bptm: instance - 606695844
14:01:53.249 [8176.8316] <2> bptm: INITIATING (VERBOSE = 5): -rptdrv -jobid -1370541655 -jm 
14:01:53.249 [8176.8316] <2> bptm: Event Global\NetBackup Terminate Event, pid: 8176 created.
14:01:53.249 [8176.8316] <2> bptm: PORT_STATUS = 0x00000000
14:01:53.249 [8176.8316] <2> main: Sending [EXIT STATUS 0] to NBJM
14:01:53.249 [8176.8316] <2> bptm: EXITING with status 0 <----------
14:01:53.249 [8176.8316] <2> bptm: Global\NetBackup Terminate Event, pid: 8176 closed.
 
14:11:16.081 [4960.6240] <2> initialize: fd values STDOUTSOCK=244 STDERRSOCK=508
14:11:16.097 [4960.6240] <2> bptm: instance - 607258695
14:11:16.097 [4960.6240] <2> bptm: INITIATING (VERBOSE = 5): -rptdrv -jobid -1370541656 -jm 
14:11:16.097 [4960.6240] <2> bptm: Event Global\NetBackup Terminate Event, pid: 4960 created.
14:11:16.097 [4960.6240] <2> bptm: PORT_STATUS = 0x00000000
14:11:16.097 [4960.6240] <2> main: Sending [EXIT STATUS 0] to NBJM
14:11:16.097 [4960.6240] <2> bptm: EXITING with status 0 <----------
14:11:16.097 [4960.6240] <2> bptm: Global\NetBackup Terminate Event, pid: 4960 closed.
 
Marianne's picture

Have you tried to disable UAC on W2008 Clients?

Or open BAR with right-click, Run as Administrator?

The restore progress log on the client may contain more helpful info.

Supporting Storage Foundation and VCS on Unix and Windows as well as NetBackup on Unix and Windows
Handy NBU Links

NathanNieman's picture

Ah I might have posted the wrong part with the file I just searched for the servers name..  It is a huge log.

I have not tried the UAC but I will.  I have ran BAR as administrator same thing.