Skip site navigation (1)Skip section navigation (2)
Date:      25 Sep 2003 09:28:45 -0000
From:      Michael Reynolds <wshs@delinked.us>
To:        FreeBSD-gnats-submit@FreeBSD.org
Subject:   kern/57206: softdep_lock locks against itself, causing kernel panic
Message-ID:  <20030925092845.69343.qmail@delinked.us>
Resent-Message-ID: <200309250930.h8P9UBwQ040090@freefall.freebsd.org>

next in thread | raw e-mail | index | archive | help

>Number:         57206
>Category:       kern
>Synopsis:       softdep_lock locks against itself, causing kernel panic
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    freebsd-bugs
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Thu Sep 25 02:30:11 PDT 2003
>Closed-Date:
>Last-Modified:
>Originator:     Michael Reynolds <wshs@delinked.us>
>Release:        FreeBSD 4.9-PRERELEASE i386
>Organization:
none
>Environment:
System: FreeBSD bored.delinked.us 4.9-PRERELEASE FreeBSD 4.9-PRERELEASE #0: Fri Sep 12 12:11:42 CDT 2003 root@bored:/usr/obj/usr/src/sys/BORED i386
See attached BORED and dmesg.boot for additional environment information
>Description:
System rebooted itself often, and seemingly random.  At first, thought it was the PAE code, but realized I last cvsup'd before 
the PAE code was a problem.  Compiled a debug kernel after it started to reboot several times daily.  Debug data attached 
below as 'log.'  Similar problem in PR database, but over a year old.  latest cvsup offered no help.
>How-To-Repeat:
unknown, but appears to be synonymous with high disk traffic
>Fix:
unknown

--- log begins here ---
Script started on Mon Sep 15 13:25:47 2003
GNU gdb 4.18 (FreeBSD)
Copyright 1998 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"...Deprecated bfd_read called at /usr/src/gnu/usr.bin/binutils/gdb/../../../../contrib/gdb/gdb/dbxread.c line 2627 in elfstab_build_psymtabs
Deprecated bfd_read called at /usr/src/gnu/usr.bin/binutils/gdb/../../../../contrib/gdb/gdb/dbxread.c line 933 in fill_symbuf

IdlePTD at phsyical address 0x005de000
initial pcb at physical address 0x004f0340
panicstr: softdep_lock: locking against myself
panic messages:
---
Fatal trap 12: page fault while in kernel mode
fault virtual address	= 0xffff000a
fault code		= supervisor read, page not present
instruction pointer	= 0x8:0xc0362120
stack pointer	        = 0x10:0xecce2e40
frame pointer	        = 0x10:0xecce2e40
code segment		= base 0x0, limit 0xfffff, type 0x1b
			= DPL 0, pres 1, def32 1, gran 1
processor eflags	= interrupt enabled, resume, IOPL = 0
current process		= 8 (syncer)
interrupt mask		= bio 
trap number		= 12
panic: page fault

syncing disks... panic: softdep_lock: locking against myself
Uptime: 2d11h5m18s

dumping to dev #ad/0x20001, offset 1000640
dump ata0: resetting devices .. done
503 502 501 500 499 498 497 496 495 494 493 492 491 490 489 488 487 486 485 484 483 482 481 480 479 478 477 476 475 474 473 472 471 470 469 468 467 466 465 464 463 462 461 460 459 458 457 456 455 454 453 452 451 450 449 448 447 446 445 444 443 442 441 440 439 438 437 436 435 434 433 432 431 430 429 428 427 426 425 424 423 422 421 420 419 418 417 416 415 414 413 412 411 410 409 408 407 406 405 404 403 402 401 400 399 398 397 396 395 394 393 392 391 390 389 388 387 386 385 384 383 382 381 380 379 378 377 376 375 374 373 372 371 370 369 368 367 366 365 364 363 362 361 360 359 358 357 356 355 354 353 352 351 350 349 348 347 346 345 344 343 342 341 340 339 338 337 336 335 334 333 332 331 330 329 328 327 326 325 324 323 322 321 320 319 318 317 316 315 314 313 312 311 310 309 308 307 306 305 304 303 302 301 300 299 298 297 296 295 294 293 292 291 290 289 288 287 286 285 284 283 282 281 280 279 278 277 276 275 274 273 272 271 270 269 268 267 266 265 264 263 262 261 260 259 258 257 25
 6 255 254 253 252 251 250 249 248 247 246 245 244 243 242 241 240 239 238 237 236 235 234 233 232 231 230 229 228 227 226 225 224 223 222 221 220 219 218 217 216 215 214 213 212 211 210 209 208 207 206 205 204 203 202 201 200 199 198 197 196 195 194 193 192 191 190 189 188 187 186 185 184 183 182 181 180 179 178 177 176 175 174 173 172 171 170 169 168 167 166 165 164 163 162 161 160 159 158 157 156 155 154 153 152 151 150 149 148 147 146 145 144 143 142 141 140 139 138 137 136 135 134 133 132 131 130 129 128 127 126 125 124 123 122 121 120 119 118 117 116 115 114 113 112 111 110 109 108 107 106 105 104 103 102 101 100 99 98 97 96 95 94 93 92 91 90 89 88 87 86 85 84 83 82 81 80 79 78 77 76 75 74 73 72 71 70 69 68 67 66 65 64 63 62 61 60 59 58 57 56 55 54 53 52 51 50 49 48 47 46 45 44 43 42 41 40 39 38 37 36 35 34 33 32 31 30 29 28 27 26 25 24 23 22 21 20 19 18 17 16 15 14 13 12 11 10 9 8 7 6 5 4 3 2 1 0 
