From owner-freebsd-current  Mon Mar 24 13:57:31 2003
Delivered-To: freebsd-current@freebsd.org
Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125])
	by hub.freebsd.org (Postfix) with ESMTP id 8212137B401
	for <current@FreeBSD.org>; Mon, 24 Mar 2003 13:57:15 -0800 (PST)
Received: from fump.kawo2.rwth-aachen.de (fump.kawo2.RWTH-Aachen.DE [134.130.181.148])
	by mx1.FreeBSD.org (Postfix) with ESMTP id 06CF943F85
	for <current@FreeBSD.org>; Mon, 24 Mar 2003 13:57:14 -0800 (PST)
	(envelope-from alex@fump.kawo2.rwth-aachen.de)
Received: from fump.kawo2.rwth-aachen.de (localhost.kawo2.rwth-aachen.de [127.0.0.1])
	by fump.kawo2.rwth-aachen.de (8.12.8/8.12.6) with ESMTP id h2OLvDMf001321
	for <current@FreeBSD.org>; Mon, 24 Mar 2003 22:57:13 +0100 (CET)
	(envelope-from alex@fump.kawo2.rwth-aachen.de)
Received: (from alex@localhost)
	by fump.kawo2.rwth-aachen.de (8.12.8/8.12.6/Submit) id h2OLvCQc001320
	for current@FreeBSD.org; Mon, 24 Mar 2003 22:57:12 +0100 (CET)
Date: Mon, 24 Mar 2003 22:57:12 +0100
From: Alexander Langer <alex@big.endian.de>
To: current@FreeBSD.org
Subject: several background fsck panics
Message-ID: <20030324215712.GA844@fump.kawo2.rwth-aachen.de>
Mail-Followup-To: Alexander Langer <alex@big.endian.de>,
	current@FreeBSD.org
Mime-Version: 1.0
Content-Type: text/plain; charset=iso-8859-1
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
X-PGP-Fingerprint: 7EC1 5B98 4554 2A63 9079  2B2F 9A94 CD6F 7F14 EFA4
X-PGP-at: finger alex@big.endian.de
X-Verwirrung: Dieser Header dient der allgemeinen Verwirrung.
User-Agent: Mutt/1.5.3i
X-Spam-Status: No, hits=-5.2 required=5.0
	tests=HTML_00_10,USER_AGENT_MUTT
	autolearn=ham	version=2.50
X-Spam-Level: 
X-Spam-Checker-Version: SpamAssassin 2.50 (1.173-2003-02-20-exp)
Sender: owner-freebsd-current@FreeBSD.ORG
Precedence: bulk
List-ID: <freebsd-current.FreeBSD.ORG>
List-Archive: <http://docs.freebsd.org/mail/> (Web Archive)
List-Help: <mailto:majordomo@FreeBSD.ORG?subject=help> (List Instructions)
List-Subscribe: <mailto:majordomo@FreeBSD.ORG?subject=subscribe%20freebsd-current>
List-Unsubscribe: <mailto:majordomo@FreeBSD.ORG?subject=unsubscribe%20freebsd-current>
X-Loop: FreeBSD.ORG

Hi!

I had several panics related to background fsck now.  Once I disabled
background fsck, all went ok.

It began when I pressed the reset buttons on several boots while the
system was still doing fscks.

Then sometime this happened:

Mar 24 21:31:12 fump root: /dev/ad0s2g: 701589 files, 12766670 used,
32836022 free (76598 frags, 4094928 blocks, 0.2% fragmentation) 
Mar 24 21:32:27 fump kernel: handle_workitem_freeblocks: block count
Mar 24 21:37:36 fump root: fsck_ufs: cannot find inode 1443360 

and a bit later:

