NDMP restore issue

We normally see this when NBU believes it needs to restore to 'normal' NBU client with NBU software installed.

So, somewhere somehow there is an incorrect configuration.

Can you configure a backup policy for this filer and try to backup one volume?
No need to wait for backup to start - the moment the backup starts writing to tape or other destination, kill the backup.
This will confirm all is well with NDMP config.

To troubleshoot the restore:
Do you have bprd log folder on the master server?
If not, please create the folder under ...netbackup\logs and restart NBU.

After next failed restore attempt, please find this section in bprd log and post here:

.... <2> restorefiles:    browse_client =
.... <2> restorefiles:    requesting_client =
.... <2> restorefiles:    destination_client =
.... <2> restorefiles:    requesting_client_hostname =
.... <2> restorefiles:    destination_client_hostname =
.... <2> restorefiles:    requesting_user =
.... <2> restorefiles:    requesting_group =
.... <2> restorefiles:    progress_file =
.... <2> restorefiles:    rename_file =
.... <2> restorefiles:    policy =
.... <2> restorefiles:    client_type =

Hi Marianne,

I have got this folder, but there is no text file with information. What can I do that there NBU will create a file ?

I can´t do a backup, I haven´t got a tape.

When I try to restore everything to its original location I get the following error message:

 

11/9/2015 3:11:05 PM - Info ndmpagent(pid=4160) INF - Restoring NDMP files from /root_vdm_4/...  
11/9/2015 3:12:20 PM - Error ndmpagent(pid=4160) ndmp_data_connect_v3 failed, status = -1 (-1)       
11/9/2015 3:12:20 PM - Error ndmpagent(pid=4160) NDMP restore failed from path /root_vdm_4/...
11/9/2015 3:12:20 PM - Info bpbrm(pid=6276) child done, status 25         
11/9/2015 3:12:20 PM - Info bpbrm(pid=6276) sending message to media manager: STOP RESTORE "_1230568092"     
11/9/2015 3:12:21 PM - Info bpbrm(pid=6276) got ERROR 5 from media manager       
11/9/2015 3:12:21 PM - restored image "_1230568092" - (the restore failed to recover the requested files(5)); restore time 00:03:31
11/9/2015 3:12:21 PM - end Restore; elapsed time: 00:03:33
Restore error(2850)

NetBackup needs to be restarted on the master to enable bprd log.
Please double-check that the folder is in the correct location.
A text file will be created immediately after restarting NBU.

Please share the lines in Activity Monitor above the ones you posted?

Hi,

here are the complete lines :

11/9/2015 3:08:48 PM - begin Restore
11/9/2015 3:08:49 PM - 1 images required
11/9/2015 3:08:49 PM - media 000399 required
11/9/2015 3:08:50 PM - restoring image defmoa_1230568092
11/9/2015 3:08:50 PM - Info bpbrm(pid=6276) defmoa is the host to restore to      
11/9/2015 3:08:50 PM - Info bpbrm(pid=6276) telling media manager to start restore on client     
11/9/2015 3:08:51 PM - Info bpbrm(pid=5936) defmoa is the host to restore to      
11/9/2015 3:08:51 PM - Info bpbrm(pid=5936) start tar32 on client         
11/9/2015 3:08:51 PM - Info tar32(pid=4160) Restore started.           
11/9/2015 3:08:51 PM - connected
11/9/2015 3:08:52 PM - Info bptm(pid=748) Waiting for mount of media id 000399 (copy 1) on server ge-2008. 
11/9/2015 3:08:52 PM - started process bptm (748)
11/9/2015 3:08:52 PM - mounting 000399
11/9/2015 3:08:52 PM - Info bptm(pid=748) INF - Waiting for mount of media id 000399 on server ge-2008 for reading.
11/9/2015 3:08:52 PM - requesting resource 000399
11/9/2015 3:08:52 PM - granted resource 000399
11/9/2015 3:08:52 PM - granted resource HP.ULTRIUM3-SCSI.001
11/9/2015 3:09:33 PM - mounted; mount time: 00:00:41
11/9/2015 3:09:33 PM - Info bptm(pid=748) 000399            
11/9/2015 3:09:33 PM - Info bptm(pid=748) INF - Waiting for positioning of media id 000399 on server ge-2008 for reading.
11/9/2015 3:09:33 PM - positioning 000399 to file 7
11/9/2015 3:11:03 PM - positioned 000399; position time: 00:01:30
11/9/2015 3:11:03 PM - begin reading
11/9/2015 3:11:05 PM - Info ndmpagent(pid=4160) INF - Restoring NDMP files from /root_vdm_4/DEP5/Blizz   
11/9/2015 3:12:20 PM - Error ndmpagent(pid=4160) ndmp_data_connect_v3 failed, status = -1 (-1)       
11/9/2015 3:12:20 PM - Error ndmpagent(pid=4160) NDMP restore failed from path /root_vdm_4/DEP5/Blizz      
11/9/2015 3:12:20 PM - Info bpbrm(pid=6276) child done, status 25         
11/9/2015 3:12:20 PM - Info bpbrm(pid=6276) sending message to media manager: STOP RESTORE defmoa_1230568092     
11/9/2015 3:12:21 PM - Info bpbrm(pid=6276) got ERROR 5 from media manager       
11/9/2015 3:12:21 PM - restored image defmoa_1230568092 - (the restore failed to recover the requested files(5)); restore time 00:03:31
11/9/2015 3:12:21 PM - end Restore; elapsed time: 00:03:33
Restore error(2850)

