Status 84, I/O device error, hardware or software?

[rocker65]

Seemingly straight forward. But it's not.

Windows 2003 server running NB 7.0. Brand spanking new MSL6000 library. Two LTO4 drives. Same firmware revs. Silo says it's health is perfect. Windows server says the tape drives are responding perfectly. Netbackup is not happy. Backup fail to start if I use the one tape drive in question drive_HP.ULTRIUM4-SCSI.000.  The tape drive does not get downed after a failure. The drive paths are valid and are shown as such. I am using the native drivers shipped with Windows 2003, so I haven't changed a thing WRT drivers. So I don't know if it's a hardware issue or a driver issue.

This is the error from the backup report:

1/27/2011    11:05:31 AM    backupsrv01 systema Error    1867    Backup    backup of client systema exited with status 84 (media write error)

Taken from bptm log on the server

11:17:02.109 [7164.7240] <2> io_write_back_header: drive index 0, xdevvir015_1296144931, file num = 31, mpx_headers = 1, copy 1
11:17:02.109 [7164.7240] <2> write_data: completed writing backup header, start writing data when first buffer is available, copy 1
11:17:02.109 [7164.7240] <2> write_data: first write, twin_index: 0 cindex: 0 dont_process: 1 wrote_backup_hdr: 1 finished_buff: 0
11:17:02.109 [7164.7240] <2> write_data: received first buffer (65536 bytes), begin writing data
11:17:02.578 [7164.7240] <2> write_data: write of 65536 bytes indicated only 0 bytes were written, err = 1117
11:17:02.578 [7164.7240] <4> write_data: WriteFile failed with: The request could not be performed because of an I/O device error. (1117); bytes written = 65536; size = 0
11:17:02.578 [7164.7240] <2> send_brm_msg: MEDIA NOT READY
11:17:02.578 [7164.7240] <2> write_data: attempting write error recovery, err = 1117
11:17:02.578 [7164.7240] <2> tape_error_rec: error recovery to block 7059537 requested
11:17:02.578 [7164.7240] <2> tape_error_rec: attempting error recovery, delay 3 minutes before next attempt, tries left = 5
11:20:02.578 [7164.7240] <2> io_ioctl: command (0)MTWEOF 0 from (overwrite.c.258) on drive index 0
11:20:02.578 [7164.7240] <2> get_drive_path: SCSI coordinates {3,0,0,2}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_hp&prod_ultrium_4-scsi&rev_b56w#5&180ccf8d&0&000002#{53f5630b-b6bf-11d0-94f2-00a0c91efb8b}
11:20:02.578 [7164.7240] <2> io_close: closing C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, from overwrite.c.273
11:20:02.578 [7164.7240] <2> openTpreqFile: tpreq_file: C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, serial_num: HU1038CGNB
11:20:02.578 [7164.7240] <2> get_drive_path: SCSI coordinates {3,0,0,2}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_hp&prod_ultrium_4-scsi&rev_b56w#5&180ccf8d&0&000002#{53f5630b-b6bf-11d0-94f2-00a0c91efb8b}
11:20:02.578 [7164.7240] <2> check_serial_num: serial number match for drive with SCSI coordinates {3,0,0,2}, dos_path \\.\Tape0, drive serial number HU1038CGNB, expected serial number HU1038CGNB
11:20:02.593 [7164.7240] <2> init_tape: \\.\Tape0 (SCSI coordinates {3,0,0,2}) configured with blocksize 0
11:20:02.593 [7164.7240] <2> init_tape: \\.\Tape0 (SCSI coordinates {3,0,0,2}) has compression enabled
11:20:02.609 [7164.7240] <2> io_open: SCSI RESERVE
11:20:02.609 [7164.7240] <2> io_open: file C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000 successfully opened (mode 2)
11:20:02.609 [7164.7240] <2> tape_error_rec: spacing to EOD for error recovery
11:20:02.609 [7164.7240] <2> tape_error_rec: absolute block position at EOD is 7059538
11:20:02.609 [7164.7240] <2> tape_error_rec: locating to absolute block number 7059537 for error recovery
11:20:02.625 [7164.7240] <2> tape_error_rec: absolute block position after read position is 7059537
11:20:02.625 [7164.7240] <2> send_brm_msg: MEDIA READY
11:20:02.625 [7164.7240] <2> write_data: write of 65536 bytes indicated only 0 bytes were written, err = 1117
11:20:02.625 [7164.7240] <4> write_data: WriteFile failed with: The request could not be performed because of an I/O device error. (1117); bytes written = 65536; size = 0
11:20:02.625 [7164.7240] <2> send_brm_msg: MEDIA NOT READY
11:20:02.625 [7164.7240] <2> write_data: attempting write error recovery, err = 1117
11:20:02.625 [7164.7240] <2> tape_error_rec: error recovery to block 7059537 requested
11:20:02.625 [7164.7240] <2> tape_error_rec: attempting error recovery, delay 3 minutes before next attempt, tries left = 4
11:23:02.625 [7164.7240] <2> io_ioctl: command (0)MTWEOF 0 from (overwrite.c.258) on drive index 0
11:23:02.625 [7164.7240] <2> get_drive_path: SCSI coordinates {3,0,0,2}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_hp&prod_ultrium_4-scsi&rev_b56w#5&180ccf8d&0&000002#{53f5630b-b6bf-11d0-94f2-00a0c91efb8b}
11:23:02.625 [7164.7240] <2> io_close: closing C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, from overwrite.c.273
11:23:02.625 [7164.7240] <2> openTpreqFile: tpreq_file: C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, serial_num: HU1038CGNB
11:23:02.625 [7164.7240] <2> get_drive_path: SCSI coordinates {3,0,0,2}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_hp&prod_ultrium_4-scsi&rev_b56w#5&180ccf8d&0&000002#{53f5630b-b6bf-11d0-94f2-00a0c91efb8b}
11:23:02.625 [7164.7240] <2> check_serial_num: serial number match for drive with SCSI coordinates {3,0,0,2}, dos_path \\.\Tape0, drive serial number HU1038CGNB, expected serial number HU1038CGNB
11:23:02.640 [7164.7240] <2> init_tape: \\.\Tape0 (SCSI coordinates {3,0,0,2}) configured with blocksize 0
11:23:02.640 [7164.7240] <2> init_tape: \\.\Tape0 (SCSI coordinates {3,0,0,2}) has compression enabled
11:23:02.640 [7164.7240] <2> io_open: SCSI RESERVE
11:23:02.640 [7164.7240] <2> io_open: file C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000 successfully opened (mode 2)
11:23:02.640 [7164.7240] <2> tape_error_rec: spacing to EOD for error recovery
11:23:02.656 [7164.7240] <2> tape_error_rec: absolute block position at EOD is 7059538
11:23:02.656 [7164.7240] <2> tape_error_rec: locating to absolute block number 7059537 for error recovery
11:23:02.671 [7164.7240] <2> tape_error_rec: absolute block position after read position is 7059537
11:23:02.671 [7164.7240] <2> send_brm_msg: MEDIA READY
11:23:03.125 [7164.7240] <2> write_data: write of 65536 bytes indicated only 0 bytes were written, err = 1117
11:23:03.125 [7164.7240] <4> write_data: WriteFile failed with: The request could not be performed because of an I/O device error. (1117); bytes written = 65536; size = 0
11:23:03.125 [7164.7240] <2> send_brm_msg: MEDIA NOT READY
11:23:03.125 [7164.7240] <2> write_data: attempting write error recovery, err = 1117
11:23:03.125 [7164.7240] <2> tape_error_rec: error recovery to block 7059545 requested
11:23:03.125 [7164.7240] <2> tape_error_rec: attempting error recovery, delay 3 minutes before next attempt, tries left = 5
11:26:03.125 [7164.7240] <2> io_ioctl: command (0)MTWEOF 0 from (overwrite.c.258) on drive index 0
11:26:03.125 [7164.7240] <2> get_drive_path: SCSI coordinates {3,0,0,2}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_hp&prod_ultrium_4-scsi&rev_b56w#5&180ccf8d&0&000002#{53f5630b-b6bf-11d0-94f2-00a0c91efb8b}
11:26:03.125 [7164.7240] <2> io_close: closing C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, from overwrite.c.273
11:26:03.140 [7164.7240] <2> openTpreqFile: tpreq_file: C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, serial_num: HU1038CGNB
11:26:03.140 [7164.7240] <2> get_drive_path: SCSI coordinates {3,0,0,2}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_hp&prod_ultrium_4-scsi&rev_b56w#5&180ccf8d&0&000002#{53f5630b-b6bf-11d0-94f2-00a0c91efb8b}
11:26:03.140 [7164.7240] <2> check_serial_num: serial number match for drive with SCSI coordinates {3,0,0,2}, dos_path \\.\Tape0, drive serial number HU1038CGNB, expected serial number HU1038CGNB
11:26:03.140 [7164.7240] <2> init_tape: \\.\Tape0 (SCSI coordinates {3,0,0,2}) configured with blocksize 0
11:26:03.156 [7164.7240] <2> init_tape: \\.\Tape0 (SCSI coordinates {3,0,0,2}) has compression enabled
11:26:03.156 [7164.7240] <2> io_open: SCSI RESERVE
11:26:03.156 [7164.7240] <2> io_open: file C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000 successfully opened (mode 2)
11:26:03.156 [7164.7240] <2> tape_error_rec: spacing to EOD for error recovery
11:26:03.156 [7164.7240] <2> tape_error_rec: absolute block position at EOD is 7059545
11:26:03.156 [7164.7240] <2> send_brm_msg: MEDIA READY
11:26:03.640 [7164.7240] <2> write_data: write of 65536 bytes indicated only 0 bytes were written, err = 1117
11:26:03.640 [7164.7240] <4> write_data: WriteFile failed with: The request could not be performed because of an I/O device error. (1117); bytes written = 65536; size = 0
11:26:03.640 [7164.7240] <2> send_brm_msg: MEDIA NOT READY
11:26:03.640 [7164.7240] <2> write_data: attempting write error recovery, err = 1117
11:26:03.640 [7164.7240] <2> tape_error_rec: error recovery to block 7059553 requested
11:26:03.640 [7164.7240] <2> tape_error_rec: attempting error recovery, delay 3 minutes before next attempt, tries left = 5
11:26:12.718 [7244.5416] <2> bptm: INITIATING (VERBOSE = 0): -rptdrv -jobid -1296047350 -jm
11:26:12.718 [7244.5416] <2> drivename_open: Called with Create 0, file HP.ULTRIUM4-SCSI.000
11:26:12.718 [7244.5416] <2> drivename_checklock: Called
11:26:12.718 [7244.5416] <2> drivename_checklock: File is locked

