Vinum & U320 SCSI, slower than UDMA100 IDE ?

[Sander Smeenk]

Hi,

I recently installed a Dual P4 2.8ghz with FBSD 4.9 and made a RAID10
array of the 4 scsi disks available. The idea was that this would be
faster to read from than normal IDE disks. As a test I took the
company's web/ directory, which is 1.6gb in size and has 22082 files.

I extracted this web/ directory on the IDE disk and on the RAID10
array, and noticed that extracting it took much longer on RAID10 than it
did on IDE. I assumed that it was slower on RAID10 because it needed to
stripe the data to all these disks, mirror it and what not.

Then I did a read test, like this:

| date;find . -type f|while read FILE;do cat "$FILE" > /dev/null;done;date

I know it's not the most sophisticated test, but at least it shows that
on the IDE disk, this 'test' took 24 seconds to complete. On the RAID10
array it took a whopping 73 seconds to complete.

I would understand if the RAID10 array was as fast as IDE, or faster,
but i'm a bit amazed by these results. The RAID10 array was built on 4x
36.7gb Ultra320 SCSI disks, connected to an Adaptec 39320D Ultra320 SCSI
adapter, which is a PCI-X card, configured in a PCI-X slot.

dmesg shows this for each of the 4 disks connected:

| da0 at ahd0 bus 0 target 2 lun 0
| da0: <MAXTOR ATLAS10K4_36WLS DFV0> Fixed Direct Access SCSI-3 device 
| da0: 320.000MB/s transfers (160.000MHz, offset 127, 16bit), 
|      Tagged Queueing Enabled
| da0: 35074MB (71833096 512 byte sectors: 255H 63S/T 4471C)

The relevant volume for this in the vinum config looks like this:

| volume varweb setupstate
|   plex org striped 3841k
|     sd length 7G drive vd0
|     sd length 7G drive vd1
|     sd length 7G drive vd2
|     sd length 7G drive vd3
|   plex org striped 3841k
|     sd length 7G drive vd3
|     sd length 7G drive vd2
|     sd length 7G drive vd1
|     sd length 7G drive vd0

Relevant parts from mount now show:

| /dev/ad0s1g on /backup (ufs, local, soft-updates)
| /dev/vinum/varweb on /var/web (ufs, local, soft-updates)

What could cause this major decrease in speed? 
Or is this normal behaviour, and is the RAID array faster with
concurrent reads / writes than the IDE disk, but not with single reads /
writes?

As a possible reason for this slowdown the only thing I can find is
this, from dmesg:

| ahd0: <Adaptec 39320D Ultra320 SCSI adapter> port 0x7000-0x70ff,0x7400-0x74ff mem 0xfc200000-0xfc201fff irq 10 at device 1.0 on pci3
| aic7902: Ultra320 Wide Channel A, SCSI Id=7, PCI-X 101-133Mhz, 512 SCBs
| ahd1: <Adaptec 39320D Ultra320 SCSI adapter> port 0x7800-0x78ff,0x7c00-0x7cff mem 0xfc202000-0xfc203fff irq 10 at device 1.1 on pci3
| aic7902: Ultra320 Wide Channel B, SCSI Id=7, PCI-X 101-133Mhz, 512 SCBs

[ .. later on in the boot process .. ]

