Re: panic: System call lstat returning with 1 locks held

From: Attilio Rao <attilio_at_freebsd.org>
Date: Fri, 1 Feb 2008 19:41:58 +0100
2008/2/1, Yar Tikhiy <yar_at_comp.chem.msu.su>:
> On Fri, Feb 01, 2008 at 12:41:30AM -0600, Scot Hetzel wrote:
>  > On 1/31/08, Attilio Rao <attilio_at_freebsd.org> wrote:
>  > > 2008/1/31, Yar Tikhiy <yar_at_comp.chem.msu.su>:
>  > >
>  > > > On Thu, Jan 31, 2008 at 11:43:10AM +0100, Attilio Rao wrote:
>  > >  >  >
>  > >  >  > The assertion failing should not happen now.
>  > >  >  > Could you please hand-add a check in _lockmgr_disown()
>  > >  >  > (kern/kern_lock.c) in order to check for the panicstr before to call
>  > >  >  > WITNESS? I cannot access to perforce now and produce a suitable diff,
>  > >  >  > so you can just do this by hand:
>  > >  >  >
>  > >  >  > if (lkp->lk_lockholder == td) {
>  > >  >  >         if (panicstr != NULL)
>  > >  >  >                 WITNESS_UNLOCK(&lkp->lk_object, LOP_EXCLUSIVE, file, line);
>  > >  >  >         td->td_locks--;
>  > >  >  > }
>  > >  >
>  > >  >
>  > >  > Shouldn't the test for panicstr be inverse: `panicstr == NULL'?
>  > >  >  I guess we shouldn't call WITNESS when panicing, should we?
>  > >  >  Sorry if I got it wrong.
>  > >
>  > >
>  > > Weee, you are right, sorry!
>  > >
>  > >
>  > I added this change to kern/kern_lock.c, but I'm still getting this
>  > panic after mounting the ntfs filesystem, and using cvsup to update
>  > the local mirror:
>  >
>  > Fatal trap 9: general protection fault while in kernel mode
>  > cpuid = 0; apic id = 00
>  > instruction pointer     = 0x8:0xffffffff80301051
>  > stack pointer           = 0x10:0xffffffffd43b9100
>  > frame pointer           = 0x10:0xffffffffd43b9190
>  > code segment            = base 0x0, limit 0xfffff, type 0x1b
>  >                         = DPL 0, pres 1, long 1, def32 0, gran 1
>  > processor eflags        = resume, IOPL = 0
>  > current process         = 1229 (cvsup)
>  > panic: Assertion !mtx_owned(&w_mtx) failed at ../../../kern/subr_witness.c:959
>  > cpuid = 0
>  > Uptime: 4m38s
>  > Physical memory: 2031 MB
>  > Dumping 324 MB: 309 293 277 261 245 229 213 197 181 165 149 133 117
>  > 101 85 69 53 37 21 5
>
>
> FWIW, the same panic happens in my case, too.  In addition, reported
>  are a number of LORs I haven't seen before.  The relevant kernel
>  message log from the serial console is attached.  Thanks!
>
>  --
>  Yar
>
>  [...]
>  WARNING: WITNESS option enabled, expect reduced performance.
>  GEOM_LABEL: Label for provider ad0s1 is ntfs/SYSTEM.
>  GEOM_LABEL: Label for provider ad0s2 is ntfs/STORE.
>  lock order reversal:
>   1st 0xc2ecfe28 devfs (devfs) _at_ /usr/src/sys/kern/vfs_subr.c:2061
>   2nd 0xc2fbead4 devfsmount (devfsmount) _at_ /usr/src/sys/fs/devfs/devfs_vnops.c:20
>  1
>  KDB: stack backtrace:
>  db_trace_self_wrapper(c0b0fa49,d3cecbbc,c07a2c5e,c0b11f90,c2fbead4,...) at db_tr
>  ace_self_wrapper+0x26
>  kdb_backtrace(c0b11f90,c2fbead4,c0b0343a,c0b0343a,c0b0347b,...) at kdb_backtrace
>  +0x29
>  witness_checkorder(c2fbead4,9,c0b0347b,c9,c7,...) at witness_checkorder+0x6de
>  _sx_xlock(c2fbead4,0,c0b0347b,c9,c2fbead4,...) at _sx_xlock+0x7d
>  devfs_allocv(c2fbd700,c2fc3000,d3cecc28,c2d0fcc0,c0b17d73,...) at devfs_allocv+0
>  x144
>  devfs_root(c2fc3000,2,c0e1c118,c2d0fcc0,ca,...) at devfs_root+0x51
>  set_rootvnode(c0e1c100,0,c0b17d73,5ed,c07e0150,...) at set_rootvnode+0x2b
>  vfs_mountroot(c0dc9d50,4,c0b078ec,260,0,...) at vfs_mountroot+0x356
>  start_init(0,d3cecd38,c0b091cd,30c,c2d0dab0,...) at start_init+0x65
>  fork_exit(c0732530,0,d3cecd38) at fork_exit+0xb8
>  fork_trampoline() at fork_trampoline+0x8
>  --- trap 0, eip = 0, esp = 0xd3cecd70, ebp = 0 ---
>  Trying to mount root from ufs:/dev/ad0s3a
>  WARNING: / was not properly dismounted
>  lock order reversal:
>   1st 0xc2ecf9e8 ufs (ufs) _at_ /usr/src/sys/kern/vfs_subr.c:2061
>   2nd 0xc2fc3000 vfslock (vfslock) _at_ /usr/src/sys/kern/vfs_subr.c:364
>  KDB: stack backtrace:
>  db_trace_self_wrapper(c0b0fa49,d3cec9e0,c07a2c5e,c0b11f90,c2fc3000,...) at db_tr
>  ace_self_wrapper+0x26
>  kdb_backtrace(c0b11f90,c2fc3000,c0b17e71,c0b17e71,c0b1840e,...) at kdb_backtrace
>  +0x29
>  witness_checkorder(c2fc3000,1,c0b1840e,16c,151,...) at witness_checkorder+0x6de
>  _lockmgr(c2fc3000,2001,c2fc3030,c0b1840e,16c,...) at _lockmgr+0x174
>  vfs_busy(c2fc3000,0,0,c2d0fcc0,d3cecb58,...) at vfs_busy+0x198
>  lookup(d3cecb44,c0b17b21,c6,bf,c2ce142c,...) at lookup+0x7c4
>  namei(d3cecb44,c2d0fd54,c0bc54a4,c0b17d73,c2fc3030,...) at namei+0x34b
>  kern_unlink(c2d0fcc0,c0b181b0,1,628,0,...) at kern_unlink+0x40
>  vfs_mountroot_try(c0b1836a,c0b0660d,c0aff4ee,1,c07e0150,...) at vfs_mountroot_tr
>  y+0x470
>  vfs_mountroot(c0dc9d50,4,c0b078ec,260,0,...) at vfs_mountroot+0x418
>  start_init(0,d3cecd38,c0b091cd,30c,c2d0dab0,...) at start_init+0x65
>  fork_exit(c0732530,0,d3cecd38) at fork_exit+0xb8
>  fork_trampoline() at fork_trampoline+0x8
>  --- trap 0, eip = 0, esp = 0xd3cecd70, ebp = 0 ---
>  lock order reversal:
>   1st 0xc2d13044 user map (user map) _at_ /usr/src/sys/vm/vm_map.c:3111
>   2nd 0xc2ecf7c8 ufs (ufs) _at_ /usr/src/sys/kern/vfs_subr.c:2061
>  KDB: stack backtrace:
>  db_trace_self_wrapper(c0b0fa49,d3cec9cc,c07a2c5e,c0b11f90,c2ecf7c8,...) at db_tr
>  ace_self_wrapper+0x26
>  kdb_backtrace(c0b11f90,c2ecf7c8,c0b06ec0,c0b06ec0,c0b1840e,...) at kdb_backtrace
>  +0x29
>  witness_checkorder(c2ecf7c8,1,c0b1840e,80d,c0dd52f4,...) at witness_checkorder+0
>  x6de
>  _lockmgr(c2ecf7c8,3041,c2ecf7f8,c0b1840e,80d,...) at _lockmgr+0x174
>  ffs_lock(d3ceca78,c075b6bd,c0dd52f4,3041,c2ecf770,...) at ffs_lock+0x8a
>  VOP_LOCK1_APV(c0bdfbc0,d3ceca78,c0b0660b,3,c2ecf7f8,...) at VOP_LOCK1_APV+0xa5
>  _vn_lock(c2ecf770,3041,c0b1840e,80d,0,...) at _vn_lock+0xf2
>  vget(c2ecf770,3041,c2d0fcc0,4a9,c1460600,...) at vget+0x109
>  vnode_pager_lock(c1460480,0,c0b2ec90,127,d3cecbe8,...) at vnode_pager_lock+0x1ad
>  vm_fault(c2d13000,80d2000,2,8,80d2000,...) at vm_fault+0x1df
>  trap_pfault(5,0,c0b3ce02,2c8,c2d0dab0,...) at trap_pfault+0x118
>  trap(d3cecd38) at trap+0x267
>  calltrap() at calltrap+0x6
>  --- trap 0xc, eip = 0x80480e5, esp = 0xbfbfeef0, ebp = 0xbfbfef10 ---
>  Enter full pathname of shell or RETURN for /bin/sh:
>  #
>  # mount -r /usr
>  # mount -r /var
>  # mount /ntfs
>  #
>  # umount /ntfs
>  lock order reversal:
>   1st 0xc2fece28 ntfs (ntfs) _at_ /usr/src/sys/kern/vfs_subr.c:2361
>   2nd 0xc2fbbe24 ntnode (ntnode) _at_ /usr/src/sys/modules/ntfs/../../fs/ntfs/ntfs_s
>  ubr.c:361
>  KDB: stack backtrace:
>  db_trace_self_wrapper(c0b0fa49,d614ea38,c07a2c5e,c0b11f90,c2fbbe24,...) at db_tr
>  ace_self_wrapper+0x26
>  kdb_backtrace(c0b11f90,c2fbbe24,c301f540,c301f540,c301f6aa,...) at kdb_backtrace
>  +0x29
>  witness_checkorder(c2fbbe24,9,c301f6aa,169,167,...) at witness_checkorder+0x6de
>  _lockmgr(c2fbbe24,2002,c2fbbe54,c301f6aa,169,...) at _lockmgr+0x448
>  ntfs_ntget(c2fbbe00,c3020320,d614eab4,c2fbbe00,c3020320,...) at ntfs_ntget+0x5d
>  ntfs_reclaim(d614eb04,c0b3ef3d,0,c2fecdd0,c3021aa0,...) at ntfs_reclaim+0x3b
>  VOP_RECLAIM_APV(c3020320,d614eb04,c3021aa0,0,0,...) at VOP_RECLAIM_APV+0xc5
>  vgonel(c2fece58,0,c0b1840e,95b,1,...) at vgonel+0x1cf
>  vflush(c2fc2538,0,1,c3021aa0,c0e1bfe0,...) at vflush+0x367
>  ntfs_unmount(c2fc2538,8000000,c3021aa0,4f0,4da,...) at ntfs_unmount+0x4f
>  dounmount(c2fc2538,8000000,c3021aa0,482,8,...) at dounmount+0x426
>  unmount(c3021aa0,d614ecfc,8,d614ed38,c0bbeef0,...) at unmount+0x2e0
>  syscall(d614ed38) at syscall+0x2b3
>
> Xint0x80_syscall() at Xint0x80_syscall+0x20
>
> --- syscall (22, FreeBSD ELF32, unmount), eip = 0x280c62db, esp = 0xbfbfe6ac, eb
>  p = 0xbfbfe768 ---
>  kernel trap 12 with interrupts disabled
>
>
>  Fatal trap 12: page fault while in kernel mode
>
> cpuid = 0; apic id = 00
>
> fault virtual address   = 0xdeadc0ee
>  fault code              = supervisor read, page not present
>  instruction pointer     = 0x20:0xc07a0676
>  stack pointer           = 0x28:0xd614e9a0
>  frame pointer           = 0x28:0xd614e9a4
>
> code segment            = base 0x0, limit 0xfffff, type 0x1b
>
>                         = DPL 0, pres 1, def32 1, gran 1
>
> processor eflags        = resume, IOPL = 0
>
> current process         = 43 (umount)
>  [thread pid 43 tid 100052 ]
>  Stopped at      isitmychild+0x6:        movl    0x10(%eax),%ecx
>  db> panic: Assertion !mtx_owned(&w_mtx) failed at /usr/src/sys/kern/subr_witness
>  .c:959
>  cpuid = 0
>  Uptime: 2m14s
>  Cannot dump. No dump device defined.
>  Automatic reboot in 15 seconds - press a key on the console to abort

It would be suitable for you to add DDB to your kernel config and see
a backtrace for it?

Attilio


-- 
Peace can only be achieved by understanding - A. Einstein
Received on Fri Feb 01 2008 - 17:42:00 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:26 UTC