Mar 24 21:48:59 fump syslogd: kernel boot file is /boot/kernel/kernel
Mar 24 21:48:59 fump kernel: /usr: bad dir ino 500641 at offset 0:
mangled entry
Mar 24 21:48:59 fump kernel: panic: ufs_dirbad: bad dir
Mar 24 21:48:59 fump kernel: 
Mar 24 21:48:59 fump kernel: syncing disks, buffers remaining... 3810
3810 3810 3809 3809 3809 3806 3807 3807 3807 3807 3807 3803 3803 3803
3780 378
2 3782 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780
3780 3780 3780 3780 3780 3780 3780 
Mar 24 21:48:59 fump kernel: giving up on 2299 buffers
Mar 24 21:48:59 fump kernel: Uptime: 36m18s
Mar 24 21:48:59 fump kernel: Dumping 511 MB
Mar 24 21:48:59 fump kernel: ata0: resetting devices ..
Mar 24 21:48:59 fump kernel: done
Mar 24 21:48:59 fump kernel: 16 32 48 64 80[CTRL-C to abort]  96 112 128
144 160 176 192 208 224 240 256 272 288 304 320 336 352[CTRL-C to abort]
[C
TRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort]
[CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort]
[CTRL-
C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort]
[CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort]
[CTRL-C to
 abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort]

As I was in X, I thought my system just hung w/o dumping the core (my
hdd led is broken obviously), I then pressed reset.

Next turn:

Mar 24 21:48:59 fump kernel: WARNING: /data was not properly dismounted
Mar 24 21:48:59 fump kernel: /data: mount pending error: blocks 32 files 0
Mar 24 21:48:59 fump kernel: /data: superblock summary recomputed

system entered multi-user, I logged in, but did not start anything but
my login shell.

Mar 24 21:53:37 fump syslogd: kernel boot file is /boot/kernel/kernel
Mar 24 21:53:37 fump kernel: dev = ad0s2g, block = 1, fs = /data
Mar 24 21:53:37 fump kernel: panic: ffs_blkfree: freeing free block
Mar 24 21:53:37 fump kernel: 

(entered debugger, I did a "c")

Mar 24 21:53:37 fump kernel: syncing disks, buffers remaining... panic:
bremfree: removing a buffer not on a queue
Mar 24 21:53:37 fump kernel: Uptime: 2m10s
Mar 24 21:53:37 fump kernel: Dumping 511 MB
Mar 24 21:53:37 fump kernel: ata0: resetting devices ..
Mar 24 21:53:37 fump kernel: done
Mar 24 21:53:37 fump kernel: 16 32 48 64 80 96 112 128 144 160 176 192 

I pressed "reset" again as it would have dumped the wrong panic
and I wanted to dump the panic that caused the initial panic.
Next boot:

Mar 24 22:22:58 fump kernel: RENT WAS I=2404025
Mar 24 22:22:58 fump savecore: reboot after panic: bremfree: removing a
buffer not on a queue
Mar 24 22:22:58 fump savecore: writing core to vmcore.1

ok, here's the stuff:


Script started on Mon Mar 24 22:50:14 2003
root@fump /data/crash # gdb -k
GNU gdb 5.2.1 (FreeBSD)
Copyright 2002 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "i386-undermydesk-freebsd".
(kgdb) exec-file /boot/kernel/kernel
(kgdb) symbol-file /usr/obj/usr/src/sys/ZEROGRAVITY/kernel.debug 
Reading symbols from /usr/obj/usr/src/sys/ZEROGRAVITY/kernel.debug...done.
(kgdb) core-file vmcore.1
panic: bremfree: removing a buffer not on a queue
panic messages:
---
panic: ufs_dirbad: bad dir

syncing disks, buffers remaining... 3810 3810 3810 3809 3809 3809 3806 3807 3807 3807 3807 3807 3803 3803 3803 3780 3782 3782 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 3780 
giving up on 2299 buffers
Uptime: 36m18s
Dumping 511 MB
ata0: resetting devices ..
done
 16 32 48 64 80[CTRL-C to abort]  96 112 128 144 160 176 192 208 224 240 256 272 288 304 320 336 352[CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] Copyright (c) 1992-2003 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 5.0-CURRENT #5: Tue Mar 18 16:04:55 CET 2003
    alex@fump.kawo2.rwth-aachen.de:/data/obj/usr/src/sys/ZEROGRAVITY
