From owner-freebsd-stable Sun Jun 15 13:39:31 1997 Return-Path: Received: (from root@localhost) by hub.freebsd.org (8.8.5/8.8.5) id NAA24724 for stable-outgoing; Sun, 15 Jun 1997 13:39:31 -0700 (PDT) Received: from shell.uniserve.com (tom@shell.uniserve.com [204.244.210.252]) by hub.freebsd.org (8.8.5/8.8.5) with ESMTP id NAA24717 for ; Sun, 15 Jun 1997 13:39:29 -0700 (PDT) Received: from localhost (tom@localhost) by shell.uniserve.com (8.8.5/8.8.5) with SMTP id NAA08964; Sun, 15 Jun 1997 13:38:17 -0700 (PDT) X-Authentication-Warning: shell.uniserve.com: tom owned process doing -bs Date: Sun, 15 Jun 1997 13:38:17 -0700 (PDT) From: Tom To: Tomi Vainio cc: freebsd-stable@FreeBSD.ORG Subject: Re: ahc driver problem In-Reply-To: <199706151945.WAA17262@zeta.fidata.fi> Message-ID: MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII Sender: owner-stable@FreeBSD.ORG X-Loop: FreeBSD.org Precedence: bulk On Sun, 15 Jun 1997, Tomi Vainio wrote: > Once again I was making weekly world on my 2.2-stable machine. This > time system couldn't anymore recover on this timedout state. Normally > I see one or two SCB timedout messages on syslog. > > Tomppa It seems that sd0 is dying. Tom > Jun 15 22:09:54 tick /kernel: sd0(ahc0:0:0): SCB 0x3 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:09:54 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:11:01 tick /kernel: Ordered Tag queued > Jun 15 22:17:05 tick /kernel: SCSISIGI == 0x4 > Jun 15 22:17:06 tick /kernel: SEQADDR = 0x128 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:06 tick /kernel: Ordered Tag queued > Jun 15 22:17:06 tick /kernel: sd0(ahc0:0:0): SCB 0x6 timedout while recovery in progress > Jun 15 22:17:06 tick /kernel: sd0(ahc0:0:0): SCB 0x3 timedout while recovery in progress > Jun 15 22:17:06 tick /kernel: sd0(ahc0:0:0): SCB 0x2 timedout while recovery in progress > Jun 15 22:17:06 tick /kernel: sd0(ahc0:0:0): SCB 0x7 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:17:06 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:06 tick /kernel: sd0(ahc0:0:0): abort message in message buffer > Jun 15 22:17:06 tick /kernel: sd0(ahc0:0:0): SCB 0x3 - timed out in dataout phase, SCSISIGI == 0x14 > Jun 15 22:17:06 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:06 tick /kernel: ahc0: Issued Channel A Bus Reset. 4 SCBs aborted > Jun 15 22:17:06 tick /kernel: Clearing bus reset > Jun 15 22:17:06 tick /kernel: Clearing 'in-reset' flag > Jun 15 22:17:06 tick /kernel: sd0(ahc0:0:0): no longer in timeout > Jun 15 22:17:06 tick /kernel: sd0(ahc0:0:0): no longer in timeout > Jun 15 22:17:06 tick /kernel: sd0(ahc0:0:0): UNIT ATTENTION asc:29,0 > Jun 15 22:17:06 tick /kernel: sd0(ahc0:0:0): Power on, reset, or bus device reset occurred field replaceable unit: 1 > Jun 15 22:17:07 tick /kernel: , retries:1 > Jun 15 22:17:07 tick /kernel: sd0(ahc0:0:0): SCB 0x7 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:17:07 tick /kernel: SEQADDR = 0x128 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:07 tick /kernel: Ordered Tag queued > Jun 15 22:17:07 tick /kernel: sd0(ahc0:0:0): SCB 0x6 timedout while recovery in progress > Jun 15 22:17:07 tick /kernel: sd0(ahc0:0:0): SCB 0x3 timedout while recovery in progress > Jun 15 22:17:07 tick /kernel: sd0(ahc0:0:0): SCB 0x2 timedout while recovery in progress > Jun 15 22:17:07 tick /kernel: sd0(ahc0:0:0): SCB 0x7 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:17:07 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:07 tick /kernel: sd0(ahc0:0:0): abort message in message buffer > Jun 15 22:17:07 tick /kernel: sd0(ahc0:0:0): SCB 0x3 - timed out in dataout phase, SCSISIGI == 0x14 > Jun 15 22:17:07 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:07 tick /kernel: ahc0: Issued Channel A Bus Reset. 4 SCBs aborted > Jun 15 22:17:07 tick /kernel: Clearing bus reset > Jun 15 22:17:07 tick /kernel: Clearing 'in-reset' flag > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): no longer in timeout > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): no longer in timeout > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): UNIT ATTENTION asc:29,0 > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): Power on, reset, or bus device reset occurred field replaceable unit: 1 > Jun 15 22:17:08 tick /kernel: , retries:4 > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): SCB 0x7 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:17:08 tick /kernel: SEQADDR = 0x128 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:08 tick /kernel: Ordered Tag queued > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): SCB 0x6 timedout while recovery in progress > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): SCB 0x3 timedout while recovery in progress > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): SCB 0x2 timedout while recovery in progress > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): SCB 0x7 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:17:08 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): abort message in message buffer > Jun 15 22:17:08 tick /kernel: sd0(ahc0:0:0): SCB 0x3 - timed out in dataout phase, SCSISIGI == 0x14 > Jun 15 22:17:08 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:09 tick /kernel: ahc0: Issued Channel A Bus Reset. 4 SCBs aborted > Jun 15 22:17:09 tick /kernel: Clearing bus reset > Jun 15 22:17:09 tick /kernel: Clearing 'in-reset' flag > Jun 15 22:17:09 tick /kernel: sd0(ahc0:0:0): no longer in timeout > Jun 15 22:17:09 tick /kernel: sd0(ahc0:0:0): no longer in timeout > Jun 15 22:17:09 tick /kernel: sd0(ahc0:0:0): UNIT ATTENTION asc:29,0 > Jun 15 22:17:09 tick /kernel: sd0(ahc0:0:0): Power on, reset, or bus device reset occurred field replaceable unit: 1 > Jun 15 22:17:09 tick /kernel: , retries:2 > Jun 15 22:17:09 tick /kernel: sd0(ahc0:0:0): SCB 0x7 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:17:09 tick /kernel: SEQADDR = 0x128 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:09 tick /kernel: Ordered Tag queued > Jun 15 22:17:09 tick /kernel: sd0(ahc0:0:0): SCB 0x6 timedout while recovery in progress > Jun 15 22:17:09 tick /kernel: sd0(ahc0:0:0): SCB 0x3 timedout while recovery in progress > Jun 15 22:17:09 tick /kernel: sd0(ahc0:0:0): SCB 0x2 timedout while recovery in progress > Jun 15 22:17:09 tick /kernel: sd0(ahc0:0:0): SCB 0x7 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:17:10 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:10 tick /kernel: sd0(ahc0:0:0): abort message in message buffer > Jun 15 22:17:10 tick /kernel: sd0(ahc0:0:0): SCB 0x3 - timed out in dataout phase, SCSISIGI == 0x14 > Jun 15 22:17:10 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:10 tick /kernel: ahc0: Issued Channel A Bus Reset. 4 SCBs aborted > Jun 15 22:17:10 tick /kernel: Clearing bus reset > Jun 15 22:17:10 tick /kernel: Clearing 'in-reset' flag > Jun 15 22:17:10 tick /kernel: sd0(ahc0:0:0): no longer in timeout > Jun 15 22:17:10 tick /kernel: sd0(ahc0:0:0): no longer in timeout > Jun 15 22:17:10 tick /kernel: sd0(ahc0:0:0): UNIT ATTENTION asc:29,0 > Jun 15 22:17:10 tick /kernel: sd0(ahc0:0:0): Power on, reset, or bus device reset occurred field replaceable unit: 1 > Jun 15 22:17:10 tick /kernel: , FAILURE > Jun 15 22:17:10 tick /kernel: sd0(ahc0:0:0): SCB 0x3 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:17:10 tick /kernel: SEQADDR = 0x128 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:10 tick /kernel: Ordered Tag queued > Jun 15 22:17:10 tick /kernel: sd0(ahc0:0:0): SCB 0x6 timedout while recovery in progress > Jun 15 22:17:11 tick /kernel: sd0(ahc0:0:0): SCB 0x2 timedout while recovery in progress > Jun 15 22:17:11 tick /kernel: sd0(ahc0:0:0): SCB 0x7 timedout while recovery in progress > Jun 15 22:17:11 tick /kernel: sd0(ahc0:0:0): SCB 0x3 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:17:11 tick /kernel: SEQADDR = 0x128 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:11 tick /kernel: sd0(ahc0:0:0): abort message in message buffer > Jun 15 22:17:11 tick /kernel: sd0(ahc0:0:0): SCB 0x3 - timed out in dataout phase, SCSISIGI == 0x14 > Jun 15 22:17:11 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:11 tick /kernel: ahc0: Issued Channel A Bus Reset. 4 SCBs aborted > Jun 15 22:17:11 tick /kernel: Clearing bus reset > Jun 15 22:17:11 tick /kernel: Clearing 'in-reset' flag > Jun 15 22:17:11 tick /kernel: sd0(ahc0:0:0): no longer in timeout > Jun 15 22:17:11 tick /kernel: sd0(ahc0:0:0): UNIT ATTENTION asc:29,0 > Jun 15 22:17:11 tick /kernel: sd0(ahc0:0:0): Power on, reset, or bus device reset occurred field replaceable unit: 1 > Jun 15 22:17:11 tick /kernel: , retries:3 > Jun 15 22:17:11 tick /kernel: sd0(ahc0:0:0): SCB 0x7 - timed out in dataout phase, SCSISIGI == 0x4 > Jun 15 22:17:12 tick /kernel: SEQADDR = 0x127 SCSISEQ = 0x12 SSTAT0 = 0x0 SSTAT1 = 0x2 > Jun 15 22:17:12 tick /kernel: Ordered Tag queued > Jun 15 22:17:12 tick /kernel: sd0(ahc0:0:0): SCB 0x6 timedout while recovery in progress > Jun 15 22:17:12 tick /kernel: sd0(ahc0:0:0): SCB 0x3 timedout while recovery in progress > Jun 15 22:17:12 tick /kernel: sd0(ahc0:0:0): SCB 0x2 timedout while recovery in progress > Jun 15 22:17:12 tick /kernel: swap_pager: indefinite wait buffer: device: 132097, blkno: 9928x14 > Jun 15 22:17:12 tick /kernel: SEQADDR = Copyright (c) 1992-1997 FreeBSD Inc. > Jun 15 22:17:12 tick /kernel: Copyright (c) 1982, 1986, 1989, 1991, 1993 > Jun 15 22:17:12 tick /kernel: The Regents of the University of California. All rights reserved. > Jun 15 22:17:12 tick /kernel: > Jun 15 22:17:12 tick /kernel: FreeBSD 2.2-STABLE #0: Fri Jun 6 19:28:26 EET DST 1997 > Jun 15 22:17:12 tick /kernel: tomppa@tick:/f/local/sup/2.2/sys/compile/TICK > Jun 15 22:17:12 tick /kernel: CPU: Pentium Pro (232.52-MHz 686-class CPU) > Jun 15 22:17:12 tick /kernel: Origin = "GenuineIntel" Id = 0x619 Stepping=9 > Jun 15 22:17:13 tick /kernel: Features=0xf9ff,MTRR,PGE,MCA,CMOV> > Jun 15 22:17:13 tick /kernel: real memory = 67108864 (65536K bytes) > Jun 15 22:17:13 tick /kernel: avail memory = 63688704 (62196K bytes) > Jun 15 22:17:13 tick /kernel: Probing for devices on PCI bus 0: > Jun 15 22:17:13 tick /kernel: chip0 rev 2 on pci0:0 > Jun 15 22:17:13 tick /kernel: chip1 rev 1 on pci0:1:0 > Jun 15 22:17:13 tick /kernel: chip2 rev 0 on pci0:1:1 > Jun 15 22:17:13 tick /kernel: de0 rev 35 int a irq 15 on pci0:9 > Jun 15 22:17:13 tick /kernel: de0: 21040 [10Mb/s] pass 2.3 > Jun 15 22:17:13 tick /kernel: de0: address 00:40:c7:94:07:97 > Jun 15 22:17:13 tick /kernel: de0: enabling BNC/AUI port > Jun 15 22:17:13 tick /kernel: vga0 rev 1 int a irq 12 on pci0:11 > Jun 15 22:17:13 tick /kernel: ahc0 rev 0 int a irq 11 on pci0:12 > Jun 15 22:17:13 tick /kernel: ahc0: aic7880 Wide Channel, SCSI Id=7, 16/255 SCBs > Jun 15 22:17:13 tick /kernel: ahc0 waiting for scsi devices to settle > Jun 15 22:17:13 tick /kernel: ahc0: target 0 Tagged Queuing Device > Jun 15 22:17:13 tick /kernel: (ahc0:0:0): "SEAGATE ST32155N 0532" type 0 fixed SCSI 2 > Jun 15 22:17:13 tick /kernel: sd0(ahc0:0:0): Direct-Access 2049MB (4197405 512 byte sectors) > Jun 15 22:17:14 tick /kernel: sd0(ahc0:0:0): with 4177 cyls, 8 heads, and an average 125 sectors/track > Jun 15 22:17:14 tick /kernel: ahc0: target 1 Tagged Queuing Device > Jun 15 22:17:14 tick /kernel: (ahc0:1:0): "CONNER CP30540 545MB3.5 B0BD" type 0 fixed SCSI 2 > Jun 15 22:17:14 tick /kernel: sd1(ahc0:1:0): Direct-Access 520MB (1065912 512 byte sectors) > Jun 15 22:17:14 tick /kernel: sd1(ahc0:1:0): with 2242 cyls, 6 heads, and an average 79 sectors/track > Jun 15 22:17:14 tick /kernel: ahc0: target 3 Tagged Queuing Device > Jun 15 22:17:14 tick /kernel: (ahc0:3:0): "SEAGATE ST5660N 0518" type 0 fixed SCSI 2 > Jun 15 22:17:14 tick /kernel: sd2(ahc0:3:0): Direct-Access 520MB (1065664 512 byte sectors) > Jun 15 22:17:14 tick /kernel: sd2(ahc0:3:0): with 3002 cyls, 4 heads, and an average 88 sectors/track > Jun 15 22:17:14 tick /kernel: (ahc0:6:0): "PLEXTOR CD-ROM PX-12TS 1.02" type 5 removable SCSI 2 > Jun 15 22:17:14 tick /kernel: cd0(ahc0:6:0): CD-ROM cd present [220090 x 2048 byte records] > Jun 15 22:17:14 tick /kernel: probe0(ahc0:9:0): scsi_cmd > Jun 15 22:17:14 tick /kernel: probe0(ahc0:9:0): scsi_done > Jun 15 22:17:14 tick /kernel: (ahc0:9:0): command: 0,0,0,0,0,0-[0 bytes] > Jun 15 22:17:14 tick /kernel: probe0(ahc0:9:0): scsi_cmd > Jun 15 22:17:14 tick /kernel: probe0(ahc0:9:0): scsi_done > Jun 15 22:17:14 tick /kernel: (ahc0:9:0): command: 40,0,0,3,0,0,0,0,0,0-[0 bytes] > Jun 15 22:17:14 tick /kernel: probe0(ahc0:9:0): scsi_cmd > Jun 15 22:17:15 tick /kernel: probe0(ahc0:9:0): scsi_done > Jun 15 22:17:15 tick /kernel: (ahc0:9:0): command: 12,0,0,0,2c,0-[44 bytes] > Jun 15 22:17:15 tick /kernel: ------------------------------ > Jun 15 22:17:15 tick /kernel: 000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 > Jun 15 22:17:15 tick /kernel: 016: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 > Jun 15 22:17:15 tick /kernel: 032: 00 00 00 00 00 00 00 00 00 00 00 00 > Jun 15 22:17:15 tick /kernel: ------------------------------ > Jun 15 22:17:15 tick /kernel: Probing for devices on the ISA bus: > Jun 15 22:17:15 tick /kernel: sc0 at 0x60-0x6f irq 1 on motherboard > Jun 15 22:17:15 tick /kernel: sc0: VGA color <4 virtual consoles, flags=0x0> > Jun 15 22:17:15 tick /kernel: lpt0: disabled, not probed. > Jun 15 22:17:15 tick /kernel: sio0 at 0x3f8-0x3ff irq 4 on isa > Jun 15 22:17:15 tick /kernel: sio0: type 16550A > Jun 15 22:17:15 tick /kernel: sio1 at 0x2f8-0x2ff irq 3 on isa > Jun 15 22:17:15 tick /kernel: sio1: type 16550A > Jun 15 22:17:15 tick /kernel: wdc0 at 0x1f0-0x1f7 irq 14 flags 0x80ff80ff on isa > Jun 15 22:17:15 tick /kernel: wdc0: unit 0 (wd0): , 32-bit, multi-block-8 > Jun 15 22:17:15 tick /kernel: wd0: 516MB (1057392 sectors), 1049 cyls, 16 heads, 63 S/T, 512 B/S > Jun 15 22:17:16 tick /kernel: fdc0 at 0x3f0-0x3f7 irq 6 drq 2 on isa > Jun 15 22:17:16 tick /kernel: fdc0: NEC 72065B > Jun 15 22:17:16 tick /kernel: fd0: 1.44MB 3.5in > Jun 15 22:17:16 tick /kernel: pas0 at 0x388 irq 10 drq 5 on isa > Jun 15 22:17:16 tick /kernel: pas0: > Jun 15 22:17:16 tick /kernel: opl0 at 0x388 on isa > Jun 15 22:17:16 tick /kernel: opl0: > Jun 15 22:17:16 tick /kernel: sb0 at 0x220 irq 7 drq 1 on isa > Jun 15 22:17:16 tick /kernel: sb0: > Jun 15 22:17:16 tick /kernel: apm0 on isa > Jun 15 22:17:16 tick /kernel: apm: found APM BIOS version 1.1 > Jun 15 22:17:16 tick /kernel: npx0 on motherboard > Jun 15 22:17:16 tick /kernel: npx0: INT 16 interface > Jun 15 22:17:16 tick /kernel: WARNING: / was not properly dismounted. > > -- > Tomi Vainio, Fimeko-Data Oy Phone: +358 (0)9 4582421 > Mail: tomppa@iki.fi tomppa@fidata.fi Telefax: +358 (0)9 4582425 >