---
#0  dumpsys () at ../../kern/kern_shutdown.c:487
487		if (dumping++) {
(kgdb) where full
#0  dumpsys () at ../../kern/kern_shutdown.c:487
	error = 0
#1  0xc02351ff in boot (howto=260) at ../../kern/kern_shutdown.c:316
	howto = 260
#2  0xc0235624 in poweroff_wait (junk=0xc0464fe0, howto=0) at ../../kern/kern_shutdown.c:595
	fmt = 0xc0464fe0 "softdep_lock: locking against myself"
	bootopt = 260
	buf = "softdep_lock: locking against myself", '\000' <repeats 219 times>
#3  0xc0361e52 in acquire_lock (lk=0xc04c269c) at ../../ufs/ffs/ffs_softdep.c:261
	lk = (struct lockit *) 0xc0464fe0
	holder = 260
#4  0xc036648e in softdep_fsync_mountdev (vp=0xeccd2c00) at ../../ufs/ffs/ffs_softdep.c:4024
	bp = (struct buf *) 0x0
	nbp = (struct buf *) 0xecce2cbc
	wk = (struct worklist *) 0x0
#5  0xc036a752 in ffs_fsync (ap=0xecce2ce0) at ../../ufs/ffs/ffs_vnops.c:134
	vp = (struct vnode *) 0xeccd2c00
	bp = (struct buf *) 0x0
	nbp = (struct buf *) 0xecce2cf4
	s = -1068418240
	error = 0
	wait = 0
	passes = -322098176
	skipmeta = -1068990688
	lbn = 2147483647
#6  0xc03693a7 in ffs_sync (mp=0xd05dd200, waitfor=2, cred=0xc1460480, p=0xc0513b40) at vnode_if.h:558
	a = {a_desc = 0xc0487c60, a_vp = 0xeccd2c00, a_cred = 0xc1460480, a_waitfor = 2, a_p = 0xc0513b40}
	vp = (struct vnode *) 0x0
	cred = (struct ucred *) 0xc1460480
	waitfor = 2
	p = (struct proc *) 0xc0513b40
	p = (struct proc *) 0xc0513b40
	nvp = (struct vnode *) 0x0
	vp = (struct vnode *) 0x0
	ip = (struct inode *) 0x0
	ump = (struct ufsmount *) 0xd05dd000
	fs = (struct fs *) 0xd05f3000
	error = 0
	allerror = 0
#7  0xc0265c3f in sync (p=0xc0513b40, uap=0x0) at ../../kern/vfs_syscalls.c:577
	p = (struct proc *) 0xc0513b40
	mp = (struct mount *) 0xd05dd200
	nmp = (struct mount *) 0x0
	asyncflag = 0
#8  0xc0234f9a in boot (howto=256) at ../../kern/kern_shutdown.c:235
	bp = (struct buf *) 0x0
	iter = 5
	nbusy = -1069032980
	pbusy = -322032284
	howto = 256
#9  0xc0235624 in poweroff_wait (junk=0xc047d9ec, howto=-1069034257) at ../../kern/kern_shutdown.c:595
---Type <return> to continue, or q <return> to quit---
	fmt = 0xc047d9ec "%s"
	bootopt = 256
	buf = "softdep_lock: locking against myself", '\000' <repeats 219 times>
#10 0xc03e48d6 in trap_fatal (frame=0xecce2e00, eva=4294901770) at ../../i386/i386/trap.c:974
	frame = (struct trapframe *) 0x100
	code = -1069032980
	type = 12
	ss = -1069032980
	esp = 0
	softseg = {ssd_base = 0, ssd_limit = 1048575, ssd_type = 27, ssd_dpl = 0, ssd_p = 1, ssd_xx = 5, ssd_xx1 = 0, 
  ssd_def32 = 1, ssd_gran = 1}
#11 0xc03e45a9 in trap_pfault (frame=0xecce2e00, usermode=0, eva=4294901770) at ../../i386/i386/trap.c:867
	va = 4294901760
	vm = (struct vmspace *) 0x0
	map = 0xc050414c
	rv = 0
	ftype = 1 '\001'
	p = (struct proc *) 0xe3f572a0
#12 0xc03e4193 in trap (frame={tf_fs = -322043888, tf_es = -786169840, tf_ds = 16, tf_edi = 0, tf_esi = -786164992, 
      tf_ebp = -322032064, tf_isp = -322032084, tf_ebx = -65536, tf_edx = 0, tf_ecx = -65536, tf_eax = -798313216, tf_trapno = 12, 
      tf_err = 0, tf_eip = -1070194400, tf_cs = 8, tf_eflags = 66071, tf_esp = -322032032, tf_ss = -1070178270})
    at ../../i386/i386/trap.c:466
	p = (struct proc *) 0xe3f572a0
	sticks = 3667074136
	i = 0
	ucode = 0
	type = 12
	code = 0
	eva = 4294901770