Preloaded elf kernel "/boot/kernel/kernel" at 0xc0682000.
Preloaded elf module "/boot/kernel/nvidia.ko" at 0xc06820a8.
Preloaded elf module "/boot/kernel/linux.ko" at 0xc0682154.
Preloaded elf module "/boot/kernel/acpi.ko" at 0xc0682200.
Timecounter "i8254"  frequency 1193182 Hz
Timecounter "TSC"  frequency 1477361327 Hz
CPU: AMD Athlon(TM) XP1700+ (1477.36-MHz 686-class CPU)
  Origin = "AuthenticAMD"  Id = 0x662  Stepping = 2
  Features=0x383f9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE>
  AMD Features=0xc0480000<MP,AMIE,DSP,3DNow!>
real memory  = 536788992 (511 MB)
avail memory = 514334720 (490 MB)
Allocating major#253 to "net"
Allocating major#252 to "pci"
Pentium Pro MTRR support enabled
npx0: <math processor> on motherboard
npx0: INT 16 interface
acpi0: <ASUS   A7V266-E> on motherboard
    ACPI-0625: *** Info: GPE Block0 defined as GPE0 to GPE15
pcibios: BIOS version 2.10
Using $PIR table, 10 entries at 0xc00f13a0
acpi0: power button is handled as a fixed feature programming model.
Timecounter "ACPI-fast"  frequency 3579545 Hz
acpi_timer0: <24-bit timer at 3.579545MHz> port 0xe408-0xe40b on acpi0
acpi_cpu0: <CPU> port 0x530-0x537 on acpi0
acpi_button0: <Power Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
pcib1: <ACPI PCI-PCI bridge> at device 1.0 on pci0
pci1: <ACPI PCI bus> on pcib1
nvidia0: <GeForce2 MX/MX 400> mem 0xf0000000-0xf7ffffff,0xeb000000-0xebffffff irq 10 at device 0.0 on pci1
pcm0: <CMedia CMI8738> port 0xd800-0xd8ff irq 5 at device 5.0 on pci0
sym0: <875> port 0xd400-0xd4ff mem 0xea000000-0xea000fff,0xea800000-0xea8000ff irq 9 at device 12.0 on pci0
sym0: No NVRAM, ID 7, Fast-20, SE, parity checking
xl0: <3Com 3c905B-TX Fast Etherlink XL> port 0xd000-0xd07f mem 0xe9800000-0xe980007f irq 10 at device 13.0 on pci0
xl0: Ethernet address: 00:50:04:0f:66:6f
miibus0: <MII bus> on xl0
xlphy0: <3Com internal media interface> on miibus0
xlphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
pci0: <display, VGA> at device 15.0 (no driver attached)
pci0: <multimedia, video> at device 16.0 (no driver attached)
pci0: <multimedia> at device 16.1 (no driver attached)
isab0: <PCI-ISA bridge> at device 17.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <VIA 8233 UDMA100 controller> port 0xb800-0xb80f at device 17.1 on pci0
ata0: at 0x1f0 irq 14 on atapci0
ata1: at 0x170 irq 15 on atapci0
uhci0: <VIA 83C572 USB controller> port 0xb400-0xb41f irq 9 at device 17.2 on pci0
usb0: <VIA 83C572 USB controller> on uhci0
usb0: USB revision 1.0
uhub0: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 2 ports with 2 removable, self powered
ulpt0: Hewlett-Packard DeskJet 930C, rev 1.00/1.00, addr 2, iclass 7/1
ulpt0: using bi-directional mode
uhci1: <VIA 83C572 USB controller> port 0xb000-0xb01f irq 9 at device 17.3 on pci0
usb1: <VIA 83C572 USB controller> on uhci1
usb1: USB revision 1.0
uhub1: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
uhub1: port error, restarting port 1
uhub1: port error, giving up port 1
uhub1: port error, restarting port 2
uhub1: port error, giving up port 2
uhci2: <VIA 83C572 USB controller> port 0xa800-0xa81f irq 9 at device 17.4 on pci0
usb2: <VIA 83C572 USB controller> on uhci2
usb2: USB revision 1.0
uhub2: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub2: 2 ports with 2 removable, self powered
uhub2: port error, restarting port 1
uhub2: port error, giving up port 1
uhub2: port error, restarting port 2
uhub2: port error, giving up port 2
sio0 port 0x3f8-0x3ff irq 4 on acpi0
sio0: type 16550A
sio1 port 0x2f8-0x2ff irq 3 on acpi0
sio1: type 16550A
atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0
atkbd0: <AT Keyboard> flags 0x1 irq 1 on atkbdc0
kbd0 at atkbd0
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: model MouseMan+, device ID 0
orm0: <Option ROM> at iomem 0xc0000-0xcc7ff on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounters tick every 10.000 msec
ipfw2 initialized, divert enabled, rule-based forwarding enabled, default to accept, logging disabled
DUMMYNET initialized (011031)
IPv6 packet filtering initialized, default to accept, logging disabled
acpi_cpu: throttling enabled, 16 steps (100% to 6.2%), currently 100.0%
Allocating major#251 to "devstat"
ad0: 114473MB <ST3120023A> [232581/16/63] at ata0-master UDMA100
ad2: 57259MB <MAXTOR 4K060H3> [116336/16/63] at ata1-master UDMA100
ad3: 57259MB <MAXTOR 4K060H3> [116336/16/63] at ata1-slave UDMA100
acd0: CD-R <CR-4801TE> at ata0-slave PIO3
Waiting 15 seconds for SCSI devices to settle
Mounting root from ufs:/dev/ad0s2a
cd1 at ata0 bus 0 target 1 lun 0
cd1: <MITSUMI CR-4801TE 2.03> Removable CD-ROM SCSI-0 device 
cd1: 11.000MB/s transfers
cd1: cd present [359842 x 2352 byte records]
cd0 at sym0 bus 0 target 2 lun 0
cd0: <PIONEER DVD-ROM DVD-303 1.10> Removable CD-ROM SCSI-2 device 
cd0: 20.000MB/s transfers (20.000MHz, offset 8)
cd0: Attempt to query device size failed: NOT READY, Medium not present
WARNING: / was not properly dismounted
WARNING: /data was not properly dismounted
/data: mount pending error: blocks 32 files 0
/data: superblock summary recomputed
WARNING: /storage was not properly dismounted
/storage: superblock summary recomputed
WARNING: /fun was not properly dismounted
WARNING: /tmp was not properly dismounted
WARNING: /usr was not properly dismounted
WARNING: /var was not properly dismounted
link_elf: symbol cdevsw_add undefined
WARNING: driver "vmmon" used unreserved major device number 200
/dev/vmmon: Module vmmon: registered with major=200 minor=0 tag=$Name: build-570 $
/dev/vmmon: Module vmmon: initialized
xl0: promiscuous mode enabled
vmnet1: promiscuous mode enabled
dev = ad0s2g, block = 1, fs = /data
panic: ffs_blkfree: freeing free block

