Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 27 Jun 2002 16:58:32 -0500
From:      Doug Swarin <doug@staff.texas.net>
To:        freebsd-stable@freebsd.org
Subject:   -STABLE double-panic in ffs_blkfree and then lockmgr
Message-ID:  <20020627165832.A43941@staff.texas.net>

next in thread | raw e-mail | index | archive | help
I'm seeing a double panic on systems here that are under heavy disk
load. I've included a brief analysis and dmesg below. I still have
the dump and can do more debugging if necessary. Unfortunately, I
cannot reproduce the problem at will.

After reboot, the machine needs a manual fsck due to unexpected
softupdates inconsistencies.

I've looked at the CVS repository and don't see any recent commits
that might fix this. I have the latest -STABLE revs of ffs_alloc.c
and ffs_softdep.c.

Thanks,
Doug Swarin
doug@texas.net


Here's the gdb session:

SMP 2 cpus
IdlePTD at phsyical address 0x00324000
initial pcb at physical address 0x00293600
panicstr: lockmgr: locking against myself
panic messages:
---
panic: ffs_blkfree: freeing free block
mp_lock = 00000001; cpuid = 0; lapic.id = 01000000
boot() called on cpu#0

syncing disks... 150 50 8 4 4 4 4 4 4 4 panic: lockmgr: locking against myself
mp_lock = 00000001; cpuid = 0; lapic.id = 01000000
boot() called on cpu#0
Uptime: 29d2h41m9s
xl0: reset didn't complete

(kgdb) back

#0  dumpsys () at /usr/src/sys/kern/kern_shutdown.c:487
#1  0xc0161cb3 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:316
#2  0xc0162125 in panic (fmt=0xc02487c0 "lockmgr: locking against myself")
    at /usr/src/sys/kern/kern_shutdown.c:595
#3  0xc015c4e3 in lockmgr (lkp=0xd2ec5498, flags=33620002,
    interlkp=0xc02a72b4, p=0xe4c06780) at /usr/src/sys/kern/kern_lock.c:337
#4  0xc0188da9 in getblk (vp=0xe750cb40, blkno=64, size=16384, slpflag=0,
    slptimeo=0) at /usr/src/sys/sys/buf.h:305
#5  0xc0186f1e in bread (vp=0xe750cb40, blkno=64, size=16384, cred=0x0,
    bpp=0xe7519b38) at /usr/src/sys/kern/vfs_bio.c:508
#6  0xc01d264c in ffs_blkfree (ip=0xe7519bc0, bno=67888, size=16384)
    at /usr/src/sys/ufs/ffs/ffs_alloc.c:1424
#7  0xc01d6fff in indir_trunc (ip=0xe7519bc0, dbn=263584, level=0, lbn=12,
    countp=0xe7519bb0) at /usr/src/sys/ufs/ffs/ffs_softdep.c:2233
#8  0xc01d6db9 in handle_workitem_freeblocks (freeblks=0xc90f4800)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:2133
#9  0xc01d52bb in process_worklist_item (matchmnt=0x0, flags=0)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:723
#10 0xc01d5152 in softdep_process_worklist (matchmnt=0x0)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:622
#11 0xc0161b11 in boot (howto=256) at /usr/src/sys/kern/kern_shutdown.c:261
#12 0xc0162125 in panic (fmt=0xc0258820 "ffs_blkfree: freeing free block")
    at /usr/src/sys/kern/kern_shutdown.c:595
#13 0xc01d2716 in ffs_blkfree (ip=0xe7519e0c, bno=65536, size=16384)
    at /usr/src/sys/ufs/ffs/ffs_alloc.c:1444
#14 0xc01d6fff in indir_trunc (ip=0xe7519e0c, dbn=255200, level=0, lbn=12,
    countp=0xe7519dfc) at /usr/src/sys/ufs/ffs/ffs_softdep.c:2233
#15 0xc01d6db9 in handle_workitem_freeblocks (freeblks=0xc8e22a80)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:2133
#16 0xc01d52bb in process_worklist_item (matchmnt=0x0, flags=0)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:723
#17 0xc01d5152 in softdep_process_worklist (matchmnt=0x0)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:622
#18 0xc018f6e3 in sched_sync () at /usr/src/sys/kern/vfs_subr.c:1177

(kgdb) up 13
#13 0xc01d2716 in ffs_blkfree (ip=0xe7519e0c, bno=65536, size=16384)
                blkno = fragstoblks(fs, bno);
                if (!ffs_isfreeblock(fs, blksfree, blkno)) {
                        printf("dev = %s, block = %ld, fs = %s\n",
                            devtoname(ip->i_dev), (long)bno, fs->fs_fsmnt);  
                        panic("ffs_blkfree: freeing free block");
                }