Any guidance would be warmly welcomed.

Thanks

[Marianne]

The Hardware Compatibility Guide says the following wrt drivers:

For 32-bit, use the Symantec drivers
For 64-bit, use the Vendor driver

Remember to stop AND disable Removable Storage Manager service.

To troubleshoot status 84, see this In-depth troubleshooting guide: http://www.symantec.com/docs/TECH43243

Extract:

"I/O errors
As an application, NetBackup has no direct access to a device, instead relying on the operating
system (OS) to handle any communication with the device. This means that during a write
operation NetBackup asks the OS to write to the device and report back the success or failure of
that operation. If there is a failure, NetBackup will merely report that a failure occurred, and any
troubleshooting should start at the OS level. If the OS is unable to perform the write, there are three
likely causes; OS configuration, a problem on the SCSI path, or a problem with the device."

About downing a tape drive: NBU will by default down a drive after 3 I/O errors in 12 hours.

[rocker65]

Hi Marianne

I tried the Symantec drivers, I assume you are talking about the tapeinst.exe? I tried that, including stopping and disabling the removable storage manager service. The 32 bit windows system could not recognise or see the tape devices. I had to remove those drivers and reinstall the windows drivers and the drives came back online. Also, I had to enable the storage manager service again.

The windows log files, as in the event view shows zero errors for the tape drive. The silo is happy when it runs it's self test. The brocade says all is good.