#13 0xc0362120 in worklist_remove (item=0xffff0000) at ../../ufs/ffs/ffs_softdep.c:467
	item = (struct worklist *) 0x0
#14 0xc0366022 in softdep_update_inodeblock (ip=0xd1241300, bp=0xda931c58, waitfor=0) at ../../ufs/ffs/ffs_softdep.c:3847
	ip = (struct inode *) 0x68d040
	inodedep = (struct inodedep *) 0xd06ab500
	wk = (struct worklist *) 0x68d040
	gotit = 6869056
#15 0xc0360f61 in ffs_update (vp=0xee413000, waitfor=0) at ../../ufs/ffs/ffs_inode.c:106
	fs = (struct fs *) 0xd063c800
	bp = (struct buf *) 0xda931c58
	ip = (struct inode *) 0xd1241300
	error = 0
#16 0xc036c10c in ufs_inactive (ap=0xecce2ed8) at ../../ufs/ufs/ufs_inode.c:97
	ap = (struct vop_inactive_args *) 0x0
	vp = (struct vnode *) 0xee413000
	ip = (struct inode *) 0xd1241300
	p = (struct proc *) 0xe3f572a0
	mode = 0
	error = 0
#17 0xc0371b09 in ufs_vnoperate (ap=0xecce2ed8) at ../../ufs/ufs/ufs_vnops.c:2376
	ap = (struct vop_generic_args *) 0x0
#18 0xc0263d88 in vput (vp=0xee413000) at vnode_if.h:815
---Type <return> to continue, or q <return> to quit---
	a = {a_desc = 0xc0487ea0, a_vp = 0xee413000, a_p = 0xe3f572a0}
	vp = (struct vnode *) 0xee413000
	p = (struct proc *) 0x0
	vp = (struct vnode *) 0xee413000
	p = (struct proc *) 0x0
#19 0xc0364e28 in handle_workitem_remove (dirrem=0xd12c11a0) at ../../ufs/ffs/ffs_softdep.c:2852
	dirrem = (struct dirrem *) 0xd12c11a0
	p = (struct proc *) 0xe3f572a0
	inodedep = (struct inodedep *) 0xd06ab500
	vp = (struct vnode *) 0xee413000
	ip = (struct inode *) 0x0
	oldinum = 0
	error = 0
#20 0xc03624a1 in process_worklist_item (matchmnt=0x0, flags=0) at ../../ufs/ffs/ffs_softdep.c:716
	flags = 0
	wk = (struct worklist *) 0xd12c11a0
	matchfs = (struct fs *) 0x0
	vp = (struct vnode *) 0x0
	matchcnt = 0
#21 0xc0362346 in softdep_process_worklist (matchmnt=0x0) at ../../ufs/ffs/ffs_softdep.c:622
	matchmnt = (struct mount *) 0x0
	p = (struct proc *) 0xe3f572a0
	matchcnt = 0
	loopcount = 13
	starttime = 1063600232
