Any assistance greatly appreciated. Thank you all in advance!
Master is Windows 2003 SP2, NBU v6.5.4
Media Server1 is Windows 2003 SP2, NBU v6.5.4
Media Server2 is Windows 2000 SP4, NBU v6.54
VTL library is Quantum DXi5500
Total 12 VTL drives
VTL drive index 0-5 are shared by both media servers
VTL drive index 6-12 are only used by media server 2
Media errors are occurring during backup windows at night and when backups are re-ran during the day. Drives that are shown as busy are all over the place, not just the shared drives. I have deleted and re-added the drives to both media servers. They both just had a reboot yesterday. Drivers are updated. Server1 controls the library.
Verbosity level of 5 for bptm logs are below. From both media servers that shows one of the VTL drives they share:
Server1
11:17:23.311 [860.3828] <2> logconnections: BPDBM CONNECT FROM **.***.***.**.**** TO **.***.***.**.****
11:17:23.311 [860.3828] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required
11:17:23.311 [860.3828] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required
11:17:23.311 [860.3828] <2> check_authentication: no authentication required
11:17:23.311 [860.3828] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002
11:17:23.311 [860.3828] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002
11:17:34.452 [860.3828] <16> write_data: cannot write image to media id SV0031, drive index 1, The device is not ready.
11:17:34.452 [860.3828] <2> send_MDS_msg: DEVICE_STATUS 1 93475 media_server_name SV0031 4003786 SWF-VDLT-02 2000115 WRITE_ERROR 0 0
11:17:34.452 [860.3828] <2> EndpointSelectorFactory::get_selector: +++ ENTERING +++ : obj = 00F20608 (Endpoint_Selector.cpp:1097)
11:17:34.452 [860.3828] <2> EndpointSelectorFactory::get_selector: --- EXITING --- : obj = 00F20608 (Endpoint_Selector.cpp:1097)
11:17:34.452 [860.3828] <2> EndpointSelector::select_endpoint: +++ ENTERING +++ : obj = 00F20678 (Endpoint_Selector.cpp:367)
11:17:34.452 [860.3828] <2> EndpointSelector::select_endpoint: endpoint count is: 2(Endpoint_Selector.cpp:449)
11:17:34.452 [860.3828] <2> EndpointSelector::getPreferredEndpoint: +++ ENTERING +++ : obj = 00F20678 (Endpoint_Selector.cpp:860)
11:17:34.452 [860.3828] <2> EndpointSelector::getPreferredEndpoint: Found host in connection list, using this endpoint: master_server_name addr:10.33.4.247(Endpoint_Selector.cpp:906)
11:17:34.452 [860.3828] <2> EndpointSelector::getPreferredEndpoint: --- EXITING --- : obj = 00F20678 (Endpoint_Selector.cpp:860)
11:17:34.452 [860.3828] <2> EndpointSelector::select_endpoint: There are no endpoints that match server list(Endpoint_Selector.cpp:511)
11:17:34.452 [860.3828] <2> EndpointSelector::performCallUsingEndpoint: +++ ENTERING +++ : obj = 00F20678 (Endpoint_Selector.cpp:972)
11:17:34.452 [860.3828] <2> EndpointSelector::performCallUsingEndpoint: This is a pbxiop endpoint(Endpoint_Selector.cpp:993)
11:17:34.452 [860.3828] <2> EndpointSelector::performCallUsingEndpoint: Host: master_server_name, Port: 1556, Insecure serviceID: EMM(Endpoint_Selector.cpp:999)
11:17:34.452 [860.3828] <2> EndpointSelector::performCallUsingEndpoint: invocation->perform_call(...) SUCCESS(Endpoint_Selector.cpp:1010)
11:17:34.452 [860.3828] <2> EndpointSelector::performCallUsingEndpoint: --- EXITING --- : obj = 00F20678 (Endpoint_Selector.cpp:972)
11:17:34.452 [860.3828] <2> EndpointSelector::select_endpoint: --- EXITING --- : obj = 00F20678 (Endpoint_Selector.cpp:367)
11:17:34.452 [860.3828] <2> EndpointSelector::success: +++ ENTERING +++ : obj = 00F20678 (Endpoint_Selector.cpp:602)
11:17:34.452 [860.3828] <2> EndpointSelector::success: --- EXITING --- : obj = 00F20678 (Endpoint_Selector.cpp:602)
11:17:35.655 [860.3828] <2> Orb::setDebugLevelFromVxul: Orb logging configuration level set to 0(Orb.cpp:2311)
11:17:35.655 [860.3828] <2> emmlib_handleMessage: (0) CORBA call returned 0
11:17:35.655 [860.3828] <2> log_media_error: successfully wrote to error file - 05/07/10 11:17:35 SV0031 1 WRITE_ERROR SWF-VDLT-02
11:17:35.670 [860.3828] <2> wait_for_sigcld: waiting for child 1548 to exit, timeout is 300
11:17:35.670 [860.3828] <2> check_error_history: just tpunmount: called from bptm line 21231, EXIT_Status = 84
11:17:35.670 [860.3828] <2> io_close: closing D:\srvapps\Veritas\NetBackup\db\media\tpreq\drive_SWF-VDLT-02, from bptm.c.18660
11:17:35.670 [860.3828] <2> drivename_write: Called with mode 1
11:17:35.670 [860.3828] <2> drivename_unlock: unlocked
11:17:35.670 [860.3828] <2> drivename_checklock: Called
11:17:35.670 [860.3828] <2> drivename_lock: lock established
11:17:35.670 [860.3828] <2> drivename_unlock: unlocked
11:17:35.670 [860.3828] <2> drivename_close: Called for file SWF-VDLT-02
11:17:35.670 [860.3828] <2> tpunmount: NOP: MEDIA_DONE 0 366351 0 SV0031 4003786 0 {3AFBE6BC-A8A4-40DA-8103-72FC7DC792D9}
11:17:35.670 [860.3828] <2> bptm: EXITING with status 84 <----------
Server2
03:39:22.253 [4324.896] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2046: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
03:39:22.253 [4324.896] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2060: service: bpdbm
03:39:22.471 [4324.896] <2> logconnections: BPDBM CONNECT FROM **.***.***.***** TO **.***.***.*****
03:39:23.128 [4324.896] <4> write_backup: begin writing backup id client_server_1273210147, copy 1, fragment 13, to media id SV0143 on drive SWF-VDLT-02 (index 1)
03:39:23.128 [4324.896] <2> write_data: twin_index: 0 active: 1 dont_process: 0 wrote_backup_hdr: 0 finished_buff: 0 saved_cindex: 0 twin_is_disk 0 delay_brm: 0
03:39:23.128 [4324.896] <2> write_data: Total Kbytes transferred 1471488
03:41:29.142 [4324.896] <2> write_data: cannot read position on drive index 1, The device is not ready.
03:41:29.142 [4324.896] <2> io_write_back_header: drive index 1, client_server_1273210147, file num = 22, mpx_headers = 0, copy 1
03:43:35.140 [4324.896] <2> io_write_block: WriteFile() failed err = 21
03:43:35.234 [4324.896] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2046: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
03:43:35.234 [4324.896] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2060: service: bpdbm
03:43:35.468 [4324.896] <2> logconnections: BPDBM CONNECT FROM 10.135.128.68.10499 TO 10.33.4.247.13724
03:43:36.124 [4324.896] <16> io_write_block: write error on media id SV0143, drive index 1, writing header block, 21
03:43:36.124 [4324.896] <2> send_MDS_msg: DEVICE_STATUS 1 93039 media_server_name SV0143 4003898 SWF-VDLT-02 2000115 WRITE_ERROR 0 0
03:43:36.312 [4324.896] <2> log_media_error: successfully wrote to error file - 05/07/10 03:43:36 SV0143 1 WRITE_ERROR SWF-VDLT-02
03:43:36.327 [4324.896] <2> check_error_history: just tpunmount: called from bptm line 21231, EXIT_Status = 84
03:43:36.327 [4324.896] <2> io_close: closing F:\srvapps\Veritas\NetBackup\db\media\tpreq\drive_SWF-VDLT-02, from bptm.c.18660
03:43:36.327 [4324.896] <2> drivename_write: Called with mode 1
03:43:36.327 [4324.896] <2> drivename_unlock: unlocked
03:43:36.327 [4324.896] <2> drivename_checklock: Called
03:43:36.327 [4324.896] <2> drivename_lock: lock established
03:43:36.327 [4324.896] <2> drivename_unlock: unlocked
03:43:36.327 [4324.896] <2> drivename_close: Called for file SWF-VDLT-02
03:43:36.343 [4324.896] <2> tpunmount: NOP: MEDIA_DONE 0 366266 0 SV0143 4003898 0 {DCD7939C-F7D9-43F6-8A16-4D181AA79D55}
03:43:36.343 [4324.896] <2> bptm: EXITING with status 84 <----------
03:43:39.343 [4324.896] <2> cleanup: Detached from BPBRM shared memory