syncing disks, buffers remaining... panic: bremfree: removing a buffer not on a queue
Uptime: 2m10s
Dumping 511 MB
ata0: resetting devices ..
done
[CTRL-C to abort]  16[CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort]  32[CTRL-C to abort]  48 64 80 96 112 128 144[CTRL-C to abort]  160 176[CTRL-C to abort]  192[CTRL-C to abort] 
D size failed:Copyright (c) 1992-2003 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 5.0-CURRENT #5: Tue Mar 18 16:04:55 CET 2003
    alex@fump.kawo2.rwth-aachen.de:/data/obj/usr/src/sys/ZEROGRAVITY
Preloaded elf kernel "/boot/kernel/kernel" at 0xc0682000.
Preloaded elf module "/boot/kernel/nvidia.ko" at 0xc06820a8.
Preloaded elf module "/boot/kernel/linux.ko" at 0xc0682154.
Preloaded elf module "/boot/kernel/acpi.ko" at 0xc0682200.
Timecounter "i8254"  frequency 1193182 Hz
Timecounter "TSC"  frequency 1477361206 Hz
CPU: AMD Athlon(TM) XP1700+ (1477.36-MHz 686-class CPU)
  Origin = "AuthenticAMD"  Id = 0x662  Stepping = 2
  Features=0x383f9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE>
  AMD Features=0xc0480000<MP,AMIE,DSP,3DNow!>
real memory  = 536788992 (511 MB)
avail memory = 514334720 (490 MB)
Allocating major#253 to "net"
Allocating major#252 to "pci"
Pentium Pro MTRR support enabled
npx0: <math processor> on motherboard
npx0: INT 16 interface
acpi0: <ASUS   A7V266-E> on motherboard
    ACPI-0625: *** Info: GPE Block0 defined as GPE0 to GPE15
