NDMP restore is hung after reading one media.

[Deepak_Irani1]

Hi All,

I am trying to restore a directory on NDMP to its original location. My restore actually requires 8 medias. Restore is going in hung state after reading backup image on one media. Nothing is happening after that. I was not able to find any errors in bptm and bprd as well. Below are job logs. 

7/15/2016 5:29:38 AM - begin Restore
7/15/2016 5:29:48 AM - media BE1658 required
7/15/2016 5:29:48 AM - media BE1331 required
7/15/2016 5:29:48 AM - media BE1308 required
7/15/2016 5:29:48 AM - media BE1667 required
7/15/2016 5:29:48 AM - media BE1273 required
7/15/2016 5:29:48 AM - media BE1513 required
7/15/2016 5:29:48 AM - media BE1694 required
7/15/2016 5:29:48 AM - media BE1673 required
7/15/2016 5:29:48 AM - restoring image bbtflrbe802_1457446031
7/15/2016 5:29:51 AM - Info bpbrm(pid=18752) bbtflrbe802 is the host to restore to      
7/15/2016 5:29:51 AM - Info bpbrm(pid=18752) reading file list from client        
7/15/2016 5:29:51 AM - connecting
7/15/2016 5:29:51 AM - Info bpbrm(pid=18752) starting bptm           
7/15/2016 5:29:52 AM - Info ndmpagent(pid=18576) Restore started           
7/15/2016 5:29:52 AM - connected; connect time: 00:00:01
7/15/2016 5:29:53 AM - Info bptm(pid=18320) start            
7/15/2016 5:29:53 AM - started process bptm (18320)
7/15/2016 5:29:53 AM - Info bpdm(pid=18320) reading backup image          
7/15/2016 5:29:55 AM - Info bptm(pid=18320) Waiting for mount of media id BE1331 (copy 1) on server bbtsrvbrl5. 
7/15/2016 5:29:55 AM - started process bptm (18320)
7/15/2016 5:29:55 AM - mounting BE1331
7/15/2016 5:29:55 AM - requesting resource BE1331
7/15/2016 5:29:55 AM - granted resource BE1331
7/15/2016 5:29:55 AM - granted resource HP.ULTRIUM3-SCSI.000
7/15/2016 5:29:56 AM - Info bptm(pid=18320) INF - Waiting for mount of media id BE1331 on server bbtsrvbrl5 for reading.
7/15/2016 5:30:49 AM - mounted; mount time: 00:00:54
7/15/2016 5:30:49 AM - Info bptm(pid=18320) BE1331            
7/15/2016 5:30:50 AM - Info bptm(pid=18320) INF - Waiting for positioning of media id BE1331 on server bbtsrvbrl5 for reading.
7/15/2016 5:30:50 AM - positioning BE1331 to file 13
7/15/2016 5:31:08 AM - positioned BE1331; position time: 00:00:18
7/15/2016 5:31:09 AM - Info bptm(pid=18320) completed reading backup image         
7/15/2016 5:31:09 AM - Info bptm(pid=18320) EXITING with status 0 <----------        

There is no progression after this. Please suggest how I can proceed further.

[PatS729]

Is this a local / three way / remote NDMP ? Any chance that multiplexing was enabled ? If so what value used for multiplexing?

[Deepak_Irani1]

Hi PatS729,

This is a local NDMP backup. 

Multiplexing is not ehnabled in our environment.

[Marianne]

It seems as if the restore completed successfully with status 0.
Are you saying the restore is staying active but not doing anything after this point?

Have you checked the restore progress log?
And destination folder(s) where restore is written?

We often see that multiple media id's are requested because the entire big image was written across multiple tapes.

When tapes are listed, NBU only queries the header files that contains all media id's.
At this stage no fragment info is queried.

Only when the restore goes active does it query the relevant fragment and load the tape. 
Quite often the requested files are found on only one tape.

[Deepak_Irani1]

Hi Marianne,

Sorry for late response.

Yes. The restore is not moving after this. There is no data restored on to the destination. Th restore is at the same point after 2 days also. 

Below is the restore progress log.

05:29:37 7/15/2016: Restore Started

05:29:48 (107157.xxx) Media id BE1658 is needed for the restore.
05:29:48 (107157.xxx) Media id BE1331 is needed for the restore.
05:29:48 (107157.xxx) Media id BE1308 is needed for the restore.
05:29:48 (107157.xxx) Media id BE1667 is needed for the restore.
05:29:48 (107157.xxx) Media id BE1273 is needed for the restore.
05:29:48 (107157.xxx) Media id BE1513 is needed for the restore.
05:29:48 (107157.xxx) Media id BE1694 is needed for the restore.
05:29:48 (107157.xxx) Media id BE1673 is needed for the restore.

05:29:48 (107157.001) Restoring from copy 1 of image created 3/8/2016 3:07:11 PM
05:29:54 (107157.001) INF - If Media id BE1331 is not in a robotic library administrative interaction may be required to satisfy this mount request.
05:29:56 (107157.001) INF - Waiting for mount of media id BE1331 on server bbtsrvbrl5 for reading.
05:30:50 (107157.001) INF - Waiting for positioning of media id BE1331 on server bxxxxxxx for reading.
05:31:08 (107157.001) INF - Beginning restore from server bxxxxxxx to client byyyyyyy.

There us no progress after this point. 

[Marianne]

So - Acrivity Monitor reports successful restore (status 0) but the Job Progress does not show anything beyond "Beginning restore ..." ?

How much data are you restoring? Entire volume or selected files and/or folders? 
Is DAR enabled

According to AM the restore completed successfully within 1 second!

Have you enabled logging in your environment? 

Logs needed to trace process flow:

Master: bprd (restart NBU after creating the log)

Media: bptm and bpbrm (at level 3 minimum) and ndmpagent 

Please also share version info - NetBackup on master and media as well as Filer make/model and software version.
I have found similar old Connect posts related to 6.x versions...

[Deepak_Irani1]

Hi Marriane,

Yes. The restore progress logs are not moving after beginning restore.

I am not sure about the amount of data size. We are not restoring the entire volume. We are restoring a directory with sub directories and files inside of it. 

Yes, Per AM the restore is sown as completed within a sec. Logging is enabled in master server. However, all the below logs are not enabled.  We will enable the logs and provide once generated.

[Marianne]

Did you see this part of my previous post?

Please also share version info - NetBackup on master and media as well as Filer make/model and software version.
I have found similar old Connect posts related to 6.x versions...

[Deepak_Irani1 · Accepted solution]

Hi All,

We are now able to complete the restore.

The drive on which restore was attempted had issues. After drive replacement, Netbackup was able to restore the data on to NDMP filer. However, the restore was completed with 2813. Restore job is unable to get the final status.

We worked with Veritas as well for this issue who suggested to install below EEB. 

Etrack 3126218 

https://veritas.box.com/s/q3sxi27sjji6qvtn4oh533dojddnj8jt

We did not try installing above EEB as restore was completed already.