From owner-freebsd-stable Wed May 29 7:37:16 2002 Delivered-To: freebsd-stable@freebsd.org Received: from sv07e.atm-tzs.kmjeuro.com (sv07e.atm-tzs.kmjeuro.com [193.81.94.207]) by hub.freebsd.org (Postfix) with ESMTP id BCD3937B404 for ; Wed, 29 May 2002 07:36:33 -0700 (PDT) Received: from kmjeuro.com (adsl.sbg.kmjeuro.com [193.154.189.16]) (authenticated bits=0) by sv07e.atm-tzs.kmjeuro.com (8.12.3/8.12.3) with ESMTP id g4TEZhHw080469 for ; Wed, 29 May 2002 16:35:44 +0200 (CEST) (envelope-from k.joch@kmjeuro.com) Message-ID: <3CF4E73F.8030207@kmjeuro.com> Date: Wed, 29 May 2002 16:35:43 +0200 From: "Karl M. Joch" User-Agent: Mozilla/5.0 (X11; U; FreeBSD i386; en-US; rv:1.0rc2) Gecko/20020514 X-Accept-Language: en-us, en MIME-Version: 1.0 To: freebsd-stable@FreeBSD.ORG Subject: Re: 4.6-RC: indefinite wait buffer / (da0:ahc0:0:0:0): SCB 0x81 - timed out References: <20020529154501.A38504@deejai2.mch.fsc.net> Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit X-MailScanner: Mail Server protected by CTS Austria www.ctseuro.com Message found to be clean Sender: owner-freebsd-stable@FreeBSD.ORG Precedence: bulk List-ID: List-Archive: (Web Archive) List-Help: (List Instructions) List-Subscribe: List-Unsubscribe: X-Loop: FreeBSD.ORG never heard of that fix. so I changed a SCSI controller today because of this message :-(. ahc0: port 0xe100-0xe1ff mem 0x84000000-0x84000fff irq 9 at device 13.0 on pci0 aic7870: Single Channel A, SCSI Id=7, 16/253 SCBs May 28 19:02:13 router /kernel: (da0:ahc0:0:0:0): SCB 0x24 - timed out May 28 19:02:28 router /kernel: ahc0: Dumping Card State while idle, at SEQADDR 0x7 May 28 19:02:28 router /kernel: ACCUM = 0xcd, SINDEX = 0x64, DINDEX = 0x65, ARG_2 = 0x3 May 28 19:02:28 router /kernel: HCNT = 0x0 SCBPTR = 0x9 May 28 19:02:28 router /kernel: SCSISEQ = 0x12, SBLKCTL = 0x0 May 28 19:02:28 router /kernel: DFCNTRL = 0x0, DFSTATUS = 0x2d May 28 19:02:28 router /kernel: LASTPHASE = 0x1, SCSISIGI = 0x0, SXFRCTL0 = 0x80 May 28 19:02:28 router /kernel: SSTAT0 = 0x5, SSTAT1 = 0xa May 28 19:02:28 router /kernel: STACK == 0x3, 0x16c, 0x13c, 0x0 May 28 19:02:28 router /kernel: SCB count = 110 May 28 19:02:28 router /kernel: Kernel NEXTQSCB = 25 May 28 19:02:28 router /kernel: Card NEXTQSCB = 25 May 28 19:02:28 router /kernel: QINFIFO entries: May 28 19:02:29 router /kernel: Waiting Queue entries: May 28 19:02:29 router /kernel: Disconnected Queue entries: 9:15 15:3 6:20 4:16 13:34 11:39 10:27 2:108 3:13 8:14 5:38 12:32 0:28 14:18 1:22 7:36 May 28 19:02:29 router /kernel: QOUTFIFO entries: May 28 19:02:29 router /kernel: Sequencer Free SCB List: May 28 19:02:29 router /kernel: Sequencer SCB Info: 0(c 0x64, s 0x7, l 0, t 0x1c) 1(c 0x64, s 0x7, l 0, t 0x16) 2(c 0x64, s 0x7, l 0, t 0x6c) 3(c 0x64, s 0x May 28 19:02:29 router /kernel: Pending list: 15(c 0x60, s 0x7, l 0), 7(c 0x64, s 0x7, l 0), 21(c 0x64, s 0x7, l 0), 29(c 0x64, s 0x7, l 0), 24(c 0x64, s 0x May 28 19:02:29 router /kernel: Kernel Free SCB list: 12 33 2 6 10 9 5 11 26 17 4 23 35 19 0 37 31 109 90 91 92 93 94 95 96 97 98 99 80 81 82 83 84 85 86 87 May 28 19:02:29 router /kernel: sg[0] - Addr 0x38a1000 : Length 4096 May 28 19:02:29 router /kernel: sg[1] - Addr 0x13c2000 : Length 4096 May 28 19:02:29 router /kernel: (da0:ahc0:0:0:0): Queuing a BDR SCB May 28 19:02:29 router /kernel: (da0:ahc0:0:0:0): Bus Device Reset Message Sent May 28 19:02:29 router /kernel: (da0:ahc0:0:0:0): no longer in timeout, status = 34b May 28 19:02:29 router /kernel: ahc0: Bus Device Reset on A:0. 22 SCBs aborted Karl Martin Kraemer wrote: > Hello all, > > My aic7880 Ultra SCSI on-board adapter had been working painlessly > for a long time (after having SCSI time-out problems about a year ago, > which were fixed at that time by Justin's source code correction in the > FreeBSD-STABLE sources). Now, with 4.6-RC, the problems re-appear, > as soon as the machine becomes I/O-loaded (saving to DAT). > The effect is that the machine freezes for 30 seconds. > > Here's the error list which is displayed after recovering from the timeout: > May 29 10:49:52 deejai2 /kernel: swap_pager: indefinite wait buffer: device: #da/0x20001, blkno: 44224, size: 4096 > May 29 10:50:18 deejai2 /kernel: swap_pager: indefinite wait buffer: device: #da/0x20001, blkno: 44224, size: 4096 > May 29 10:50:18 deejai2 /kernel: swap_pager: indefinite wait buffer: device: #da/0x20001, blkno: 81976, size: 4096 > May 29 10:50:18 deejai2 /kernel: (da0:ahc0:0:0:0): SCB 0x81 - timed out > May 29 10:50:18 deejai2 /kernel: ahc0: Dumping Card State while idle, at SEQADDR 0x175 > May 29 10:50:18 deejai2 /kernel: ACCUM = 0x3, SINDEX = 0x20, DINDEX = 0xb8, ARG_2 = 0x20 > May 29 10:50:18 deejai2 /kernel: HCNT = 0x0 SCBPTR = 0xe > May 29 10:50:18 deejai2 /kernel: SCSISEQ = 0x12, SBLKCTL = 0x2 > May 29 10:50:18 deejai2 /kernel: DFCNTRL = 0xc, DFSTATUS = 0x6d > May 29 10:50:18 deejai2 /kernel: LASTPHASE = 0x1, SCSISIGI = 0x0, SXFRCTL0 = 0x80 > May 29 10:50:18 deejai2 /kernel: SSTAT0 = 0x5, SSTAT1 = 0xa > May 29 10:50:18 deejai2 /kernel: STACK == 0x16a, 0x147, 0x0, 0xe > May 29 10:50:18 deejai2 /kernel: SCB count = 140 > May 29 10:50:18 deejai2 /kernel: Kernel NEXTQSCB = 96 > May 29 10:50:18 deejai2 /kernel: Card NEXTQSCB = 129 > May 29 10:50:19 deejai2 /kernel: QINFIFO entries: 129 30 51 10 33 18 113 6 86 49 83 119 17 44 121 36 67 41 > May 29 10:50:19 deejai2 /kernel: Waiting Queue entries: > May 29 10:50:19 deejai2 /kernel: Disconnected Queue entries: > May 29 10:50:19 deejai2 /kernel: QOUTFIFO entries: > May 29 10:50:19 deejai2 /kernel: Sequencer Free SCB List: 1 13 15 6 2 3 4 10 5 12 7 9 8 11 0 > May 29 10:50:19 deejai2 /kernel: Sequencer SCB Info: 0(c 0x68, s 0xf, l 0, t 0xff) 1(c 0x68, s 0xf, l 0, t 0xff) 2(c 0x68, s 0xf, l 0, t 0xff) 3(c 0x68, s 0xf, l 0, t 0xff) 4(c 0x68, s 0xf, l 0, t 0xff) 5(c 0x68, s 0xf, l 0, t 0xff) 6(c 0x68, s 0xf, l 0, t 0xff) 7(c 0x68, s 0xf, l 0, t 0xff) 8(c 0x68, s 0xf, l 0, t 0xff) 9(c 0x68, s 0xf, l 0, t 0xff) 10(c 0x68, s 0xf, l 0, t 0xff) 11(c 0x68, s 0xf, l 0, t 0xff) 12(c 0x68, s 0xf, l 0, t 0xff) 13(c 0x68, s 0xf, l 0, t 0xff) 14(c 0x68, s 0xf, l 0, t 0xff) 15(c 0x68, s 0xf, l 0, t 0xff) > May 29 10:50:19 deejai2 /kernel: Pending list: 41(c 0x6a, s 0xf, l 0), 67(c 0x68, s 0xf, l 0), 36(c 0x68, s 0xf, l 0), 121(c 0x68, s 0xf, l 0), 44(c 0x6a, s 0xf, l 0), 17(c 0x68, s 0xf, l 0), 119(c 0x68, s 0xf, l 0), 83(c 0x68, s 0xf, l 0), 49(c 0x68, s 0xf, l 0), 86(c 0x68, s 0xf, l 0), 6(c 0x68, s 0xf, l 0), 113(c 0x68, s 0xf, l 0), 18(c 0x68, s 0xf, l 0), 33(c 0x68, s 0xf, l 0), 10(c 0x68, s 0xf, l 0), 51(c 0x68, s 0xf, l 0), 30(c 0x68, s 0xf, l 0), 129(c 0x68, s 0xf, l 0) > May 29 10:50:19 deejai2 /kernel: Kernel Free SCB list: 55 38 22 53 71 114 64 101 34 63 79 12 56 123 100 104 120 23 103 124 74 125 43 4 40 61 0 5 69 25 78 26 20 29 108 7 127 37 65 106 118 80 72 57 54 27 115 73 31 21 16 128 68 76 13 58 59 28 111 19 105 102 116 84 9 91 89 32 66 81 35 77 107 39 122 8 60 11 47 88 46 98 50 1 2 82 48 70 97 15 92 90 14 126 95 99 94 24 45 87 62 110 52 85 93 3 109 117 42 75 112 139 138 137 136 135 134 133 132 131 130 > May 29 10:50:19 deejai2 /kernel: sg[0] - Addr 0x924e000 : Length 1024 > May 29 10:50:19 deejai2 /kernel: (da0:ahc0:0:0:0): SCB 129: Immediate reset. Flags = 0x4020 > May 29 10:50:19 deejai2 /kernel: (da0:ahc0:0:0:0): no longer in timeout, status = 34b > May 29 10:50:19 deejai2 /kernel: ahc0: Issued Channel A Bus Reset. 18 SCBs aborted > > and later again: > May 29 15:25:51 deejai2 /kernel: swap_pager: indefinite wait buffer: device: #da/0x20001, blkno: 19936, size: 4096 > May 29 15:26:10 deejai2 /kernel: (da0:ahc0:0:0:0): SCB 0x7e - timed out > May 29 15:26:10 deejai2 /kernel: ahc0: Dumping Card State while idle, at SEQADDR 0x175 > May 29 15:26:10 deejai2 /kernel: ACCUM = 0x3, SINDEX = 0x20, DINDEX = 0xb8, ARG_2 = 0x1f > May 29 15:26:10 deejai2 /kernel: HCNT = 0x0 SCBPTR = 0x7 > May 29 15:26:10 deejai2 /kernel: SCSISEQ = 0x12, SBLKCTL = 0x2 > May 29 15:26:10 deejai2 /kernel: DFCNTRL = 0xc, DFSTATUS = 0x6d > May 29 15:26:10 deejai2 /kernel: LASTPHASE = 0x1, SCSISIGI = 0x0, SXFRCTL0 = 0x80 > May 29 15:26:10 deejai2 /kernel: SSTAT0 = 0x5, SSTAT1 = 0xa > May 29 15:26:10 deejai2 /kernel: STACK == 0x16a, 0x147, 0xe, 0xe > May 29 15:26:10 deejai2 /kernel: SCB count = 140 > May 29 15:26:10 deejai2 /kernel: Kernel NEXTQSCB = 121 > May 29 15:26:10 deejai2 /kernel: Card NEXTQSCB = 126 > May 29 15:26:10 deejai2 /kernel: QINFIFO entries: 126 4 104 30 58 6 72 0 81 66 93 57 124 97 54 > May 29 15:26:10 deejai2 /kernel: Waiting Queue entries: > May 29 15:26:10 deejai2 /kernel: Disconnected Queue entries: > May 29 15:26:10 deejai2 /kernel: QOUTFIFO entries: > May 29 15:26:10 deejai2 /kernel: Sequencer Free SCB List: 4 14 1 9 8 15 10 12 6 11 3 0 13 2 5 > May 29 15:26:11 deejai2 /kernel: Sequencer SCB Info: 0(c 0x68, s 0xf, l 0, t 0xff) 1(c 0x68, s 0xf, l 0, t 0xff) 2(c 0x68, s 0xf, l 0, t 0xff) 3(c 0x68, s 0xf, l 0, t 0xff) 4(c 0x68, s 0xf, l 0, t 0xff) 5(c 0x68, s 0xf, l 0, t 0xff) 6(c 0x68, s 0xf, l 0, t 0xff) 7(c 0x68, s 0xf, l 0, t 0xff) 8(c 0x68, s 0xf, l 0, t 0xff) 9(c 0x68, s 0xf, l 0, t 0xff) 10(c 0x68, s 0xf, l 0, t 0xff) 11(c 0x68, s 0xf, l 0, t 0xff) 12(c 0x68, s 0xf, l 0, t 0xff) 13(c 0x68, s 0xf, l 0, t 0xff) 14(c 0x68, s 0xf, l 0, t 0xff) 15(c 0x68, s 0xf, l 0, t 0xff) > May 29 15:26:11 deejai2 /kernel: Pending list: 54(c 0x68, s 0xf, l 0), 97(c 0x6a, s 0xf, l 0), 124(c 0x68, s 0xf, l 0), 57(c 0x6a, s 0xf, l 0), 93(c 0x48, s 0x1f, l 0), 66(c 0x68, s 0xf, l 0), 81(c 0x68, s 0xf, l 0), 0(c 0x68, s 0xf, l 0), 72(c 0x68, s 0xf, l 0), 6(c 0x68, s 0xf, l 0), 58(c 0x68, s 0xf, l 0), 30(c 0x68, s 0xf, l 0), 104(c 0x68, s 0xf, l 0), 4(c 0x68, s 0xf, l 0), 126(c 0x68, s 0xf, l 0) > May 29 15:26:11 deejai2 /kernel: Kernel Free SCB list: 7 79 39 43 75 38 46 55 29 87 86 2 9 95 122 89 62 33 44 103 53 70 123 110 20 23 3 88 92 50 51 45 64 22 36 99 68 82 14 112 80 127 49 84 100 98 113 63 106 12 120 109 117 101 32 16 115 125 74 105 37 118 69 107 83 56 18 19 96 8 76 40 42 15 48 60 73 61 119 28 78 65 128 5 26 41 17 10 24 1 11 71 77 47 27 13 31 91 25 90 129 59 108 34 94 21 67 102 85 114 116 52 111 35 139 138 137 136 135 134 133 132 131 130 > May 29 15:26:11 deejai2 /kernel: Untagged Q(1): 93 > May 29 15:26:11 deejai2 /kernel: sg[0] - Addr 0x4e3b000 : Length 4096 > May 29 15:26:11 deejai2 /kernel: sg[1] - Addr 0x833c000 : Length 4096 > May 29 15:26:11 deejai2 /kernel: sg[2] - Addr 0x60fd000 : Length 4096 > May 29 15:26:11 deejai2 /kernel: sg[3] - Addr 0x913e000 : Length 4096 > May 29 15:26:11 deejai2 /kernel: sg[4] - Addr 0x6edf000 : Length 4096 > May 29 15:26:11 deejai2 /kernel: sg[5] - Addr 0x8180000 : Length 4096 > May 29 15:26:11 deejai2 /kernel: sg[6] - Addr 0xf81000 : Length 4096 > May 29 15:26:11 deejai2 /kernel: sg[7] - Addr 0x8e22000 : Length 4096 > May 29 15:26:11 deejai2 /kernel: (da0:ahc0:0:0:0): SCB 126: Immediate reset. Flags = 0x4020 > May 29 15:26:11 deejai2 /kernel: (da0:ahc0:0:0:0): no longer in timeout, status = 34b > May 29 15:26:11 deejai2 /kernel: ahc0: Issued Channel A Bus Reset. 15 SCBs aborted > > Attached please find the dmesg output and the output of "pciconf -l". > > Can I supply any more information to track this problems down? > > Martin > > > ------------------------------------------------------------------------ > > Copyright (c) 1992-2002 The FreeBSD Project. > Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 > The Regents of the University of California. All rights reserved. > FreeBSD 4.6-RC #3: Fri May 24 17:06:58 CEST 2002 > martin@deejai2.mch.fsc.net:/usr/src/sys/compile/DEEJAI4B > Timecounter "i8254" frequency 1193182 Hz > CPU: Pentium II/Pentium II Xeon/Celeron (267.27-MHz 686-class CPU) > Origin = "GenuineIntel" Id = 0x634 Stepping = 4 > Features=0x80f9ff > real memory = 201318400 (196600K bytes) > avail memory = 190353408 (185892K bytes) > Preloaded elf kernel "kernel" at 0xc0544000. > Preloaded userconfig_script "/boot/kernel.conf" at 0xc054409c. > Preloaded elf module "splash_pcx.ko" at 0xc05440ec. > Preloaded elf module "vesa.ko" at 0xc0544190. > Preloaded splash_image_data "/boot/saturn_2.pcx" at 0xc054422c. > VESA: v2.0, 2048k memory, flags:0x1, mode table:0xc0537282 (1000022) > VESA: Matrox Graphics Inc. > Pentium Pro MTRR support enabled > md0: Malloc disk > Using $PIR table, 9 entries at 0xc00fdf30 > npx0: on motherboard > npx0: INT 16 interface > pcib0: on motherboard > pci0: on pcib0 > pcib1: at device 1.0 on pci0 > pci1: on pcib1 > ahc0: port 0xf800-0xf8ff mem 0xfedfb000-0xfedfbfff irq 9 at device 6.0 on pci0 > ahc0: Using left over BIOS settings > aic7880: Ultra Wide Channel A, SCSI Id=15, 16/253 SCBs > isab0: at device 7.0 on pci0 > isa0: on isab0 > atapci0: port 0xfcf0-0xfcff at device 7.1 on pci0 > ata0: at 0x1f0 irq 14 on atapci0 > ata1: at 0x170 irq 15 on atapci0 > pci0: at 7.2 irq 9 > intpm0: port 0xf0b0-0xf0bf irq 9 at device 7.3 on pci0 > intpm0: I/O mapped f0b0 > intpm0: intr IRQ 9 enabled revision 0 > smbus0: on intsmb0 > smb0: on smbus0 > intpm0: PM I/O mapped f0c0 > ahc1: port 0xe000-0xe0ff mem 0xfedf9000-0xfedf9fff irq 9 at device 14.0 on pci0 > aic7880: Ultra Single Channel A, SCSI Id=7, 16/253 SCBs > xl0: <3Com 3c905-TX Fast Etherlink XL> port 0xe800-0xe83f irq 9 at device 18.0 on pci0 > xl0: Ethernet address: 00:10:4b:55:c4:88 > miibus0: on xl0 > nsphy0: on miibus0 > nsphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto > pci0: at 20.0 irq 9 > vt0 on isa0 > vt0: ega, mono, 9 scr, unknown kbd, [R3.20-b24] > vt0: driver is using old-style compatability shims > orm0: