unexpected EOF on archive file while restoring

[Kasra_Hashemi]

Hi   I have just Started to Restore some files and I have put the required tapes in HP MSL Library , but after some hours I have encountered the below logs

   I am so sure that files are written to tapes but I am not able to restore them , If we assume that some files are corrupted , is there any way that I forcibly restore them ?

11:29:34 2/27/2018: Restore Started

11:29:35 (42267.xxx) Restore job id 42267 will require 1 image.
11:29:35 (42267.xxx) Media id Y560L5 is needed for the restore.
11:29:35 (42267.xxx) Media id Y597L5 is needed for the restore.
11:29:35 (42267.xxx) Media id Y598L5 is needed for the restore.

11:29:36 (42267.001) Restoring from copy 1 of image created 10/11/2017 2:00:02 PM from policy Bank_Files_Clone1
11:29:40 (42267.001) INF - If Media id Y560L5 is not in a robotic library administrative interaction may be required to satisfy this mount request.
11:29:40 (42267.001) INF - Waiting for mount of media id Y560L5 on server l-bck for reading.
11:30:52 (42267.001) INF - Waiting for positioning of media id Y560L5 on server l-bck for reading.
11:32:29 (42267.001) INF - Beginning restore from server l-bck to client srv1.lotus.ir.
11:32:31 (42267.001) /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_02.dmp
11:32:31 (42267.001) Changed /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_02.dmp to /backup_temp/archive/LTSLIVE_lotus_2017-10-11--000223_02.dmp
11:32:31 (42267.001) File /backup_temp/archive/LTSLIVE_lotus_2017-10-11--000223_02.dmp exists. Keeping it.
12:04:54 (42267.001) /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_01.dmp
12:04:54 (42267.001) Changed /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_01.dmp to /backup_temp/archive/LTSLIVE_lotus_2017-10-11--000223_01.dmp
12:04:54 (42267.001) File /backup_temp/archive/LTSLIVE_lotus_2017-10-11--000223_01.dmp exists. Keeping it.
12:37:11 (42267.001) INF - Waiting for positioning of media id Y560L5 on server l-bck for reading.
12:37:43 (42267.001) INF - Continuing restore from server l-bck to client srv1.lotus.ir.
12:37:44 (42267.001) /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_09.dmp
12:37:44 (42267.001) Changed /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_09.dmp to /backup_temp/archive/LTSLIVE_lotus_2017-10-11--000223_09.dmp
12:37:44 (42267.001) File /backup_temp/archive/LTSLIVE_lotus_2017-10-11--000223_09.dmp exists. Keeping it.
13:23:17 (42267.001) /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_08.dmp
13:23:17 (42267.001) Changed /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_08.dmp to /backup_temp/archive/LTSLIVE_lotus_2017-10-11--000223_08.dmp
13:23:17 (42267.001) File /backup_temp/archive/LTSLIVE_lotus_2017-10-11--000223_08.dmp exists. Keeping it.
15:42:12 (42267.001) INF - Waiting for positioning of media id Y560L5 on server l-bck for reading.
15:43:57 (42267.001) INF - Continuing restore from server l-bck to client srv1.lotus.ir.
15:43:58 (42267.001) /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_06.dmp
15:43:58 (42267.001) Changed /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_06.dmp to /backup_temp/archive/LTSLIVE_lotus_2017-10-11--000223_06.dmp
16:04:35 (42267.001) The following files/folders were not restored:
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_06.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_03.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_07.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_16.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_04.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_05.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_11.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_10.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--030000_struct.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_15.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_12.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_14.dmp
16:04:35 (42267.001) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_13.dmp
16:04:35 (42267.001) Unexpected EOF on archive file
16:04:35 (42267.001) attr_set failed for /backup_temp/archive/LTSLIVE_lotus_2017-10-11--000223_06.dmp - Attribute system.nfs4_acl not set. Errno = 95: Operation not supported
16:04:35 (42267.001) INF - TAR EXITING WITH STATUS = 0
16:04:35 (42267.001) INF - TAR RESTORED 0 OF 5 FILES SUCCESSFULLY
16:04:35 (42267.001) INF - TAR KEPT 4 EXISTING FILES
16:04:35 (42267.001) INF - TAR PARTIALLY RESTORED 0 FILES

16:04:36 (42267.001) Status of restore from copy 1 of image created 10/11/2017 2:00:02 PM = media read error