#22 0xc02636af in sched_sync () at ../../kern/vfs_subr.c:1198
	slp = (struct synclist *) 0xd04cfeb4
	vp = (struct vnode *) 0x0
	starttime = 1063600232
	s = 0
	p = (struct proc *) 0xe3f572a0
(kgdb) quit

Script done on Mon Sep 15 13:26:14 2003
--- log ends here ---


--- BORED starts here ---
machine         i386
cpu             I386_CPU
cpu             I486_CPU
cpu             I586_CPU
cpu             I686_CPU
ident           BORED
maxusers        512
makeoptions     DEBUG=-g

options         MATH_EMULATE
options         INET
options         INET6
options         FFS
options         FFS_ROOT
options         SOFTUPDATES
options         UFS_DIRHASH
options         MFS
options         MD_ROOT
options         NFS
options         NFS_ROOT
options         MSDOSFS
options         CD9660
options         CD9660_ROOT
options         PROCFS
options         COMPAT_43
options         SCSI_DELAY=15000
options         UCONSOLE
options         USERCONFIG
options         VISUAL_USERCONFIG
options         KTRACE
options         SYSVSHM
options         SYSVMSG
options         SYSVSEM
options         P1003_1B
options         _KPOSIX_PRIORITY_SCHEDULING
options         ICMP_BANDLIM
options         KBD_INSTALL_CDEV
options         AHC_REG_PRETTY_PRINT
options         AHD_REG_PRETTY_PRINT
options         RANDOM_IP_ID
options         TCP_DROP_SYNFIN
options         NMBCLUSTERS=81920
options         NO_F00F_HACK
options         CPU_WT_ALLOC
options         NO_MEMORY_HOLE

device          isa
device          eisa
device          pci

device          fdc0    at isa? port IO_FD1 irq 6 drq 2
device          fd0     at fdc0 drive 0
device          fd1     at fdc0 drive 1

device          ata0    at isa? port IO_WD1 irq 14
device          ata1    at isa? port IO_WD2 irq 15
device          ata
device          atadisk
device          atapicd
device          atapifd
device          atapist
options         ATA_STATIC_ID

device          ahb
device          ahc
device          ahd
device          amd
device          isp
device          mpt
device          ncr
device          sym
options         SYM_SETUP_LP_PROBE_MAP=0x40

device          adv0    at isa?
device          adw
device          bt0     at isa?
device          aha0    at isa?
device          aic0    at isa?

device          ncv
device          nsp
device          stg

device          scbus
device          da
device          sa
device          cd
device          pass

device          asr
device          dpt
device          iir
device          mly
device          ciss

device          aac
device          aacp
device          ida
device          amr
device          mlx
device          twe

device          atkbdc0 at isa? port IO_KBD
device          atkbd0  at atkbdc? irq 1 flags 0x1
device          psm0    at atkbdc? irq 12

device          vga0    at isa?

pseudo-device   splash

device          sc0     at isa? flags 0x100

device          npx0    at nexus? port IO_NPX irq 13 

device          apm0    at nexus? disable flags 0x20

device          card
device          pcic0   at isa? irq 0 port 0x3e0 iomem 0xd0000
device          pcic1   at isa? irq 0 port 0x3e2 iomem 0xd4000 disable

device          sio0    at isa? port IO_COM1 flags 0x10 irq 4
device          sio1    at isa? port IO_COM2 irq 3
device          sio2    at isa? disable port IO_COM3 irq 5
device          sio3    at isa? disable port IO_COM4 irq 9

device          ppc0    at isa? irq 7
device          ppbus
device          lpt
device          plip
device          ppi

device          de
device          em
device          txp
device          vx

device          miibus
device          dc
device          fxp
device          pcn
device          rl
device          sf
device          sis
device          ste
device          tl
device          tx
device          vr
device          wb
device          xl0
device          bge

device          ed0     at isa? port 0x280 irq 10 iomem 0xd8000
device          ex
device          ep
device          fe0     at isa? port 0x300
device          xe
device          awi
device          wi
device          an
device          ie0     at isa? port 0x300 irq 10 iomem 0xd0000
device          lnc0    at isa? port 0x280 irq 10 drq 0
device          cs0     at isa? port 0x300
device          sn0     at isa? port 0x300 irq 10

pseudo-device   loop
pseudo-device   ether
pseudo-device   sl      1
pseudo-device   ppp     1
pseudo-device   tun
pseudo-device   pty
pseudo-device   md
pseudo-device   gif
pseudo-device   faith   1
pseudo-device   stf     1