This is wrong for NDMP restore:

11/9/2015 3:08:51 PM - Info bpbrm(pid=5936) start tar32 on client  
11/9/2015 3:08:51 PM - Info tar32(pid=4160) Restore started.           
11/9/2015 3:08:51 PM - connected 

As there is no client installed on a filer, NBU should not even try to connect to the filer.

The restore setup in bprd log will hopefully point us in the right direction. (The 'restorefiles' section.)

If the 'Client_Name' on the master was accidently changed to defmoa, then NBU will select the master server as destination.

If this is not the case and all configured correctly, check and verify that port 1000 is open between the master/media server and the filer.

Here bpbrm log on media server will be needed to troubleshoot.

This is the other document on bprd 

15:44:02.104 [7512.2168] <2> job_connect: SO_KEEPALIVE set on socket 580 for client ge-2008
15:44:02.104 [7512.2168] <2> logconnections: BPJOBD CONNECT FROM 192.168.100.32.65254 TO 192.168.100.32.13723 fd = 580
15:44:02.104 [7512.2168] <2> job_authenticate_connection: ignoring VxSS authentication check for now...
15:44:02.104 [7512.2168] <2> job_connect: Connected to the host ge-2008 contype 53 jobid <0> socket <580>
15:44:02.104 [7512.2168] <2> job_connect: Connected on port 65254
15:44:02.322 [7512.2168] <2> process_msgQ_msg: Got is mpx main up request from pid 2904
15:44:02.431 [7512.2168] <2> process_msgQ_msg: Got new restore request from pid 2904
15:44:02.431 [7512.2168] <2> read_needed_images_from_file: reading C:\Program Files\Veritas\NetBackup\bin\bprd.d\neededimage.2904 for work to do
15:44:02.431 [7512.2168] <2> read_image_info_from_file: frag 1 file 7 of 000399 is the first need fragment for defmoa07psge_1230568092
15:44:02.431 [7512.2168] <2> add_to_tape_list: 000399 ge-2008
15:44:02.431 [7512.2168] <2> open_checkpoint_file: open restore job ckpts C:\Program Files\Veritas\NetBackup\db\jobs\restart\27.ckpts for a+
15:44:02.431 [7512.2168] <2> group_tapes_in_frag_lists: Setting brm_pid = 0 for defmoa07psge_1230568092 restfiles pid 2904
15:44:02.431 [7512.2168] <2> run_restores: Non-MPX image restore
15:44:02.462 [7512.2168] <2> Orb::init: Enabling ORBNativeCharCodeSet UTF-8(Orb.cpp:594)
15:44:02.462 [7512.2168] <2> Orb::init: initializing ORB EMMlib_Orb with: bprd -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static Resource_Factory '-ORBNativeCharCodeSet UTF-8'" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static EndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb EMMlib_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(Orb.cpp:825)
15:44:02.478 [7512.2168] <2> Orb::init: caching EndpointSelectorFactory(Orb.cpp:840)
15:44:02.478 [7512.2168] <2> Orb::setOrbConnectTimeout: timeout seconds: 60(Orb.cpp:1481)
15:44:02.478 [7512.2168] <2> Orb::setOrbRequestTimeout: timeout seconds: 1800(Orb.cpp:1490)
15:44:02.494 [7512.2168] <2> get_media_server_version: NBU version of ge-2008 is 750000
15:44:02.494 [7512.2168] <2> start_mpx_group: media server ge-2008 version from db = 0x000b71b0 
15:44:02.494 [7512.2168] <2> start_mpx_group: /usr/openv/netbackup/bin/bpbrm bpbrm -restore -mpx_restore -S ge-2008 -mt 2 -to 0 -mud 180 -mediasvr ge-2008 -masterversion 750000
15:44:02.494 [7512.2168] <2> logconnections: BPCD CONNECT FROM 192.168.100.32.65258 TO 192.168.100.32.13782 fd = 604
15:44:02.603 [7512.2168] <2> start_mpx_group: bpbrm stdout from bpcr = 604
15:44:02.603 [7512.2168] <2> start_mpx_group: bpbrm stderr from bpcr = 620
15:44:02.696 [7512.2168] <2> read_bpbrm_msg: (pid 0) PID of bpbrm = 3668

