SCSI / AIC7xxx / Tape Library Problem
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
linux (Ubuntu) |
Fix Released
|
Medium
|
Unassigned |
Bug Description
Hi there
I have a problem with an Ecrix Autopak tape library on Ubuntu. This problem first appeared in Breezy but has persisted through to Dapper. Currently I'm running kernel version 2.6.15-26-686 SMP. This bug prevents the use of backup programs such as Amanda and Arkeia. Steps to reproduce are easy:
Simply load a tape into the library using mtx:
root@gramps:~ # mtx -f /dev/sg1 load 5
(long pause)
mtx: Request Sense: Long Report=yes
mtx: Request Sense: Valid Residual=yes
mtx: Request Sense: Error Code=70 (Current)
mtx: Request Sense: Sense Key=Not Ready
mtx: Request Sense: FileMark=no
mtx: Request Sense: EOM=no
mtx: Request Sense: ILI=no
mtx: Request Sense: Residual = 00 00 00 00
mtx: Request Sense: Additional Sense Code = 04
mtx: Request Sense: Additional Sense Qualifier = 00
mtx: Request Sense: BPV=no
mtx: Request Sense: Error in CDB=no
mtx: Request Sense: SKSV=no
MOVE MEDIUM from Element Address 4 to 82 Failed
Dmesg reports the following error:
Aug 2 09:30:43 gramps kernel: [17183103.300000] 2:0:3:0: Attempting to queue an ABORT message
Aug 2 09:30:43 gramps kernel: [17183103.300000] CDB: 0xa5 0x0 0x0 0x56 0x0 0x4 0x0 0x52 0x0 0x0 0x0 0x0
Aug 2 09:30:43 gramps kernel: [17183103.300000] scsi2: At time of recovery, card was not paused
Aug 2 09:30:43 gramps kernel: [17183103.300000] >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
Aug 2 09:30:43 gramps kernel: [17183103.300000] scsi2: Dumping Card State while idle, at SEQADDR 0x9
Aug 2 09:30:43 gramps kernel: [17183103.300000] Card was paused
Aug 2 09:30:43 gramps kernel: [17183103.300000] ACCUM = 0x4, SINDEX = 0x37, DINDEX = 0x24, ARG_2 = 0x0
Aug 2 09:30:43 gramps kernel: [17183103.300000] HCNT = 0x0 SCBPTR = 0x0
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCSIPHASE[0x0] SCSISIGI[0x0] ERROR[0x0]
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCSIBUSL[0x0] LASTPHASE[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCSISEQ[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SBLKCTL[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SEQCTL[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SSTAT0[0x0] SSTAT1[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SSTAT2[0x0] SSTAT3[0x0] SIMODE0[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SIMODE1[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SXFRCTL0[
Aug 2 09:30:43 gramps kernel: [17183103.300000] DFSTATUS[
Aug 2 09:30:43 gramps kernel: [17183103.300000] STACK: 0xe2 0x164 0x179 0x3
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB count = 4
Aug 2 09:30:43 gramps kernel: [17183103.300000] Kernel NEXTQSCB = 3
Aug 2 09:30:43 gramps kernel: [17183103.300000] Card NEXTQSCB = 3
Aug 2 09:30:43 gramps kernel: [17183103.300000] QINFIFO entries:
Aug 2 09:30:43 gramps kernel: [17183103.300000] Waiting Queue entries:
Aug 2 09:30:43 gramps kernel: [17183103.300000] Disconnected Queue entries: 0:2
Aug 2 09:30:43 gramps kernel: [17183103.300000] QOUTFIFO entries:
Aug 2 09:30:43 gramps kernel: [17183103.300000] Sequencer Free SCB List: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31
Aug 2 09:30:43 gramps kernel: [17183103.300000] Sequencer SCB Info:
Aug 2 09:30:43 gramps kernel: [17183103.300000] 0 SCB_CONTROL[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_SCSIID[0x37] SCB_LUN[0x0] SCB_TAG[0x2]
Aug 2 09:30:43 gramps kernel: [17183103.300000] 1 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 2 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 3 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 4 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 5 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 6 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 7 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 8 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 9 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 10 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 11 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 12 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 13 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 14 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 15 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 16 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 17 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 18 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 19 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 20 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 21 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 22 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 23 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 24 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 25 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 26 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 27 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 28 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 29 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 30 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] 31 SCB_CONTROL[0x0] SCB_SCSIID[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[
Aug 2 09:30:43 gramps kernel: [17183103.300000] Pending list:
Aug 2 09:30:43 gramps kernel: [17183103.300000] 2 SCB_CONTROL[
Aug 2 09:30:43 gramps kernel: [17183103.300000] SCB_LUN[0x0]
Aug 2 09:30:43 gramps kernel: [17183103.300000] Kernel Free SCB list: 1 0
Aug 2 09:30:43 gramps kernel: [17183103.300000] Untagged Q(3): 2
Aug 2 09:30:43 gramps kernel: [17183103.300000]
Aug 2 09:30:43 gramps kernel: [17183103.300000] <<<<<<<<<<<<<<<<< Dump Card State Ends >>>>>>>>>>>>>>>>>>
Aug 2 09:30:43 gramps kernel: [17183103.300000] (scsi2:A:3:0): Device is disconnected, re-queuing SCB
Aug 2 09:30:43 gramps kernel: [17183103.300000] Recovery code sleeping
Aug 2 09:30:43 gramps kernel: [17183103.300000] (scsi2:A:3:0): Abort Message Sent
Aug 2 09:30:43 gramps kernel: [17183103.304000] (scsi2:A:3:0): SCB 2 - Abort Completed.
Aug 2 09:30:43 gramps kernel: [17183103.304000] Recovery SCB completes
Aug 2 09:30:43 gramps kernel: [17183103.304000] Recovery code awake
Aug 2 09:30:43 gramps kernel: [17183103.304000] aic7xxx_abort returns 0x2002
The SCSI hardware is as follows:
[17181565.016000] scsi2 : Adaptec AIC7XXX EISA/VLB/PCI SCSI HBA DRIVER, Rev 7.0
[17181565.016000] <Adaptec 29160 Ultra160 SCSI adapter>
[17181565.016000] aic7892: Ultra160 Wide Channel A, SCSI Id=7, 32/253 SCBs
[17181565.016000]
[17181565.040000] Vendor: ECRIX Model: VXA-1 Rev: 2B7B
[17181565.040000] Type: Sequential-Access ANSI SCSI revision: 02
[17181565.040000] target2:0:0: Beginning Domain Validation
[17181565.096000] target2:0:0: wide asynchronous
[17181565.124000] target2:0:0: FAST-20 WIDE SCSI 40.0 MB/s ST (50 ns, offset 32)
[17181565.148000] target2:0:0: Domain Validation skipping write tests
[17181565.148000] target2:0:0: Ending Domain Validation
[17181565.184000] st: Version 20050830, fixed bufsize 32768, s/g segs 256
[17181565.184000] st 2:0:0:0: Attached scsi tape st0<4>st0: try direct i/o: yes (alignment 512 B), max page reachable by HBA 1048575
[17181565.216000] st 2:0:0:0: Attached scsi generic sg0 type 1
[17181565.696000] Vendor: SPECTRA Model: 215 Rev: E015
[17181565.696000] Type: Medium Changer ANSI SCSI revision: 02
[17181565.696000] target2:0:3: Beginning Domain Validation
[17181565.748000] target2:0:3: Ending Domain Validation
[17181565.748000] 2:0:3:0: Attached scsi generic sg1 type 8
[17181568.608000] PCI: Enabling device 0000:08:06.0 (0116 -> 0117)
[17181568.608000] ACPI: PCI Interrupt 0000:08:06.0[A] -> GSI 25 (level, low) -> IRQ 193
[17181583.624000] scsi3 : Adaptec AIC7XXX EISA/VLB/PCI SCSI HBA DRIVER, Rev 7.0
[17181583.624000] <Adaptec aic7880 Ultra SCSI adapter>
[17181583.624000] aic7880: Ultra Single Channel A, SCSI Id=7, 16/253 SCBs
[17181583.624000]
[17181584.948000] Vendor: NEC Model: CD-ROM DRIVE:466 Rev: 1.06
[17181584.948000] Type: CD-ROM ANSI SCSI revision: 02
[17181584.948000] target3:0:5: Beginning Domain Validation
[17181584.952000] target3:0:5: FAST-20 SCSI 20.0 MB/s ST (50 ns, offset 15)
[17181584.952000] target3:0:5: Domain Validation skipping write tests
[17181584.952000] target3:0:5: Ending Domain Validation
[17181584.952000] 3:0:5:0: Attached scsi generic sg2 type 5
[17181585.224000] sr0: scsi3-mmc drive: 17x/40x cd/rw xa/form2 cdda tray
[17181585.224000] sr 3:0:5:0: Attached scsi CD-ROM sr0
[17181606.488000] target2:0:0: FAST-20 WIDE SCSI 40.0 MB/s ST (50 ns, offset 32)
[17181728.712000] st0: Block limits 1 - 245760 bytes.
I've tried different SCSI cards (although all aic7xxx family), different tape drives and different emulation modes on the tape library, but nothing works.
I though it may be similar to one or two other current bugs, but they all seem to be resolved in the latest kernel release while this problem still persists.
Thanks.
Changed in linux: | |
status: | Triaged → Fix Released |
As an additional note - unloading tapes from the drive seems to work fine; the problem is specifically with loading.