I guess I'll continue to mess about with cables, drivers.

BTW, I get THOUSANDS of these entries on my backup logs for RHEL 5 Linux systems. A couple hundred per system. It's really annoying as heck, but doesn't fail the backups. I can't find anything at all online that could explain it. We DONT use VxFS on our systems.

13:20:41.195 [18816] <8> bpbkar SelectFile: WRN - Unable to backup VxFS Named Data Streams, vxfs_nattr_check failed.  Errno = 13: Permission denied

[Andy_Welburn]

There was a similar solved post some time back - not sure if it will assist here?

https://www-secure.symantec.com/connect/forums/wrn-unable-backup-vxfs-named-data-streams-vxfsnattrcheck-failed-errno-13-permission-denied

[Andy_Welburn]

the robot/drives on NB?

Is it possible to physically swap the drives to see if the error follows the drive? (We used to do this with our SCSI attached LTO1s in a SK L180 library)

Altho' brand spanking new, there's nothing to stop it being faulty hardware....

[Marianne]

Extract from Device Compatibility Guide: http://www.symantec.com/docs/TECH76495

p. 137:
4. For 32-bit Windows systems, Symantec tests and recommends the use of the Symantec tape drivers. The latest release of the Symantec Tape Device Driver Installer can be downloaded from the Symantec support site. Symantec does not extensively test with the manufacturers' 32-bit tape drivers, however, they are supported, and Symantec will work with customers and vendors in an attempt to resolve any issues. Symantec and most hardware vendors listed are members of TSANet.
5. For 64-bit Windows systems, the manufacturer's most recent tape driver should be used. The Symantec tape drivers are not compatible with 64-bit Windows systems.