pcibios: BIOS version 2.10
Using $PIR table, 10 entries at 0xc00f13a0
acpi0: power button is handled as a fixed feature programming model.
Timecounter "ACPI-fast"  frequency 3579545 Hz
acpi_timer0: <24-bit timer at 3.579545MHz> port 0xe408-0xe40b on acpi0
acpi_cpu0: <CPU> port 0x530-0x537 on acpi0
acpi_button0: <Power Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
pcib1: <ACPI PCI-PCI bridge> at device 1.0 on pci0
pci1: <ACPI PCI bus> on pcib1
nvidia0: <GeForce2 MX/MX 400> mem 0xf0000000-0xf7ffffff,0xeb000000-0xebffffff irq 10 at device 0.0 on pci1
pcm0: <CMedia CMI8738> port 0xd800-0xd8ff irq 5 at device 5.0 on pci0
sym0: <875> port 0xd400-0xd4ff mem 0xea000000-0xea000fff,0xea800000-0xea8000ff irq 9 at device 12.0 on pci0
sym0: No NVRAM, ID 7, Fast-20, SE, parity checking
xl0: <3Com 3c905B-TX Fast Etherlink XL> port 0xd000-0xd07f mem 0xe9800000-0xe980007f irq 10 at device 13.0 on pci0
xl0: Ethernet address: 00:50:04:0f:66:6f
miibus0: <MII bus> on xl0
xlphy0: <3Com internal media interface> on miibus0
xlphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
pci0: <display, VGA> at device 15.0 (no driver attached)
pci0: <multimedia, video> at device 16.0 (no driver attached)
pci0: <multimedia> at device 16.1 (no driver attached)
isab0: <PCI-ISA bridge> at device 17.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <VIA 8233 UDMA100 controller> port 0xb800-0xb80f at device 17.1 on pci0
ata0: at 0x1f0 irq 14 on atapci0
ata1: at 0x170 irq 15 on atapci0
uhci0: <VIA 83C572 USB controller> port 0xb400-0xb41f irq 9 at device 17.2 on pci0
usb0: <VIA 83C572 USB controller> on uhci0
usb0: USB revision 1.0
uhub0: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 2 ports with 2 removable, self powered
ulpt0: Hewlett-Packard DeskJet 930C, rev 1.00/1.00, addr 2, iclass 7/1
ulpt0: using bi-directional mode
uhci1: <VIA 83C572 USB controller> port 0xb000-0xb01f irq 9 at device 17.3 on pci0
usb1: <VIA 83C572 USB controller> on uhci1
usb1: USB revision 1.0
uhub1: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
uhub1: port error, restarting port 1
uhub1: port error, giving up port 1
uhub1: port error, restarting port 2
uhub1: port error, giving up port 2
uhci2: <VIA 83C572 USB controller> port 0xa800-0xa81f irq 9 at device 17.4 on pci0
usb2: <VIA 83C572 USB controller> on uhci2
usb2: USB revision 1.0
uhub2: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub2: 2 ports with 2 removable, self powered
uhub2: port error, restarting port 1
uhub2: port error, giving up port 1
uhub2: port error, restarting port 2
uhub2: port error, giving up port 2
sio0 port 0x3f8-0x3ff irq 4 on acpi0
sio0: type 16550A
sio1 port 0x2f8-0x2ff irq 3 on acpi0
sio1: type 16550A
atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0
atkbd0: <AT Keyboard> flags 0x1 irq 1 on atkbdc0
kbd0 at atkbd0
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: model MouseMan+, device ID 0
orm0: <Option ROM> at iomem 0xc0000-0xcc7ff on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounters tick every 10.000 msec
ipfw2 initialized, divert enabled, rule-based forwarding enabled, default to accept, logging disabled
DUMMYNET initialized (011031)
IPv6 packet filtering initialized, default to accept, logging disabled
acpi_cpu: throttling enabled, 16 steps (100% to 6.2%), currently 100.0%
Allocating major#251 to "devstat"
ad0: 114473MB <ST3120023A> [232581/16/63] at ata0-master UDMA100
ad2: 57259MB <MAXTOR 4K060H3> [116336/16/63] at ata1-master UDMA100
ad3: 57259MB <MAXTOR 4K060H3> [116336/16/63] at ata1-slave UDMA100
acd0: CD-R <CR-4801TE> at ata0-slave PIO3
Waiting 15 seconds for SCSI devices to settle
Mounting root from ufs:/dev/ad0s2a
cd1 at ata0 bus 0 target 1 lun 0
cd1: <MITSUMI CR-4801TE 2.03> Removable CD-ROM SCSI-0 device 
cd1: 11.000MB/s transfers
cd1: cd present [359842 x 2352 byte records]
cd0 at sym0 bus 0 target 2 lun 0
cd0: <PIONEER DVD-ROM DVD-303 1.10> Removable CD-ROM SCSI-2 device 
cd0: 20.000MB/s transfers (20.000MHz, offset 8)
cd0: Attempt to query device size failed: NOT READY, Medium not present
WARNING: / was not properly dismounted
WARNING: /data was not properly dismounted
/data: superblock summary recomputed
WARNING: /storage was not properly dismounted
WARNING: /fun was not properly dismounted
WARNING: /tmp was not properly dismounted
WARNING: /usr was not properly dismounted
WARNING: /var was not properly dismounted
/var: superblock summary recomputed
link_elf: symbol cdevsw_add undefined
WARNING: driver "vmmon" used unreserved major device number 200
/dev/vmmon: Module vmmon: registered with major=200 minor=0 tag=$Name: build-570 $
/dev/vmmon: Module vmmon: initialized
xl0: promiscuous mode enabled
vmnet1: promiscuous mode enabled
dev = ad0s2g, block = 1, fs = /data
panic: ffs_blkfree: freeing free block

