From owner-freebsd-stable@FreeBSD.ORG Sat Oct 20 14:10:26 2012 Return-Path: Delivered-To: stable@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id 8DC27A0E for ; Sat, 20 Oct 2012 14:10:26 +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 4941F8FC16 for ; Sat, 20 Oct 2012 14:10:26 +0000 (UTC) Received: from albert.catwhisker.org (localhost [127.0.0.1]) by albert.catwhisker.org (8.14.5/8.14.5) with ESMTP id q9KEAJ7g032894 for ; Sat, 20 Oct 2012 07:10:19 -0700 (PDT) (envelope-from david@albert.catwhisker.org) Received: (from david@localhost) by albert.catwhisker.org (8.14.5/8.14.5/Submit) id q9KEAJWx032893 for stable@freebsd.org; Sat, 20 Oct 2012 07:10:19 -0700 (PDT) (envelope-from david) Date: Sat, 20 Oct 2012 07:10:19 -0700 From: David Wolfskill To: stable@freebsd.org Subject: stable/9 @r241776 panic: REDZONE: Buffer underflow detected... Message-ID: <20121020141019.GW1817@albert.catwhisker.org> MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="K9yN6gtjNHvbaj05" Content-Disposition: inline User-Agent: Mutt/1.5.21 (2010-09-15) X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 20 Oct 2012 14:10:26 -0000 --K9yN6gtjNHvbaj05 Content-Type: multipart/mixed; boundary="uqlJfHshKOiOfK6d" Content-Disposition: inline --uqlJfHshKOiOfK6d Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable This seems ... fairly weird to me. Yesterday, I built & booted: FreeBSD g1-227.catwhisker.org 9.1-PRERELEASE FreeBSD 9.1-PRERELEASE #274 24= 1726M: Fri Oct 19 05:40:05 PDT 2012 root@g1-227.catwhisker.org:/usr/obj= /usr/src/sys/CANARY i386 and used the machine all day; nothing unusual (including various reboots (e.g. when I disembarked the train for the final leg of my commute home, so I powered the laptop off). This morning, I built: FreeBSD g1-227.catwhisker.org 9.1-PRERELEASE FreeBSD 9.1-PRERELEASE #275 24= 1776M: Sat Oct 20 04:34:45 PDT 2012 root@g1-227.catwhisker.org:/usr/obj= /usr/src/sys/CANARY i386 and on first reboot, I got a panic. After a bit of experimentation, it appears that I get a panic @r241776 if I attempt a normal boot into multi-user mode, but if I first boot to single-user mode, then exit single-user mode, it comes up without a problem. I don't have a serial console, so I started to write down some of the panic information, but my patience ran a bit short. Here's whet I recorded (warning: hand-transcripted -- twice!): =2E.. Starting devd. REDZONE: Buffer underflow detected. 1 byte corrupted before 0xced40080 (42= 94966796 bytes allocated). Allocation backtrace: #0 0xc0ceac8f at redzone_setup+0xcf #1 0xc0a5d5c9 at malloc+0x1d9 =2E..[about 20 more such lines I didn't record]... > bt Tracing pid 901 tid 100106 td 0xd2b99000 kdb_enter(...) panic(...) free(...) devread(ce8c2d00,f7274c0c,0,c0b1e4f0,d279e380,...) at devread+0x1a6 giant_read(...) at giant_read+0x87 devfs_read(...) at devfs_read+0xc6 dofileread(...) at dofileread+0x99 sys_read(...) at sys_read+0x98 syscall(f7274d08) at syscall+0x387 Within the bounds described above, this appears to be quite reproducible -- on my laptop. My build machine (updated in parallel, at the same GRNs) does not exhibit the panic. I was unable to get a crash dump; I have dumpdev=3D"AUTO" in /etc/rc.conf, and the panic was occurring well after swap was enabled. (Yes, I know I have swap over-allocated. I plan to do something about it at some point.) I've attached a copy of dmesg.boot. Anyone else seeing this? Any ideas how to diagnose it? Thanks! Peace, david --=20 David H. Wolfskill david@catwhisker.org Taliban: Evil men with guns afraid of truth from a 14-year old girl. See http://www.catwhisker.org/~david/publickey.gpg for my public key. --uqlJfHshKOiOfK6d Content-Type: text/plain; charset=us-ascii Content-Disposition: attachment; filename="dmesg.boot.9.1-PRERELEASE" Content-Transfer-Encoding: quoted-printable Copyright (c) 1992-2012 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 9.1-PRERELEASE #275 241776M: Sat Oct 20 04:34:45 PDT 2012 root@g1-227.catwhisker.org:/usr/obj/usr/src/sys/CANARY i386 WARNING: DIAGNOSTIC option enabled, expect reduced performance. MEMGUARD DEBUGGING ALLOCATOR INITIALIZED: MEMGUARD map base: 0xc8000000 MEMGUARD map limit: 0xce681000 MEMGUARD map size: 104964 KBytes CPU: Intel(R) Core(TM)2 Duo CPU T9600 @ 2.80GHz (2793.06-MHz 686-class= CPU) Origin =3D "GenuineIntel" Id =3D 0x10676 Family =3D 0x6 Model =3D 0x17= Stepping =3D 6 Features=3D0xbfebfbff Features2=3D0x8e3fd AMD Features=3D0x20100000 AMD Features2=3D0x1 TSC: P-state invariant, performance statistics real memory =3D 4294967296 (4096 MB) avail memory =3D 3643670528 (3474 MB) Event timer "LAPIC" quality 400 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 hpet0: iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 14318180 Hz quality 950 Event timer "HPET" frequency 14318180 Hz quality 450 Event timer "HPET1" frequency 14318180 Hz quality 440 Event timer "HPET2" frequency 14318180 Hz quality 440 Event timer "HPET3" frequency 14318180 Hz quality 440 acpi0: reservation of 0, 9f000 (3) failed acpi0: reservation of 100000, df351c00 (3) failed cpu0: on acpi0 cpu1: on acpi0 atrtc0: port 0x70-0x71,0x72-0x77 irq 8 on acpi0 Event timer "RTC" frequency 32768 Hz quality 0 attimer0: port 0x40-0x43,0x50-0x53 irq 2 on acpi0 Timecounter "i8254" frequency 1193182 Hz quality 0 Event timer "i8254" frequency 1193182 Hz quality 100 Timecounter "ACPI-fast" frequency 3579545 Hz quality 900 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1008-0x100b 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 nvidia0: on vgapci0 vgapci0: child nvidia0 requested pci_enable_io vgapci0: child nvidia0 requested pci_enable_io pci0: at device 3.0 (no driver attached) atapci0: port 0xef78-0xef7f,0xef70-0xef73,0xef80-0xe= f87,0xef74-0xef77,0xef90-0xef9f irq 18 at device 3.2 on pci0 ata2: at channel 0 on atapci0 ata3: at channel 1 on atapci0 pci0: at device 3.3 (no driver attached) em0: port 0xefe0-0xefff mem 0x= f6fe0000-0xf6ffffff,0xf6fdb000-0xf6fdbfff irq 22 at device 25.0 on pci0 em0: Using an MSI interrupt em0: Ethernet address: 00:24:e8:9c:11:0f uhci0: port 0x6f60-0x6f7f irq 20 at de= vice 26.0 on pci0 uhci0: LegSup =3D 0x2f00 usbus0 on uhci0 uhci1: port 0x6f80-0x6f9f irq 21 at de= vice 26.1 on pci0 uhci1: LegSup =3D 0x2f00 usbus1 on uhci1 uhci2: port 0x6fa0-0x6fbf irq 22 at de= vice 26.2 on pci0 uhci2: LegSup =3D 0x2f00 usbus2 on uhci2 ehci0: mem 0xfed1c400-0xfed1c7ff i= rq 22 at device 26.7 on pci0 usbus3: EHCI version 1.0 usbus3 on ehci0 hdac0: mem 0xf6fdc000-0xf6fdffff irq 21 at de= vice 27.0 on pci0 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= device 0.0 on pci12 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: LegSup =3D 0x2f00 usbus4 on uhci3 uhci4: port 0x6f20-0x6f3f irq 21 at de= vice 29.1 on pci0 uhci4: LegSup =3D 0x2f00 usbus5 on uhci4 uhci5: port 0x6f40-0x6f5f irq 22 at de= vice 29.2 on pci0 uhci5: LegSup =3D 0x2f00 usbus6 on uhci5 ehci1: mem 0xfed1c000-0xfed1c3ff i= rq 20 at device 29.7 on pci0 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 fwohci0: <1394 Open Host Controller Interface> mem 0xf1bff800-0xf1bfffff ir= q 17 at device 1.1 on pci3 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 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 dcons_crom0: on firewire0 dcons_crom0: bus_addr 0x20e8000 fwohci0: Initiate bus reset fwohci0: fwohci_intr_core: BUS reset fwohci0: fwohci_intr_core: node_id=3D0x00000000, SelfID Count=3D1, CYCLEMAS= TER mode sdhci0: mem 0xf1bff600-0xf1bff6ff irq 18 at device 1.2 on= pci3 sdhci0: 1 slot(s) allocated pci3: at device 1.3 (no driver attached) isab0: at device 31.0 on pci0 isa0: on isab0 ahci0: port 0x6e70-0x6e77,0x6e78-0x6e7b,= 0x6e80-0x6e87,0x6e88-0x6e8b,0x6ea0-0x6ebf mem 0xfed1c800-0xfed1cfff irq 19 = at device 31.2 on pci0 ahci0: AHCI v1.20 with 4 3Gbps ports, Port Multiplier supported ahcich0: at channel 0 on ahci0 ahcich1: at channel 1 on ahci0 ahcich4: at channel 4 on ahci0 ahcich5: at channel 5 on ahci0 ichsmb0: port 0x1100-0x111f mem 0xf6= fd9f00-0xf6fd9fff irq 19 at device 31.3 on pci0 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] psm0: irq 12 on atkbdc0 psm0: [GIANT-LOCKED] psm0: model GlidePoint, device ID 0 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 ata1: at port 0x170-0x177,0x376 irq 15 on isa0 ppc0: parallel port not found. ctl: CAM Target Layer loaded coretemp0: on cpu0 est0: on cpu0 p4tcc0: on cpu0 coretemp1: on cpu1 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 DUMMYNET 0 with IPv6 initialized (100409) 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 hdacc0: at cad 0 on hdac0 hdaa0: at nid 1 on hdacc0 pcm0: at nid 13,10 and 11,14 on hdaa0 pcm1: at nid 15 and 24 on hdaa0 pcm2: at nid 30 on hdaa0 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 Expensive timeout(9) function: 0xc0ab2680(0xcefa12f0) 0.002124711 s ugen5.1: at usbus5 uhub5: on usbus5 ugen6.1: at usbus6 uhub6: on usbus6 ugen7.1: at usbus7 uhub7: on usbus7 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 Expensive timeout(9) function: 0xc055ae80(0xcf307e80) 0.365924998 s uhub3: 6 ports with 6 removable, self powered uhub7: 6 ports with 6 removable, self powered ada0 at ahcich0 bus 0 scbus2 target 0 lun 0 ada0: ATA-8 SATA 2.x device ada0: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes) ada0: Command Queueing enabled ada0: 476940MB (976773168 512 byte sectors: 16H 63S/T 16383C) ada0: Previously was known as ad8 cd0 at ahcich1 bus 0 scbus3 target 0 lun 0 cd0: Removable CD-ROM SCSI-0 device=20 cd0: 150.000MB/s transfers (SATA 1.x, UDMA5, ATAPI 12bytes, PIO 8192bytes) cd0: Attempt to query device size failed: NOT READY, Medium not present - t= ray closed SMP: AP CPU #1 Launched! WARNING: DIAGNOSTIC option enabled, expect reduced performance. GEOM: ada0s1: geometry does not match label (255h,63s !=3D 16h,63s). GEOM: ada0s2: geometry does not match label (255h,63s !=3D 16h,63s). GEOM: ada0s3: geometry does not match label (255h,63s !=3D 16h,63s). GEOM: ada0s4: geometry does not match label (255h,63s !=3D 16h,63s). Trying to mount root from ufs:/dev/ada0s1a [rw]... WARNING: / was not properly dismounted warning: total configured swap (5242880 pages) exceeds maximum recommended = amount (2097312 pages). warning: increase kern.maxswzone or reduce amount of swap. wlan0: Ethernet address: 00:21:6a:26:34:c0 --uqlJfHshKOiOfK6d-- --K9yN6gtjNHvbaj05 Content-Type: application/pgp-signature -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.19 (FreeBSD) iEYEARECAAYFAlCCsMsACgkQmprOCmdXAD389QCcDaRnI643aWBu+fe8vOJWdn5s GaYAnj9PESToWuBdlrbdkkr4I0W4M4u5 =m9Qu -----END PGP SIGNATURE----- --K9yN6gtjNHvbaj05--