(kgdb) print *ip
$1 = {i_lock = {lk_interlock = {lock_data = 1744881760},
    lk_flags = 4294901760, lk_sharecount = -963385344,
    lk_waitcount = 1778436192, lk_exclusivecount = 27008, lk_prio = -14175,
    lk_wmesg = 0x5dc <Address 0x5dc out of bounds>, lk_timo = 0,
    lk_lockholder = -963385224}, i_hash = {le_next = 0xe7519e80,
    le_prev = 0xc01baa06}, i_vnode = 0x3e8, i_devvp = 0xe750cb40,
  i_flag = 3279805952, i_dev = 0xc680ba80, i_number = 34198419,
  i_effnlink = 0, inode_u = {fs = 0xc6922800, e2fs = 0xc6922800}, i_dquot = {
    0x0, 0xc37dde00}, i_modrev = 1744881760, i_lockf = 0x14, i_count = 0,
  i_endoff = 0, i_diroff = -1015492590, i_offset = -1015492572,
  i_ino = 32768, i_reclen = 3331581696, i_spare = {0, 3880885904,
    3223040042}, i_dirhash = 0x6a00c860, i_din = {di_mode = 47072,
    di_nlink = -15547, di_u = {oldids = {40636, 59217},
      inumber = -414081348}, di_size = 4194304, di_atime = 0,
    di_atimensec = -968380416, di_mtime = -1071446033,
    di_mtimensec = 1744881760, di_ctime = -968380416,
    di_ctimensec = 1711278080, di_db = {-911644352, 0, -1071549621,
      -1070938240, -1018841120, -1071542463, 24, 16, 16, 0, -414081692,
      -414081268}, di_ib = {-414081288, -911644352, -916145280},
    di_flags = 3383322944, di_blocks = -1071033364, di_gen = 0, di_uid = 8,
    di_gid = 3223145634, di_spare = {0, -414081228}}}
(kgdb) print *fs
$2 = {fs_firstfield = 0, fs_unused_1 = 0, fs_sblkno = 8, fs_cblkno = 16, 
  fs_iblkno = 24, fs_dblkno = 1432, fs_cgoffset = 1024, fs_cgmask = -1, 
  fs_time = 1025205027, fs_size = 149873841, fs_dsize = 147531340, 
  fs_ncg = 1645, fs_bsize = 16384, fs_fsize = 2048, fs_frag = 8, 
  fs_minfree = 8, fs_rotdelay = 0, fs_rps = 60, fs_bmask = -16384, 
  fs_fmask = -2048, fs_bshift = 14, fs_fshift = 11, fs_maxcontig = 7, 
  fs_maxbpg = 4096, fs_fragshift = 3, fs_fsbtodb = 2, fs_sbsize = 2048, 
  fs_csmask = -1024, fs_csshift = 10, fs_nindir = 4096, fs_inopb = 128, 
  fs_nspf = 4, fs_optim = 0, fs_npsect = 4096, fs_interleave = 1, 
  fs_trackskew = 0, fs_id = {1022689224, 950943126}, fs_csaddr = 1432, 
  fs_cssize = 26624, fs_cgsize = 16384, fs_ntrak = 1, fs_nsect = 4096, 
  fs_spc = 4096, fs_ncyl = 146362, fs_cpg = 89, fs_ipg = 22528, 
  fs_fpg = 91136, fs_cstotal = {cs_ndir = 69944, cs_nbfree = 2764524, 
    cs_nifree = 36051685, cs_nffree = 615890}, fs_fmod = 1 '\001', 
  fs_clean = 0 '\000', fs_ronly = 0 '\000', fs_flags = 2 '\002', 
  fs_fsmnt = "/news", '\000' <repeats 506 times>, fs_cgrotor = 0, fs_ocsp = {
    0x0 <repeats 29 times>}, fs_contigdirs = 0xc692b1b4 "", 
  fs_csp = 0xc6923000, fs_maxcluster = 0xc6929800, fs_cpc = 0, fs_opostbl = {
    {0, 0, 0, 0, 0, 0, 0, 0} <repeats 16 times>}, fs_snapinum = {
    0 <repeats 20 times>}, fs_avgfilesize = 16384, fs_avgfpdir = 64, 
  fs_sparecon = {0 <repeats 26 times>}, fs_pendingblocks = 0, 
  fs_pendinginodes = 0, fs_contigsumsize = 7, fs_maxsymlinklen = 60, 
  fs_inodefmt = 2, fs_maxfilesize = 17592186044415, fs_qbmask = 16383, 
  fs_qfmask = 2047, fs_state = 0, fs_postblformat = 1, fs_nrpos = 1, 
  fs_postbloff = 0, fs_rotbloff = 0, fs_magic = 72020, fs_space = ""}


And here's the output of dmesg:

Copyright (c) 1992-2002 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 4.5-STABLE #0: Wed May 15 13:44:34 CDT 2002
    root@:/usr/obj/usr/src/sys/NB1800