| ahd1: PCI error Interrupt
| >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
| ahd1: Dumping Card State at program address 0x94 Mode 0x22
| Card was paused
| HS_MAILBOX[0x0] INTCTL[0x0] SEQINTSTAT[0x0] SAVED_MODE[0x0] 
| DFFSTAT[0x30]:(CURRFIFO_0|FIFO0FREE|FIFO1FREE) SCSISIGI[0x0]:(P_DATAOUT) 
| SCSIPHASE[0x0] SCSIBUS[0x0] LASTPHASE[0x1]:(P_DATAOUT|P_BUSFREE) 
| SCSISEQ0[0x0] SCSISEQ1[0x12]:(ENAUTOATNP|ENRSELI) 
| SEQCTL0[0x10]:(FASTMODE) SEQINTCTL[0x80]:(INTVEC1DSL) 
| SEQ_FLAGS[0x0] SEQ_FLAGS2[0x0] SSTAT0[0x0] SSTAT1[0x8]:(BUSFREE) 
| SSTAT2[0x0] SSTAT3[0x0] PERRDIAG[0x0] SIMODE1[0xa4]:(ENSCSIPERR|ENSCSIRST|ENSELTIMO) 
| LQISTAT0[0x0] LQISTAT1[0x0] LQISTAT2[0x0] LQOSTAT0[0x0] 
| LQOSTAT1[0x0] LQOSTAT2[0x0] 
| 
| SCB Count = 16 CMDS_PENDING = 0 LASTSCB 0xffff CURRSCB 0x0 NEXTSCB 0x0
| qinstart = 0 qinfifonext = 0
| QINFIFO:
| WAITING_TID_QUEUES:
| Pending list:
| Total 0
| Kernel Free SCB list: 15 14 13 12 11 10 9 8 7 6 5 4 3 2 1 0 
| Sequencer Complete DMA-inprog list: 
| Sequencer Complete list: 
| Sequencer DMA-Up and Complete list: 
| 
| ahd1: FIFO0 Free, LONGJMP == 0x80ff, SCB 0x0
| SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS) 
| SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL) 
| SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0] DFFSXFRCTL[0x0] 
| SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO) SHADDR = 0x00, SHCNT = 0x0 
| HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10]:(SG_CACHE_AVAIL) 
| ahd1: FIFO1 Free, LONGJMP == 0x80ff, SCB 0x0
| SEQIMODE[0x3f]:(ENCFG4TCMD|ENCFG4ICMD|ENCFG4TSTAT|ENCFG4ISTAT|ENCFG4DATA|ENSAVEPTRS) 
| SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL) 
| SG_CACHE_SHADOW[0x2]:(LAST_SEG) SG_STATE[0x0] DFFSXFRCTL[0x0] 
| SOFFCNT[0x0] MDFFSTAT[0x5]:(FIFOFREE|DLZERO) SHADDR = 0x00, SHCNT = 0x0 
| HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10]:(SG_CACHE_AVAIL) 
| LQIN: 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 
| ahd1: LQISTATE = 0x0, LQOSTATE = 0x0, OPTIONMODE = 0x42
| ahd1: OS_SPACE_CNT = 0x20 MAXCMDCNT = 0x0
| 
| SIMODE0[0x6c]:(ENOVERRUN|ENIOERR|ENSELDI|ENSELDO) 
| CCSCBCTL[0x0] 
| ahd1: REG0 == 0x3533, SINDEX = 0x33, DINDEX = 0x0
| ahd1: SCBPTR == 0x0, SCB_NEXT == 0xff00, SCB_NEXT2 == 0x0
| CDB 0 0 0 0 0 0
| STACK: 0x1 0x8 0x7 0x6 0x5 0x4 0x3 0x29
| >>>>>>>>>>>>>>>>>
| ahd1: Signaled Target Abort

But the thing is, there's NOTHING connected to ahd1, and the step that
follows this card dump is detecting disks, which succeeds like a charm.
All 4 SCSI disks are detected, and show a healthy connection state:
| da0: 320.000MB/s transfers (160.000MHz, offset 127, 16bit), Tagged Queueing Enabled

Further use of this new server did not reveal any other problems with
the SCSI controller. Everything seems to work as expected. Except for
the slowdown in reads / writes.

Can anyone shed a light on this matter? Things I overlooked?
Things I should check? I tried googling for a solution to the PCI
error interrupt problem which puts the SCSI card in pause, but I
couldn't find anything useful, just a few posts from people who also
experience this card dump thing at boot.

Any help is appreciated!

Kind regards,
Sander Smeenk.
-- 
| Before borrowing money from a friend, decide which you need more.
| 1024D/08CEC94D - 34B3 3314 B146 E13C 70C8  9BDB D463 7E41 08CE C94D