I've got this pair of TRIMM RAID arrays, which are based on the CMD
CRD-5500 (or VIPER, another OEM name for the same device) RAID controller.

I've been happily using them on my development server for some time
(though a power supply problem caused me to have to give up the one
hot-spare disk some time ago).

ahc0 at pci1 dev 4 function 0
ahc0: interrupting at irq 11
ahc0: aic7880 Wide Channel A, SCSI Id=7, 16/255 SCBs
scsibus0 at ahc0: 16 targets, 8 luns per target
sd4 at scsibus0 target 14 lun 0: <CMD TECH, CRD-5500, C1-A> SCSI2 0/direct fixed
sd4: 12285 MB, 24570 cyl, 16 head, 64 sec, 512 bytes/sect x 25159680 sectors
sd4: sync (100.0ns offset 8), 16-bit (20.000MB/s) transfers, tagged queueing
sd5 at scsibus0 target 15 lun 0: <CMD TECH, VIPER, C1-A> SCSI2 0/direct fixed
sd5: 12285 MB, 24570 cyl, 16 head, 64 sec, 512 bytes/sect x 25159680 sectors
sd5: sync (100.0ns offset 8), 16-bit (20.000MB/s) transfers, tagged queueing

(that's a 1.5W kernel on i386, specificaly an IBM PC Server 325 onboard controller)


This morning while reading through last night's /etc/daily script
reports I noted some I/O errors for files on on the filesystem on one of
them.  "HMMMM...", I thought, "That's pretty strange, that being a
RAID-5 array and all!"

Sure enough there are reports from the kernel stating the following:

: sd4(ahc0:0:14:0):  Check Condition on CDB: 0x28 00 01 78 00 ba 00 00 01 00
:     SENSE KEY:  Media Error
:    INFO FIELD:  24641722
:      ASC/ASCQ:  Uncorrected Read Error - Recommend Rewrite the Data
: 

the hex values given on the first line are not always the same.  I think
these are the three variants:

sd4(ahc0:0:14:0):  Check Condition on CDB: 0x28 00 01 78 00 b0 00 00 10 00
sd4(ahc0:0:14:0):  Check Condition on CDB: 0x28 00 01 78 00 ba 00 00 01 00
sd4(ahc0:0:14:0):  Check Condition on CDB: 0x28 00 01 78 00 b0 00 00 70 00


The sense key and the sector number are always exactly the same, and I
trigger the error on demand with:

	# dd if=/dev/rsd4c skip=24641722 count=1 conv=noerror,sync of=/dev/null
	dd: /dev/rsd4c: Input/output error
	0+0 records in
	0+0 records out
	0 bytes transferred in 7.273 secs (0 bytes/sec)
	dd: /dev/rsd4c: Input/output error
	1+0 records in
	1+0 records out
	512 bytes transferred in 7.275 secs (70 bytes/sec)

However writing to that sector "works", but doesn't "fix" anything:

	# dd of=/dev/rsd4c skip=24641722 count=1 conv=noerror if=/dev/zer>
	1+0 records in
	1+0 records out
	512 bytes transferred in 0.001 secs (512000 bytes/sec)


Nothing in the controller users manual makes any mention of this kind of
error even being possible.


For fun I tried re-assigning the block, but with no luck:

	# scsictl /dev/rsd4d reassign 24641722
	/dev/rsd4d: SCSI command timed out
	/dev/rsd4d: device is busy
	/dev/rsd4d: Check Condition on CDB: 07 00 00 00 00 00
	    SENSE KEY: Illegal Request
	     ASC/ASCQ: Invalid Command Operation Code
	
	 Additional Sense Information (byte 18 out...):
	
	        18: 0x00 0x00 0xa0 0x5b 0x00 0x00
	        24: 0x8b 0x7a 0x1c 0x8b 0x5a 0x34 0x8b 0x42

(and still the error persists of course)

Then with my port of the old FreeBSD 'scsi' utility I tried turnning on
AWRE, ARRE, and EER (they were all off before, not that it should matter
for a virtual disk), but still with no change in behaviour:

	# ./scsi -f /dev/rsd4d -m 1 -P 0
	AWRE (Auto Write Reallocation Enbld):  1 
	ARRE (Auto Read Reallocation Enbld):  1 
	TB (Transfer Block):  1 
	RC (Read Continuous):  0 
	EER (Enable Early Recovery):  1 
	PER (Post Error):  1 
	DTE (Disable Transfer on Error):  1 
	DCR (Disable Correction):  0 
	Read Retry Count:  27 
	Correction Span:  12 
	Head Offset Count:  0 
	Data Strobe Offset Count:  0 
	Write Retry Count:  0 
	Recovery Time Limit:  0 



Now interestingly there are SCSI "errors" associated with a particular
disk reported in the controller's error log for every "event":

                         INFINITY SERIES Monitor Utility             03-29-02
                                    EVENT LOG                        21:25:19

+-----------------+-----------------------+------------------+----------------+
| Sequence Number | 317                   | Date             | 03-29-02       | 
| Recorded Event  | SCSI                  | Time             | 21:23:50       | 
+-----------------+-----------------------+------------------+----------------+
| RAID Set        | 0                     | RAID Level       | 5              | 
| RAID Set Status | Non-Degraded          | Redundancy Group | 0              | 
| Logical Member  | 0                     | Partitions       | 1              | 
+-----------------+-----------------------+------------------+----------------+
| I/O Channel     | 2                                                         | 
| SCSI ID         | 1                                                         | 
| SCSI Command    | 3E 00 00 7D 55 CE 00 02 10 00 00 00                       | 
| SCSI Sense Data | 70 00 03 00 00 00 00 0A 00 00 00 00 11 00 01 00 00 00     | 
| SCSI Phases     | 02 07 04 01 03 02 07 00 FF 00 00 00 00 00 00 00           | 
| Retry Attempt   | 2                                                         | 
| SCDRP           | 8014AD30                                                  | 
| CDRP            | 8012B728                                                  | 
|                 |                                                           | 
|                 |                                                           | 
+-----------------+-----------------------------------------------------------+


(sometimes there are three retries, sometimes two.  some of the numbers
change, especially the SCDRP and CDRP, and IIRC some of the "phases"
numbers, but always the same disk and same SCSI command)

(I would much appreciate it if someone could tell me how to try to
decode the numbers above!)

So, I took that disk off-line, reformatted it, re-built the RAID set,
and still the error persists (as do the exact same events for that disk).

The disks are Seagate ST15230W's (4GB 8-bit SE).  It took ages to
re-format the disk (well over an hour), but the controller seemed to be
able to tell when the disk was still busy with the reformat and wouldn't
let me start the rebuild until it was done.

The rebuild went OK, but there were SCSI errors logged during that time,
both for the reformatted disk, and for one other disk.

Coincidentally during the time the one disk was formatting (and while
the RAID set was operating in "degraded mode", I tried reading that
"bad" sector, with the same results, except now another disk was
complaining about something, with the same SCSI command and sense data,
and even the same "phases" numbers I think, but with different SCDRP and
CDRP numbers.

First I'm going to try re-formatting the second drive that's been
mentioned in the event log (and rebuilding the RAID set).....

(actually first I'll copy the affected filesystem over to my big and
mostly empty RAIDframe filesystem! ;-)

Then if that doesn't work I'm going to try replacing the one disk that
gets the most errors (channel 2, ID 1) -- I have one identical spare (it
was the warm spare, and is in the tray with the busted power supply).

If all else fails I guess I'll have to try replacing both those drives
and rebuild and restore the whole set.....

What I can't understand is if there are a couple of unreoverable bad
sectors on two drives why is only one sector of the virtual RAID set
drive affected -- or am I only seeing one because that filesystem is
less than half full?  If the disks are giving errors then why isn't the
RAID set going into degraded mode?  If anyone can tell me what the heck
is going on, please do!  Thanks!


[[ PS:  does anyone have any spare TRIMM RM-200 trays, or even just an
equivalent to the TP-040 (aka CY-03V0) 40-watt power supply? ]]

-- 
								Greg A. Woods

+1 416 218-0098;  <gwoods@acm.org>;  <g.a.woods@ieee.org>;  <woods@robohack.ca>
Planix, Inc. <woods@planix.com>; VE3TCP; Secrets of the Weird <woods@weird.com>