From owner-freebsd-current@FreeBSD.ORG Fri Oct 1 21:48:22 2010 Return-Path: Delivered-To: current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id F0E9E106566B for ; Fri, 1 Oct 2010 21:48:22 +0000 (UTC) (envelope-from david@catwhisker.org) Received: from albert.catwhisker.org (m209-73.dsl.rawbw.com [198.144.209.73]) by mx1.freebsd.org (Postfix) with ESMTP id 6EA438FC21 for ; Fri, 1 Oct 2010 21:48:22 +0000 (UTC) Received: from albert.catwhisker.org (localhost [127.0.0.1]) by albert.catwhisker.org (8.14.4/8.14.4) with ESMTP id o91LKcSa080856 for ; Fri, 1 Oct 2010 14:20:38 -0700 (PDT) (envelope-from david@albert.catwhisker.org) Received: (from david@localhost) by albert.catwhisker.org (8.14.4/8.14.4/Submit) id o91LKcsg080855 for current@freebsd.org; Fri, 1 Oct 2010 14:20:38 -0700 (PDT) (envelope-from david) Date: Fri, 1 Oct 2010 14:20:38 -0700 From: David Wolfskill To: current@freebsd.org Message-ID: <20101001212038.GE1535@albert.catwhisker.org> Mail-Followup-To: David Wolfskill , current@freebsd.org Mime-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="inZzG0lmAPZRgTxV" Content-Disposition: inline User-Agent: Mutt/1.4.2.3i Cc: Subject: Hang near end of kernel probes since r213267 (likely earlier) X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 01 Oct 2010 21:48:23 -0000 --inZzG0lmAPZRgTxV Content-Type: multipart/mixed; boundary="OM63UbYQsNeyh2dn" Content-Disposition: inline --OM63UbYQsNeyh2dn Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable I have recently acquired a new laptop (to replace the "Frankenlaptop" I've been using for the last several years). The new machine is a Dell Precision M4400, so it's pretty recent technology compared to what I'm used to. :-} I installed FreeBSD 8.1-R on slice 1, customized it a bit to work in my environment, then cloned slice 1 to slice 2, booted from slice 2, populated /usr/src via "svn co" (pointing to stable/8, and upgraded slice to stable/8 as of r213245. So far, so good. I tinkered with it a bit more, building ports the way I want them, &c.; the following day, I upgraded to r213267. That went well, so I cloned slice 2 to slice 4, used "svn switch" to flip /usr/src from slice 4 to head, booted from slice 4, and upgraded slice 4 to 9.0-CURRENT as of r213267. On the reboot following the install (the "smoke test"), I noticed that the machine got most of the way through the kernel probes, then hung (requiring a power cycle to break out of it). It did this a few more times, then the next boot worked. I thought this odd, but not necessarily demonstrating a problem with FreeBSD: I hadn't had much experienmce with this particular hardware, after all. The following day (as is my usual pattern), I upgraded slice 2 to stable/8 as of r213295 without incident. After upgrading the installed ports, I then booted from slice 4 (after several tries), then upgraded slice 4 to head as of r213295. Again, attempts to boot from slice 4 usually -- but not always -- would hang, always in the same place. Now, I had hada a somewhat-similar hang on my work desktop, which is also a Dell machine. And in that case -- though there were several differences, soime of which may well be relevant -- a BIOS upgrade resolved that issue. So I checked; the laptop had BIOS A19, and Dell had A23 available. This morning, I upgraded slice 2 to stable/8 as of r213322, booted slice 4, and upgraded it to head as of r213322. Again, it woudl hang more often than not. This afternoon, after receiving appropriate encouragement (that yes, I probably could use Dell's Linux BIOS updater from a KNOPPIX environment), I was able to successfully update the BIOS to A23. Unfortunately, booting head (slice 4) still hangs -- usually. I'm unable to detect a pattern in why it sometimes boots OK, while most of the time it hangs. So when it hangs (today), It's runing: FreeBSD localhost 9.0-CURRENT FreeBSD 9.0-CURRENT #1 r213322: Fri Oct 1 10= :18:30 PDT 2010 root@g1-222.catwhisker.org.:/usr/obj/usr/src/sys/CANARY= i386 And looking at the stable/8 /var/log/messages, when it boots under head, it runs along: =2E.. Oct 1 13:37:41 localhost kernel: ugen6.1: at usbus6 Oct 1 13:37:41 localhost kernel: uhub6: on usbus6 Oct 1 13:37:41 localhost kernel: ugen7.1: at usbus7 Oct 1 13:37:41 localhost kernel: uhub7: on usbus7 Oct 1 13:37:41 localhost kernel: ad4: 238475MB = at ata2-master UDMA100 SATA 3Gb/s Oct 1 13:37:41 localhost kernel: acd0: DVDR at ata3-master UDMA100 SATA 1.5Gb/s Oct 1 13:37:41 localhost kernel: hdac0: HDA Codec #0: IDT 92HD71B7 Oct 1 13:37:41 localhost kernel: pcm0: at= cad 0 nid 1 on hdac0 Oct 1 13:37:41 localhost kernel: pcm1: at= cad 0 nid 1 on hdac0 Oct 1 13:37:41 localhost kernel: pcm2: a= t cad 0 nid 1 on hdac0 Oct 1 13:37:41 localhost kernel: uhub0: 2 ports with 2 removable, self pow= ered Oct 1 13:37:41 localhost kernel: uhub1: 2 ports with 2 removable, self pow= ered Oct 1 13:37:41 localhost kernel: uhub2: 2 ports with 2 removable, self pow= ered Oct 1 13:37:41 localhost kernel: uhub4: 2 ports with 2 removable, self pow= ered Oct 1 13:37:41 localhost kernel: uhub5: 2 ports with 2 removable, self pow= ered Oct 1 13:37:41 localhost kernel: uhub6: 2 ports with 2 removable, self pow= ered Oct 1 13:37:41 localhost kernel: uhub3: 6 ports with 6 removable, self pow= ered Oct 1 13:37:41 localhost kernel: uhub7: 6 ports with 6 removable, self pow= ered Oct 1 13:37:41 localhost kernel: acd0: FAILURE - INQUIRY ILLEGAL REQUEST a= sc=3D0x24 ascq=3D0x00=20 Oct 1 13:37:41 localhost kernel: (probe0:ata3:0:0:0): TEST UNIT READY. CDB= : 0 0 0 0 0 0=20 Oct 1 13:37:41 localhost kernel: (probe0:ata3:0:0:0): CAM status: SCSI Sta= tus Error Oct 1 13:37:41 localhost kernel: (probe0:ata3:0:0:0): SCSI status: Check C= ondition Oct 1 13:37:41 localhost kernel: (probe0:ata3:0:0:0): SCSI sense: NOT READ= Y asc:3a,1 (Medium not present - tray closed) Oct 1 13:37:41 localhost kernel: cd0 at ata3 bus 0 scbus1 target 0 lun 0 Oct 1 13:37:41 localhost kernel: cd0: Rem= ovable CD-ROM SCSI-0 device=20 Oct 1 13:37:41 localhost kernel: cd0: 100.000MB/s transfersSMP: AP CPU #1 = Launched! Oct 1 13:37:41 localhost kernel:=20 Oct 1 13:37:41 localhost kernel: cd0: Attempt to query device size failed:= NOT READY, Medium not present - tray closed Oct 1 13:37:41 localhost kernel: Trying to mount root from ufs:/dev/ad4s2a Oct 1 13:37:41 localhost kernel: ugen2.2: at usbus2 and stops right there when it hangs. When it does not hang, the boot continues at that point with: Oct 1 13:37:41 localhost kernel: WARNING: TMPFS is considered to be a high= ly experimental feature in FreeBSD. Oct 1 13:37:41 localhost kernel: wlan0: Ethernet address: 00:21:6a:26:34:c0 Oct 1 13:37:41 localhost kernel: iwn0: radio is disabled by hardware switch Oct 1 13:37:42 localhost kernel: em0: link state changed to DOWN Oct 1 13:37:44 localhost kernel: em0: link state changed to UP =2E... Now, I never saw this behavior with the old laptop, and I had been tracking stable/7, stable/8, and head on that on a daily basis ever since a stable/8 existed. (And I've been tracking head rather longer than that.) While I'm not about to assume that this indicates something wrong with FreeBSD, I'm a bit less inclined to believe that it might be a hardware/BIOS issue than I was yesterday. Here are some differences between what I saw with my work desktop vs. the new laptop: * Desktop would reliably hang on each alternate boot. No pattern detected for laptop, but hangs predominate (by a factor of about 4:1). * Desktop would hang on alternate boots regardless of which branch of FreeBSD I was trying to boot. Laptop only hangs on head. * BIOS upgrade resolved issue with desktop. So far, it hasn't with the laptop. How might I get sufficient appropriate additional detail that I might be able to help get this figured out, and possibly even fixed? I've attached a copy of the stable/8 dmesg.boot. I can get one form head, but this is what I have at the moment. I will, of course, be happy to test patches. Thanks! Peace, david --=20 David H. Wolfskill david@catwhisker.org Depriving a girl or boy of an opportunity for education is evil. See http://www.catwhisker.org/~david/publickey.gpg for my public key. --OM63UbYQsNeyh2dn Content-Type: text/plain; charset=us-ascii Content-Disposition: attachment; filename="dmesg.boot" Content-Transfer-Encoding: quoted-printable Copyright (c) 1992-2010 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.1-STABLE #3 r213295: Thu Sep 30 04:11:06 PDT 2010 root@g1-222.catwhisker.org.:/common/S2/obj/usr/src/sys/CANARY i386 Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: Intel(R) Core(TM)2 Duo CPU T9600 @ 2.80GHz (2793.01-MHz 686-class= CPU) Origin =3D "GenuineIntel" Id =3D 0x10676 Family =3D 6 Model =3D 17 St= epping =3D 6 Features=3D0xbfebfbff Features2=3D0x8e3fd AMD Features=3D0x20100000 AMD Features2=3D0x1 TSC: P-state invariant real memory =3D 4294967296 (4096 MB) avail memory =3D 3657080832 (3487 MB) ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs FreeBSD/SMP: 1 package(s) x 2 core(s) cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 1 ioapic0: Changing APIC ID to 2 ioapic0 irqs 0-23 on motherboard kbd1 at kbdmux0 acpi0: on motherboard acpi0: [ITHREAD] acpi_hpet0: iomem 0xfed00000-0xfed003ff on acp= i0 Timecounter "HPET" frequency 14318180 Hz quality 900 acpi0: reservation of 0, 9f000 (3) failed acpi0: reservation of 100000, df351c00 (3) failed Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1008-0x100b on acpi0 cpu0: on acpi0 cpu1: on acpi0 acpi_ec0: port 0x930,0x934 on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 pcib1: at device 1.0 on pci0 pci1: on pcib1 vgapci0: port 0xdf00-0xdf7f mem 0xf5000000-0xf5fff= fff,0xe0000000-0xefffffff,0xf2000000-0xf3ffffff irq 16 at device 0.0 on pci1 em0: port 0xefe0-0xefff mem 0x= f6fe0000-0xf6ffffff,0xf6fdb000-0xf6fdbfff irq 22 at device 25.0 on pci0 em0: Using MSI interrupt em0: [FILTER] em0: Ethernet address: 00:21:70:d5:28:dd uhci0: port 0x6f60-0x6f7f irq 20 at de= vice 26.0 on pci0 uhci0: [ITHREAD] uhci0: LegSup =3D 0x2f00 usbus0: on uhci0 uhci1: port 0x6f80-0x6f9f irq 21 at de= vice 26.1 on pci0 uhci1: [ITHREAD] uhci1: LegSup =3D 0x2f00 usbus1: on uhci1 uhci2: port 0x6fa0-0x6fbf irq 22 at de= vice 26.2 on pci0 uhci2: [ITHREAD] uhci2: LegSup =3D 0x2f00 usbus2: on uhci2 ehci0: mem 0xfed1c400-0xfed1c7ff i= rq 22 at device 26.7 on pci0 ehci0: [ITHREAD] usbus3: EHCI version 1.0 usbus3: on ehci0 hdac0: mem 0xf6fdc000-0xf6f= dffff irq 21 at device 27.0 on pci0 hdac0: HDA Driver Revision: 20100226_0142 hdac0: [ITHREAD] pcib2: at device 28.0 on pci0 pci11: on pcib2 pcib3: at device 28.1 on pci0 pci12: on pcib3 iwn0: mem 0xf1ffe000-0xf1ffffff irq 17 at devi= ce 0.0 on pci12 iwn0: MIMO 3T3R, MoW, address 00:21:6a:26:34:c0 iwn0: [ITHREAD] iwn0: 11a rates: 6Mbps 9Mbps 12Mbps 18Mbps 24Mbps 36Mbps 48Mbps 54Mbps iwn0: 11b rates: 1Mbps 2Mbps 5.5Mbps 11Mbps iwn0: 11g rates: 1Mbps 2Mbps 5.5Mbps 11Mbps 6Mbps 9Mbps 12Mbps 18Mbps 24Mbp= s 36Mbps 48Mbps 54Mbps pcib4: at device 28.2 on pci0 pci13: on pcib4 pcib5: at device 28.3 on pci0 pci14: on pcib5 uhci3: port 0x6f00-0x6f1f irq 20 at de= vice 29.0 on pci0 uhci3: [ITHREAD] uhci3: LegSup =3D 0x2f00 usbus4: on uhci3 uhci4: port 0x6f20-0x6f3f irq 21 at de= vice 29.1 on pci0 uhci4: [ITHREAD] uhci4: LegSup =3D 0x2f00 usbus5: on uhci4 uhci5: port 0x6f40-0x6f5f irq 22 at de= vice 29.2 on pci0 uhci5: [ITHREAD] uhci5: LegSup =3D 0x2f00 usbus6: on uhci5 ehci1: mem 0xfed1c000-0xfed1c3ff i= rq 20 at device 29.7 on pci0 ehci1: [ITHREAD] usbus7: EHCI version 1.0 usbus7: on ehci1 pcib6: at device 30.0 on pci0 pci3: on pcib6 cbb0: irq 19 at device 1.0 on pci3 cardbus0: on cbb0 pccard0: <16-bit PCCard bus> on cbb0 cbb0: [FILTER] cbb0: Bad Vcc requested fwohci0: <1394 Open Host Controller Interface> mem 0xf1bff800-0xf1bfffff ir= q 17 at device 1.1 on pci3 fwohci0: [ITHREAD] fwohci0: OHCI version 1.10 (ROM=3D0) fwohci0: No. of Isochronous channels is 4. fwohci0: EUI64 4a:4f:c0:00:10:37:06:01 fwohci0: Phy 1394a available S400, 1 ports. fwohci0: Link S400, max_rec 2048 bytes. firewire0: on fwohci0 dcons_crom0: on firewire0 dcons_crom0: bus_addr 0x14a8000 fwe0: on firewire0 if_fwe0: Fake Ethernet address: 4a:4f:c0:37:06:01 fwe0: Ethernet address: 4a:4f:c0:37:06:01 fwip0: on firewire0 fwip0: Firewire address: 4a:4f:c0:00:10:37:06:01 @ 0xfffe00000000, S400, ma= xrec 2048 fwohci0: Initiate bus reset fwohci0: fwohci_intr_core: BUS reset fwohci0: fwohci_intr_core: node_id=3D0x00000000, SelfID Count=3D1, CYCLEMAS= TER mode pci3: at device 1.2 (no driver attach= ed) pci3: at device 1.3 (no driver attached) isab0: at device 31.0 on pci0 isa0: on isab0 atapci0: port 0x6e70-0x6e77,0x6e78-0x6e7b,0x6e80-0x= 6e87,0x6e88-0x6e8b,0x6ea0-0x6ebf mem 0xfed1c800-0xfed1cfff irq 19 at device= 31.2 on pci0 atapci0: [ITHREAD] atapci0: AHCI v1.20 controller with 4 3Gbps ports, PM supported ata2: on atapci0 ata2: [ITHREAD] ata3: on atapci0 ata3: [ITHREAD] ata4: on atapci0 ata4: [ITHREAD] ata5: on atapci0 ata5: [ITHREAD] ichsmb0: port 0x1100-0x111f mem 0xf6= fdaf00-0xf6fdafff irq 19 at device 31.3 on pci0 ichsmb0: [ITHREAD] smbus0: on ichsmb0 smb0: on smbus0 acpi_lid0: on acpi0 acpi_button0: on acpi0 acpi_button1: on acpi0 acpi_acad0: on acpi0 battery0: on acpi0 battery1: on acpi0 acpi_tz0: on acpi0 atkbdc0: port 0x60,0x64,0x62,0x66 irq 1 on ac= pi0 atkbd0: irq 1 on atkbdc0 kbd0 at atkbd0 atkbd0: [GIANT-LOCKED] atkbd0: [ITHREAD] psm0: irq 12 on atkbdc0 psm0: [GIANT-LOCKED] psm0: [ITHREAD] psm0: model GlidePoint, device ID 0 atrtc0: port 0x70-0x71,0x72-0x77 irq 8 on acpi0 pmtimer0 on isa0 orm0: at iomem 0xc0000-0xce7ff,0xce800-0xcffff pnpid ORM0= 000 on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=3D0x300> 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. est0: on cpu0 p4tcc0: on cpu0 est1: on cpu1 p4tcc1: on cpu1 Timecounters tick every 1.000 msec firewire0: 1 nodes, maxhop <=3D 0 cable IRM irm(0) (me)=20 firewire0: bus manager 0=20 ipfw2 (+ipv6) initialized, divert enabled, nat loadable, rule-based forward= ing enabled, default to deny, logging disabled load_dn_sched dn_sched FIFO loaded load_dn_sched dn_sched PRIO loaded load_dn_sched dn_sched QFQ loaded load_dn_sched dn_sched RR loaded load_dn_sched dn_sched WF2Q+ loaded 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 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 ad4: 238475MB at ata2-master UDMA100 SATA 3Gb/s acd0: DVDR at ata3-master UDMA100 SATA 1.= 5Gb/s hdac0: HDA Codec #0: IDT 92HD71B7 pcm0: at cad 0 nid 1 on hdac0 pcm1: at cad 0 nid 1 on hdac0 pcm2: at cad 0 nid 1 on hdac0 uhub0: 2 ports with 2 removable, self powered uhub1: 2 ports with 2 removable, self powered uhub2: 2 ports with 2 removable, self powered uhub4: 2 ports with 2 removable, self powered uhub5: 2 ports with 2 removable, self powered uhub6: 2 ports with 2 removable, self powered uhub3: 6 ports with 6 removable, self powered uhub7: 6 ports with 6 removable, self powered acd0: FAILURE - INQUIRY ILLEGAL REQUEST asc=3D0x24 ascq=3D0x00=20 (probe0:ata3:0:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0=20 (probe0:ata3:0:0:0): CAM status: SCSI Status Error (probe0:ata3:0:0:0): SCSI status: Check Condition (probe0:ata3:0:0:0): SCSI sense: NOT READY asc:3a,1 (Medium not present - t= ray closed) cd0 at ata3 bus 0 scbus1 target 0 lun 0 cd0: Removable CD-ROM SCSI-0 device=20 cd0: 100.000MB/s transfersSMP: AP CPU #1 Launched! cd0: Attempt to query device size failed: NOT READY, Medium not present - t= ray closed Trying to mount root from ufs:/dev/ad4s2a ugen2.2: at usbus2 WARNING: TMPFS is considered to be a highly experimental feature in FreeBSD. wlan0: Ethernet address: 00:21:6a:26:34:c0 iwn0: radio is disabled by hardware switch --OM63UbYQsNeyh2dn-- --inZzG0lmAPZRgTxV Content-Type: application/pgp-signature Content-Disposition: inline -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.16 (FreeBSD) iEYEARECAAYFAkymUKUACgkQmprOCmdXAD1ABwCfRcaCF88V/T3oAQK5kGdn3iot JQAAn2yDPjThplUscAJwJ0o/ZNjcXBpW =8zrT -----END PGP SIGNATURE----- --inZzG0lmAPZRgTxV--