Video Screencast Help
Give us your opinion and win with Symantec! Please help us by taking this survey to tell us about your experience with Symantec Connect, so that we can continue to grow and improve.  Take the survey.

Restore from tape fails with 'TAR Read Error' in Backup Exec 6.5

Created: 04 Oct 2010 | 4 comments

I am not able to restore from the tape. I was searching for solution and checked most of the settings and thats seems fine here are the failed log details.

15:28:26 10/1/2010: Restore Started

15:28:28 (62.xxx) Restore job id 62 will require 1 image.
15:28:28 (62.xxx) Media id B00500 is needed for the restore.
15:28:41 (62.001) Restoring from image created 7/2/2010 1:36:06 PM
15:28:43 (62.001) INF - If Media id B00500 is not in a robotic library administrative interaction may be required to satisfy this mount request.
15:28:46 (62.001) INF - Waiting for mount of media id B00500 on server miracle-main for reading.
15:28:47 (62.001) INF - TAR STARTED
15:28:48 (62.001) INF - Waiting for positioning of media id B00500 on server miracle-main for reading.
15:30:52 (62.001) INF - Beginning restore from server miracle-main to client miracle-main.
15:30:53 (62.001) FTL - tar file read error
15:30:53 (62.001) INF - TAR EXITING WITH STATUS = 13
15:30:53 (62.001) INF - TAR RESTORED 0 OF 1 FILES SUCCESSFULLY
15:30:53 (62.001) INF - TAR KEPT 0 EXISTING FILES
15:30:53 (62.001) INF - TAR PARTIALLY RESTORED 0 FILES
15:30:53 (62.001) Status of restore from image created 7/2/2010 1:36:06 PM = file read failed
15:30:54 (62.xxx) INF - Status = the restore failed to recover the requested files.

Comments 4 CommentsJump to latest comment

Salmanbutt24's picture

Here are the bptm logs when image was not find.

19:26:52.515 [4620.1548] <2> logconnections: BPCD CONNECT FROM 192.168.1.141.4148 TO 192.168.1.141.13724
19:26:52.515 [4620.1548] <2> vnet_connect_to_vnetd_extra: vnet_vnetd.c.179: msg: VNETD CONNECT FROM 192.168.1.141.4149 TO 192.168.1.141.13724 fd = 1384
19:26:52.625 [4620.1548] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.532: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a
19:26:52.625 [4620.1548] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.549: ipc_string: 4150
19:26:52.671 [4620.1548] <2> db_error_add_to_file: dberrorq.c:midnite = 1285905600
19:26:52.687 [4620.1548] <4> mpx_issue_begin_msg: begin reading backup id nystoragesrvr_1278018376 (restore), copy 1, fragment 1 from media id B00500 on drive index 0
19:26:52.687 [4620.1548] <2> send_brm_msg: CURRENT POSITION B00500 1
19:26:52.687 [4620.1548] <2> process_brm_msg: no pending message from bpbrm
19:26:53.687 [4620.1548] <2> read_brm_msg: CONTINUE RESTORE
19:26:53.687 [4620.1548] <2> send_brm_msg: MEDIA READY
19:26:53.718 [4620.1548] <2> mpx_read_data: begin reading data from media id B00500, file num 1
19:26:53.718 [4620.1548] <2> get_tape_position_for_read: absolute block position prior to reading is 3
19:26:54.500 [4620.1548] <2> mpx_check_children: received exit status 13 from tar
19:26:54.500 [4620.1548] <2> notify: executing - C:\Program Files\Veritas\NetBackup\bin\restore_notify.cmd bptm nystoragesrvr_1278018376 restore
19:26:55.031 [4620.1548] <2> send_brm_msg: MEDIA NOT READY
19:26:55.031 [4620.1548] <2> send_brm_msg: EXIT nystoragesrvr_1278018376 13
19:26:55.031 [4620.1548] <2> bct_clear_active: Set BCTable entry 0 to inactive, ACTIVE_GC count decremented to 0
19:26:55.031 [4620.1548] <2> mpx_read_data: waited for empty buffer 1 times, delayed 33 times
19:26:55.031 [4620.1548] <2> io_close: closing C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, from mpxrestore.c.2679
19:26:55.031 [4620.1548] <2> mpx_waiting_term: waiting for TERMINATE or another START RESTORE
19:26:55.031 [4620.1548] <2> read_brm_msg: STOP RESTORE nystoragesrvr_1278018376
19:26:55.031 [4620.1548] <2> process_brm_msg: could not find backupid nystoragesrvr_1278018376 to terminate
19:26:56.046 [4620.1548] <2> mpx_check_msg_pending: could not open msg pending event, The system cannot find the file specified.
19:26:56.046 [4620.1548] <2> read_brm_msg: TERMINATE
 

Salmanbutt24's picture

Just got the catalog verification completed here are the results

10/4/2010 4:42:41 PM - end reading; read time: 00:20:43
10/4/2010 4:42:41 PM - positioning B00500 to file 5
10/4/2010 4:42:41 PM - positioned B00500; position time: 00:00:00
10/4/2010 4:42:41 PM - begin reading
10/4/2010 4:53:36 PM - end reading; read time: 00:10:55
10/4/2010 4:53:37 PM - positioning B00500 to file 6
10/4/2010 4:53:37 PM - positioned B00500; position time: 00:00:00
10/4/2010 4:53:37 PM - begin reading
10/4/2010 5:19:38 PM - end reading; read time: 00:26:01
10/4/2010 5:19:38 PM - positioning B00500 to file 7
10/4/2010 5:19:38 PM - positioned B00500; position time: 00:00:00
10/4/2010 5:19:38 PM - begin reading
10/4/2010 5:21:01 PM - end reading; read time: 00:01:23
10/4/2010 5:21:02 PM - positioning B00500 to file 8
10/4/2010 5:21:02 PM - positioned B00500; position time: 00:00:00
10/4/2010 5:21:02 PM - begin reading
10/4/2010 5:22:07 PM - end reading; read time: 00:01:05
10/4/2010 5:22:12 PM - Warning bptm(pid=4260) TapeAlert Code: 0x32, Type: Warning, Flag: LOST STATISTICS, from drive HP.ULTRIUM4-SCSI.000 (index 0), Media Id B00500
10/4/2010 5:22:14 PM - end Verify; elapsed time: 01:43:29
the requested operation was successfully completed(0)

Zak Meekins 2's picture

Is the DAR option turned on? I have had similiar issues with DAR, turned it off and the restore worked fine.

Salmanbutt24's picture

yes it was enabled, but restore didnt work either after we set it disable...