cancel
Showing results for 
Search instead for 
Did you mean: 

Restore specific files/folders from Netbackup Tape

Salmanbutt24
Level 3

My scenario is as follow

1. Recieved a media tape which was backed up through NetBackup 6.0

2. I need to restore any single file to verify the backup on that tape. I have NB 6.5 and as I searched online and found that. First configure media volume than select initiate import from catalog, after its completion search on catalog with import option and click on import with selecting the image. Both jobs completed successfully but unable to restore any single file from this image. I am using Backup, Archive and Restore - Netbackup and every time I select for restore it gave me error that

"WARNNING: server does not contain any backups for client using the specified policy type as requested by client"

We have same machine for server and client. any help much appriciated...

1 ACCEPTED SOLUTION

Accepted Solutions

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

'AccountingToTape' is probably the policy name, right?

To find the Policy Type, navigate to the images folder as per TN http://www.symantec.com/business/support/index?page=content&id=TECH59297

Find the client name for which images were imported (PLEASE NOTE correct spelling of client name). Open 10-digit sub-directory (if there's more than one, open the newest one).

Here you will find image files with their header files. Header files have no extention, in this format: <policy-name>_<10-digit-number>_<sched-type>

e.g FileSystemBackups_1285351605_FULL

Open this file with Notepad.

Look for CLIENT_TYPE in this file (about line number 9)

In my header file, the line looks like this:

CLIENT_TYPE 13

This CLIENT_TYPE is actually the Policy Type. A few examples of Policy Type numbers:

0 = Standard
4 = Oracle
6 = Informix-On-BAR
7 = Sybase
10 = NetWare
13 = MS-Windows
14 = OS/2
15 = MS-SQL-Server
16 = MS-Exchange-Server
19 = NDMP

Once you have found the policy type in the header file, try to browse again. Use the two TN posted by Suryakiran21 as guidelines to specify search criteria in BAR GUI.

View solution in original post

19 REPLIES 19

J_H_Is_gone
Level 6

In the BAR when you choose your From server and your destation server, below that is policy type.

That has to match the same policy type that was used to make the backup tape to start with (on your 6.0 master)

Salmanbutt24
Level 3

Yes. I can see that policy type in administration console with Tape. But during restore I am not seeing it anywhere. Is their any method to import/export policy type from tape to Netbackup 6.5 policy type options?

J_H_Is_gone
Level 6

When you open the BAR (here I am assuming windows) there is a field at the bottom where you say what policy type.  ( the types will be the same if it was 6.0 or 6.5)

So you need to choose the correct type ( try them all if you have to)

If it was a windows server that was backed up the it should be the  MS-windows-NT

if it was a unix server it would be standard.  Just choose the correct type. 

It is the last pull down  'Policy type for restores"

J_H_Is_gone
Level 6

Go to Reports

Tape Reports

Images on Tape

just put in your tape number and run report.

Make sure your screen has the column to show Policy type.

Salmanbutt24
Level 3

Yes it is the Windows. Policy type on Backup IDs on tape is 'AccountingToTape'. When I open Backup, Archive and Restore - Netbackup > Specify Netbackup Machines and Policy Types > Policy type for restores > AFS:
Apollo-wbak:
Auspex-FastBackup:
CMD-Database:
DataStore:      Tried
DataTools-SQL-BackTrack:
DB2: FlashBackup:
FlashBackup-Windows:   Tried
Informix-On-BAR:
Lotus-Notes:
MS-Exchange-Server:
MS-SharePoint:
MS-Windows-NT:    Tried
NBU-Catalog:    Tried
NCR-TeradataL
NDMPL
NetWare:
Oracle:
OS/2:
PureDisk-Export:    Tried
SAP:
Split-Mirror:
Standard:    Tried
Sybase:
Vault

only above i can see and some of them i tried already but there is no 'AccountingToTape' policy. The tape is also backed up by windows.

J_H_Is_gone
Level 6

More then liketly that is your policy name not type.

use the Report I showed above to find out the policy type.

Salmanbutt24
Level 3

Got it. Policy type is MS-Windows-NT. But still no success in restore with selecting that type...

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

'AccountingToTape' is probably the policy name, right?

To find the Policy Type, navigate to the images folder as per TN http://www.symantec.com/business/support/index?page=content&id=TECH59297

Find the client name for which images were imported (PLEASE NOTE correct spelling of client name). Open 10-digit sub-directory (if there's more than one, open the newest one).

Here you will find image files with their header files. Header files have no extention, in this format: <policy-name>_<10-digit-number>_<sched-type>

e.g FileSystemBackups_1285351605_FULL

Open this file with Notepad.

Look for CLIENT_TYPE in this file (about line number 9)

In my header file, the line looks like this:

CLIENT_TYPE 13

This CLIENT_TYPE is actually the Policy Type. A few examples of Policy Type numbers:

0 = Standard
4 = Oracle
6 = Informix-On-BAR
7 = Sybase
10 = NetWare
13 = MS-Windows
14 = OS/2
15 = MS-SQL-Server
16 = MS-Exchange-Server
19 = NDMP

Once you have found the policy type in the header file, try to browse again. Use the two TN posted by Suryakiran21 as guidelines to specify search criteria in BAR GUI.

Salmanbutt24
Level 3

Yes that was policy name. After checking of exact client name and putting the all .... right. Its worked :) Thanks all

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

I missed JH's post - the report is a LOT safer and easier.

In Windows GUI, the Images on Tape does not by default display the Policy Type.

Go to View -> Columns -> Layout

Select Policy Type, then click the Display icon at the top:

 

Salmanbutt24
Level 3

yes thats also helps, but i have to add client name of same name as on image from the tape. After thats its showing the content in the tape but now I am not able to restore from the file. I was searching for solution from different articles and almost 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.

J_H_Is_gone
Level 6

A read of a file or socket failed.
The possible causes include as follows:
* A network communication problem has occurred on the master server, media server, or one of the clients.
* An I/O error that occurred during a read from the file system.
* Read of an incomplete file or a corrupt file.
* A socket read failure that is caused by a network problem or a problem with the process that writes to the socket.
* A problem specific to NetBackup Snapshot Client (see recommended actions).
* The first EV-SQL backup after a NetBackup installation failed.
See the Troubleshooting section of the NetBackup for Enterprise Vault Agent Administrator's Guide.

 

If you can do backups and restores to the destination server ok with your other tapes.  Then I would lean towards bad tape.

Salmanbutt24
Level 3

Ok. Media Master and client is same machine and aldo did checked with different tapes and different files everytime same error appears. and we dont have robotic library its a standalone HP ultrium 1840 box with windows machine. Since I am a new with NBU so i need some more information regarding snapshot, socket and EV-SQL stuff...

regarding I/O error following log was generated but its only a information

Event Type: Information
Event Source: NetBackup Tape Manager
Event Category: None
Event ID: 5122
Date:  10/1/2010
Time:  3:28:48 PM
User:  N/A
Computer: MIRACLE-MAIN
Description:
DeviceIoControl() error on bus 0, target 0, lun 0 (1117:The request could not be performed because of an I/O device error. )


 

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

Hopefully you have a bptm log? It might contain more info about the I/O error and the 'tar file read error'.
 

Salmanbutt24
Level 3

i have some logs folders in C:\Program Files\VERITAS\NetBackup\logs but where can i find bptm logs?

Salmanbutt24
Level 3

ok, after some google find about how to enable bptm logs. here are the results after restore job failed again, hopefully that will helps

19:25:17.984 [5460.1808] <2> bptm: INITIATING (VERBOSE = 0): -rptdrv -jobid -1285975505 -jm
19:25:18.000 [5460.1808] <2> main: Sending [EXIT STATUS 0] to NBJM
19:25:18.000 [5460.1808] <2> bptm: EXITING with status 0 <----------
19:26:19.078 [4388.2600] <2> bptm: INITIATING (VERBOSE = 0): -delete_expired
19:26:19.093 [4388.2600] <2> bptm: EXITING with status 0 <----------
19:26:19.484 [4292.3212] <2> bptm: INITIATING (VERBOSE = 0): -delete_all_expired
19:26:19.484 [4292.3212] <4> bptm: emmserver_name = miracle-main
19:26:19.484 [4292.3212] <4> bptm: emmserver_port = 1556
19:26:19.515 [4292.3212] <2> Orb::init: initializing ORB Default_CLIENT_Orb with: dbstunitq -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory ''" -ORBSvcConfDirective "static EndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb Default_CLIENT_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul(Orb.cpp:691)
19:26:19.609 [4292.3212] <2> bptm: EXITING with status 0 <----------
19:26:43.078 [4620.1548] <2> bptm: INITIATING (VERBOSE = 0): -pid 2324 -mpx_restore -S miracle-main -mud 180
19:26:43.109 [4620.1548] <4> bptm: emmserver_name = miracle-main
19:26:43.109 [4620.1548] <4> bptm: emmserver_port = 1556
19:26:43.140 [4620.1548] <2> Orb::init: initializing ORB Default_CLIENT_Orb with: dbstunitq -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory ''" -ORBSvcConfDirective "static EndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb Default_CLIENT_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul(Orb.cpp:691)
19:26:43.203 [4620.1548] <2> send_brm_msg: PID of bpxm = 4620
19:26:43.250 [4620.1548] <2> process_mpx_protocol: wait for initial START RESTORE message from bpbrm
19:26:44.281 [4620.1548] <2> read_brm_msg: START RESTORE -b nystoragesrvr_1278018376 -bt 1278018376 -c miracle-main -cl AllToTape -st 0 -ct 13 -firstblk 1 -flport 0 -flipc 4072 -restoreid 63.001 -cn 1 -hostname miracle-main -rclnt nystoragesrvr -rclnthostname nystoragesrvr -Z -L /C/ProgramFiles/Veritas/NetBackup/logs/user_ops/Miracle/logs/NBWIN024 -ru root -lcmsg en -lctime en -no_callback -connect_options 0x01010100 -jobid 63 -shm
19:26:44.406 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
19:26:44.406 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpdbm
19:26:44.406 [4620.1548] <2> logconnections: BPDBM CONNECT FROM 192.168.1.141.4113 TO 192.168.1.141.13724
19:26:44.875 [4620.1548] <2> mpx_read_init: image is not multiplexed
19:26:44.875 [4620.1548] <2> mpx_read_init: media id B00500, copy 1, fragment 1 (24174784 Kbytes) filenum 1 being considered for restore
19:26:44.875 [4620.1548] <2> mpx_compute_skip_info: will skip to block 0 of fragment 1 to start restore, remain = 1, bytes_to_skip = 512
19:26:44.921 [4620.1548] <2> mpx_compute_skip_info: changed Kbytes_left to 24174784
19:26:44.937 [4620.1548] <2> mpx_read_init: filenumber for new restore is 1, Mpx_Filenum is -1
19:26:44.937 [4620.1548] <2> mpx_setup_restore_shm: using 30 data buffers, buffer size is 65536
19:26:44.953 [4620.1548] <2> mpx_setup_restore_shm: child delay = 10, parent delay = 15 (milliseconds)
19:26:44.953 [4620.1548] <2> mpx_setup_restore_shm: shm_size = 1968600, buffer address = 0x1870000, buf control = 0x1a50000, ready ptr = 0x1a502d0, res_cntl = 0x1a502d8
19:26:45.000 [4620.1548] <2> setup_tar_info: Min_records before frag switch is 90000, locate available = 1
19:26:45.000 [4620.1548] <2> setup_tar_info: Global\NetBackup Media Manager SHM Info Path 63.001 file successfully created
19:26:45.312 [4620.1548] <2> LOCAL CLASS_ATT_DEFS: Product ID = 6
19:26:45.406 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
19:26:45.406 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpcd
19:26:45.421 [4620.1548] <2> logconnections: BPCD CONNECT FROM 192.168.1.141.4125 TO 192.168.1.141.13724
19:26:45.421 [4620.1548] <2> vnet_connect_to_vnetd_extra: vnet_vnetd.c.179: msg: VNETD CONNECT FROM 192.168.1.141.4126 TO 192.168.1.141.13724 fd = 1548
19:26:45.562 [4620.1548] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.532: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a
19:26:45.562 [4620.1548] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.549: ipc_string: 4127
19:26:45.625 [4620.1548] <2> nbjm_media_request: Passing job control to NBJM, type READ
19:26:46.093 [4620.1548] <2> Orb::init: Created anon service name: NB_4620_376743533221(Orb.cpp:599)
19:26:46.093 [4620.1548] <2> Orb::init: endpointvalue is : pbxiop://1556:NB_4620_376743533221(Orb.cpp:617)
19:26:46.093 [4620.1548] <2> Orb::init: initializing ORB Default_DAEMON_Orb with: Unknown -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory ''" -ORBSvcConfDirective "static EndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb Default_DAEMON_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBEndpoint pbxiop://1556:NB_4620_376743533221 -ORBSvcConf nul(Orb.cpp:691)
19:26:49.062 [4620.1548] <2> Media_signal_poll: Read bpbrm message (MultiResReq.cpp:2142)
19:26:49.062 [4620.1548] <2> process_brm_msg: no pending message from bpbrm
19:26:49.062 [4620.1548] <2> RequestInitialResources: returning
19:26:49.062 [4620.1548] <2> parse_resource_strings: MEDIADB 1 41 B00500 4000010 ------ 20 1278018376 0 1286495417 1285961328 501861445 26 26 0 2 3 2176 1024 0 0 0
19:26:49.062 [4620.1548] <2> parse_resource_strings: Parsed message type 15, version 1, 21 parameters
19:26:49.078 [4620.1548] <2> parse_resource_strings: VOLUME 1 B00500 4000010 -------- DataStore *NULL* *NULL* 24 0 0 0 0 {00000000-0000-0000-0000-000000000000} 0
19:26:49.078 [4620.1548] <2> parse_resource_strings: Parsed message type 16, version 1, 14 parameters
19:26:49.078 [4620.1548] <2> parse_resource_strings: DRIVE 3 HP.ULTRIUM4-SCSI.000 2000002 HU19054U7L {2,0,3,0} -1 -1 -1 -1 -1 -1 -1 -1 *NULL* *NULL* *NULL* *NULL* 1 17 0 1 0 0
19:26:49.078 [4620.1548] <2> parse_resource_strings: Parsed message type 17, version 3, 23 parameters
19:26:49.078 [4620.1548] <2> parse_resource_strings: STORAGE 1 *NULL* 0 0 0 0 0 0 miracle-main miracle-main *NULL*
19:26:49.078 [4620.1548] <2> parse_resource_strings: Parsed message type 18, version 1, 11 parameters
19:26:49.078 [4620.1548] <2> parse_resource_strings: DISKGROUP 0 6 *NULL* 6 *NULL* 6 *NULL*
19:26:49.078 [4620.1548] <2> parse_resource_strings: Parsed message type 21, version 0, 7 parameters
19:26:49.078 [4620.1548] <2> parse_resource_strings: DISKVOLUME 0 6 *NULL* 6 *NULL* 0
19:26:49.078 [4620.1548] <2> parse_resource_strings: Parsed message type 22, version 0, 6 parameters
19:26:49.078 [4620.1548] <2> parse_resource_strings: DISKMOUNTPOINT 0 6 *NULL*
19:26:49.078 [4620.1548] <2> parse_resource_strings: Parsed message type 23, version 0, 3 parameters
19:26:49.078 [4620.1548] <2> parse_resource_strings: FTRANS 0 0 12 miracle-main 6 *NULL* 0 0 0
19:26:49.078 [4620.1548] <2> parse_resource_strings: Parsed message type 24, version 0, 1 parameters
19:26:49.078 [4620.1548] <2> nbjm_media_request: Job control returned to BPTM
19:26:49.156 [4620.1548] <2> drivename_open: Called with Create 1, file HP.ULTRIUM4-SCSI.000
19:26:49.171 [4620.1548] <2> drivename_checklock: Called
19:26:49.171 [4620.1548] <2> drivename_lock: lock established
19:26:49.171 [4620.1548] <2> drivename_write: Called with mode 0
19:26:49.171 [4620.1548] <2> drivename_unlock: unlocked
19:26:49.171 [4620.1548] <2> drivename_checklock: Called
19:26:49.171 [4620.1548] <2> drivename_lock: lock established
19:26:49.171 [4620.1548] <2> mount_open_media: Waiting for mount of media id B00500 (copy 1) on server miracle-main.
19:26:49.203 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
19:26:49.203 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpjobd
19:26:49.203 [4620.1548] <2> logconnections: BPJOBD CONNECT FROM 192.168.1.141.4136 TO 192.168.1.141.13724
19:26:49.218 [4620.1548] <2> job_authenticate_connection: ignoring VxSS authentication check for now...
19:26:49.218 [4620.1548] <2> job_connect: Connected to the host miracle-main contype 10 jobid <63> socket <1420>
19:26:49.218 [4620.1548] <2> job_connect: Connected on port 4136
19:26:49.296 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
19:26:49.296 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpcd
19:26:49.312 [4620.1548] <2> logconnections: BPCD CONNECT FROM 192.168.1.141.4138 TO 192.168.1.141.13724
19:26:49.312 [4620.1548] <2> vnet_connect_to_vnetd_extra: vnet_vnetd.c.179: msg: VNETD CONNECT FROM 192.168.1.141.4139 TO 192.168.1.141.13724 fd = 1380
19:26:49.406 [4620.1548] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.532: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a
19:26:49.406 [4620.1548] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.549: ipc_string: 4140
19:26:49.484 [4620.1548] <2> openNTDevice: config_path: {2,0,3,0}, serial_num: HU19054U7L
19:26:49.484 [4620.1548] <2> get_drive_path: SCSI coordinates {2,0,3,0}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_hp&prod_ultrium_4-scsi&rev_b56d#5&37282b4d&0&030#{53f5630b-b6bf-11d0-94f2-00...}
19:26:49.484 [4620.1548] <2> check_serial_num: serial number match for drive with SCSI coordinates {2,0,3,0}, dos_path \\.\Tape0, drive serial number HU19054U7L, expected serial number HU19054U7L
19:26:49.500 [4620.1548] <2> manage_scsi_reserve: SCSI RESERVE
19:26:50.500 [4620.1548] <2> tapelib: wait_for_ltid, Mount, timeout 0
19:26:52.031 [4620.1548] <2> openTpreqFile: tpreq_file: C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, serial_num: HU19054U7L
19:26:52.046 [4620.1548] <2> get_drive_path: SCSI coordinates {2,0,3,0}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_hp&prod_ultrium_4-scsi&rev_b56d#5&37282b4d&0&030#{53f5630b-b6bf-11d0-94f2-00...}
19:26:52.046 [4620.1548] <2> check_serial_num: serial number match for drive with SCSI coordinates {2,0,3,0}, dos_path \\.\Tape0, drive serial number HU19054U7L, expected serial number HU19054U7L
19:26:52.046 [4620.1548] <2> init_tape: \\.\Tape0 (SCSI coordinates {2,0,3,0}) configured with blocksize 0
19:26:52.046 [4620.1548] <2> init_tape: \\.\Tape0 (SCSI coordinates {2,0,3,0}) has compression enabled
19:26:52.046 [4620.1548] <2> io_open: SCSI RESERVE (C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000)
19:26:52.093 [4620.1548] <2> io_open: report_attr, fl1 0x00000439, fl2 0x00000004
19:26:52.093 [4620.1548] <2> io_open: WORM media is loaded
19:26:52.093 [4620.1548] <2> io_open: Reported medium manufacturer [SONY], sn [F100129341]
19:26:52.093 [4620.1548] <2> openTpreqFile: tpreq_file: C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, serial_num: HU19054U7L
19:26:52.093 [4620.1548] <2> get_drive_path: SCSI coordinates {2,0,3,0}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_hp&prod_ultrium_4-scsi&rev_b56d#5&37282b4d&0&030#{53f5630b-b6bf-11d0-94f2-00...}
19:26:52.093 [4620.1548] <2> check_serial_num: serial number match for drive with SCSI coordinates {2,0,3,0}, dos_path \\.\Tape0, drive serial number HU19054U7L, expected serial number HU19054U7L
19:26:52.109 [4620.1548] <2> init_tape: \\.\Tape0 (SCSI coordinates {2,0,3,0}) configured with blocksize 0
19:26:52.109 [4620.1548] <2> io_open: file C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000 successfully opened (mode 0)
19:26:52.109 [4620.1548] <2> io_read_media_header: drive index 0, reading media header, buflen = 65536, buff = 0xe52550, copy 1
19:26:52.109 [4620.1548] <2> io_ioctl: command (5)MTREW 1 from (bptm.c.8039) on drive index 0
19:26:52.140 [4620.1548] <2> io_ioctl: command (1)MTFSF 1 from (bptm.c.8296) on drive index 0
19:26:52.156 [4620.1548] <2> bptm media_id_to_monitor: job_id = 63
19:26:52.156 [4620.1548] <2> bptm media_id_to_monitor: pSrcMediaId = B00500
19:26:52.156 [4620.1548] <2> read_backup_mount_media: media id B00500 mounted on drive index 0
19:26:52.156 [4620.1548] <2> send_MDS_msg: MEDIADB 1 41 B00500 4000010 *NULL* 20 1278018376 0 1286495417 1285975612 501861445 26 26 0 2 4 2176 1024 0 0 0
19:26:52.281 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
19:26:52.296 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpcd
19:26:52.296 [4620.1548] <2> logconnections: BPCD CONNECT FROM 192.168.1.141.4143 TO 192.168.1.141.13724
19:26:52.296 [4620.1548] <2> vnet_connect_to_vnetd_extra: vnet_vnetd.c.179: msg: VNETD CONNECT FROM 192.168.1.141.4144 TO 192.168.1.141.13724 fd = 1376
19:26:52.375 [4620.1548] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.532: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a
19:26:52.390 [4620.1548] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.549: ipc_string: 4145
19:26:52.468 [4620.1548] <2> io_position_for_read: positioning B00500 to file number 1
19:26:52.468 [4620.1548] <2> io_read_back_header: drive index 0, reading backup header
19:26:52.468 [4620.1548] <2> io_position_for_read: successfully positioned B00500 to file number 1
19:26:52.515 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
19:26:52.515 [4620.1548] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpcd
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
19:26:56.046 [4620.1548] <2> openTpreqFile: tpreq_file: C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, serial_num: HU19054U7L
19:26:56.046 [4620.1548] <2> get_drive_path: SCSI coordinates {2,0,3,0}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_hp&prod_ultrium_4-scsi&rev_b56d#5&37282b4d&0&030#{53f5630b-b6bf-11d0-94f2-00...}
19:26:56.046 [4620.1548] <2> check_serial_num: serial number match for drive with SCSI coordinates {2,0,3,0}, dos_path \\.\Tape0, drive serial number HU19054U7L, expected serial number HU19054U7L
19:26:56.062 [4620.1548] <2> init_tape: \\.\Tape0 (SCSI coordinates {2,0,3,0}) configured with blocksize 0
19:26:56.062 [4620.1548] <2> init_tape: \\.\Tape0 (SCSI coordinates {2,0,3,0}) has compression enabled
19:26:56.062 [4620.1548] <2> io_open: SCSI RESERVE
19:26:56.062 [4620.1548] <2> io_open: file C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000 successfully opened (mode 2)
19:26:56.062 [4620.1548] <2> process_tapealert: TapeAlert returned 0x00000000 0x00000000 (from tpunmount)
19:26:56.062 [4620.1548] <2> io_close: closing C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, from bptm.c.17622
19:26:56.062 [4620.1548] <2> drivename_write: Called with mode 1
19:26:56.062 [4620.1548] <2> drivename_unlock: unlocked
19:26:56.062 [4620.1548] <2> drivename_checklock: Called
19:26:56.062 [4620.1548] <2> drivename_lock: lock established
19:26:56.062 [4620.1548] <2> drivename_unlock: unlocked
19:26:56.062 [4620.1548] <2> drivename_close: Called for file HP.ULTRIUM4-SCSI.000
19:26:56.078 [4620.1548] <2> tpunmount: NOP: MEDIA_DONE 0 0 0 B00500 4000010 180 {EBABF4B0-F284-4ACB-A5C3-C00D404C30EB}
19:26:56.078 [4620.1548] <2> db_error_add_to_file: dberrorq.c:midnite = 1285905600
19:26:56.078 [4620.1548] <4> mpx_read_backup: successfully restored 0 of 1 requests, read total of 1920 Kbytes at 2452.107 Kbytes/sec
19:26:56.078 [4620.1548] <2> job_monitoring_exex: ACK disconnect
19:26:56.078 [4620.1548] <2> job_disconnect: Disconnected
19:26:56.078 [4620.1548] <2> bptm: Calling tpunmount for media B00500
19:26:56.078 [4620.1548] <2> send_MDS_msg: MEDIA_DONE 0 63 0 B00500 4000010 180 {EBABF4B0-F284-4ACB-A5C3-C00D404C30EB}
19:26:56.078 [4620.1548] <16> packageBptmResourceDoneMsg: msg (MEDIA_DONE 0 63 0 B00500 4000010 180 {EBABF4B0-F284-4ACB-A5C3-C00D404C30EB})
19:26:56.078 [4620.1548] <16> packageBptmResourceDoneMsg: keyword MEDIA_DONE version 0 jobid 63 copyNum 0 mediaId B00500 mediaKey 4000010 unloadDelay 180 allocId {EBABF4B0-F284-4ACB-A5C3-C00D404C30EB}
19:26:56.078 [4620.1548] <16> packageBptmResourceDoneMsg: returns 0
19:26:56.125 [4620.1548] <2> JobInst::sendIrmMsg: returning
19:26:56.125 [4620.1548] <2> bptm: EXITING with status 0 <----------
 

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

In all honesty, the errors that you experience while doing the restore should have been a new thread, since your original query was solved...

Is media id B00500 the same tape that you've imported at the beginning of the thread?

The problem that I see in bptm log is that the tape is positioned, it starts reading, but then the requested image cannot be found:

19:26:55.031 [4620.1548] <2> process_brm_msg: could not find backupid nystoragesrvr_1278018376 to terminate

 

Please run a Verify on the tape - either through the GUI (Images -> Verify) or from cmd (bpverify).

Please ensure that you have bpbrm log before doing the verify. If you already have bpbrm log, please post section of log around 19:26 when 'file read error' was experienced.

Salmanbutt24
Level 3

Yes! you are correct. I have opened a new question at https://www-secure.symantec.com/connect/forums/restore-tape-fails-tar-read-error-backup-exec-65 will update after verifying the tape image.