Timecounter "i8254"  frequency 1193182 Hz
CPU: AMD Athlon(tm) MP 1800+ (1533.40-MHz 686-class CPU)
  Origin = "AuthenticAMD"  Id = 0x662  Stepping = 2
  Features=0x383fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE>
  AMD Features=0xc0480000<<b19>,AMIE,DSP,3DNow!>
real memory  = 2147483648 (2097152K bytes)
config> q
avail memory = 2088857600 (2039900K bytes)
Programming 24 pins in IOAPIC #0
IOAPIC #0 intpin 2 -> irq 0
FreeBSD/SMP: Multiprocessor motherboard
 cpu0 (BSP): apic id:  1, version: 0x00040010, at 0xfee00000
 cpu1 (AP):  apic id:  0, version: 0x00040010, at 0xfee00000
 io0 (APIC): apic id:  2, version: 0x00170011, at 0xfec00000
Preloaded elf kernel "kernel" at 0xc0305000.
Preloaded userconfig_script "/boot/kernel.conf" at 0xc030509c.
Pentium Pro MTRR support enabled
md0: Malloc disk
Using $PIR table, 12 entries at 0xc00fdf00
npx0: <math processor> on motherboard
npx0: INT 16 interface
pcib0: <Host to PCI bridge> on motherboard
pci0: <PCI bus> on pcib0
pcib1: <PCI to PCI bridge (vendor=1022 device=700d)> at device 1.0 on pci0
pci1: <PCI bus> on pcib1
pci1: <S3 Savage 4 graphics accelerator> at 5.0 irq 10
isab0: <PCI to ISA bridge (vendor=1022 device=7440)> at device 7.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <AMD 768 ATA100 controller> port 0xf000-0xf00f at device 7.1 on pci0
ata0: at 0x1f0 irq 14 on atapci0
ata1: at 0x170 irq 15 on atapci0
amdpm0: <AMD 756/766/768 Power Management Controller> port 0x8000-0x80ff at device 7.3 on pci0
amdsmb0: AMD 756/766/768 SMBus interface
smbus0: <System Management Bus> on amdsmb0
smb0: <SMBus general purpose I/O> on smbus0
twe0: <3ware Storage Controller> port 0x1010-0x101f mem 0xe8000000-0xe87fffff,0xe8800000-0xe880000f irq 5 at device 9.0 on pci0
twe0: 8 ports, Firmware FE7X 1.04.00.024, BIOS BE7X 1.07.02.008
pcib2: <PCI to PCI bridge (vendor=1022 device=7448)> at device 16.0 on pci0
pci2: <PCI bus> on pcib2
fxp0: <Intel Pro 10/100B/100+ Ethernet> port 0x2080-0x20bf mem 0xe8a20000-0xe8a3ffff,0xe8a01000-0xe8a01fff irq 11 at device 7.0 on pci2
fxp0: Ethernet address 00:02:b3:a2:49:0a
inphy0: <i82555 10/100 media interface> on miibus0
inphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
xl0: <3Com 3c905C-TX Fast Etherlink XL> port 0x2000-0x207f mem 0xe8a02000-0xe8a0207f irq 11 at device 8.0 on pci2
xl0: reset didn't complete
xl0: Ethernet address: 00:e0:81:20:02:1a
miibus1: <MII bus> on xl0
ukphy0: <Generic IEEE 802.3u media interface> on miibus1
ukphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
orm0: <Option ROMs> at iomem 0xc0000-0xcefff,0xcf000-0xcf7ff,0xcf800-0xd07ff,0xd1000-0xd27ff on isa0
fdc0: <NEC 72065B or clone> at port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on isa0
fdc0: FIFO enabled, 8 bytes threshold
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
atkbdc0: <Keyboard controller (i8042)> at port 0x60,0x64 on isa0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
sio0 at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0
sio0: type 16550A
sio1 at port 0x2f8-0x2ff irq 3 on isa0
sio1: type 16550A
ppc0: <Parallel port> at port 0x378-0x37f irq 7 on isa0
ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mode
ppc0: FIFO with 16/16/9 bytes threshold
lpt0: <Printer> on ppbus0
lpt0: Interrupt-driven port
APIC_IO: Testing 8254 interrupt delivery
APIC_IO: routing 8254 via IOAPIC #0 intpin 2
DUMMYNET initialized (011031)
IP packet filtering initialized, divert enabled, rule-based forwarding enabled, default to accept, unlimited logging
twed0: <RAID10, Normal> on twe0
twed0: 305272MB (625197056 sectors)
twe0: command interrupt
Mounting root from ufs:/dev/twed0s1a
SMP: AP CPU #1 Launched!
fxp0: Microcode loaded, int_delay: 1000 usec  bundle_max: 6

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




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20020627165832.A43941>