Peter C. Lai
2008-Nov-21 09:51 UTC
ahc(4) on aic7899 wedges with a Tandberg LTO-2 sa drive
I've got a Tandberg TS 400 LTO-2 drive in a Dell PE1800 which is wedging ahc(4) after writing about 5 GB of data. I've attached dmesg.boot. uname -a: FreeBSD phoenix.simons-rock.edu 7.1-PRERELEASE FreeBSD 7.1-PRERELEASE #0: Fri Oct 17 23:17:38 EDT 2008 root@phoenix.simons-rock.edu:/usr/obj/usr/src/sys/PHOENIXPCL i386 I put in a tape, and mt -f /dev/sa0 status gives the following kernel message: Nov 21 12:06:28 phoenix kernel: (ahc0:A:6:0): Sending PPR bus_width 1, period 9, offset 7e, ppr_options 2 Nov 21 12:06:28 phoenix kernel: (ahc0:A:6:0): Received PPR width 1, period 9, offset 7e,options 2 Nov 21 12:06:28 phoenix kernel: Filtered to width 1, period 9, offset 7e, options 2 Nov 21 12:06:28 phoenix kernel: (sa0:ahc0:0:6:0): error 6 Nov 21 12:06:28 phoenix kernel: (sa0:ahc0:0:6:0): Unretryable Error Nov 21 12:06:28 phoenix kernel: (ahc0:A:6:0): Sending PPR bus_width 1, period 9, offset 7e, ppr_options 2 Nov 21 12:06:28 phoenix kernel: (ahc0:A:6:0): Received PPR width 1, period 9, offset 7e,options 2 Nov 21 12:06:28 phoenix kernel: Filtered to width 1, period 9, offset 7e, options 2 Nov 21 12:06:28 phoenix kernel: (sa0:ahc0:0:6:0): error 6 Nov 21 12:06:28 phoenix kernel: (sa0:ahc0:0:6:0): Unretryable Error Nov 21 12:06:28 phoenix kernel: (ahc0:A:6:0): Sending PPR bus_width 1, period 9, offset 7e, ppr_options 2 Nov 21 12:06:28 phoenix kernel: (ahc0:A:6:0): Received PPR width 1, period 9, offset 7e,options 2 Nov 21 12:06:28 phoenix kernel: Nov 21 12:06:28 phoenix kernel: Filtered to width 1, period 9, offset 7e, options 2 Nov 21 12:06:28 phoenix kernel: (sa0:ahc0:0:6:0): error 6 Nov 21 12:06:28 phoenix kernel: (sa0:ahc0:0:6:0): Unretryable Error Nov 21 12:07:30 phoenix kernel: (ahc0:A:6:0): Sending PPR bus_width 1, period 9, offset 7e, ppr_options 2 Nov 21 12:07:30 phoenix kernel: (ahc0:A:6:0): Received PPR width 1, period 9, offset 7e,options 2 Nov 21 12:07:30 phoenix kernel: Filtered to width 1, period 9, offset 7e, options 2 Nov 21 12:07:30 phoenix kernel: (sa0:ahc0:0:6:0): Retrying Command but it returns ok at the end: Mode Density Blocksize bpi Compression Current: 0x42 variable 0 0x1 ---------available modes--------- 0: 0x42 variable 0 0x1 1: 0x42 variable 0 0x1 2: 0x42 variable 0 0x1 3: 0x42 variable 0 0x1 --------------------------------- Current Driver State: at rest. --------------------------------- File Number: 0 Record Number: 0 Residual Count 0 I am using star bs=32k -no-fifo to write to the tape. ahc(4) crashes regardless of setting the blocksize on the hardware (to 32k) or not: Nov 21 08:58:15 phoenix kernel: ahc0: Recovery Initiated Nov 21 08:58:15 phoenix kernel: >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<< Nov 21 08:58:15 phoenix kernel: ahc0: Dumping Card State while idle, at SEQADDR 0x8 Nov 21 08:58:15 phoenix kernel: Card was paused Nov 21 08:58:15 phoenix kernel: ACCUM = 0x4, SINDEX = 0x67, DINDEX = 0x27, ARG_2 = 0x3b Nov 21 08:58:15 phoenix kernel: HCNT = 0x0 SCBPTR = 0x0 Nov 21 08:58:15 phoenix kernel: SCSIPHASE[0x0] SCSISIGI[0x0] ERROR[0x0] SCSIBUSL[0x0] Nov 21 08:58:15 phoenix kernel: LASTPHASE[0x1]:(P_BUSFREE) SCSISEQ[0x12]:(ENAUTOATNP|ENRSELI) Nov 21 08:58:15 phoenix kernel: SBLKCTL[0xa]:(SELWIDE|SELBUSB) SCSIRATE[0x0] SEQCTL[0x10]:(FASTMODE) Nov 21 08:58:15 phoenix kernel: SEQ_FLAGS[0xc0]:(NO_CDB_SENT|NOT_IDENTIFIED) SSTAT0[0x0] Nov 21 08:58:15 phoenix kernel: SSTAT1[0x0] SSTAT2[0x0] SSTAT3[0x0] SIMODE0[0x8]:(ENSWRAP) Nov 21 08:58:15 phoenix kernel: SIMODE1[0xa4]:(ENSCSIPERR|ENSCSIRST|ENSELTIMO) SXFRCTL0[0x80]:(DFON) Nov 21 08:58:15 phoenix kernel: DFCNTRL[0x0] DFSTATUS[0x89]:(FIFOEMP|HDONE|PRELOAD_AVAIL) Nov 21 08:58:15 phoenix kernel: STACK: 0x0 0x164 0x179 0x3 Nov 21 08:58:15 phoenix kernel: SCB count = 254 Nov 21 08:58:15 phoenix kernel: Kernel NEXTQSCB = 247 Nov 21 08:58:15 phoenix kernel: Card NEXTQSCB = 247 Nov 21 08:58:15 phoenix kernel: QINFIFO entries: Nov 21 08:58:15 phoenix kernel: Waiting Queue entries: Nov 21 08:58:15 phoenix kernel: Disconnected Queue entries: 0:238 Nov 21 08:58:15 phoenix kernel: QOUTFIFO entries: Nov 21 08:58:15 phoenix kernel: 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 Nov 21 08:58:15 phoenix kernel: Sequencer SCB Info: Nov 21 08:58:15 phoenix kernel: 0 SCB_CONTROL[0x44]:(DISCONNECTED|DISCENB) SCB_SCSIID[0x67] Nov 21 08:58:15 phoenix kernel: SCB_LUN[0x0] SCB_TAG[0xee] Nov 21 08:58:15 phoenix kernel: 1 SCB_CONTROL[0x0] SCB_SCSIID[0xff]:(TWIN_CHNLB|OID|TWIN_TID) Nov 21 08:58:15 phoenix kernel: SCB_LUN[0xff]:(SCB_XFERLEN_ODD|LID) SCB_TAG[0xff] Nov 21 08:58:15 phoenix kernel: 2 SCB_CONTROL[0x0] SCB_SCSIID[0xff]:(TWIN_CHNLB|OID|TWIN_TID) Nov 21 08:58:15 phoenix kernel: SCB_LUN[0xff]:(SCB_XFERLEN_ODD|LID) SCB_TAG[0xff] Nov 21 08:58:15 phoenix kernel: 3 SCB_CONTROL[0x0] SCB_SCSIID[0xff]:(TWIN_CHNLB|OID|TWIN_TID) Nov 21 08:58:15 phoenix kernel: SCB_LUN[0xff]:(SCB_XFERLEN_ODD|LID) SCB_TAG[0xff] Nov 21 08:58:15 phoenix kernel: 4 SCB_CONTROL[0x0] SCB_SCSIID[0xff]:(TWIN_CHNLB|OID|TWIN_TID) ... Nov 21 08:58:15 phoenix kernel: 31 SCB_CONTROL[0x0] SCB_SCSIID[0xff]:(TWIN_CHNLB|OID|TWIN_TID) Nov 21 08:58:15 phoenix kernel: SCB_LUN[0xff]:(SCB_XFERLEN_ODD|LID) SCB_TAG[0xff] Nov 21 08:58:15 phoenix kernel: Pending list: Nov 21 08:58:15 phoenix kernel: 238 SCB_CONTROL[0x40]:(DISCENB) SCB_SCSIID[0x67] SCB_LUN[0x0] Nov 21 08:58:15 phoenix kernel: Kernel Free SCB list: 239 240 241 242 243 244 245 246 248 249 250 251 252 253 237 236 235 234 233 232 231 230 229 228 227 226 225 224 223 222 221 220 219 218 217 216 215 214 213 212 211 210 209 208 207 206 205 204 203 202 201 200 199 198 197 196 195 194 193 192 191 190 189 188 187 186 185 184 183 182 181 180 179 178 177 176 175 174 173 172 171 170 169 168 167 166 165 164 163 162 161 160 159 158 157 156 155 154 153 152 151 150 149 148 147 146 145 144 143 142 141 140 139 138 137 136 135 134 133 132 131 130 129 128 127 126 125 124 123 122 121 120 119 118 117 116 115 114 113 112 111 110 109 108 107 106 105 104 103 102 101 100 99 98 97 96 95 94 93 92 91 90 89 88 87 86 85 84 83 82 81 80 79 78 77 76 75 74 73 72 71 70 69 68 67 66 65 64 63 62 61 60 59 58 57 56 55 54 53 52 51 50 49 48 47 46 45 44 43 42 41 40 39 38 37 36 35 34 33 32 31 30 29 28 27 26 25 24 23 22 21 20 19 18 17 16 15 14 13 12 11 10 9 8 7 6 5 4 3 2 1 0 Nov 21 08:58:15 phoenix kernel: Untagged Q(6): 238 Nov 21 08:58:15 phoenix kernel: Nov 21 08:58:15 phoenix kernel: <<<<<<<<<<<<<<<<< Dump Card State Ends >>>>>>>>>>>>>>>>>> Nov 21 08:58:15 phoenix kernel: (sa0:ahc0:0:6:0): SCB 0xee - timed out Nov 21 08:58:15 phoenix kernel: sg[0] - Addr 0x21706000 : Length 4096 Nov 21 08:58:15 phoenix kernel: sg[1] - Addr 0x217aa000 : Length 4096 Nov 21 08:58:15 phoenix kernel: sg[2] - Addr 0x2183b000 : Length 4096 ... Nov 21 08:58:15 phoenix kernel: sg[7] - Addr 0x221f6000 : Length 4096 Nov 21 08:58:15 phoenix kernel: (sa0:ahc0:0:6:0): Queuing a BDR SCB Nov 21 08:58:15 phoenix kernel: Infinite interrupt loop, INTSTAT = 0ahc0: Timedout SCBs already complete. Interrupts may not be functioning. Nov 21 08:58:17 phoenix kernel: Infinite interrupt loop, INTSTAT = 0ahc0: Recovery Initiated Nov 21 08:58:17 phoenix kernel: >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<< Nov 21 08:58:17 phoenix kernel: ahc0: Dumping Card State while idle, at SEQADDR 0x18 Nov 21 08:58:17 phoenix kernel: Card was paused ... Nov 21 08:58:17 phoenix kernel: (sa0:ahc0:0:6:0): no longer in timeout, status = 24b Nov 21 08:58:17 phoenix kernel: ahc0: target 6 using 8bit transfers Nov 21 08:58:17 phoenix kernel: ahc0: target 6 using asynchronous transfers Nov 21 08:58:17 phoenix kernel: ahc0: Issued Channel A Bus Reset. 1 SCBs aborted Nov 21 08:58:17 phoenix kernel: (sa0:ahc0:0:6:0): Command timed out Nov 21 08:58:17 phoenix kernel: (sa0:ahc0:0:6:0): error 5 Nov 21 08:58:17 phoenix kernel: (sa0:ahc0:0:6:0): Retries Exausted Nov 21 08:58:17 phoenix kernel: ahc0: Timedout SCBs already complete. Interrupts may not be functioning. Nov 21 08:58:17 phoenix kernel: (ahc0:A:6:0): Sending PPR bus_width 1, period 9, offset 7e, ppr_options 2 Nov 21 08:58:17 phoenix kernel: (ahc0:A:6:0): Received PPR width 1, period 9, offset 7e,options 2 Nov 21 08:58:17 phoenix kernel: Filtered to width 1, period 9, offset 7e, options 2 Nov 21 08:58:17 phoenix kernel: ahc0: target 6 using 16bit transfers Nov 21 08:58:17 phoenix kernel: ahc0: target 6 synchronous at 80.0MHz DT, offset = 0x7e Nov 21 09:02:17 phoenix kernel: ahc0: Recovery Initiated ... until shutdown. A shutdown -r will still leave the controller wedged until a fullblow powercycle is done without the tape in the drive. Reading from tapes work just fine though. Also this identical hardware work just fine under Linux. Please help. Thanks! -- ==========================================================Peter C. Lai | Bard College at Simon's Rock Systems Administrator | 84 Alford Rd. Information Technology Svcs. | Gt. Barrington, MA 01230 USA peter AT simons-rock.edu | (413) 528-7428 ===========================================================