Date: Mon, 2 Feb 2004 22:58:23 -0500 (EST) From: Daniel Papasian <dpapasia@andrew.cmu.edu> To: freebsd-current@freebsd.org Subject: panic: bremfree: removing a buffer not a queue (WAS: Re:5.2-RELEASE: Possible bug in filesystem code?) Message-ID: <Pine.BSF.4.58-036.0402022249350.689@damnleftist.res.cmu.edu> In-Reply-To: <Pine.BSF.4.58-036.0401141004270.29924@damnleftist.res.cmu.edu> References: <Pine.BSF.4.58-036.0401141004270.29924@damnleftist.res.cmu.edu>
next in thread | previous in thread | raw e-mail | index | archive | help
On Wed, 14 Jan 2004, Daniel Papasian wrote:
> I really hate to potentially create some distress over something that may
> be very difficult to repeat, but...
But, alas, I've gotten it to repeat. It panics because
bp->b_lock->lk_sharecount + bp->b_lock->lk_exclusivecount = 1, which is
apparently too low, but if someone has any more insight it'd be
appreciated.
Thanks,
Dan
------------------
>From the crashdump:
------------------
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-unknown-freebsd"...
panic: ffs_blkfree: freeing free block
panic messages:
---
panic: ffs_blkfree: freeing free block
syncing disks, buffers remaining... panic: bremfree: removing a buffer not on a queue
Uptime: 13m53s
Dumping 511 MB
16 32 48 64 80 96 112 128 144 160 176 192 208[CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] 224[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] 240[CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] 256 272 288 304 320 336 352 368 384 400 416 432 448 464 480 496
---
Reading symbols from /boot/kernel/splash_bmp.ko...done.
Loaded symbols for /boot/kernel/splash_bmp.ko
Reading symbols from /boot/kernel/bktr.ko...done.
Loaded symbols for /boot/kernel/bktr.ko
Reading symbols from /boot/kernel/bktr_mem.ko...done.
Loaded symbols for /boot/kernel/bktr_mem.ko
Reading symbols from /boot/kernel/nvidia.ko...done.
Loaded symbols for /boot/kernel/nvidia.ko
Reading symbols from /usr/src/sys/i386/compile/DAMNLEFTIST/modules/usr/src/sys/modules/linux/linux.ko.debug...done.
Loaded symbols for /usr/src/sys/i386/compile/DAMNLEFTIST/modules/usr/src/sys/modules/linux/linux.ko.debug
Reading symbols from /usr/src/sys/i386/compile/DAMNLEFTIST/modules/usr/src/sys/modules/acpi/acpi.ko.debug...done.
Loaded symbols for /usr/src/sys/i386/compile/DAMNLEFTIST/modules/usr/src/sys/modules/acpi/acpi.ko.debug
Reading symbols from /usr/src/sys/i386/compile/DAMNLEFTIST/modules/usr/src/sys/modules/linprocfs/linprocfs.ko.debug...done.
Loaded symbols for /usr/src/sys/i386/compile/DAMNLEFTIST/modules/usr/src/sys/modules/linprocfs/linprocfs.ko.debug
#0 doadump () at ../../../kern/kern_shutdown.c:240
240 dumping++;
(kgdb) bt
#0 doadump () at ../../../kern/kern_shutdown.c:240
#1 0xc0537876 in boot (howto=260) at ../../../kern/kern_shutdown.c:372
#2 0xc0537ae3 in panic () at ../../../kern/kern_shutdown.c:550
#3 0xc0578917 in bremfreel (bp=0xced63cb8) at ../../../kern/vfs_bio.c:647
#4 0xc0578861 in bremfree (bp=0xced63cb8) at ../../../kern/vfs_bio.c:629
#5 0xc0581811 in vop_stdfsync ()
#6 0xc0501d40 in spec_fsync ()
#7 0xc0501268 in spec_vnoperate ()
#8 0xc063e879 in ffs_sync ()
#9 0xc058aece in sync ()
#10 0xc05374cc in boot (howto=256) at ../../../kern/kern_shutdown.c:281
#11 0xc0537ae3 in panic () at ../../../kern/kern_shutdown.c:550
#12 0xc06261d8 in ffs_blkfree ()
#13 0xc06365a4 in indir_trunc ()
#14 0xc0636025 in handle_workitem_freeblocks ()
#15 0xc06330f0 in process_worklist_item ()
#16 0xc0632e20 in softdep_process_worklist ()
#17 0xc0588438 in sched_sync () at ../../../kern/vfs_subr.c:1766
#18 0xc0525c6e in fork_exit ()
(kgdb) up 3
#3 0xc0578917 in bremfreel (bp=0xced63cb8) at ../../../kern/vfs_bio.c:647
647 panic("bremfree: removing a buffer not on a queue");
(kgdb) list
642 KASSERT(BUF_REFCNT(bp) == 1, ("bremfree: bp %p not locked",bp));
643 TAILQ_REMOVE(&bufqueues[bp->b_qindex], bp, b_freelist);
644 bp->b_qindex = QUEUE_NONE;
645 } else {
646 if (BUF_REFCNT(bp) <= 1)
647 panic("bremfree: removing a buffer not on a queue");
648 }
649
650 /*
651 * Fixup numfreebuffers count. If the buffer is invalid or not
(kgdb) print *bp
$2 = {b_io = {bio_cmd = 2, bio_dev = 0xc49e0500, bio_disk = 0x0, bio_offset = 12910477312, bio_bcount = 16384, bio_data = 0xd25d6000 "", bio_flags = 4,
bio_error = 0, bio_resid = 0, bio_done = 0xc057c444 <bufdonebio>, bio_driver1 = 0x0, bio_driver2 = 0x0, bio_caller1 = 0x0, bio_caller2 = 0xced63cb8,
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 = 10,
bio_inbed = 0, bio_parent = 0x0, bio_t0 = {sec = 0, frac = 0}, bio_task = 0, bio_task_arg = 0x0, bio_pblkno = 0}, b_op = 0xc0723888, b_magic = 280038160,
b_iodone = 0, b_blkno = 25215776, b_offset = 12910477312, b_vnbufs = {tqe_next = 0xced66e90, tqe_prev = 0xc4a30048}, b_left = 0x0, b_right = 0xced66e90,
b_vflags = 1, b_freelist = {tqe_next = 0xced641e0, tqe_prev = 0xced7a2f0}, b_qindex = 0, b_flags = 536871072, b_xflags = 17 '\021', b_lock = {
lk_interlock = 0xc0746e2c, lk_flags = 1024, lk_sharecount = 0, lk_waitcount = 0, lk_exclusivecount = 1, lk_prio = 80, lk_wmesg = 0xc06d94b2 "bufwait",
lk_timo = 0, lk_lockholder = 0xc1d22b40, lk_newlock = 0x0}, b_bufsize = 16384, b_runningbufspace = 0, b_kvabase = 0xd25d6000 "", b_kvasize = 16384,
b_lblkno = 25215776, b_vp = 0xc4a30000, b_object = 0xc1038948, b_dirtyoff = 0, b_dirtyend = 0, b_rcred = 0x0, b_wcred = 0x0, b_saveaddr = 0xd25d6000, b_pager = {
pg_reqpage = 0}, b_cluster = {cluster_head = {tqh_first = 0xced64028, tqh_last = 0xcebe02e8}, cluster_entry = {tqe_next = 0xced64028, tqe_prev = 0xcebe02e8}},
b_pages = {0xc1116688, 0xc11208d0, 0xc18c2b18, 0xc18d2760, 0x0 <repeats 28 times>}, b_npages = 4, b_dep = {lh_first = 0xc4db7ec0}}
(kgdb) print bp->b_lock
$3 = {lk_interlock = 0xc0746e2c, lk_flags = 1024, lk_sharecount = 0, lk_waitcount = 0, lk_exclusivecount = 1, lk_prio = 80, lk_wmesg = 0xc06d94b2 "bufwait",
lk_timo = 0, lk_lockholder = 0xc1d22b40, lk_newlock = 0x0}
-----------------------------------------------------
dmesg output follows
-----------------------------------------------------
Copyright (c) 1992-2004 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.2-RELEASE #2: Tue Jan 13 10:02:19 EST 2004
dpapasia@damnleftist.res.cmu.edu:/usr/src/sys/i386/compile/DAMNLEFTIST
Preloaded elf kernel "/boot/kernel/kernel" at 0xc0a4b000.
Preloaded elf module "/boot/kernel/splash_bmp.ko" at 0xc0a4b26c.
Preloaded splash_image_data "/boot/splash.bmp" at 0xc0a4b31c.
Preloaded elf module "/boot/kernel/bktr.ko" at 0xc0a4b36c.
Preloaded elf module "/boot/kernel/bktr_mem.ko" at 0xc0a4b418.
Preloaded elf module "/boot/kernel/nvidia.ko" at 0xc0a4b4c8.
Preloaded elf module "/boot/kernel/linux.ko" at 0xc0a4b574.
Preloaded elf module "/boot/kernel/acpi.ko" at 0xc0a4b620.
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: AMD Athlon(tm) Processor (1394.08-MHz 686-class CPU)
Origin = "AuthenticAMD" Id = 0x644 Stepping = 4
Features=0x183f9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR>
AMD Features=0xc0440000<RSVD,AMIE,DSP,3DNow!>
real memory = 536805376 (511 MB)
avail memory = 511758336 (488 MB)
bktr_mem: memory holder loaded
Pentium Pro MTRR support enabled
npx0: [FAST]
npx0: <math processor> on motherboard
npx0: INT 16 interface
acpi0: <AMIINT SiS735XX> on motherboard
pcibios: BIOS version 2.10
Using $PIR table, 8 entries at 0xc00f7780
acpi0: Power Button (fixed)
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0
acpi_cpu0: <CPU> port 0x530-0x537 on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
pcib0: slot 2 INTD is routed to irq 12
pcib0: slot 2 INTA is routed to irq 11
pcib0: slot 3 INTA is routed to irq 11
pcib0: slot 9 INTA is routed to irq 5
pcib0: slot 11 INTA is routed to irq 12
pcib0: slot 11 INTA is routed to irq 12
pcib0: slot 15 INTA is routed to irq 12
agp0: <SIS Generic host to PCI bridge> mem 0xd0000000-0xd3ffffff at device 0.0 on pci0
pcib1: <PCI-PCI bridge> at device 1.0 on pci0
pci1: <PCI bus> on pcib1
pcib0: slot 1 INTA is routed to irq 5
pcib1: slot 0 INTA is routed to irq 5
nvidia0: <GeForce2 MX 100/200> mem 0xc0000000-0xc7ffffff,0xce000000-0xceffffff irq 5 at device 0.0 on pci1
isab0: <PCI-ISA bridge> at device 2.0 on pci0
isa0: <ISA bus> on isab0
ohci0: <SiS 5571 USB controller> mem 0xcfffe000-0xcfffefff irq 12 at device 2.2 on pci0
usb0: OHCI version 1.0, legacy support
usb0: <SiS 5571 USB controller> on ohci0
usb0: USB revision 1.0
uhub0: SiS OHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 3 ports with 3 removable, self powered
ohci1: <SiS 5571 USB controller> mem 0xcffff000-0xcfffffff irq 11 at device 2.3 on pci0
usb1: OHCI version 1.0, legacy support
usb1: <SiS 5571 USB controller> on ohci1
usb1: USB revision 1.0
uhub1: SiS OHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 3 ports with 3 removable, self powered
ums0: Microsoft Microsoft 3-Button Mouse with IntelliEye(TM), rev 1.10/3.00, addr 2, iclass 3/1
ums0: 3 buttons and Z dir.
atapci0: <SiS 735 UDMA100 controller> port 0xff00-0xff0f at device 2.5 on pci0
ata0: at 0x1f0 irq 14 on atapci0
ata0: [MPSAFE]
ata1: at 0x170 irq 15 on atapci0
ata1: [MPSAFE]
sis0: <SiS 900 10/100BaseTX> port 0xdc00-0xdcff mem 0xcfffd000-0xcfffdfff irq 11 at device 3.0 on pci0
sis0: Ethernet address: 00:07:95:57:35:cc
miibus0: <MII bus> on sis0
rlphy0: <RTL8201L 10/100 media interface> on miibus0
rlphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
pcm0: <AudioPCI ES1371-B> port 0xd800-0xd83f irq 5 at device 9.0 on pci0
pcm0: <Cirrus Logic CS4297A AC97 Codec>
bktr0: <BrookTree 878> mem 0xcddfe000-0xcddfefff irq 12 at device 11.0 on pci0
bktr0: AVer Media TV/FM, Philips NTSC tuner.
pci0: <multimedia> at device 11.1 (no driver attached)
fwohci0: <Texas Instruments TSB12LV26> mem 0xcfff8000-0xcfffbfff,0xcfffc800-0xcfffcfff irq 12 at device 15.0 on pci0
fwohci0: OHCI version 1.0 (ROM=1)
fwohci0: No. of Isochronous channel is 4.
fwohci0: EUI64 08:00:28:56:00:00:00:1f
fwohci0: Phy 1394a available S400, 3 ports.
fwohci0: Link S400, max_rec 2048 bytes.
firewire0: <IEEE1394(FireWire) bus> on fwohci0
sbp0: <SBP-2/SCSI over FireWire> on firewire0
fwe0: <Ethernet over FireWire> on firewire0
if_fwe0: Fake Ethernet address: 0a:00:28:00:00:1f
fwohci0: Initiate bus reset
fwohci0: BUS reset
fwohci0: node_id=0xc000ffc0, gen=1, CYCLEMASTER mode
firewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me)
firewire0: bus manager 0 (me)
acpi_button0: <Sleep Button> on acpi0
atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0
atkbd0: <AT Keyboard> flags 0x1 irq 1 on atkbdc0
kbd0 at atkbd0
fdc0: cmd 3 failed at out byte 1 of 3
sio0 port 0x3f8-0x3ff irq 4 on acpi0
sio0: type 16550A
sio1 port 0x2f8-0x2ff irq 3 on acpi0
sio1: type 16550A
ppc0 port 0x378-0x37f irq 7 on acpi0
ppc0: Generic chipset (NIBBLE-only) in COMPATIBLE mode
ppbus0: <Parallel port bus> on ppc0
plip0: <PLIP network interface> on ppbus0
lpt0: <Printer> on ppbus0
lpt0: Interrupt-driven port
ppi0: <Parallel I/O> on ppbus0
fdc0: cmd 3 failed at out byte 1 of 3
orm0: <Option ROM> at iomem 0xcc000-0xd3fff on isa0
pmtimer0 on isa0
fdc0: cannot reserve I/O port range (6 ports)
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
Timecounter "TSC" frequency 1394076331 Hz quality 800
Timecounters tick every 10.000 msec
GEOM: create disk ad0 dp=0xc49d2060
ad0: 38166MB <WDC WD400AB-72BVA0> [77545/16/63] at ata0-master UDMA100
acd0: DVDROM <HITACHI DVD-ROM GD-2500> at ata1-master PIO4
acd1: CDRW <SONY CD-RW CRX160E> at ata1-slave PIO4
Mounting root from ufs:/dev/ad0s2a
WARNING: / was not properly dismounted
WARNING: /tmp was not properly dismounted
WARNING: /usr was not properly dismounted
/usr: mount pending error: blocks 88 files 1
/usr: superblock summary recomputed
WARNING: /var was not properly dismounted
/var: superblock summary recomputed
Warning: pid 570 used static ldt allocation.
See the i386_set_ldt man page for more info
dev = ad0s2f, block = 6353472, fs = /usr
panic: ffs_blkfree: freeing free block
syncing disks, buffers remaining... panic: bremfree: removing a buffer not on a queue
Uptime: 13m53s
Dumping 511 MB
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?Pine.BSF.4.58-036.0402022249350.689>