amd64/133977: "panic: ffs_blkfree: freeing free block" after 7.0R->7.1R amd64 src upgrade

Rowan Crowe freebsdpr at sensation.net.au
Fri Apr 24 18:00:08 UTC 2009 

>Number:         133977
>Category:       amd64
>Synopsis:       "panic: ffs_blkfree: freeing free block" after 7.0R->7.1R amd64 src upgrade
>Confidential:   no
>Severity:       critical
>Priority:       medium
>Responsible:    freebsd-amd64
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Fri Apr 24 18:00:07 UTC 2009
>Closed-Date:
>Last-Modified:
>Originator:     Rowan Crowe
>Release:        7.1-RELEASE amd64
>Organization:
>Environment:
>Description:
After doing a source upgrade of FreeBSD 7.0-RELEASE to 7.1-RELEASE I am consistently seeing a panic, approximately 25-35 minutes after each boot. At the time the system is effectively idle (it's a MySQL server, but mysqld has been disabled at startup while I diagnose the problem). Two notable exceptions: gmirror is rebuilding two mirrors, and fsck_ufs is checking the file systems. Based on some quick research I suspect it's the latter that is causing the panic. If so I'm stuck in a vicious cycle since the file system is going to be checked after every crash...

This is what the panic output shows:


------
dev = stripe/raid10, block = 1, fs = /db
panic: ffs_blkfree: freeing free block
cpuid = 1
GEOM_MIRROR: Device db2: rebuilding provider ad16 stopped.
GEOM_MIRROR: Device db1: rebuilding provider ad12 stopped.
Uptime: 31m16s
Physical memory: 8183 MB
Dumping: 656 MB:
<system freezes at this point>
------

Note 1: /db is a stripe (name: "raid10") of two mirrors (names: "db1", "db2"), approx 1.5TB of usable size.


Output of /var/run/dmesg.boot:

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 7.1-RELEASE #0: Fri Apr 24 18:04:00 EST 2009
    rowan at db1au.sitedossier.com:/usr/src/sys/amd64/compile/DB1AU
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) Core(TM)2 Duo CPU     E8200  @ 2.66GHz (2669.04-MHz K8-class CPU)
  Origin = "GenuineIntel"  Id = 0x10676  Stepping = 6
  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=0x8e3fd<SSE3,RSVD2,MON,DS_CPL,VMX,SMX,EST,TM2,SSSE3,CX16,xTPR,PDCM,<b19>>
  AMD Features=0x20100800<SYSCALL,NX,LM>
  AMD Features2=0x1<LAHF>
  Cores per package: 2