pseudo-device   bpf     20
device          snp     8

device          uhci
device          ohci
device          usb
device          ugen
device          uhid
device          ukbd
device          ulpt
device          umass
device          ums
device          uscanner
device          urio
device          aue
device          cue
device          kue

options IPFIREWALL
options IPFIREWALL_DEFAULT_TO_ACCEPT
options IPFIREWALL_FORWARD
options IPFIREWALL_VERBOSE
options IPFIREWALL_VERBOSE_LIMIT=100
options IPV6FIREWALL
options IPV6FIREWALL_DEFAULT_TO_ACCEPT
options IPV6FIREWALL_VERBOSE
options IPV6FIREWALL_VERBOSE_LIMIT=100
options IPFILTER
options IPFILTER_LOG
options IPFW2
options MROUTING
options IPSTEALTH
options IPDIVERT
options DUMMYNET
options BRIDGE
options SC_DISABLE_REBOOT
options QUOTA
options IPSEC
options IPSEC_ESP
options IPSEC_FILTERGIF
options SC_DISABLE_DDBKEY

options PERFMON
options PANIC_REBOOT_WAIT_TIME=10
pseudo-device crypto
options COMPAT_LINUX
options SUIDDIR

pseudo-device speaker
--- BORED ends here ---


--- dmesg.boot starts here ---
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 4.8-STABLE #0: Wed Aug  6 21:31:50 GMT 2003
    root@bored:/usr/obj/usr/src/sys/BORED
Timecounter "i8254"  frequency 1193182 Hz
CPU: Intel(R) Celeron(TM) CPU                1300MHz (1302.97-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0x6b1  Stepping = 1
  Features=0x383fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE>
real memory  = 528416768 (516032K bytes)
config> di sn0
config> di lnc0
config> di ie0
config> di fe0
config> di cs0
config> di bt0
config> di aic0
config> di aha0
config> di adv0
config> q
avail memory = 507056128 (495172K bytes)
Preloaded elf kernel "kernel" at 0xc05bb000.
Preloaded userconfig_script "/boot/kernel.conf" at 0xc05bb09c.
Pentium Pro MTRR support enabled
md0: Malloc disk
Using $PIR table, 6 entries at 0xc00fd420
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=1106 device=8601)> at device 1.0 on pci0
pci1: <PCI bus> on pcib1
pci1: <Trident model 8500 VGA-compatible display device> at 0.0 irq 10
isab0: <VIA 82C686 PCI-ISA bridge> at device 7.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <VIA 82C686 ATA100 controller> port 0xe000-0xe00f at device 7.1 on pci0
ata0: at 0x1f0 irq 14 on atapci0
ata1: at 0x170 irq 15 on atapci0
uhci0: <VIA 83C572 USB controller> port 0xe400-0xe41f irq 12 at device 7.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
uhci1: <VIA 83C572 USB controller> port 0xe800-0xe81f irq 12 at device 7.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
pci0: <unknown card> (vendor=0x1106, dev=0x3057) at 7.4
rl0: <RealTek 8139 10/100BaseTX> port 0xec00-0xecff mem 0xe7000000-0xe70000ff irq 11 at device 13.0 on pci0
rl0: Ethernet address: 00:20:ed:58:33:2f
miibus0: <MII bus> on rl0
rlphy0: <RealTek internal media interface> on miibus0
rlphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
orm0: <Option ROM> at iomem 0xc0000-0xcbfff 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
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/8 bytes threshold
plip0: <PLIP network interface> on ppbus0
lpt0: <Printer> on ppbus0
lpt0: Interrupt-driven port
ppi0: <Parallel I/O> on ppbus0
DUMMYNET initialized (011031)
ipfw2 initialized, divert enabled, rule-based forwarding enabled, default to accept, logging limited to 100 packets/entry by default
BRIDGE 020214 loaded
IPv6 packet filtering initialized, default to accept, logging limited to 100 packets/entry
IPsec: Initialized Security Association Processing.
IP Filter: v3.4.31 initialized.  Default = pass all, Logging = enabled
ad0: 38166MB <WDC WD400BB-00DEA0> [77545/16/63] at ata0-master UDMA100
acd0: CDROM <ATAPI-CD ROM-DRIVE-56MAX> at ata1-master PIO4
Mounting root from ufs:/dev/ad0s1a
WARNING: / was not properly dismounted
--- dmesg.boot ends here ---


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



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