Download  SymantecDeviceDriversforWindowsServers20070215_287850.exe from http://www.symantec.com/docs/TECH51096

I you leave the RSM service running, it will 'fight' NetBackup for device control and cause all sorts of problems. See https://www-secure.symantec.com/connect/articles/tuning-windows-2003-and-2008-symantec-netbackup
OLD but still relevant: http://www.symantec.com/docs/TECH18968
http://www.symantec.com/docs/TECH32254

Please add this line to <install-path>\veritas\volmgr\vm.conf:
VERBOSE

Stop/start NBU Device Management Service.

You should be able to see all Media Management messages/errors logged in Event Viewer System and Application logs.

******************************

Please start a separate discussion for the Linux backup WRN messages.

[rocker65]

Hello

I have followed all these configuration items from the hardware configuration document and understand the I need the Symantec tape drivers for the 32 bit windows. For whatever reason, those drivers simply do not work. And that's of course with the RSM service stopped and disabled. The only way that  netbackp can see the LTO drives is with the native drivers, which I believe are HP's drivers, approved by MS. 

The HP library and tape testing tools showed some polling issues, but both drives had this problem. The HP documentation plus the Symantec documentation recommend on turning the TUR feature off from the registry. I have tried, but alas I am helpless with windows and am still trying to figure out how to make these changes. Not sure if this feature could cause all the problems I having with just one drive, and consistently that same drive.

Will call HP monday and have them listen to my swan song.

[rocker65]

