Skip site navigation (1)Skip section navigation (2)
Date:      Sat, 23 Jul 2005 20:58:20 -0500 (CDT)
From:      Karl Denninger <karl@denninger.net>
To:        FreeBSD-gnats-submit@FreeBSD.org
Subject:   i386/83974: FreeBSD-6.0-BETA1 blows up with PCI SATA w/using Gmirror
Message-ID:  <200507240158.j6O1wK3H016776@FS.denninger.net>
Resent-Message-ID: <200507240200.j6O20Wd1096978@freefall.freebsd.org>

next in thread | raw e-mail | index | archive | help

>Number:         83974
>Category:       i386
>Synopsis:       FreeBSD-6.0-BETA1 blows up with PCI SATA w/using Gmirror
>Confidential:   no
>Severity:       critical
>Priority:       high
>Responsible:    freebsd-i386
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Sun Jul 24 02:00:32 GMT 2005
>Closed-Date:
>Last-Modified:
>Originator:     Karl Denninger
>Release:        FreeBSD 6.0-BETA1 i386
>Organization:
Karls Sushi and Packet Smashers
>Environment:
System: FreeBSD 6.0-BETA1 #1: Fri Jul 22 12:06:22 CDT 2005 root@Sandbox.denninger.net:/usr/obj/usr/src/sys/GENERIC 

	See below for the kernel configuration and DMESG output.
	
>Description:
	Machine booted with 6.0BETA1 in an attempt to verify the status of
	PR i386/7764.

	Same disks and adapter attached to system.

	Gmirror insert run to rebuild both child disks.  Completed
	successfully.

	"make -j4 buildworld" run to attempt to duplicate problem.

	System failed with the following output on console and in
	/var/log/messages.  Machine unable to be rebooted, as the last
	message continued to repeat and the system was unable to shut
	down; it got to the syncing buffers line, said it was giving up on
	one buffer, but continued to emit the last line and would not shut
	down even after more than 20 minutes of waiting.  The power button 
	had to be used to turn it off, resulting in an unclean shutdown
	and a full FSCK requirement on reboot.

	This problem looks to be essentially identical to that experienced
	under 5.4-RELEASE, and which was the subject of the previous PR,
	but is much more serious in that once it occurs the system is
	completely unstable and cannot even be rebooted normally.

	GEOM_MIRROR: Device boot: provider ad4s1 detected.
	GEOM_MIRROR: Device boot: rebuilding provider ad4s1.
	GEOM_MIRROR: Device boot: provider ad6s1 detected.
	GEOM_MIRROR: Device boot: rebuilding provider ad6s1.
	GEOM_MIRROR: Device boot: rebuilding provider ad4s1 finished.
	GEOM_MIRROR: Device boot: provider ad4s1 activated.
	GEOM_MIRROR: Device boot: rebuilding provider ad6s1 finished.
	GEOM_MIRROR: Device boot: provider ad6s1 activated.
	subdisk4: detached
	ad4: detached
	unknown: FAILURE - SETFEATURES SET TRANSFER MODE timed out
	unknown: timeout waiting to issue command
	unknown: error issueing SETFEATURES SET TRANSFER MODE command
	GEOM_MIRROR: Device boot: provider ad4s1 disconnected.
	GEOM_MIRROR: Request failed (error=6).  ad4s1[READ(offset=35096543232, length=10240)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35463411712, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35467393024, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35501357056, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35501551616, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35501553664, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35502305280, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35502583808, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35502764032, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35648684032,   length=16384)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35705600000, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35840983040, length=16384)]  
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35840999424, length=16384)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35848910848, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35854632960, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=35866456064, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=36226842624, length=16384)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=36226859008, length=16384)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=36233115648, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=36234352640, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=36234868736, length=2048)]
	GEOM_MIRROR: Request failed (error=6).  ad4s1[WRITE(offset=36274173952, length=2048)]
	unknown: req=0xc1e2e320 SETFEATURES SET TRANSFER MODE semaphore timeout !!  DANGER Will Robinson !!
	unknown: req=0xc1e2e320 SETFEATURES SET TRANSFER MODE semaphore timeout !!  DANGER Will Robinson !!
	unknown: req=0xc1e2e320 SETFEATURES SET TRANSFER MODE semaphore timeout !!  DANGER Will Robinson !!
	unknown: req=0xc1e2e320 SETFEATURES SET TRANSFER MODE semaphore timeout !!  DANGER Will Robinson !!
	unknown: req=0xc1e2e320 SETFEATURES SET TRANSFER MODE semaphore timeout !!  DANGER Will Robinson !!

	(final line repeats indefinitely)

	Build environment, including hardware:

