From owner-freebsd-bugs@FreeBSD.ORG Mon Mar 22 13:40:04 2010 Return-Path: Delivered-To: freebsd-bugs@hub.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 58315106566B for ; Mon, 22 Mar 2010 13:40:04 +0000 (UTC) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [IPv6:2001:4f8:fff6::28]) by mx1.freebsd.org (Postfix) with ESMTP id 30BA38FC1E for ; Mon, 22 Mar 2010 13:40:04 +0000 (UTC) Received: from freefall.freebsd.org (localhost [127.0.0.1]) by freefall.freebsd.org (8.14.4/8.14.4) with ESMTP id o2MDe4GK049631 for ; Mon, 22 Mar 2010 13:40:04 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.14.4/8.14.4/Submit) id o2MDe499049630; Mon, 22 Mar 2010 13:40:04 GMT (envelope-from gnats) Resent-Date: Mon, 22 Mar 2010 13:40:04 GMT Resent-Message-Id: <201003221340.o2MDe499049630@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-bugs@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, Charles Owens Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 4D418106564A for ; Mon, 22 Mar 2010 13:39:22 +0000 (UTC) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (www.freebsd.org [IPv6:2001:4f8:fff6::21]) by mx1.freebsd.org (Postfix) with ESMTP id 3B7718FC0C for ; Mon, 22 Mar 2010 13:39:22 +0000 (UTC) Received: from www.freebsd.org (localhost [127.0.0.1]) by www.freebsd.org (8.14.3/8.14.3) with ESMTP id o2MDdLHA029174 for ; Mon, 22 Mar 2010 13:39:21 GMT (envelope-from nobody@www.freebsd.org) Received: (from nobody@localhost) by www.freebsd.org (8.14.3/8.14.3/Submit) id o2MDdLki029173; Mon, 22 Mar 2010 13:39:21 GMT (envelope-from nobody) Message-Id: <201003221339.o2MDdLki029173@www.freebsd.org> Date: Mon, 22 Mar 2010 13:39:21 GMT From: Charles Owens To: freebsd-gnats-submit@FreeBSD.org X-Send-Pr-Version: www-3.1 Cc: Subject: kern/144956: Early minute-plus delay in boot on Intel Nehalem system X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 22 Mar 2010 13:40:04 -0000 >Number: 144956 >Category: kern >Synopsis: Early minute-plus delay in boot on Intel Nehalem system >Confidential: no >Severity: serious >Priority: medium >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Mon Mar 22 13:40:03 UTC 2010 >Closed-Date: >Last-Modified: >Originator: Charles Owens >Release: 8.0-RELEASE-p2 >Organization: Great Bay Software >Environment: FreeBSD BeaconHA2 8.0-RELEASE-p2 FreeBSD 8.0-RELEASE-p2 #4: Thu Mar 4 04:21:04 UTC 2010 cowens@newcastle.greatbaysoftware.com:/usr/obj/usr/src/sys/BEACON i386 >Description: (Note: issue _is_ seen with GENERIC kernel. Kernel shown here is the PAE conf with slight tweaks) On system based on the Intel S5520UR motherboard, during _every_ boot it pauses for about 70 seconds just before any kernel initialization messages appear. We see the loader appearing to complete its work (the kernel is loaded) and then... it sits. Once it starts up again (with usual kernel-boot messages) it appears to boot normally (no error messages). This has been seen also with both FreeBSD 7.1 and 7.2. FreeBSD has always worked fine with other Intel server motherboards we've tested, so this appears to be something specific to this relatively new model. Attempts have been made to debug the issue with KDB/DDB, but we've been unable to break into the kernel before the hang begins. Kernel boot log: Copyright (c) 1992-2009 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 is a registered trademark of The FreeBSD Foundation. FreeBSD 8.0-RELEASE-p2 #4: Thu Mar 4 04:21:04 UTC 2010 cowens@newcastle.greatbaysoftware.com:/usr/obj/usr/src/sys/BEACON Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: Intel(R) Xeon(R) CPU E5520 @ 2.27GHz (2261.27-MHz 686-class CPU) Origin = "GenuineIntel" Id = 0x106a5 Stepping = 5 Features=0xbfebfbff Features2=0x9ce3bd AMD Features=0x28100000 AMD Features2=0x1 TSC: P-state invariant real memory = 6442450944 (6144 MB) avail memory = 6205816832 (5918 MB) ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 16 CPUs FreeBSD/SMP: 2 package(s) x 4 core(s) x 2 SMT threads cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 1 cpu2 (AP): APIC ID: 2 cpu3 (AP): APIC ID: 3 cpu4 (AP): APIC ID: 4 cpu5 (AP): APIC ID: 5 cpu6 (AP): APIC ID: 6 cpu7 (AP): APIC ID: 7 cpu8 (AP): APIC ID: 16 cpu9 (AP): APIC ID: 17 cpu10 (AP): APIC ID: 18 cpu11 (AP): APIC ID: 19 cpu12 (AP): APIC ID: 20 cpu13 (AP): APIC ID: 21 cpu14 (AP): APIC ID: 22 cpu15 (AP): APIC ID: 23 ioapic0 irqs 0-23 on motherboard ioapic1 irqs 24-47 on motherboard lapic0: Forcing LINT1 to edge trigger ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware ispfw: registered firmware kbd1 at kbdmux0 acpi0: on motherboard acpi0: [ITHREAD] acpi0: Power Button (fixed) Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0 acpi_hpet0: iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 14318180 Hz quality 900 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 pcib1: irq 28 at device 1.0 on pci0 pci1: on pcib1 igb0: port 0x3020-0x303f mem 0xb1b20000-0xb1b3ffff,0xb1b44000-0xb1b47fff irq 40 at device 0.0 on pci1 igb0: Using MSIX interrupts with 3 vectors igb0: [ITHREAD] igb0: [ITHREAD] igb0: [ITHREAD] igb0: Ethernet address: 00:15:17:b4:cf:e4 igb1: port 0x3000-0x301f mem 0xb1b00000-0xb1b1ffff,0xb1b40000-0xb1b43fff irq 28 at device 0.1 on pci1 igb1: Using MSIX interrupts with 3 vectors igb1: [ITHREAD] igb1: [ITHREAD] igb1: [ITHREAD] igb1: Ethernet address: 00:15:17:b4:cf:e5 pcib2: irq 24 at device 3.0 on pci0 pci2: on pcib2 em0: port 0x2020-0x203f mem 0xb1a60000-0xb1a7ffff,0xb1a40000-0xb1a5ffff irq 24 at device 0.0 on pci2 em0: Using MSI interrupt em0: [FILTER] em0: Ethernet address: 00:15:17:cb:e6:e6 em1: port 0x2000-0x201f mem 0xb1a20000-0xb1a3ffff,0xb1a00000-0xb1a1ffff irq 34 at device 0.1 on pci2 em1: Using MSI interrupt em1: [FILTER] em1: Ethernet address: 00:15:17:cb:e6:e7 pcib3: irq 30 at device 7.0 on pci0 pci3: on pcib3 pcib4: irq 32 at device 9.0 on pci0 pci4: on pcib4 pcib5: irq 33 at device 10.0 on pci0 pci5: on pcib5 pci0: at device 16.0 (no driver attached) pci0: at device 16.1 (no driver attached) pci0: at device 17.0 (no driver attached) pci0: at device 17.1 (no driver attached) pci0: at device 20.0 (no driver attached) pci0: at device 20.1 (no driver attached) pci0: at device 20.2 (no driver attached) pci0: at device 20.3 (no driver attached) pci0: at device 22.0 (no driver attached) pci0: at device 22.1 (no driver attached) pci0: at device 22.2 (no driver attached) pci0: at device 22.3 (no driver attached) pci0: at device 22.4 (no driver attached) pci0: at device 22.5 (no driver attached) pci0: at device 22.6 (no driver attached) pci0: at device 22.7 (no driver attached) uhci0: port 0x40c0-0x40df irq 19 at device 26.0 on pci0 uhci0: [ITHREAD] uhci0: LegSup = 0x103f usbus0: on uhci0 uhci1: port 0x40a0-0x40bf irq 19 at device 26.1 on pci0 uhci1: [ITHREAD] uhci1: LegSup = 0x003f usbus1: on uhci1 uhci2: port 0x4080-0x409f irq 19 at device 26.2 on pci0 uhci2: [ITHREAD] uhci2: LegSup = 0x003f usbus2: on uhci2 ehci0: mem 0xb1c21000-0xb1c213ff irq 19 at device 26.7 on pci0 ehci0: [ITHREAD] usbus3: EHCI version 1.0 usbus3: on ehci0 pcib6: irq 16 at device 28.0 on pci0 pci6: on pcib6 mfi0: port 0x1000-0x10ff mem 0xb1900000-0xb193ffff,0xb1940000-0xb197ffff irq 16 at device 0.0 on pci6 mfi0: Megaraid SAS driver Ver 3.00 mfi0: [ITHREAD] pcib7: irq 16 at device 28.4 on pci0 pci7: on pcib7 vgapci0: mem 0xb0000000-0xb0ffffff,0xb1800000-0xb1803fff,0xb1000000-0xb17fffff irq 16 at device 0.0 on pci7 pcib8: irq 17 at device 28.5 on pci0 pci8: on pcib8 uhci3: port 0x4060-0x407f irq 16 at device 29.0 on pci0 uhci3: [ITHREAD] uhci3: LegSup = 0x003f usbus4: on uhci3 uhci4: port 0x4040-0x405f irq 16 at device 29.1 on pci0 uhci4: [ITHREAD] uhci4: LegSup = 0x003f usbus5: on uhci4 uhci5: port 0x4020-0x403f irq 16 at device 29.2 on pci0 uhci5: [ITHREAD] uhci5: LegSup = 0x003f usbus6: on uhci5 ehci1: mem 0xb1c20000-0xb1c203ff irq 16 at device 29.7 on pci0 ehci1: [ITHREAD] usbus7: EHCI version 1.0 usbus7: on ehci1 pcib9: at device 30.0 on pci0 pci9: on pcib9 isab0: at device 31.0 on pci0 isa0: on isab0 atapci0: port 0x4138-0x413f,0x414c-0x414f,0x4130-0x4137,0x4148-0x414b,0x4110-0x411f,0x4100-0x410f irq 18 at device 31.2 on pci0 atapci0: [ITHREAD] ata2: on atapci0 ata2: [ITHREAD] ata3: on atapci0 ata3: [ITHREAD] pci0: at device 31.3 (no driver attached) atapci1: port 0x4128-0x412f,0x4144-0x4147,0x4120-0x4127,0x4140-0x4143,0x40f0-0x40ff,0x40e0-0x40ef irq 21 at device 31.5 on pci0 atapci1: [ITHREAD] ata4: on atapci1 ata4: [ITHREAD] ata5: on atapci1 ata5: [ITHREAD] acpi_button0: on acpi0 atrtc0: port 0x70-0x71,0x74-0x77 irq 8 on acpi0 uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 uart0: [FILTER] uart0: console (9600,n,8,1) uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0 uart1: [FILTER] ipmi0: port 0xca2,0xca3 on acpi0 ipmi0: KCS mode found at io 0xca2 on acpi cpu0: on acpi0 est0: on cpu0 p4tcc0: on cpu0 cpu1: on acpi0 est1: on cpu1 p4tcc1: on cpu1 cpu2: on acpi0 est2: on cpu2 p4tcc2: on cpu2 cpu3: on acpi0 est3: on cpu3 p4tcc3: on cpu3 cpu4: on acpi0 est4: on cpu4 p4tcc4: on cpu4 cpu5: on acpi0 est5: on cpu5 p4tcc5: on cpu5 cpu6: on acpi0 est6: on cpu6 p4tcc6: on cpu6 cpu7: on acpi0 est7: on cpu7 p4tcc7: on cpu7 cpu8: on acpi0 est8: on cpu8 p4tcc8: on cpu8 cpu9: on acpi0 est9: on cpu9 p4tcc9: on cpu9 cpu10: on acpi0 est10: on cpu10 p4tcc10: on cpu10 cpu11: on acpi0 est11: on cpu11 p4tcc11: on cpu11 cpu12: on acpi0 est12: on cpu12 p4tcc12: on cpu12 cpu13: on acpi0 est13: on cpu13 p4tcc13: on cpu13 cpu14: on acpi0 est14: on cpu14 p4tcc14: on cpu14 cpu15: on acpi0 est15: on cpu15 p4tcc15: on cpu15 ipmi1: on isa0 device_attach: ipmi1 attach returned 16 pmtimer0 on isa0 ipmi1: on isa0 device_attach: ipmi1 attach returned 16 orm0: at iomem 0xc0000-0xc7fff,0xc8000-0xc8fff,0xc9000-0xc9fff pnpid ORM0000 on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 ata0 at port 0x1f0-0x1f7,0x3f6 irq 14 on isa0 ata0: [ITHREAD] ata1 at port 0x170-0x177,0x376 irq 15 on isa0 ata1: [ITHREAD] ppc0: parallel port not found. Timecounters tick every 1.000 msec usbus0: 12Mbps Full Speed USB v1.0 usbus1: 12Mbps Full Speed USB v1.0 usbus2: 12Mbps Full Speed USB v1.0 usbus3: 480Mbps High Speed USB v2.0 usbus4: 12Mbps Full Speed USB v1.0 usbus5: 12Mbps Full Speed USB v1.0 usbus6: 12Mbps Full Speed USB v1.0 usbus7: 480Mbps High Speed USB v2.0 AcpiOsExecute: failed to enqueue task, consider increasing the debug.acpi.max_tasks tunable ACPI Error (psparse-0633): Method parse/execution failed [\\_SB_.PCI0.HEC2.HSCI] (Node 0xccbff700)mfid0: on mfi0 mfid0: 303268MB (621092864 sectors) RAID volume '' is optimal ugen0.1: at usbus0 uhub0: on usbus0 ugen1.1: at usbus1 uhub1: on usbus1 ugen2.1: at usbus2 uhub2: on usbus2 ugen3.1: at usbus3 uhub3: on usbus3 ugen4.1: at usbus4 uhub4: on usbus4 ugen5.1: at usbus5 uhub5: on usbus5 ugen6.1: at usbus6 uhub6: on usbus6 ugen7.1: at usbus7 uhub7: on usbus7 , AE_NO_MEMORY ACPI Error (psparse-0633): Method parse/execution failed [\\_GPE._L06] (Node 0xccc065e0), AE_NO_MEMORY ACPI Exception: AE_NO_MEMORY, while evaluating GPE method [_L06] 20090521 evgpe-705 AcpiOsExecute: failed to enqueue task, consider increasing the debug.acpi.max_tasks tunable ipmi0: IPMI device rev. 1, firmware rev. 0.2, version 2.0 ipmi0: Number of channels 2 ipmi0: Attached watchdog lapic5: Forcing LINT1 to edge trigger SMP: AP CPU #5 Launched! lapic23: Forcing LINT1 to edge trigger SMP: AP CPU #15 Launched! lapic20: Forcing LINT1 to edge trigger SMP: AP CPU #12 Launched! lapic6: Forcing LINT1 to edge trigger SMP: AP CPU #6 Launched! lapic2: Forcing LINT1 to edge trigger SMP: AP CPU #2 Launched! lapic7: Forcing LINT1 to edge trigger SMP: AP CPU #7 Launched! lapic16: Forcing LINT1 to edge trigger SMP: AP CPU #8 Launched! lapic17: Forcing LINT1 to edge trigger SMP: AP CPU #9 Launched! lapic3: Forcing LINT1 to edge trigger SMP: AP CPU #3 Launched! lapic4: Forcing LINT1 to edge trigger SMP: AP CPU #4 Launched! lapic1: Forcing LINT1 to edge trigger SMP: AP CPU #1 Launched! lapic22: Forcing LINT1 to edge trigger SMP: AP CPU #14 Launched! lapic18: Forcing LINT1 to edge trigger SMP: AP CPU #10 Launched! lapic21: Forcing LINT1 to edge trigger SMP: AP CPU #13 Launched! lapic19: Forcing LINT1 to edge trigger SMP: AP CPU #11 Launched! GEOM_JOURNAL: Journal 3779144311: mfid0s1a contains data. GEOM_JOURNAL: Journal 3779144311: mfid0s1a contains journal. GEOM_JOURNAL: Journal mfid0s1a clean. GEOM_JOURNAL: BIO_FLUSH not supported by mfid0s1a. GEOM_JOURNAL: Journal 2337978298: mfid0s1d contains data.uhub1: 2 ports with 2 removable, self powered GEOM_JOURNAL uhub5: : 2 ports with 2 removable, self poweredJournal 2337978298: mfid0s1d contains journal. uhub6: 2 ports with 2 removable, self powered GEOM_JOURNALuhub2: : 2 ports with 2 removable, self poweredJournal mfid0s1d clean. uhub4: 2 ports with 2 removable, self powered uhub0: GEOM_JOURNAL2 ports with 2 removable, self powered: BIO_FLUSH not supported by mfid0s1d. Root mount waiting for: usbus7 usbus3 Root mount waiting for: usbus7 usbus3 uhub3: 6 ports with 6 removable, self powered uhub7: 6 ports with 6 removable, self powered Root mount waiting for: usbus7 usbus3 ugen3.2: at usbus3 uhub8: on usbus3 ugen7.2: at usbus7 umass0: on usbus7 umass0: SCSI over Bulk-Only; quirks = 0x0000 Root mount waiting for: usbus7 usbus3 uhub8: 4 ports with 4 removable, self powered umass0:0:0:-1: Attached to scbus0 Root mount waiting for: usbus7 usbus3 (probe0:umass-sim0:0:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 Trying to mount root from ufs:/dev/ufs/root (probe0:umass-sim0:0:0:0): CAM Status: SCSI Status Error (probe0:umass-sim0:0:0:0): SCSI Status: Check Condition (probe0:umass-sim0:0:0:0): NOT READY asc:3a,2 (probe0:umass-sim0:0:0:0): Medium not present - tray open (probe0:umass-sim0:0:0:0): Unretryable error cd0 at umass-sim0 bus 0 target 0 lun 0 cd0: Removable CD-ROM SCSI-0 device cd0: 40.000MB/s transfers cd0: Attempt to query device size failed: NOT READY, Medium not present - tray open ugen2.2: at usbus2 ukbd0: on usbus2 kbd0 at ukbd0 ums0: on usbus2 ums0: 3 buttons and [Z] coordinates ID=0 ugen6.2: at usbus6 uhub9: on usbus6 uhub9: 4 ports with 4 removable, self powered ugen6.3: at usbus6 ukbd1: on usbus6 kbd2 at ukbd1 uhid0: on usbus6 ums1: on usbus6 ums1: 5 buttons and [XYZ] coordinates ID=0 ums2: on usbus6 ums2: 3 buttons and [Z] coordinates ID=0 >How-To-Repeat: Boot FreeBSD from a system based on the S5520UR motherboard. >Fix: >Release-Note: >Audit-Trail: >Unformatted: