From owner-freebsd-stable@FreeBSD.ORG Tue Apr 29 01:03:29 2014 Return-Path: Delivered-To: stable@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1 with cipher ADH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 8835DDDA for ; Tue, 29 Apr 2014 01:03:29 +0000 (UTC) Received: from gw.catspoiler.org (gw.catspoiler.org [75.1.14.242]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 3FB9418D4 for ; Tue, 29 Apr 2014 01:03:29 +0000 (UTC) Received: from FreeBSD.org (mousie.catspoiler.org [192.168.101.2]) by gw.catspoiler.org (8.13.3/8.13.3) with ESMTP id s3T13MfY027827 for ; Mon, 28 Apr 2014 18:03:26 -0700 (PDT) (envelope-from truckman@FreeBSD.org) Message-Id: <201404290103.s3T13MfY027827@gw.catspoiler.org> Date: Mon, 28 Apr 2014 17:56:03 -0700 (PDT) From: Don Lewis Subject: Thinkpad R60 hangs when booting recent 8.4-STABLE To: stable@FreeBSD.org MIME-Version: 1.0 Content-Type: TEXT/plain; charset=us-ascii X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.17 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 29 Apr 2014 01:03:29 -0000 I've been upgrading my 8.4-STABLE machines to r264698 and haven't had any issues until I tried to upgrade my laptop. I was previously running r259528 without any problems, but it now hangs during boot. It's a hard hang and the machine doesn't respond to anything, including Caps Lock. I took a picture of the screen and compared it to dmesg.boot from booting kernel.old and the boot messages appear to be identical up to the point where the hang occurs. Copyright (c) 1992-2013 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.4-STABLE #51 r259528M: Wed Dec 18 16:44:30 PST 2013 dl@hairball.catspoiler.org:/usr/obj/usr/src/sys/UP_ATAPICAM i386 gcc version 4.2.1 20070831 patched [FreeBSD] Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: Intel(R) Pentium(R) M processor 1500MHz (1498.74-MHz 686-class CPU) Origin = "GenuineIntel" Id = 0x695 Family = 6 Model = 9 Stepping = 5 Features=0xa7e9f9bf Features2=0x180 real memory = 1073741824 (1024 MB) avail memory = 1032552448 (984 MB) kbd1 at kbdmux0 ACPI Warning: 32/64X length mismatch in Gpe1Block: 0/32 (20101013/tbfadt-625) ACPI Warning: Optional field Gpe1Block has zero address or length: 0x000000000000102C/0x0 (20101013/tbfadt-655) acpi0: on motherboard acpi0: [ITHREAD] acpi_ec0: port 0x62,0x66 on acpi0 acpi0: Power Button (fixed) acpi0: reservation of 0, a0000 (3) failed acpi0: reservation of 100000, 3ff00000 (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 acpi_lid0: on acpi0 acpi_button0: on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 agp0: on hostb0 [Boot hangs here with recent kernel] pcib1: at device 1.0 on pci0 pci1: on pcib1 vgapci0: port 0x3000-0x30ff mem 0xe0000000-0xe7ffffff,0xc0100000-0xc010ffff irq 11 at device 0.0 on pci1 uhci0: port 0x1800-0x181f irq 11 at device 29.0 on pci0 uhci0: [ITHREAD] usbus0 on uhci0 uhci1: port 0x1820-0x183f irq 6 at device 29.1 on pci0 uhci1: [ITHREAD] usbus1 on uhci1 uhci2: port 0x1840-0x185f irq 9 at device 29.2 on pci0 uhci2: [ITHREAD] usbus2 on uhci2 ehci0: mem 0xc0000000-0xc00003ff irq 9 at device 29.7 on pci0 ehci0: [ITHREAD] usbus3: EHCI version 1.0 usbus3 on ehci0 pcib2: at device 30.0 on pci0 pci2: on pcib2 cbb0: irq 6 at device 0.0 on pci2 cardbus0: on cbb0 pccard0: <16-bit PCCard bus> on cbb0 cbb0: [FILTER] ath0: mem 0xc0200000-0xc020ffff irq 9 at device 2.0 on pci2 ath0: [ITHREAD] ath0: AR5212 mac 5.9 RF2112 phy 4.3 fwohci0: mem 0xc0215000-0xc02157ff,0xc0210000-0xc0213fff irq 11 at device 7.0 on pci2 fwohci0: [ITHREAD] fwohci0: OHCI version 1.10 (ROM=0) fwohci0: No. of Isochronous channels is 4. fwohci0: EUI64 00:06:1b:00:20:09:dc:c3 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 0x14a0000 fwe0: on firewire0 if_fwe0: Fake Ethernet address: 02:06:1b:09:dc:c3 fwe0: Ethernet address: 02:06:1b:09:dc:c3 fwip0: on firewire0 fwip0: Firewire address: 00:06:1b:00:20:09:dc:c3 @ 0xfffe00000000, S400, maxrec 2048 fwohci0: Initiate bus reset fwohci0: fwohci_intr_core: BUS reset fwohci0: fwohci_intr_core: node_id=0x00000000, SelfID Count=1, CYCLEMASTER mode fxp0: port 0x8000-0x803f mem 0xc0214000-0xc0214fff irq 5 at device 8.0 on pci2 miibus0: on fxp0 inphy0: PHY 1 on miibus0 inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto, auto-flow fxp0: Ethernet address: 00:06:1b:d4:72:bb fxp0: [ITHREAD] isab0: at device 31.0 on pci0 isa0: on isab0 atapci0: port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0x1860-0x186f at device 31.1 on pci0 ata0: at channel 0 on atapci0 ata0: [ITHREAD] ata1: at channel 1 on atapci0 ata1: [ITHREAD] pci0: at device 31.3 (no driver attached) pci0: at device 31.5 (no driver attached) pci0: at device 31.6 (no driver attached) acpi_tz0: on acpi0 atrtc0: port 0x70-0x71 irq 8 on acpi0 atkbdc0: port 0x60,0x64 irq 1 on acpi0 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 Generic PS/2 mouse, device ID 0 uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 uart0: [FILTER] ppc0: port 0x3bc-0x3be irq 7 on acpi0 ppc0: Generic chipset (NIBBLE-only) in COMPATIBLE mode ppc0: [ITHREAD] ppbus0: on ppc0 plip0: on ppbus0 plip0: [ITHREAD] lpt0: on ppbus0 lpt0: [ITHREAD] lpt0: Interrupt-driven port ppi0: on ppbus0 battery0: on acpi0 acpi_acad0: on acpi0 pmtimer0 on isa0 orm0: at iomem 0xc0000-0xcffff,0xdc000-0xdffff,0xe0000-0xeffff 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 est0: on cpu0 p4tcc0: on cpu0 Timecounter "TSC" frequency 1498736259 Hz quality 800 Timecounters tick every 1.000 msec firewire0: 1 nodes, maxhop <= 0 cable IRM irm(0) (me) firewire0: bus manager 0 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 ad0: 152627MB at ata0-master UDMA100 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 uhub0: 2 ports with 2 removable, self powered uhub1: 2 ports with 2 removable, self powered uhub2: 2 ports with 2 removable, self powered GEOM: ad0s2: geometry does not match label (255h,63s != 16h,63s). uhub3: 6 ports with 6 removable, self powered ugen3.2: at usbus3 uhub4: on usbus3 uhub4: MTT enabled unknown: FAILURE - INQUIRY ILLEGAL REQUEST asc=0x24 ascq=0x00 (probe0:ata1:0:0:0): TEST UNIT READY. CDB: 00 00 00 00 00 00 (probe0:ata1:0:0:0): CAM status: SCSI Status Error (probe0:ata1:0:0:0): SCSI status: Check Condition (probe0:ata1:0:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present) cd0 at ata1 bus 0 scbus1 target 0 lun 0 cd0: Removable CD-ROM SCSI-0 device cd0: 3.300MB/s transfers cd0: Attempt to query device size failed: NOT READY, Medium not present cd0: quirks=0x10<10_BYTE_ONLY> Root mount waiting for: usbus3 uhub4: 4 ports with 4 removable, self powered ugen3.3: at usbus3 axe0: on usbus3 Trying to mount root from ufs:/dev/ad0s2a miibus1: on axe0 ukphy0: PHY 16 on miibus1 ukphy0: none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto ue0: on axe0 ue0: Ethernet address: 20:aa:4b:45:95:95 wlan0: Ethernet address: 00:16:ce:00:ac:a7 The dmesg contents for a verbose boot looks pretty much the same as well. Here's an extract from booting the old kernel with the place where the new kernel hangs flagged: [SNIP] pcib0: port 0xcf8-0xcff on acpi0 ACPI: Found matching pin for 0.29.INTA at func 0: 11 ACPI: Found matching pin for 0.29.INTB at func 1: 6 ACPI: Found matching pin for 0.29.INTC at func 2: 9 ACPI: Found matching pin for 0.29.INTD at func 7: 9 ACPI: Found matching pin for 0.31.INTA at func 1: 255 ACPI: Found matching pin for 0.31.INTB at func 3: 10 pci0: on pcib0 pci0: domain=0, physical bus=0 found-> vendor=0x8086, dev=0x3340, revid=0x03 domain=0, bus=0, slot=0, func=0 class=06-00-00, hdrtype=0x00, mfdev=0 cmdreg=0x0106, statreg=0x2090, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) map[10]: type Prefetchable Memory, range 32, base 0xd0000000, size 28, enabled found-> vendor=0x8086, dev=0x3341, revid=0x03 domain=0, bus=0, slot=1, func=0 class=06-04-00, hdrtype=0x01, mfdev=0 cmdreg=0x0107, statreg=0x00a0, cachelnsz=0 (dwords) lattimer=0x60 (2880 ns), mingnt=0x0c (3000 ns), maxlat=0x00 (0 ns) found-> vendor=0x8086, dev=0x24c2, revid=0x01 domain=0, bus=0, slot=29, func=0 class=0c-03-00, hdrtype=0x00, mfdev=1 cmdreg=0x0005, statreg=0x0280, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=11 map[20]: type I/O Port, range 32, base 0x1800, size 5, enabled pcib0: matched entry for 0.29.INTA (src \\_SB_.LNKA:0) pcib0: slot 29 INTA routed to irq 11 via \\_SB_.LNKA unknown: Reserved 0x20 bytes for rid 0x20 type 4 at 0x1800 found-> vendor=0x8086, dev=0x24c4, revid=0x01 domain=0, bus=0, slot=29, func=1 class=0c-03-00, hdrtype=0x00, mfdev=0 cmdreg=0x0005, statreg=0x0280, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=b, irq=6 map[20]: type I/O Port, range 32, base 0x1820, size 5, enabled pcib0: matched entry for 0.29.INTB (src \\_SB_.LNKD:0) pcib0: slot 29 INTB routed to irq 6 via \\_SB_.LNKD unknown: Reserved 0x20 bytes for rid 0x20 type 4 at 0x1820 found-> vendor=0x8086, dev=0x24c7, revid=0x01 domain=0, bus=0, slot=29, func=2 class=0c-03-00, hdrtype=0x00, mfdev=0 cmdreg=0x0005, statreg=0x0280, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=c, irq=9 map[20]: type I/O Port, range 32, base 0x1840, size 5, enabled pcib0: matched entry for 0.29.INTC (src \\_SB_.LNKC:0) pcib0: slot 29 INTC routed to irq 9 via \\_SB_.LNKC unknown: Reserved 0x20 bytes for rid 0x20 type 4 at 0x1840 found-> vendor=0x8086, dev=0x24cd, revid=0x01 domain=0, bus=0, slot=29, func=7 class=0c-03-20, hdrtype=0x00, mfdev=0 cmdreg=0x0106, statreg=0x0290, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=d, irq=9 powerspec 2 supports D0 D3 current D0 map[10]: type Memory, range 32, base 0xc0000000, size 10, enabled pcib0: matched entry for 0.29.INTD (src \\_SB_.LNKH:0) pcib0: slot 29 INTD routed to irq 9 via \\_SB_.LNKH unknown: Reserved 0x400 bytes for rid 0x10 type 3 at 0xc0000000 found-> vendor=0x8086, dev=0x2448, revid=0x81 domain=0, bus=0, slot=30, func=0 class=06-04-00, hdrtype=0x01, mfdev=0 cmdreg=0x0107, statreg=0x8080, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x04 (1000 ns), maxlat=0x00 (0 ns) found-> vendor=0x8086, dev=0x24cc, revid=0x01 domain=0, bus=0, slot=31, func=0 class=06-01-00, hdrtype=0x00, mfdev=1 cmdreg=0x000f, statreg=0x0280, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) found-> vendor=0x8086, dev=0x24ca, revid=0x01 domain=0, bus=0, slot=31, func=1 class=01-01-8a, hdrtype=0x00, mfdev=0 cmdreg=0x0005, statreg=0x0280, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=255 map[20]: type I/O Port, range 32, base 0x1860, size 4, enabled map[24]: type Memory, range 32, base 0, size 10, memory disabled found-> vendor=0x8086, dev=0x24c3, revid=0x01 domain=0, bus=0, slot=31, func=3 class=0c-05-00, hdrtype=0x00, mfdev=0 cmdreg=0x0001, statreg=0x0280, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=b, irq=10 map[20]: type I/O Port, range 32, base 0x1880, size 5, enabled pcib0: matched entry for 0.31.INTB (src \\_SB_.LNKB:0) pcib0: slot 31 INTB routed to irq 10 via \\_SB_.LNKB found-> vendor=0x8086, dev=0x24c5, revid=0x01 domain=0, bus=0, slot=31, func=5 class=04-01-00, hdrtype=0x00, mfdev=0 cmdreg=0x0007, statreg=0x0290, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=b, irq=10 powerspec 2 supports D0 D3 current D0 map[10]: type I/O Port, range 32, base 0x1c00, size 8, enabled map[14]: type I/O Port, range 32, base 0x18c0, size 6, enabled map[18]: type Memory, range 32, base 0xc0000c00, size 9, enabled map[1c]: type Memory, range 32, base 0xc0000800, size 8, enabled pcib0: matched entry for 0.31.INTB (src \\_SB_.LNKB:0) pcib0: slot 31 INTB routed to irq 10 via \\_SB_.LNKB found-> vendor=0x8086, dev=0x24c6, revid=0x01 domain=0, bus=0, slot=31, func=6 class=07-03-00, hdrtype=0x00, mfdev=0 cmdreg=0x0005, statreg=0x0290, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=b, irq=10 powerspec 2 supports D0 D3 current D0 map[10]: type I/O Port, range 32, base 0x2400, size 8, enabled map[14]: type I/O Port, range 32, base 0x2000, size 7, enabled pcib0: matched entry for 0.31.INTB (src \\_SB_.LNKB:0) pcib0: slot 31 INTB routed to irq 10 via \\_SB_.LNKB agp0: on hostb0 hostb0: Reserved 0x10000000 bytes for rid 0x10 type 3 at 0xd0000000 agp0: allocating GATT for aperture of size 256M [Hangs here] pcib1: at device 1.0 on pci0 pcib1: domain 0 pcib1: secondary bus 1 pcib1: subordinate bus 1 pcib1: I/O decode 0x3000-0x3fff pcib1: memory decode 0xc0100000-0xc01fffff pcib1: prefetched decode 0xe0000000-0xe7ffffff ACPI: Found matching pin for 1.0.INTA at func 0: 11 pci1: on pcib1 pci1: domain=0, physical bus=1 [SNIP] There haven't been any recent changes to agp. There were a few changes to pci two months ago, but they don't look especially suspicious. Any thoughts before I start bisecting?