cancel
Showing results for 
Search instead for 
Did you mean: 

VTL drives and media getting 84/86 errors. Drives show device not ready

newbie_girl
Level 3
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

1 ACCEPTED SOLUTION

Accepted Solutions

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

Looks to me like a sure hardware call.
Anything in System Log?

See this TN: http://seer.entsupport.symantec.com/docs/287146.htm
Extract:
This can occur when NetBackup sends a request to the robot to move a tape but the robotic operation is not successful.  This issue is most likely the result of a hardware issue with the robot or tape drive.

View solution in original post

5 REPLIES 5

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

write_data: cannot write image to media id SV0031, drive index 1, The device is not ready.

There will probably be some hardware error in Event Viewer System log as well.
I'd log a call with the VTL vendor.

newbie_girl
Level 3
Thank you Marianne!  I had contemplated doing that actually.  Now I certainly will.  Only one of the media servers showed any sort of HW related errors in the event logs.  Which would makes I suppose, since it is the robot control host.  



Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

Looks to me like a sure hardware call.
Anything in System Log?

See this TN: http://seer.entsupport.symantec.com/docs/287146.htm
Extract:
This can occur when NetBackup sends a request to the robot to move a tape but the robotic operation is not successful.  This issue is most likely the result of a hardware issue with the robot or tape drive.

morritezpaul
Not applicable

A virtual tape library (VTL) is a data storage virtualization technology used typically for backup and recovery purposes. A VTL presents a storage component (usually hard disk storage) as tape libraries or tape drives for use with existing backup software.

Virtualizing the disk storage as tape allows integration of VTLs with existing backup software and existing backup and recovery processes and policies. The benefits of such virtualization include storage consolidation and faster data restore processes.

Nicolai
Moderator
Moderator
Partner    VIP   
You may check the VTL doesn't run full during backup. Besides HW error this is the only way I can think of a VTL can do media related errors.