29320A: tons of "unexpected busfree while idle"

Fri Jan 21 05:58:19 PST 2005

Hi,

I am having a lot of "unexpected busfree while idle" events with Adaptec
29320A Ultra320 SCSI adapter.

While trying to eliminate various possibilities, it turned out that the
problem disappears if I downgrade sys/dev/aic7xxx directory to

   -D '01 Sep 2004' -rRELENG_5

So it looks like the problem was introduced sometime after that.

Other things we've tried, which did not help, with a single exception:

- using fresh RELENG_5 driver;
- using fresh HEAD driver;
- sticking this PCIX card into a normal PCI slot;
- sticking the card into a 5.3 Athlon64 box (also normal PCI);
- using different cables;
- using FreeBSD 4.8 (the problem disappeared here, too).

More details:

Jan 18 10:15:56 seifert kernel: ahd0: <Adaptec 29320A Ultra320 SCSI adapter> port 0xb400-0xb4ff,0xb800-0xb8ff mem 0xfc5fe000-0xfc5fffff irq 26 at device 4.0 on pci2
Jan 18 10:15:56 seifert kernel: ahd0: [GIANT-LOCKED]
Jan 18 10:15:56 seifert kernel: aic7901: Ultra320 Wide Channel A, SCSI Id=7, PCI-X 50-66Mhz, 512 SCBs

Jan 18 10:15:56 seifert kernel: ahd0: Unexpected busfree while idle, 0 SCBs aborted, PRGMCNT == 0xb9
Jan 18 10:15:56 seifert kernel: >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
Jan 18 10:15:56 seifert kernel: ahd0: Dumping Card State at program address 0xb7 Mode 0x33
Jan 18 10:15:56 seifert kernel: Card was paused
Jan 18 10:15:56 seifert kernel: INTSTAT[0x8] SELOID[0x4] SELID[0x0] HS_MAILBOX[0x0] 
Jan 18 10:15:56 seifert kernel: INTCTL[0x80] SEQINTSTAT[0x0] SAVED_MODE[0x11] DFFSTAT[0x33] 
Jan 18 10:15:56 seifert kernel: SCSISIGI[0xe6] SCSIPHASE[0x8] SCSIBUS[0x80] LASTPHASE[0x1] 
Jan 18 10:15:56 seifert kernel: SCSISEQ0[0x0] SCSISEQ1[0x12] SEQCTL0[0x0] SEQINTCTL[0x0] 
Jan 18 10:15:56 seifert kernel: SEQ_FLAGS[0xc0] SEQ_FLAGS2[0x0] QFREEZE_COUNT[0x2] 
Jan 18 10:15:56 seifert kernel: KERNEL_QFREEZE_COUNT[0x2] MK_MESSAGE_SCB[0xff00] MK_MESSAGE_SCSIID[0xff] 
Jan 18 10:15:56 seifert kernel: SSTAT0[0x22] SSTAT1[0x19] SSTAT2[0x10] SSTAT3[0x0] 
Jan 18 10:15:56 seifert kernel: PERRDIAG[0x0] SIMODE1[0xac] LQISTAT0[0x0] LQISTAT1[0x0] 
Jan 18 10:15:56 seifert kernel: LQISTAT2[0x0] LQOSTAT0[0x0] LQOSTAT1[0x0] LQOSTAT2[0x0] 
Jan 18 10:15:56 seifert kernel: 
Jan 18 10:15:56 seifert kernel: SCB Count = 16 CMDS_PENDING = 2 LASTSCB 0xffff CURRSCB 0xb NEXTSCB 0x0
Jan 18 10:15:56 seifert kernel: qinstart = 23 qinfifonext = 23
Jan 18 10:15:56 seifert kernel: QINFIFO:
Jan 18 10:15:56 seifert kernel: WAITING_TID_QUEUES:
Jan 18 10:15:56 seifert kernel: Pending list:
Jan 18 10:15:56 seifert kernel: 11 FIFO_USE[0x0] SCB_CONTROL[0x44] SCB_SCSIID[0x47] 
Jan 18 10:15:56 seifert kernel: 15 FIFO_USE[0x0] SCB_CONTROL[0x44] SCB_SCSIID[0x7] 
Jan 18 10:15:56 seifert kernel: Total 2
Jan 18 10:15:56 seifert kernel: Kernel Free SCB list: 1 2 3 4 5 6 7 8 9 10 12 13 14 0 
Jan 18 10:15:56 seifert kernel: Sequencer Complete DMA-inprog list: 
Jan 18 10:15:56 seifert kernel: Sequencer Complete list: 
Jan 18 10:15:56 seifert kernel: Sequencer DMA-Up and Complete list: 
Jan 18 10:15:56 seifert kernel: Sequencer On QFreeze and Complete list: 
Jan 18 10:15:56 seifert kernel: 
Jan 18 10:15:56 seifert kernel: 
Jan 18 10:15:56 seifert kernel: ahd0: FIFO0 Free, LONGJMP == 0x80ff, SCB 0x0
Jan 18 10:15:56 seifert kernel: SEQIMODE[0x3f] SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89] 
Jan 18 10:15:56 seifert kernel: SG_CACHE_SHADOW[0x2] SG_STATE[0x0] DFFSXFRCTL[0x0] 
Jan 18 10:15:56 seifert kernel: SOFFCNT[0x0] MDFFSTAT[0x5] SHADDR = 0x00, SHCNT = 0x0 
Jan 18 10:15:56 seifert kernel: HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10] 
Jan 18 10:15:56 seifert kernel: 
Jan 18 10:15:56 seifert kernel: ahd0: FIFO1 Free, LONGJMP == 0x8063, SCB 0xb
Jan 18 10:15:56 seifert kernel: SEQIMODE[0x3f] SEQINTSRC[0x0] DFCNTRL[0x4] DFSTATUS[0x89] 
Jan 18 10:15:56 seifert kernel: SG_CACHE_SHADOW[0x2] SG_STATE[0x0] DFFSXFRCTL[0x0] 
Jan 18 10:15:56 seifert kernel: SOFFCNT[0x0] MDFFSTAT[0x5] SHADDR = 0x00, SHCNT = 0x0 
Jan 18 10:15:56 seifert kernel: HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10] 
Jan 18 10:15:56 seifert kernel: LQIN: 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 
Jan 18 10:15:56 seifert kernel: ahd0: LQISTATE = 0x0, LQOSTATE = 0x0, OPTIONMODE = 0x42
Jan 18 10:15:56 seifert kernel: ahd0: OS_SPACE_CNT = 0x20 MAXCMDCNT = 0x0
Jan 18 10:15:56 seifert kernel: ahd0: SAVED_SCSIID = 0x0 SAVED_LUN = 0x0
Jan 18 10:15:56 seifert kernel: SIMODE0[0xc] 
Jan 18 10:15:56 seifert kernel: CCSCBCTL[0x4] 
Jan 18 10:15:56 seifert kernel: ahd0: REG0 == 0xb, SINDEX = 0x1b8, DINDEX = 0x1ba
Jan 18 10:15:56 seifert kernel: ahd0: SCBPTR == 0xb, SCB_NEXT == 0xff00, SCB_NEXT2 == 0xff72
Jan 18 10:15:56 seifert kernel: CDB 1a 0 a 0 14 0
Jan 18 10:15:56 seifert kernel: STACK: 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
Jan 18 10:15:56 seifert kernel: <<<<<<<<<<<<<<<<< Dump Card State Ends >>>>>>>>>>>>>>>>>>