Not without a boat load of work. It's a 4 slot silo, with only 2 drives. But the thing literally is out of the box. I'm still trying to set it up. There's just one drive that I can't write to. No error/blink codes, no errors anywhere except for NB.

[rocker65]

I saw this. Looks like his solution was to create an exclude file with the .schedule name and put /sys in there. I have /sys in my exclude file and the bbpkar log file explicitly shows it being excluded, or at least acknowledge that it is to be excluded.  It then launching into a massive diatribe of complaining.

08:27:37.254 [21483] <4> bpbkar: INF - Excluded /sys by exclude_list entry /sys
08:27:37.298 [21483] <8> bpbkar: WRN - Unable to backup VxFS Named Data Streams, vxfs_nattr_check failed.  Errno = 13: Permission denied
08:27:37.298 [21483] <8> bpbkar: WRN - Unable to backup VxFS Named Data Streams, vxfs_nattr_check failed.  Errno = 13: Permission denied
08:27:37.298 [21483] <8> bpbkar: WRN - Unable to backup VxFS Named Data Streams, vxfs_nattr_check failed.  Errno = 13: Permission denied

Will try the exlude_file.schedulename on mondy. If it works, then it's a bug as far as I'm concerned.

[Marianne]

Please add the VERBOSE entry to vm.conf and restart Device Management service.

Also ensure that you have bptm log dir.

When next status 84 occurs, check Event Viewer System and Application logs as well as bptm log for clues.

[Amit_Karia]

Have you tried native OS backup to see if tape is mounting and writing in the drive

This will help you isolate issues between software/hardware .

Not sure about windows(ntbackup) but , You can take OS backups through tar commands which directly interacts with Tape deivces in Unix OS

[rocker65]

That's actually a good idea. I have to wait until this very long NFS backup completes on the one good tape drive I have. I then have to enable the removeable media service and fire up ntbackup. I assume ntbackup lets me write to fibre attached tapes?

[rocker65]

Good morning

I have added VERBOSE to the vm.conf file, did that many days ago.

Backup details for failed backup:

1/31/2011 8:31:01 AM - connected; connect time: 00:00:01
1/31/2011 8:31:53 AM - mounted; mount time: 00:00:53
1/31/2011 8:31:57 AM - positioning CA8582 to file 129
1/31/2011 8:32:42 AM - positioned CA8582; position time: 00:00:45
1/31/2011 8:32:42 AM - begin writing
1/31/2011 8:41:47 AM - Error bptm(pid=3192) cannot write image to media id CA8582, drive index 0, The request could not be performed because of an I/O device error.
1/31/2011 8:41:47 AM - Error bpbrm(pid=6916) from client xdevvir015: ERR - Cannot write to STDOUT. Errno = 104: Connection reset by peer
1/31/2011 8:41:48 AM - end writing; write time: 00:09:06
media write error(84)

bptm log:

