From owner-freebsd-stable Wed Mar 14 3:34:15 2001 Delivered-To: freebsd-stable@freebsd.org Received: from areilly.bpc-users.org (CPE-144-132-234-126.nsw.bigpond.net.au [144.132.234.126]) by hub.freebsd.org (Postfix) with SMTP id 49CA537B71A for ; Wed, 14 Mar 2001 03:34:06 -0800 (PST) (envelope-from areilly@bigpond.net.au) Received: (qmail 56524 invoked by uid 1000); 14 Mar 2001 11:34:03 -0000 From: "Andrew Reilly" Date: Wed, 14 Mar 2001 22:34:03 +1100 To: Jordan Hubbard Cc: stable@FreeBSD.ORG, gibbs@FreeBSD.ORG Subject: Re: Uh oh. Looks like something broke with the AHC driver.. Message-ID: <20010314223403.A56449@gurney.reilly.home> References: <20010314013116G.jkh@osd.bsdi.com> Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline User-Agent: Mutt/1.2.5i In-Reply-To: <20010314013116G.jkh@osd.bsdi.com>; from jkh@osd.bsdi.com on Wed, Mar 14, 2001 at 01:31:16AM -0800 Sender: owner-freebsd-stable@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.ORG On Wed, Mar 14, 2001 at 01:31:16AM -0800, Jordan Hubbard wrote: > I'm just testing the 4.3-BETA2 on my standard scratchbox (a dual PIII/500 > with two 9.1GB Quantum drives) and with the latest BETA build, I'm > seeing an unusual problem during extraction of the distribution bits: > > First, I start getting the following message looping on the > console: > > (da0:ahc0:0:0:0): Invalidating pack > > > (cd0:ahc0:0:4:0): SCB 0x12 - timed out in Data-out phase, SEQADDR == 0x8 > STACK == 0x3, 0x181, 0x16b, 0x0 > SXFRCTL0 == 0x80 > ahc0: Dumping Card State at SEQADDR 0x8 > SCSISEQ = 0x12, SBLKCTL = 0xa, SSTAT0 0x0 > SCB count = 90 > Kernel NEXTQSCB = 20 > Card NEXTQSCB = 20 > QINFIFO entries: > Waiting Queue entries: > Disconnected Queue entries: > > > Suffice it to say that the installation croaks at this point. Now > here's the interesting bit: This only happens reliably if I enable > soft updates on the root partition. Any real correlation? I have no > idea. Anyway, JFYI. If I can start reproducing it in other ways, > I'll let you know whether I've started to consider it a release > show-stopper bug or not. Here's a possible "me too". I haven't reported this before because (a) da2 is my backup Fujitsu MO drive, and it does do odd things occasionally, and (b) the backup disk is currently full and I haven't thrown the requisite round-tuit at it. If this actually represents a problem, and I can help with debugging it, please just say what you need... Following are a chunk of kernel messages from /var/log/messages and the contents of /var/run/dmesg.boot. The system is: FreeBSD gurney.reilly.home 4.3-BETA FreeBSD 4.3-BETA #7: Sun Mar 11 13:38:49 EST 2001 root@gurney.reilly.home:/usr/obj/usr/src/sys/GURNEY i386 Mar 14 03:11:24 gurney /kernel: (da2:ahc0:0:6:0): SCB 0x3 - timed out while idle, SEQADDR == 0x7 Mar 14 03:11:24 gurney /kernel: STACK == 0x3, 0x186, 0x147, 0xcd Mar 14 03:11:24 gurney /kernel: SXFRCTL0 == 0x80 Mar 14 03:11:24 gurney /kernel: ahc0: Dumping Card State at SEQADDR 0x7 Mar 14 03:11:24 gurney /kernel: SCSISEQ = 0x12, SBLKCTL = 0x2, SSTAT0 0x5 Mar 14 03:11:24 gurney /kernel: SCB count = 20 Mar 14 03:11:24 gurney /kernel: Kernel NEXTQSCB = 14 Mar 14 03:11:24 gurney /kernel: Card NEXTQSCB = 14 Mar 14 03:11:24 gurney /kernel: QINFIFO entries: Mar 14 03:11:24 gurney /kernel: Waiting Queue entries: Mar 14 03:11:24 gurney /kernel: Disconnected Queue entries: 0:3 Mar 14 03:11:24 gurney /kernel: QOUTFIFO entries: Mar 14 03:11:24 gurney /kernel: Sequencer Free SCB List: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 Mar 14 03:11:24 gurney /kernel: Pending list: 3 Mar 14 03:11:24 gurney /kernel: Kernel Free SCB list: 15 16 17 18 19 0 1 2 4 5 6 7 8 9 13 12 11 10 Mar 14 03:11:24 gurney /kernel: Untagged Q(6): 3 Mar 14 03:11:24 gurney /kernel: sg[0] - Addr 0x5285e00 : Length 512 Mar 14 03:11:24 gurney /kernel: (da2:ahc0:0:6:0): Queuing a BDR SCB Mar 14 03:11:24 gurney /kernel: (da2:ahc0:0:6:0): Bus Device Reset Message Sent Mar 14 03:11:24 gurney /kernel: (da2:ahc0:0:6:0): no longer in timeout, status = 34b Mar 14 03:11:24 gurney /kernel: ahc0: Bus Device Reset on A:6. 1 SCBs aborted Mar 14 03:12:24 gurney /kernel: (da2:ahc0:0:6:0): SCB 0x3 - timed out while idle, SEQADDR == 0x7 Mar 14 03:12:24 gurney /kernel: STACK == 0x3, 0x186, 0x147, 0xcd Mar 14 03:12:24 gurney /kernel: SXFRCTL0 == 0x80 Mar 14 03:12:24 gurney /kernel: ahc0: Dumping Card State at SEQADDR 0x7 Mar 14 03:12:24 gurney /kernel: SCSISEQ = 0x12, SBLKCTL = 0x2, SSTAT0 0x5 Mar 14 03:12:24 gurney /kernel: SCB count = 20 Mar 14 03:12:24 gurney /kernel: Kernel NEXTQSCB = 14 Mar 14 03:12:24 gurney /kernel: Card NEXTQSCB = 14 Mar 14 03:12:24 gurney /kernel: QINFIFO entries: Mar 14 03:12:24 gurney /kernel: Waiting Queue entries: Mar 14 03:12:24 gurney /kernel: Disconnected Queue entries: 0:3 Mar 14 03:12:24 gurney /kernel: QOUTFIFO entries: Mar 14 03:12:24 gurney /kernel: Sequencer Free SCB List: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 Mar 14 03:12:24 gurney /kernel: Pending list: 3 Mar 14 03:12:24 gurney /kernel: Kernel Free SCB list: 15 16 17 18 19 0 1 2 4 5 6 7 8 9 13 12 11 10 Mar 14 03:12:24 gurney /kernel: Untagged Q(6): 3 Mar 14 03:12:24 gurney /kernel: sg[0] - Addr 0x5285e00 : Length 512 Mar 14 03:12:24 gurney /kernel: (da2:ahc0:0:6:0): Queuing a BDR SCB Mar 14 03:12:24 gurney /kernel: (da2:ahc0:0:6:0): Bus Device Reset Message Sent Mar 14 03:12:24 gurney /kernel: (da2:ahc0:0:6:0): no longer in timeout, status = 34b Mar 14 03:12:24 gurney /kernel: ahc0: Bus Device Reset on A:6. 1 SCBs aborted Mar 14 03:13:54 gurney /kernel: (da2:ahc0:0:6:0): SCB 0x3 - timed out while idle, SEQADDR == 0x7 Mar 14 03:13:54 gurney /kernel: STACK == 0x3, 0x186, 0x147, 0xcd Mar 14 03:13:54 gurney /kernel: SXFRCTL0 == 0x80 Mar 14 03:13:54 gurney /kernel: ahc0: Dumping Card State at SEQADDR 0x7 Mar 14 03:13:54 gurney /kernel: SCSISEQ = 0x12, SBLKCTL = 0x2, SSTAT0 0x5 Mar 14 03:13:54 gurney /kernel: SCB count = 20 Mar 14 03:13:54 gurney /kernel: Kernel NEXTQSCB = 14 Mar 14 03:13:54 gurney /kernel: Card NEXTQSCB = 14 Mar 14 03:13:54 gurney /kernel: QINFIFO entries: Mar 14 03:13:54 gurney /kernel: Waiting Queue entries: Mar 14 03:13:54 gurney /kernel: Disconnected Queue entries: 0:3 Mar 14 03:13:54 gurney /kernel: QOUTFIFO entries: Mar 14 03:13:54 gurney /kernel: Sequencer Free SCB List: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 Mar 14 03:13:54 gurney /kernel: Pending list: 3 Mar 14 03:13:54 gurney /kernel: Kernel Free SCB list: 15 16 17 18 19 0 1 2 4 5 6 7 8 9 13 12 11 10 Mar 14 03:13:54 gurney /kernel: Untagged Q(6): 3 Mar 14 03:13:54 gurney /kernel: sg[0] - Addr 0x5285e00 : Length 512 Mar 14 03:13:54 gurney /kernel: (da2:ahc0:0:6:0): Queuing a BDR SCB Mar 14 03:13:54 gurney /kernel: (da2:ahc0:0:6:0): Bus Device Reset Message Sent Mar 14 03:13:54 gurney /kernel: (da2:ahc0:0:6:0): no longer in timeout, status = 34b Mar 14 03:13:54 gurney /kernel: ahc0: Bus Device Reset on A:6. 1 SCBs aborted Mar 14 03:14:54 gurney /kernel: (da2:ahc0:0:6:0): SCB 0x3 - timed out while idle, SEQADDR == 0x7 Mar 14 03:14:54 gurney /kernel: STACK == 0x3, 0x186, 0x147, 0xcd Mar 14 03:14:54 gurney /kernel: SXFRCTL0 == 0x80 Mar 14 03:14:54 gurney /kernel: ahc0: Dumping Card State at SEQADDR 0x7 Mar 14 03:14:54 gurney /kernel: SCSISEQ = 0x12, SBLKCTL = 0x2, SSTAT0 0x5 Mar 14 03:14:54 gurney /kernel: SCB count = 20 Mar 14 03:14:54 gurney /kernel: Kernel NEXTQSCB = 14 Mar 14 03:14:54 gurney /kernel: Card NEXTQSCB = 14 Mar 14 03:14:54 gurney /kernel: QINFIFO entries: Mar 14 03:14:54 gurney /kernel: Waiting Queue entries: Mar 14 03:14:54 gurney /kernel: Disconnected Queue entries: 0:3 Mar 14 03:14:54 gurney /kernel: QOUTFIFO entries: Mar 14 03:14:54 gurney /kernel: Sequencer Free SCB List: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 Mar 14 03:14:54 gurney /kernel: Pending list: 3 Mar 14 03:14:54 gurney /kernel: Kernel Free SCB list: 15 16 17 18 19 0 1 2 4 5 6 7 8 9 13 12 11 10 Mar 14 03:14:54 gurney /kernel: Untagged Q(6): 3 Mar 14 03:14:54 gurney /kernel: sg[0] - Addr 0x5285e00 : Length 512 Mar 14 03:14:54 gurney /kernel: (da2:ahc0:0:6:0): Queuing a BDR SCB Mar 14 03:14:54 gurney /kernel: (da2:ahc0:0:6:0): Bus Device Reset Message Sent Mar 14 03:14:54 gurney /kernel: (da2:ahc0:0:6:0): no longer in timeout, status = 34b Mar 14 03:14:54 gurney /kernel: ahc0: Bus Device Reset on A:6. 1 SCBs aborted Mar 14 03:15:42 gurney /kernel: (da2:ahc0:0:6:0): SCB 0x3 - timed out while idle, SEQADDR == 0x7 Mar 14 03:15:42 gurney /kernel: STACK == 0x3, 0x186, 0x147, 0xcd Mar 14 03:15:42 gurney /kernel: SXFRCTL0 == 0x80 Mar 14 03:15:42 gurney /kernel: ahc0: Dumping Card State at SEQADDR 0x7 Mar 14 03:15:42 gurney /kernel: SCSISEQ = 0x12, SBLKCTL = 0x2, SSTAT0 0x5 Mar 14 03:15:42 gurney /kernel: SCB count = 20 Mar 14 03:15:42 gurney /kernel: Kernel NEXTQSCB = 14 Mar 14 03:15:42 gurney /kernel: Card NEXTQSCB = 14 Mar 14 03:15:42 gurney /kernel: QINFIFO entries: Mar 14 03:15:42 gurney /kernel: Waiting Queue entries: Mar 14 03:15:42 gurney /kernel: Disconnected Queue entries: 0:3 Mar 14 03:15:42 gurney /kernel: QOUTFIFO entries: Mar 14 03:15:42 gurney /kernel: Sequencer Free SCB List: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 Mar 14 03:15:42 gurney /kernel: Pending list: 3 Mar 14 03:15:42 gurney /kernel: Kernel Free SCB list: 15 16 17 18 19 0 1 2 4 5 6 7 8 9 13 12 11 10 Mar 14 03:15:42 gurney /kernel: Untagged Q(6): 3 Mar 14 03:15:42 gurney /kernel: sg[0] - Addr 0x5285e00 : Length 512 Mar 14 03:15:42 gurney /kernel: (da2:ahc0:0:6:0): Queuing a BDR SCB Mar 14 03:15:42 gurney /kernel: (da2:ahc0:0:6:0): Bus Device Reset Message Sent Mar 14 03:15:42 gurney /kernel: (da2:ahc0:0:6:0): no longer in timeout, status = 34b Mar 14 03:15:42 gurney /kernel: ahc0: Bus Device Reset on A:6. 1 SCBs aborted Mar 14 03:15:42 gurney /kernel: da2: reading primary partition table: error reading fsbn 0 Copyright (c) 1992-2001 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.3-BETA #7: Sun Mar 11 13:38:49 EST 2001 root@gurney.reilly.home:/usr/obj/usr/src/sys/GURNEY Timecounter "i8254" frequency 1193182 Hz CPU: Pentium III/Pentium III Xeon/Celeron (499.15-MHz 686-class CPU) Origin = "GenuineIntel" Id = 0x672 Stepping = 2 Features=0x387f9ff real memory = 134152192 (131008K bytes) avail memory = 126623744 (123656K bytes) Preloaded elf kernel "kernel" at 0xc03e9000. Pentium Pro MTRR support enabled npx0: on motherboard npx0: INT 16 interface pcib0: on motherboard pci0: on pcib0 agp0: mem 0xe0000000-0xe3ffffff at device 0.0 on pci0 pcib1: at device 1.0 on pci0 pci1: on pcib1 pci1: at 0.0 irq 11 isab0: at device 7.0 on pci0 isa0: on isab0 atapci0: port 0xf000-0xf00f at device 7.1 on pci0 ata0: at 0x1f0 irq 14 on atapci0 ata1: at 0x170 irq 15 on atapci0 uhci0: port 0xd000-0xd01f irq 10 at device 7.2 on pci0 usb0: on uhci0 usb0: USB revision 1.0 uhub0: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub0: 2 ports with 2 removable, self powered chip0: port 0x5000-0x500f at device 7.3 on pci0 ed0: port 0xd400-0xd41f irq 5 at device 9.0 on pci0 ed0: address 00:00:e8:e1:8e:74, type NE2000 (16 bit) rl0: port 0xd800-0xd8ff mem 0xea001000-0xea0010ff irq 9 at device 10.0 on pci0 rl0: Ethernet address: 00:48:54:50:0f:88 miibus0: on rl0 rlphy0: on miibus0 rlphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto pcm0: port 0xdc00-0xdc3f irq 10 at device 11.0 on pci0 ahc0: port 0xe000-0xe0ff mem 0xea000000-0xea000fff irq 11 at device 12.0 on pci0 aic7880: Wide Channel A, SCSI Id=7, 16/255 SCBs fdc0: at port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on isa0 fdc0: FIFO enabled, 8 bytes threshold fd0: <1440-KB 3.5" drive> on fdc0 drive 0 atkbdc0: at port 0x60,0x64 on isa0 atkbd0: irq 1 on atkbdc0 psm0: irq 12 on atkbdc0 psm0: model Generic PS/2 mouse, device ID 0 vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 sc0: on isa0 sc0: VGA <16 virtual consoles, flags=0x200> sio0 at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0 sio0: type 16550A sio1 at port 0x2f8-0x2ff irq 3 on isa0 sio1: type 16550A ppc0: at port 0x378-0x37f irq 7 on isa0 ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mode ppc0: FIFO with 16/16/16 bytes threshold lpt0: on ppbus0 lpt0: Interrupt-driven port ppi0: on ppbus0 plip0: on ppbus0 IP packet filtering initialized, divert enabled, rule-based forwarding enabled, default to deny, logging limited to 100 packets/entry by default IPsec: Initialized Security Association Processing. ad0: 6149MB [13328/15/63] at ata0-master UDMA33 ad1: 6149MB [13328/15/63] at ata0-slave UDMA33 acd0: CDROM at ata1-master using UDMA33 Waiting 5 seconds for SCSI devices to settle Mounting root from ufs:/dev/ad0s2a da2 at ahc0 bus 0 target 6 lun 0 da2: Removable Optical SCSI-2 device da2: 10.000MB/s transfers (10.000MHz, offset 10) da2: 217MB (446325 512 byte sectors: 64H 32S/T 217C) -- Andrew To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-stable" in the body of the message