usable memory = 8581054464 (8183 MB)
avail memory  = 8293785600 (7909 MB)
ACPI APIC Table: <GBT    GBTUACPI>
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
kbd1 at kbdmux0
acpi0: <GBT GBTUACPI> on motherboard
acpi0: [ITHREAD]
acpi0: Power Button (fixed)
acpi0: reservation of 0, a0000 (3) failed
acpi0: reservation of 100000, cfde0000 (3) failed
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0
acpi_hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0
Timecounter "HPET" frequency 14318180 Hz quality 900
acpi_button0: <Power Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
pcib1: <PCI-PCI bridge> irq 16 at device 1.0 on pci0
pci1: <PCI bus> on pcib1
vgapci0: <VGA-compatible display> mem 0xe4000000-0xe4ffffff,0xd0000000-0xdfffffff,0xe5000000-0xe5ffffff irq 16 at device 0.0 on pci1
pcib2: <PCI-PCI bridge> irq 16 at device 6.0 on pci0
pci2: <PCI bus> on pcib2
em0: <Intel(R) PRO/1000 Network Connection 6.9.6> port 0x9000-0x901f mem 0xe8020000-0xe803ffff,0xe8000000-0xe801ffff irq 16 at device 0.0 on pci2
em0: Using MSI interrupt
em0: [FILTER]
em0: Ethernet address: 00:1b:21:05:11:d4
uhci0: <UHCI (generic) USB controller> port 0xe200-0xe21f irq 16 at device 26.0 on pci0
uhci0: [GIANT-LOCKED]
uhci0: [ITHREAD]
usb0: <UHCI (generic) USB controller> on uhci0
usb0: USB revision 1.0
uhub0: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb0
uhub0: 2 ports with 2 removable, self powered
uhci1: <UHCI (generic) USB controller> port 0xe000-0xe01f irq 21 at device 26.1 on pci0
uhci1: [GIANT-LOCKED]
uhci1: [ITHREAD]
usb1: <UHCI (generic) USB controller> on uhci1
usb1: USB revision 1.0
uhub1: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb1
uhub1: 2 ports with 2 removable, self powered
uhci2: <UHCI (generic) USB controller> port 0xe100-0xe11f irq 18 at device 26.2 on pci0
uhci2: [GIANT-LOCKED]
uhci2: [ITHREAD]
usb2: <UHCI (generic) USB controller> on uhci2
usb2: USB revision 1.0
uhub2: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb2
uhub2: 2 ports with 2 removable, self powered
ehci0: <EHCI (generic) USB 2.0 controller> mem 0xef100000-0xef1003ff irq 18 at device 26.7 on pci0
ehci0: [GIANT-LOCKED]
ehci0: [ITHREAD]
usb3: EHCI version 1.0
usb3: companion controllers, 2 ports each: usb0 usb1 usb2
usb3: <EHCI (generic) USB 2.0 controller> on ehci0
usb3: USB revision 2.0
uhub3: <Intel EHCI root hub, class 9/0, rev 2.00/1.00, addr 1> on usb3
uhub3: 6 ports with 6 removable, self powered
umass0: <SanDisk USB Flash Drive, class 0/0, rev 2.00/2.00, addr 2> on uhub3
umass1: <SanDisk USB Flash Drive, class 0/0, rev 2.00/2.00, addr 3> on uhub3
pcib3: <ACPI PCI-PCI bridge> irq 16 at device 28.0 on pci0
pci3: <ACPI PCI bus> on pcib3
pcib4: <ACPI PCI-PCI bridge> irq 18 at device 28.2 on pci0
pci4: <ACPI PCI bus> on pcib4
atapci0: <SiI SiI 3132 SATA300 controller> port 0xa000-0xa07f mem 0xea004000-0xea00407f,0xea000000-0xea003fff irq 18 at device 0.0 on pci4
atapci0: [ITHREAD]
ata2: <ATA channel 0> on atapci0
ata2: [ITHREAD]
ata3: <ATA channel 1> on atapci0
ata3: [ITHREAD]
pcib5: <ACPI PCI-PCI bridge> irq 19 at device 28.3 on pci0
pci5: <ACPI PCI bus> on pcib5
pcib6: <ACPI PCI-PCI bridge> irq 16 at device 28.4 on pci0
pci6: <ACPI PCI bus> on pcib6
re0: <RealTek 8168/8168B/8168C/8168CP/8168D/8111B/8111C/8111CP PCIe Gigabit Ethernet> port 0xc000-0xc0ff mem 0xec000000-0xec000fff irq 16 at device 0.0 on pci6
re0: turning off MSI enable bit.
re0: Chip rev. 0x38000000
re0: MAC rev. 0x00000000
miibus0: <MII bus> on re0
rgephy0: <RTL8169S/8110S/8211B media interface> PHY 1 on miibus0
rgephy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-FDX, auto
re0: Ethernet address: 00:1d:7d:02:aa:6a
re0: [FILTER]
pcib7: <ACPI PCI-PCI bridge> irq 17 at device 28.5 on pci0
pci7: <ACPI PCI bus> on pcib7
re1: <RealTek 8168/8168B/8168C/8168CP/8168D/8111B/8111C/8111CP PCIe Gigabit Ethernet> port 0xd000-0xd0ff mem 0xee000000-0xee000fff irq 17 at device 0.0 on pci7
re1: turning off MSI enable bit.
re1: Chip rev. 0x38000000
re1: MAC rev. 0x00000000
miibus1: <MII bus> on re1
rgephy1: <RTL8169S/8110S/8211B media interface> PHY 1 on miibus1
rgephy1:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-FDX, auto
re1: Ethernet address: 00:1d:7d:02:aa:7a
re1: [FILTER]
uhci3: <UHCI (generic) USB controller> port 0xe300-0xe31f irq 23 at device 29.0 on pci0
uhci3: [GIANT-LOCKED]
uhci3: [ITHREAD]
usb4: <UHCI (generic) USB controller> on uhci3
usb4: USB revision 1.0
uhub4: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb4
uhub4: 2 ports with 2 removable, self powered
uhci4: <UHCI (generic) USB controller> port 0xe400-0xe41f irq 19 at device 29.1 on pci0
uhci4: [GIANT-LOCKED]
uhci4: [ITHREAD]
usb5: <UHCI (generic) USB controller> on uhci4
usb5: USB revision 1.0
uhub5: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb5
uhub5: 2 ports with 2 removable, self powered
uhci5: <UHCI (generic) USB controller> port 0xe500-0xe51f irq 18 at device 29.2 on pci0
uhci5: [GIANT-LOCKED]
uhci5: [ITHREAD]
usb6: <UHCI (generic) USB controller> on uhci5
usb6: USB revision 1.0
uhub6: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb6
uhub6: 2 ports with 2 removable, self powered
ehci1: <EHCI (generic) USB 2.0 controller> mem 0xef101000-0xef1013ff irq 23 at device 29.7 on pci0
ehci1: [GIANT-LOCKED]
ehci1: [ITHREAD]
usb7: EHCI version 1.0
usb7: companion controllers, 2 ports each: usb4 usb5 usb6
usb7: <EHCI (generic) USB 2.0 controller> on ehci1
usb7: USB revision 2.0
uhub7: <Intel EHCI root hub, class 9/0, rev 2.00/1.00, addr 1> on usb7
uhub7: 6 ports with 6 removable, self powered
pcib8: <ACPI PCI-PCI bridge> at device 30.0 on pci0
pci8: <ACPI PCI bus> on pcib8
isab0: <PCI-ISA bridge> at device 31.0 on pci0
isa0: <ISA bus> on isab0
atapci1: <Intel AHCI controller> port 0xe600-0xe607,0xe700-0xe703,0xe800-0xe807,0xe900-0xe903,0xea00-0xea1f mem 0xef102000-0xef1027ff irq 19 at device 31.2 on pci0
atapci1: [ITHREAD]
atapci1: AHCI Version 01.20 controller with 6 ports detected
ata4: <ATA channel 0> on atapci1
ata4: [ITHREAD]
ata5: <ATA channel 1> on atapci1
ata5: [ITHREAD]
ata6: <ATA channel 2> on atapci1
ata6: [ITHREAD]
ata7: <ATA channel 3> on atapci1
ata7: [ITHREAD]
ata8: <ATA channel 4> on atapci1
ata8: [ITHREAD]
ata9: <ATA channel 5> on atapci1
ata9: [ITHREAD]
pci0: <serial bus, SMBus> at device 31.3 (no driver attached)
speaker0: <PC speaker> port 0x61 on acpi0
sio0: configured irq 4 not in bitmap of probed irqs 0
sio0: port may not be enabled
sio0: configured irq 4 not in bitmap of probed irqs 0
sio0: port may not be enabled
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
sio0: type 16550A
sio0: [FILTER]
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
atkbd0: [ITHREAD]
cpu0: <ACPI CPU> on acpi0
acpi_perf0: <ACPI CPU Frequency Control> on cpu0
p4tcc0: <CPU Frequency Thermal Control> on cpu0
cpu1: <ACPI CPU> on acpi0
est1: <Enhanced SpeedStep Frequency Control> on cpu1
est: CPU supports Enhanced Speedstep, but is not recognized.
est: cpu_vendor GenuineIntel, msr 61a082006000820
device_attach: est1 attach returned 6
p4tcc1: <CPU Frequency Thermal Control> on cpu1
orm0: <ISA Option ROMs> at iomem 0xd0000-0xd1fff,0xd2000-0xd5fff on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
sio1: configured irq 3 not in bitmap of probed irqs 0
sio1: port may not be enabled
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounters tick every 1.000 msec
ipfw2 initialized, divert enabled, nat loadable, rule-based forwarding enabled, default to accept, logging unlimited
ad4: 152627MB <Seagate ST3160815AS 3.AAD> at ata2-master SATA300
ad6: 152627MB <Seagate ST3160815AS 3.AAD> at ata3-master SATA300
ad8: 286167MB <WDC WD3000GLFS-01F8U0 03.03V01> at ata4-master SATA300
ad10: 305245MB <WDC WD3200AAJS-00B4A0 01.03A01> at ata5-master SATA300
ad12: 715404MB <WDC WD7500AACS-00C7B0 01.01B01> at ata6-master SATA300
ad14: 715404MB <WDC WD7500AACS-00C7B0 01.01B01> at ata7-master SATA300
ad16: 715404MB <WDC WD7500AACS-00D6B0 01.01A01> at ata8-master SATA300
ad18: 715404MB <WDC WD7500AAKS-00RBA0 30.04G30> at ata9-master SATA300
GEOM_MIRROR: Device mirror/gm0 launched (2/2).
GEOM_MIRROR: Device mirror/idx0 launched (2/2).
GEOM_MIRROR: Device mirror/db1 launched (1/2).
GEOM_MIRROR: Device db1: rebuilding provider ad12.
GEOM_MIRROR: Device mirror/db2 launched (1/2).
GEOM_MIRROR: Device db2: rebuilding provider ad16.
GEOM_STRIPE: Device raid10 created (id=1767666037).
GEOM_STRIPE: Disk mirror/db1 attached to raid10.
GEOM_STRIPE: Disk mirror/db2 attached to raid10.
GEOM_STRIPE: Device raid10 activated.
SMP: AP CPU #1 Launched!
da1 at umass-sim1 bus 1 target 0 lun 0
da1: <SanDisk USB Flash Drive 6.51> Removable Direct Access SCSI-0 device
da1: 40.000MB/s transfers
da1: 3849MB (7883775 512 byte sectors: 255H 63S/T 490C)
da0 at umass-sim0 bus 0 target 0 lun 0
da0: <SanDisk USB Flash Drive 6.51> Removable Direct Access SCSI-0 device
da0: 40.000MB/s transfers
da0: 3849MB (7883775 512 byte sectors: 255H 63S/T 490C)
GEOM_STRIPE: Device fl0 created (id=3021002192).
GEOM_STRIPE: Disk da0 attached to fl0.
GEOM_STRIPE: Disk da1 attached to fl0.
GEOM_STRIPE: Device fl0 activated.
Trying to mount root from ufs:/dev/mirror/gm0s1a
WARNING: / was not properly dismounted
WARNING: /usr was not properly dismounted
WARNING: /var was not properly dismounted
/var: mount pending error: blocks 8 files 2
WARNING: /db was not properly dismounted
/db: mount pending error: blocks 608512 files 1
WARNING: /flash0 was not properly dismounted
em0: link state changed to UP

>How-To-Repeat:
Unsure, as all I did was the upgrade.
>Fix:
Unsure. Will attempt to temporarily disable soft-updates and the mirror rebuild to see whether the system will stay up for more than 30 mins.

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

More information about the freebsd-amd64 mailing list