16:04:37 (42267.xxx) INF - Status = Restore error.

[Kasra_Hashemi]

Hi Everybody ,

    This is another Log that I got  :

/27/2018 11:29:45 AM - Info bpbrm(pid=2292) start tar32 on client         
2/27/2018 11:29:46 AM - Info tar32(pid=76881) Restore started.           
2/27/2018 11:29:46 AM - connected; connect time: 0:00:03
2/27/2018 11:30:52 AM - mounted; mount time: 0:01:12
2/27/2018 11:30:52 AM - Info bptm(pid=7740) Y560L5            
2/27/2018 11:30:52 AM - Info bptm(pid=7740) INF - Waiting for positioning of media id Y560L5 on server l-bck for reading.
2/27/2018 11:30:52 AM - positioning Y560L5 to file 63
2/27/2018 11:32:29 AM - positioned Y560L5; position time: 0:01:37
2/27/2018 11:32:29 AM - begin reading
2/27/2018 4:04:35 PM - Error bptm(pid=7740) cannot read image from media id Y560L5, drive index 5, err = 23
2/27/2018 4:04:35 PM - Warning bptm(pid=7740) TapeAlert Code: 0x01, Type: Warning, Flag: READ WARNING, from drive HP.ULTRIUM5-SCSI.003 (index 5), Media Id Y560L5
2/27/2018 4:04:35 PM - Error bptm(pid=3416) The following files/folders were not restored:       
2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_06.dmp          
2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_03.dmp          
2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_07.dmp          
2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_16.dmp          
2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_04.dmp          
2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_05.dmp          
2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_11.dmp          
2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_10.dmp          
2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--030000_struct.dmp          
2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_15.dmp          
2/27/2018 4:04:35 PM - Error bptm(pid=3416) more than 10 files were not restored, remaining ones are shown in the progress log.
2/27/2018 4:04:35 PM - Info tar32(pid=76881) done. status: 0          
2/27/2018 4:04:35 PM - Info tar32(pid=76881) done. status: 5 - the restore failed to recover the requested files
2/27/2018 4:04:35 PM - Info bpbrm(pid=8136) child done, status 5         
2/27/2018 4:04:35 PM - Info bpbrm(pid=8136) sending message to media manager: STOP RESTORE srv1.lotus.ir_1507717802     
2/27/2018 4:04:36 PM - Info bpbrm(pid=8136) got ERROR 85 from media manager       
2/27/2018 4:04:36 PM - restored image srv1.lotus.ir_1507717802 - (media read error(85)); restore time 4:35:00
2/27/2018 4:04:37 PM - Warning bprd(pid=9224) Restore must be resumed prior to first image expiration on INFINITY      
2/27/2018 4:04:37 PM - end Restore; elapsed time: 4:35:03
Restore error (2850)

[Mouse · Accepted solution]

Tape Alert code 0x01 as per http://www.veritas.com/docs/100000622:

0x01: 'Having problems reading (slowing down)', 0x01: 'Having problems reading (slowing down)', 

So you have a physical problem with this tape. Try to clean the drive, but there is a chance the tape is gone.

[Marianne · Accepted solution]

I agree. The problem is with tape Y560L5.
Hopefully you have another copy?

[Kasra_Hashemi]

Dear @Marianne

   No I dont have any other copy . this is the only backup I have .

[Marianne]

My suggestion:

Increase bptm logging to 5 and add VERBOSE to vm.conf followed by restart of NBU Device Manager.

Next, try to run a Verify on this tape. 

Look for additional info in bptm log when 0x01 TapeAlert is seen, as well as Event Viewer System and Application log.

[Mike_Gavrilov]

1) Log says that bpbrm started tar32:

/27/2018 11:29:45 AM - Info bpbrm(pid=2292) start tar32 on client   

but only windows clients use tar32. After that we can see messages:

2/27/2018 4:04:35 PM - Error bptm(pid=3416) UTF - /media/dumps/LTSLIVE/LTSLIVE_lotus_2017-10-11--000223_06.dmp   

Did you try to restore UNIX/Linux data to a Windows client?

2) Can you mount the tape outside NBU and try to read it from the beginning  using dd (or something like it) to be sure that it's physically readable? 

[Kasra_Hashemi]

Hello ,

    unfortunately none of these solutions helped me .