Copyright (c) 1992-2005 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 6.0-BETA1 #1: Fri Jul 22 12:06:22 CDT 2005
    root@Sandbox.denninger.net:/usr/obj/usr/src/sys/GENERIC
ACPI APIC Table: <DELL   PE400SC>
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) Pentium(R) 4 CPU 2.40GHz (2394.01-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0xf29  Stepping = 9
  Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA
,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
  Features2=0x4400<CNTX-ID,<b14>>
  Hyperthreading: 2 logical CPUs
real memory  = 536297472 (511 MB)
avail memory = 515391488 (491 MB)
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
 cpu0 (BSP): APIC ID:  0
 cpu1 (AP): APIC ID:  1
ioapic0: Changing APIC ID to 2
ioapic0 <Version 2.0> irqs 0-23 on motherboard
npx0: [FAST]
npx0: <math processor> on motherboard
npx0: INT 16 interface
acpi0: <DELL PE400SC> on motherboard
acpi0: Power Button (fixed)
pci_link0: <ACPI PCI Link LNKA> irq 11 on acpi0
pci_link1: <ACPI PCI Link LNKB> irq 5 on acpi0
pci_link2: <ACPI PCI Link LNKC> irq 9 on acpi0
pci_link3: <ACPI PCI Link LNKD> irq 10 on acpi0
pci_link4: <ACPI PCI Link LNKE> on acpi0
pci_link5: <ACPI PCI Link LNKF> on acpi0
pci_link6: <ACPI PCI Link LNKG> irq 10 on acpi0
pci_link7: <ACPI PCI Link LNKH> irq 7 on acpi0
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0
cpu0: <ACPI CPU> on acpi0
cpu1: <ACPI CPU> on acpi0
acpi_button0: <Power Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
agp0: <Intel 82875P host to AGP bridge> mem 0xe8000000-0xefffffff at device 0.
0 on pci0
pcib1: <PCI-PCI bridge> at device 1.0 on pci0
pci1: <PCI bus> on pcib1
pci1: <display, VGA> at device 0.0 (no driver attached)
uhci0: <Intel 82801EB (ICH5) USB controller USB-A> port 0xff80-0xff9f irq 16 a
t device 29.0 on pci0
uhci0: [GIANT-LOCKED]
usb0: <Intel 82801EB (ICH5) USB controller USB-A> 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
uhci1: <Intel 82801EB (ICH5) USB controller USB-B> port 0xff60-0xff7f irq 19 a
t device 29.1 on pci0
uhci1: [GIANT-LOCKED]
usb1: <Intel 82801EB (ICH5) USB controller USB-B> on uhci1
usb1: USB revision 1.0
uhub1: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
uhci2: <Intel 82801EB (ICH5) USB controller USB-C> port 0xff40-0xff5f irq 18 a
t device 29.2 on pci0
uhci2: [GIANT-LOCKED]
usb2: <Intel 82801EB (ICH5) USB controller USB-C> on uhci2
usb2: USB revision 1.0
uhub2: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub2: 2 ports with 2 removable, self powered
uhci3: <Intel 82801EB (ICH5) USB controller USB-D> port 0xff20-0xff3f irq 16 a
t device 29.3 on pci0
uhci3: [GIANT-LOCKED]
usb3: <Intel 82801EB (ICH5) USB controller USB-D> on uhci3
usb3: USB revision 1.0
uhub3: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub3: 2 ports with 2 removable, self powered
ehci0: <EHCI (generic) USB 2.0 controller> mem 0xffa80800-0xffa80bff irq 23 at
 device 29.7 on pci0
ehci0: [GIANT-LOCKED]
usb4: EHCI version 1.0
usb4: companion controllers, 2 ports each: usb0 usb1 usb2 usb3
usb4: <EHCI (generic) USB 2.0 controller> on ehci0
usb4: USB revision 2.0
uhub4: Intel EHCI root hub, class 9/0, rev 2.00/1.00, addr 1
uhub4: 8 ports with 8 removable, self powered
pcib2: <ACPI PCI-PCI bridge> at device 30.0 on pci0
pci2: <ACPI PCI bus> on pcib2
atapci0: <SiI 3112 SATA150 controller> port 0xcf20-0xcf27,0xcf18-0xcf1b,0xcf28
-0xcf2f,0xcf1c-0xcf1f,0xcf30-0xcf3f mem 0xfe7dfe00-0xfe7dffff irq 22 at device
 1.0 on pci2
ata2: <ATA channel 0> on atapci0
ata3: <ATA channel 1> on atapci0
em0: <Intel(R) PRO/1000 Network Connection, Version - 2.1.7> port 0xcf40-0xcf7
f mem 0xfe7e0000-0xfe7fffff irq 18 at device 12.0 on pci2
em0: Ethernet address: 00:0c:f1:ca:16:b4
em0:  Speed:N/A  Duplex:N/A
isab0: <PCI-ISA bridge> at device 31.0 on pci0
isa0: <ISA bus> on isab0
atapci1: <Intel ICH5 UDMA100 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x
376,0xffa0-0xffaf mem 0xfebffc00-0xfebfffff irq 18 at device 31.1 on pci0
ata0: <ATA channel 0> on atapci1
ata1: <ATA channel 1> on atapci1
atapci2: <Intel ICH5 SATA150 controller> port 0xfe00-0xfe07,0xfe10-0xfe13,0xfe
20-0xfe27,0xfe30-0xfe33,0xfea0-0xfeaf irq 18 at device 31.2 on pci0
atapci2: failed to enable memory mapping!
ata4: <ATA channel 0> on atapci2
ata5: <ATA channel 1> on atapci2
pci0: <serial bus, SMBus> at device 31.3 (no driver attached)
pci0: <multimedia, audio> at device 31.5 (no driver attached)
fdc0: <floppy drive controller> port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0
fdc0: [FAST]
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: model IntelliMouse, device ID 3
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
sio0: type 16550A
sio1: <16550A-compatible COM port> port 0x2f8-0x2ff irq 3 on acpi0
sio1: type 16550A
pmtimer0 on isa0
orm0: <ISA Option ROMs> at iomem 0xc0000-0xcafff,0xcb000-0xcf7ff,0xcf800-0xd0f
ff,0xd1000-0xd3fff on isa0
ppc0: parallel port not found.
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounters tick every 1.000 msec
ad0: 38146MB <WDC WD400BB-75FRA0 77.07W77> at ata0-master UDMA100
acd0: CDROM <Lite-On LTN486S 48x Max/YDS6> at ata1-master UDMA33
ad4: 238475MB <HDS722525VLSA80 V36OA63A> at ata2-master SATA150
ad6: 239372MB <Maxtor 6B250S0 BANC1B70> at ata3-master SATA150
ATA PseudoRAID loaded
SMP: AP CPU #1 Launched!
GEOM_MIRROR: Device boot created (id=1636277663).
GEOM_MIRROR: Device boot: provider ad0s1 detected.
GEOM_MIRROR: Device boot: provider ad0s1 activated.
GEOM_MIRROR: Device boot: provider mirror/boot launched.
GEOM_MIRROR: Cannot add disk ad6s1 to boot (error=22).
Trying to mount root from ufs:/dev/mirror/boota

NOTE: Kernel is GENERIC with only the following changes to the distributed
kernel configuration file:

#options        INVARIANTS              # Enable calls of extra sanity checkin
g
#options        INVARIANT_SUPPORT       # Extra sanity checks of internal stru
ctures, required by INVARIANTS
#options        WITNESS                 # Enable checks to detect deadlocks an
d cycles
#options        WITNESS_SKIPSPIN        # Don't run witness on spinlocks for s
peed

The following card is an Adaptec 1205SA

atapci0: <SiI 3112 SATA150 controller> port 0xcf20-0xcf27,0xcf18-0xcf1b,0xcf28
-0xcf2f,0xcf1c-0xcf1f,0xcf30-0xcf3f mem 0xfe7dfe00-0xfe7dffff irq 22 at device
 1.0 on pci2

A Bustek card which has an external connector block identifies as:

atapci0: <SiI 3112 SATA150 controller> port 0xcd70-0xcd7f,0xcd5c-0xcd5f,0xcd68
-0xcd6f,0xcd58-0xcd5b,0xcd60-0xcd67 mem 0xfe7dee00-0xfe7defff irq 21 at device
 0.0 on pci2

in an IDENTICAL machine to the sandbox and exhibits the EXACT same symptoms.


>How-To-Repeat:

	"gmirror insert boot ad4s1"
	"gmirror insert boot ad6s1"

	<Wait for rebuild to complete>

	"cd /usr/src"
	"make -j4 buildworld"

	BOOM!

>Fix:

	None known.



>Release-Note:
>Audit-Trail:
>Unformatted:



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200507240158.j6O1wK3H016776>