syncing disks, buffers remaining... panic: bremfree: removing a buffer not on a queue
Uptime: 1m39s
Dumping 511 MB
ata0: resetting devices ..
done
 16 32 48 64 80 96 112 128 144 160 176 192 208 224 240 256 272 288 304 320 336 352 368 384 400 416 432 448 464 480 496
---
#0  doadump () at /usr/src/sys/kern/kern_shutdown.c:239
239		dumping++;
(kgdb) b
Breakpoint 1 at 0xc022723b: file /usr/src/sys/kern/kern_shutdown.c, line 239.
(kgdb) bt
#0  doadump () at /usr/src/sys/kern/kern_shutdown.c:239
#1  0xc02278bd in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:371
#2  0xc0227bc3 in panic () at /usr/src/sys/kern/kern_shutdown.c:542
#3  0xc026bec0 in bremfreel (bp=0xce4ea9c8) at /usr/src/sys/kern/vfs_bio.c:637
#4  0xc026bdd2 in bremfree (bp=0x0) at /usr/src/sys/kern/vfs_bio.c:619
#5  0xc0275af1 in vop_stdfsync (ap=0xd681c930) at /usr/src/sys/kern/vfs_default.c:755
#6  0xc01ec030 in spec_fsync (ap=0xd681c930) at /usr/src/sys/fs/specfs/spec_vnops.c:418
#7  0xc01eb518 in spec_vnoperate (ap=0x0) at /usr/src/sys/fs/specfs/spec_vnops.c:123
#8  0xc032e657 in ffs_sync (mp=0xc4169400, waitfor=2, cred=0xc150ae80, td=0xc0401980) at vnode_if.h:612
#9  0xc02830fb in sync (td=0xc0401980, uap=0x0) at /usr/src/sys/kern/vfs_syscalls.c:138
#10 0xc02273df in boot (howto=256) at /usr/src/sys/kern/kern_shutdown.c:280
#11 0xc0227bc3 in panic () at /usr/src/sys/kern/kern_shutdown.c:542
#12 0xc0315f2a in ffs_blkfree (fs=0xc415e800, devvp=0xc4207db0, bno=1, size=16384, inum=1) at /usr/src/sys/ufs/ffs/ffs_alloc.c:1769
#13 0xc032625f in indir_trunc (freeblks=0xc4625c00, dbn=112645184, level=0, lbn=598028, countp=0xd681cbf0)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:2616
#14 0xc0326224 in indir_trunc (freeblks=0xc4625c00, dbn=3823904, level=1, lbn=2060, countp=0xd681cbf0) at /usr/src/sys/ufs/ffs/ffs_softdep.c:2612
#15 0xc0325cf5 in handle_workitem_freeblocks (freeblks=0xc4625c00, flags=0) at /usr/src/sys/ufs/ffs/ffs_softdep.c:2481
#16 0xc0322e0a in process_worklist_item (matchmnt=0x0, flags=0) at /usr/src/sys/ufs/ffs/ffs_softdep.c:757
#17 0xc0322b30 in softdep_process_worklist (matchmnt=0x0) at /usr/src/sys/ufs/ffs/ffs_softdep.c:623
#18 0xc027ebd0 in sched_sync () at /usr/src/sys/kern/vfs_subr.c:1752
#19 0xc0212463 in fork_exit (callout=0xc027e7e0 <sched_sync>, arg=0x0, frame=0x0) at /usr/src/sys/kern/kern_fork.c:875
(kgdb) up
#1  0xc02278bd in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:371
371			doadump();
(kgdb) up
#2  0xc0227bc3 in panic () at /usr/src/sys/kern/kern_shutdown.c:542
542		boot(bootopt);
(kgdb) up
#3  0xc026bec0 in bremfreel (bp=0xce4ea9c8) at /usr/src/sys/kern/vfs_bio.c:637
637				panic("bremfree: removing a buffer not on a queue");
(kgdb) list
632			KASSERT(BUF_REFCNT(bp) == 1, ("bremfree: bp %p not locked",bp));
633			TAILQ_REMOVE(&bufqueues[bp->b_qindex], bp, b_freelist);
634			bp->b_qindex = QUEUE_NONE;
635		} else {
636			if (BUF_REFCNT(bp) <= 1)
637				panic("bremfree: removing a buffer not on a queue");
638		}
639	
640		/*
641		 * Fixup numfreebuffers count.  If the buffer is invalid or not
(kgdb) p bp
$1 = (struct buf *) 0xce4ea9c8
(kgdb) p *bp
$2 = {b_io = {bio_cmd = 2, bio_dev = 0xc417e800, bio_disk = 0x0, bio_blkno = 192, bio_offset = 98304, bio_bcount = 16384, 
    bio_data = 0xce8ca000 "", bio_flags = 4, bio_error = 0, bio_resid = 0, bio_done = 0xc026ffc0 <bufdonebio>, bio_driver1 = 0x0, 
    bio_driver2 = 0x0, bio_caller1 = 0x0, bio_caller2 = 0xce4ea9c8, bio_queue = {tqe_next = 0x0, tqe_prev = 0x0}, bio_attribute = 0x0, 
    bio_from = 0x0, bio_to = 0x0, bio_length = 0, bio_completed = 0, bio_children = 1, bio_inbed = 0, bio_parent = 0x0, bio_t0 = {sec = 0, 
      frac = 0}, bio_task = 0, bio_task_arg = 0x0, bio_pblkno = 0}, b_op = 0xc040b2d8, b_magic = 280038160, b_iodone = 0, b_offset = 98304, 
  b_vnbufs = {tqe_next = 0xce4ea4a0, tqe_prev = 0xc4207e08}, b_left = 0x0, b_right = 0xce4ea4a0, b_vflags = 4096, b_freelist = {tqe_next = 0x0, 
    tqe_prev = 0xce4fe6c0}, b_qindex = 0, b_flags = 536871072, b_xflags = 5 '\005', b_lock = {lk_interlock = 0xc043a9b4, lk_flags = 1024, 
    lk_sharecount = 0, lk_waitcount = 0, lk_exclusivecount = 1, lk_prio = 80, lk_wmesg = 0xc03c251c "bufwait", lk_timo = 0, 
    lk_lockholder = 0xc15223c0, lk_newlock = 0x0}, b_bufsize = 16384, b_runningbufspace = 0, b_kvabase = 0xce8ca000 "", b_kvasize = 16384, 
  b_lblkno = 192, b_vp = 0xc4207db0, b_object = 0xc41c8da8, b_dirtyoff = 0, b_dirtyend = 0, b_rcred = 0xc151f280, b_wcred = 0x0, b_saveaddr = 0x0, 
  b_pager = {pg_spc = 0x0, pg_reqpage = 0}, b_cluster = {cluster_head = {tqh_first = 0x0, tqh_last = 0xce4ea938}, cluster_entry = {tqe_next = 0x0, 
      tqe_prev = 0xce4ea938}}, b_pages = {0xc0be4bd8, 0xc0db9520, 0xc0c58168, 0xc0d187b0, 0x0 <repeats 28 times>}, b_npages = 4, b_dep = {
    lh_first = 0x0}}
(kgdb) up
#4  0xc026bdd2 in bremfree (bp=0x0) at /usr/src/sys/kern/vfs_bio.c:619
619		bremfreel(bp);
(kgdb) list
614	 */
615	void
616	bremfree(struct buf * bp)
617	{
618		mtx_lock(&bqlock);
619		bremfreel(bp);
620		mtx_unlock(&bqlock);
621	}
622	
623	void
(kgdb) up
#5  0xc0275af1 in vop_stdfsync (ap=0xd681c930) at /usr/src/sys/kern/vfs_default.c:755
755				bremfree(bp);
(kgdb) list
750				panic("fsync: not dirty");
751			if ((vp->v_vflag & VV_OBJBUF) && (bp->b_flags & B_CLUSTEROK)) {
752				vfs_bio_awrite(bp);
753				splx(s);
754			} else {
755				bremfree(bp);
756				splx(s);
757				bawrite(bp);
758			}
759			VI_LOCK(vp);
(kgdb) up
#6  0xc01ec030 in spec_fsync (ap=0xd681c930) at /usr/src/sys/fs/specfs/spec_vnops.c:418
418		return (vop_stdfsync(ap));
(kgdb) list
413		} */ *ap;
414	{
415		if (!vn_isdisk(ap->a_vp, NULL))
416			return (0);
417	
418		return (vop_stdfsync(ap));
419	}
420	
421	/*
422	 * Mutex to use when delaying niced I/O bound processes in spec_strategy().
(kgdb) up
#7  0xc01eb518 in spec_vnoperate (ap=0x0) at /usr/src/sys/fs/specfs/spec_vnops.c:123
123		return (VOCALL(spec_vnodeop_p, ap->a_desc->vdesc_offset, ap));
(kgdb) 
#8  0xc032e657 in ffs_sync (mp=0xc4169400, waitfor=2, cred=0xc150ae80, td=0xc0401980) at vnode_if.h:612
612	vnode_if.h: No such file or directory.
	in vnode_if.h
(kgdb) up
#9  0xc02830fb in sync (td=0xc0401980, uap=0x0) at /usr/src/sys/kern/vfs_syscalls.c:138
138				    ((td != NULL) ? td->td_ucred : NOCRED), td);
(kgdb) up
#10 0xc02273df in boot (howto=256) at /usr/src/sys/kern/kern_shutdown.c:280
280			sync(&thread0, NULL);
(kgdb) up
#11 0xc0227bc3 in panic () at /usr/src/sys/kern/kern_shutdown.c:542
542		boot(bootopt);
(kgdb) up
#12 0xc0315f2a in ffs_blkfree (fs=0xc415e800, devvp=0xc4207db0, bno=1, size=16384, inum=1) at /usr/src/sys/ufs/ffs/ffs_alloc.c:1769
1769					panic("ffs_blkfree: freeing free frag");
(kgdb) list
1764			for (i = 0; i < frags; i++) {
1765				if (isset(blksfree, cgbno + i)) {
1766					printf("dev = %s, block = %jd, fs = %s\n",
1767					    devtoname(dev), (intmax_t)(bno + i),
1768					    fs->fs_fsmnt);
1769					panic("ffs_blkfree: freeing free frag");
1770				}
1771				setbit(blksfree, cgbno + i);
1772			}
1773			cgp->cg_cs.cs_nffree += i;
(kgdb) print blksfree
$3 = (u_int8_t *) 0xce8cac28 "ÿ"
(kgdb) print cgbno
$4 = 1
(kgdb) print i
$5 = 0
(kgdb) quit
Script done on Mon Mar 24 22:52:52 2003


If you need some special data from that dump, tell me.

Alex

To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-current" in the body of the message