15:44:02.696 [7512.2168] <2> start_mpx_group: bpbrm pid = 3668
15:44:02.696 [7512.2168] <2> set_mpx_group_image_brm_pid: Setting brm_pid = 3668 for defmoa07_1230568092 restfiles pid 2904
15:44:02.696 [7512.2168] <2> next_image_using_first_blks: returning backup_id = defmoa07_1230568092, tape = 000399, fileno = 7, firstblk = 0
15:44:02.696 [7512.2168] <2> start_image_restore: Sending listen msg to restfiles 2904 for image with backup time 1230568092
15:44:02.806 [7512.2168] <2> process_msgQ_msg: Setting portnum = 0 for defmoa07_1230568092
15:44:02.806 [7512.2168] <2> start_image_restore: restfiles pid 2904 brm pid 3668 defmoa07_1230568092
15:44:02.821 [7512.2168] <2> logconnections: BPCD CONNECT FROM 192.168.100.32.65263 TO 192.168.100.32.13782 fd = 612
15:44:02.884 [7512.2168] <2> start_indep_grp: active_mpx_groups = 1
15:44:02.884 [7512.2168] <2> start_indep_grp: p_active_restore_for_first_grp = NULL
15:44:02.884 [7512.2168] <2> start_indep_grp: p_first_mpx_group_for_restore = NULL
15:46:15.234 [7512.2168] <2> read_bpbrm_msg: (pid 3668) CURRENT POSITION 000399 7
15:46:15.234 [7512.2168] <2> send_bpbrm_msg: (pid 3668) CONTINUE RESTORE
15:47:32.376 [7512.2168] <2> read_bpbrm_msg: (pid 3668) ERROR 5
15:47:32.376 [7512.2168] <2> handle_image_status: defmoa07_1230568092 restfiles pid 2904 bpbrm pid 3668 status = 5
15:47:32.376 [7512.2168] <2> remove_completed_restore: unlink record with restfiles pid 2904
15:47:32.376 [7512.2168] <2> remove_completed_restore: no more active restores
15:47:32.376 [7512.2168] <2> done_with_bpbrm: bpbrm pid 3668 has no more images to process
15:47:32.376 [7512.2168] <2> send_bpbrm_msg: (pid 3668) TERMINATE
15:47:32.376 [7512.2168] <2> start_indep_grp: active_mpx_groups = -1
15:47:32.376 [7512.2168] <2> start_indep_grp: p_active_restore_for_first_grp = NULL
15:47:32.376 [7512.2168] <2> start_indep_grp: p_first_mpx_group_for_restore = NULL

This is not what we need.

Have you restarted NBU on the master server?

If so, restore details will be logged in the bprd log.

I need to see the restore setup as per previous request.

Hello, 

I opend Port 10.000 (not 1000) on the firewall is that right ?

Yes I restarted the nbu master server. There is nothing written the brpd file after the error  Unable to connect to Netbackup host "myNdmphost":/

What can I do ?

You are 100% correct. NDMP agent uses port 10000. bprd should be a folder (not a file) under veritas\netbackup\logs. If the folder exists when NBU is started, a text file called 'date'.log will be created.

Yes in the folder is a document with the today date, but when I open the document, there is nothing in :(

What can I do ?