08:41:47.953 [3192.628] <16> write_data: cannot write image to media id CA8582, drive index 0, The request could not be performed because of an I/O device error.
08:41:47.953 [3192.628] <2> send_MDS_msg: DEVICE_STATUS 1 275 xprosrv004 CA8582 4000060 HP.ULTRIUM4-SCSI.000 2000021 WRITE_ERROR 0 0
08:41:47.968 [3192.628] <2> log_media_error: successfully wrote to error file - 01/31/11 08:41:47 CA8582 0 WRITE_ERROR HP.ULTRIUM4-SCSI.000
08:41:47.968 [3192.628] <2> check_error_history: just tpunmount: called from bptm line 21570, EXIT_Status = 84
08:41:47.968 [3192.628] <2> io_close: closing C:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_HP.ULTRIUM4-SCSI.000, from bptm.c.18975
08:41:47.968 [3192.628] <2> drivename_write: Called with mode 1
08:41:47.968 [3192.628] <2> drivename_unlock: unlocked
08:41:47.968 [3192.628] <2> drivename_checklock: Called
08:41:47.968 [3192.628] <2> drivename_lock: lock established
08:41:47.968 [3192.628] <2> drivename_unlock: unlocked
08:41:47.968 [3192.628] <2> drivename_close: Called for file HP.ULTRIUM4-SCSI.000
08:41:47.968 [3192.628] <2> tpunmount: NOP: MEDIA_DONE 0 2058 0 CA8582 4000060 0 {84722214-D99B-4837-A5E0-FFEE497A4609}
08:41:47.968 [3192.628] <2> send_brm_msg: ERROR 84
08:41:47.968 [3192.628] <2> mpx_terminate_exit: EXITING with status 84
08:41:47.968 [3192.628] <2> cleanup: Detached from BPBRM shared memory
08:41:49.031 [4832.6528] <2> bptm: INITIATING (VERBOSE = 0): -unload -dn HP.ULTRIUM4-SCSI.000 -dp {3,0,0,2} -dk 2000021 -m CA8582 -mk 4000060 -mds 0 -alocid 275 -jobid -1296241670 -jm
08:41:49.031 [4832.6528] <4> bptm: emmserver_name = prosrv004
08:41:49.031 [4832.6528] <4> bptm: emmserver_port = 1556
08:41:49.062 [4832.6528] <2> Orb::init: initializing ORB EMMlib_Orb with: dbstunitq -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static EndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb EMMlib_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(Orb.cpp:741)
08:41:49.078 [4832.6528] <2> EndpointSelector::select_endpoint: performing call with the only endpt available!(Endpoint_Selector.cpp:437)
08:41:49.078 [4832.6528] <2> send_brm_msg: PID of bpxm = 4832
08:41:49.078 [4832.6528] <2> nbjm_media_request: Passing job control to NBJM, type UNLOAD/6
08:41:49.078 [4832.6528] <2> nbjm_media_request: old_media_id = NULL, media_id = CA8582

The event viewer only has informational tidbits like:

TLD(1) closing/unlocking robotic path

tldcd.c.2691, newfd = INVALID_SOCKET, newfd=-1, timersig=1, error=0, EINTR=4, selectret=0

inquiry() function processing library HP       MSL6000 Series   0520:

 But no warnings or errors. So that's a no go for any usefull information.

Once this huge NFS backup finishes on the one good tape drive, I'm going to run the HP library tape testing software and force it to do write tests to see how it makes out. BTW, the HP test software can't see the tape drives if I use the symatec drivers. It only works with the native drivers which are HP drivers actually.

[rocker65 · Accepted solution]

After god knows how many reboots and windows hotfixes and registry hacks, we couldn't get the i/o errors to go away. And that's working with the HP storage engineers for 3 days.

I finally read the HP Installation guide that came with the unit, and it looked to me like the silo wasn't cabled the way the installation manual suggested. I recabled it as clearly described in the manual, and poof! Everhting works flawlessly.

I should mention that we paid good money to have an HP tech come and install and setup the silo for our group.

BTW, that HP MSL6060 with LTO4 drives is a fine unit.

[Andy_Welburn]

[rocker65]

If life were that easy....

Suppose I should have looked at the cabling last week.

[Andy_Welburn]

You would generally assume that someone you "buy in" to do the job would know what they were about.

But then you know what they say about "assume" ....

[Will_Restore]

we had similar trouble with another vendor and mismatch cabling. 

[rocker65]

The online guide and the paper documents and CD documentation that ships with it, AND the HP ITRC forums all talk about termination, and cabling for this silo with a 2 or 4 drive configuration. I just followed how it said to configure the unit. All the tape polling errors vanished when I tested the unit with the LTT's. Some folks on the HP ITRC forum had the same issue and the HP tech there said to never terminate the controller, just the devices as described in the docs.

I'm happily moving on now, grinding my teeth a bit.

[Stumpr2]

if at all possible I like to prove the hardware/media good at the OS level before bringing it into a Netbackup environment.