This kind of dump happens sometime during disk probe, almost never
during newfs, and always, massively, during moderately intensive disk
operations (cp -pr ncvs, rm -rf ncvs etc).

Another strangety is how the thing recognizes the disks (any version of
the driver):

Jan 18 10:15:56 seifert kernel: da0 at ahd0 bus 0 target 0 lun 0
Jan 18 10:15:56 seifert kernel: da0: <HITACHI HUS157373EL3600 A5A5> Fixed Direct Access SCSI-3 device 
Jan 18 10:15:56 seifert kernel: da0: 40.000MB/s transfers (20.000MHz, offset 81, 16bit), Tagged Queueing Enabled
Jan 18 10:15:56 seifert kernel: da0: 70513MB (144410880 512 byte sectors: 255H 63S/T 8989C)
Jan 18 10:15:56 seifert kernel: da1 at ahd0 bus 0 target 4 lun 0
Jan 18 10:15:56 seifert kernel: da1: <HITACHI HUS157373EL3600 A5A5> Fixed Direct Access SCSI-3 device 
Jan 18 10:15:56 seifert kernel: da1: 40.000MB/s transfers (20.000MHz, offset 81, 16bit), Tagged Queueing Enabled
Jan 18 10:15:56 seifert kernel: da1: 70513MB (144410880 512 byte sectors: 255H 63S/T 8989C)

According to Hitachi specs, those 15k RPM disks can sustain 79MB/s, so
why are they reported as 40MB/s disks?  In reality, I was able to get
about 36MB/s out of them with the before-september driver.

Any thoughts?
Thanks,
\Anton.
-- 
The moronity of the universe is a monotonically increasing function. --
Jarkko Hietaniemi