Video Screencast Help

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...