From owner-freebsd-bugs@FreeBSD.ORG Mon Aug 21 01:20:29 2006 Return-Path: X-Original-To: freebsd-bugs@hub.freebsd.org Delivered-To: freebsd-bugs@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 1A5CE16A4DD for ; Mon, 21 Aug 2006 01:20:29 +0000 (UTC) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id E3A2243D6E for ; Mon, 21 Aug 2006 01:20:14 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.4/8.13.4) with ESMTP id k7L1KECQ052243 for ; Mon, 21 Aug 2006 01:20:14 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.4/8.13.4/Submit) id k7L1KECJ052242; Mon, 21 Aug 2006 01:20:14 GMT (envelope-from gnats) Resent-Date: Mon, 21 Aug 2006 01:20:14 GMT Resent-Message-Id: <200608210120.k7L1KECJ052242@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-bugs@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, Alex Unleashed Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id C506916A4DE for ; Mon, 21 Aug 2006 01:11:48 +0000 (UTC) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (www.freebsd.org [216.136.204.117]) by mx1.FreeBSD.org (Postfix) with ESMTP id 5BE5E43D45 for ; Mon, 21 Aug 2006 01:11:48 +0000 (GMT) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (localhost [127.0.0.1]) by www.freebsd.org (8.13.1/8.13.1) with ESMTP id k7L1BmiW062714 for ; Mon, 21 Aug 2006 01:11:48 GMT (envelope-from nobody@www.freebsd.org) Received: (from nobody@localhost) by www.freebsd.org (8.13.1/8.13.1/Submit) id k7L1Bm4i062713; Mon, 21 Aug 2006 01:11:48 GMT (envelope-from nobody) Message-Id: <200608210111.k7L1Bm4i062713@www.freebsd.org> Date: Mon, 21 Aug 2006 01:11:48 GMT From: Alex Unleashed To: freebsd-gnats-submit@FreeBSD.org X-Send-Pr-Version: www-2.3 Cc: Subject: kern/102335: [DEVFS] sx vnode deadlock X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 21 Aug 2006 01:20:29 -0000 >Number: 102335 >Category: kern >Synopsis: [DEVFS] sx vnode deadlock >Confidential: no >Severity: serious >Priority: medium >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Mon Aug 21 01:20:14 GMT 2006 >Closed-Date: >Last-Modified: >Originator: Alex Unleashed >Release: 6.1-RELEASE >Organization: >Environment: FreeBSD merovingio.kicks-ass.org 6.1-RELEASE FreeBSD 6.1-RELEASE #0: Sun May 7 04:32:43 UTC 2006 root@opus.cse.buffalo.edu:/usr/obj/usr/src/sys/GENERIC i386 >Description: I've been able to reproduce both in 6.1-RELEASE (including -p3) and 6-STABLE (snapshot from August 16th 2006 ~01:00 GMT) a deadlock in devfs code which leaves the system unable to access the disk. I've come up with some interesting debugging info, and it looks to me like there are vnode problems while a sx lock is being held. My take at it is that the deadlock occurs when a process gets a lock on a vnode (tagged "devfs") and another process xlocks an sx lock ("devfsmount"). For some reason the one holding the sx lock wants to get the lock on the vnode through devfs_allocv(), and the other process wants to get the sx lock through devfs_lookup(). From this point on, pretty much anything wanting to touch the filesystem waits forever on devfs_root() for another vnode flagged as VV_ROOT and locked by the process holding the sx lock. Patching the devfs code with fixes from -CURRENT didn't work out. Here's some info from a DDB session after the deadlock had just occurred: db> ps pid proc uid ppid pgrp flag stat wmesg wchan cmd 17072 c4145624 0 17070 1071 0004002 [SLPQ piperd 0xc39904c8][SLP] gawk-3.1.5 17071 c4149c48 0 17070 1071 0000002 [SLPQ devfs 0xc41435c8][SLP] sh 17070 c4145830 0 17068 1071 0000002 [SLPQ wait 0xc4145830][SLP] sh 17069 c414920c 0 17067 1071 0004002 [SLPQ devfsmount 0xc396d540][SLP] xgcc <> db> trace 17069 Tracing pid 17069 tid 100071 td 0xc4146600 sched_switch(c4146600,0,1,c09545dc,c4146600) at sched_switch+0x2ea mi_switch(1,0,c0955f54,1ba,c091b594) at mi_switch+0x425 sleepq_switch(c396d540,0,c0955f54,20c,dad529f0) at sleepq_switch+0x110 sleepq_wait(c396d540,c0a36da0,c0918064,1,c09c1b6c) at sleepq_wait+0x65 cv_wait(c396d540,c0a36da0,c094f9cd,23f,dad52ad4) at cv_wait+0x1e6 _sx_xlock(c396d510,c094f9c4,23f,c09b8d80,dad52ad4) at _sx_xlock+0x99 devfs_lookup(dad52ad4,c092ddcb,37,c096da3c,c4143570) at devfs_lookup+0x36 VOP_LOOKUP_APV(c09b8d80,dad52ad4,c4146600,c4146600,0) at VOP_LOOKUP_APV+0xa4 lookup(dad52b80,0,c09204ab,b6,c070487d) at lookup+0x4ed namei(dad52b80,c091c646,275,c09550c4,c4146600) at namei+0x43c kern_lstat(c4146600,807a800,0,dad52c54,c091b47f) at kern_lstat+0x4f lstat(c4146600,dad52d04,3c4,c096ba20,c4146600) at lstat+0x2f syscall(3b,3b,3b,28232cb2,bfbfa2c1) at syscall+0x31f Xint0x80_syscall() at Xint0x80_syscall+0x1f --- syscall (190, FreeBSD ELF32, lstat), eip = 0x282251bb, esp = 0xbfbf9e7c, ebp = 0xbfbfab38 --- db> trace 17071 Tracing pid 17071 tid 100076 td 0xc394cd80 sched_switch(c394cd80,0,1,c09545dc,c394cd80) at sched_switch+0x2ea mi_switch(1,0,c0955f54,1ba,c091b594) at mi_switch+0x425 sleepq_switch(c41435c8,0,c0955f54,20c,d9bb6768) at sleepq_switch+0x110 sleepq_wait(c41435c8,0,c091bebc,c8,c394cd80) at sleepq_wait+0x65 msleep(c41435c8,c0a3743c,50,c0917eb4,0) at msleep+0x342 acquire(d9bb6840,80,60000,b1,0) at acquire+0x11c lockmgr(c41435c8,2002,c4143638,c394cd80,d9bb6888) at lockmgr+0x576 vop_stdlock(d9bb68b0,c08f40c3,42af,c091d728,1) at vop_stdlock+0x32 VOP_LOCK_APV(c09b8d80,d9bb68b0,c4143638,8,c0920936) at VOP_LOCK_APV+0xa4 vn_lock(c4143570,2002,c394cd80,7a7,2) at vn_lock+0xd2 vget(c4143570,2,c394cd80,c3972005,c396c460) at vget+0xf0 devfs_allocv(c396c400,c3889800,d9bb6b94,c394cd80,d9bb6988) at devfs_allocv+0x43 devfs_lookupx(d9bb6ad4,c094f9c4,23f,c09b8d80,d9bb6ad4) at devfs_lookupx+0x5f5 devfs_lookup(d9bb6ad4,c092ddcb,37,c096dac3,c3971000) at devfs_lookupx+0x3e VOP_LOOKUP_APV(c09b8d80,d9bb6ad4,c394cd80,c394cd80,0) at VOP_LOOKUP_APV+0xa4 lookup(d9bb6b80,0,c09204ab,b6,c0a82d70) at lookup+0x4ed namei(d9bb6b80,c091c646,275,c09550c4,c394cd80) at namei+0x43c kern_lstat(c394cd80,806d800,0,d9bb6c54,c091b47f) at kern_lstat+0x4f lstat(c394cd80,d9bb6d04,3c4,c096ba20,c394cd80) at lstat+0x2f syscall(3b,3b,3b,281b2cb2,bfbf9731) at syscall+0x31f Xint0x80_syscall() at Xint0x80_syscall+0x1f --- syscall (190, FreeBSD ELF32, lstat), eip = 0x281a51bb, esp = 0xbfbf92ec, ebp = 0xbfbf9fa8 --- db> show alllocks Process 17071 (sh) thread 0xc394cd80 (100076) exclusive sx devfsmount r = 0 (0xc396d510) locked @ fs/devfs/devfs_vnops:575 Process 34 (irq1: atkbd0) thread 0xc3687a80 (100031) exclusive sleep mutex Giant r = 0 (0xc0a37ac0) locked @ kern/kern_intr.c:683 db> show lock 0xc396d510 class: sx name: devfsmount state: XLOCK: 0xc394cd80 (tid 100076, pid 17071, "sh") waiters: 0 shared, 1 exclusive db> show lockedvnods Locked vnodes 0xc3971000: tag devfs, type VDIR usecount 3, writecount 0, refcount 3 mountedhere 0 flags (VV_ROOT) lock type devfs: EXCL (count 1) by thread 0xc394cd80 (pid 17071) #0 0xc06903a1 at lockmgr+0x621 #1 0xc06f98db at vop_stdlock+0x32 #2 0xc08e18fb at VOP_LOCK_APV+0xa4 #3 0xc0712460 at vn_lock+0xd2 #4 0xc07040ff at vget+0xf0 #5 0xc0645702 at devfs_allocv+0x43 #6 0xc064550e at devfs_root+0x2c #7 0xc06fc023 at lookup+0x829 #8 0xc06fb521 at namei+0x43c #9 0xc070ba21 at kern_lstat+0x4f #10 0xc070b9ad at lstat+0x2f #11 0xc08cbb89 at syscall+0x31f #12 0xc08b890f at Xint0x80_syscall+0x1f 0xc4143570: tag devfs, type VDIR usecount 1, writecount 0, refcount 2 mountedhere 0 flags () lock type devfs: EXCL (count 1) by thread 0xc4146600 (pid 17069) with 1 pending #0 0xc06903a1 at lockmgr+0x621 #1 0xc06f98db at vop_stdlock+0x32 #2 0xc08e18fb at VOP_LOCK_APV+0xa4 #3 0xc0712460 at vn_lock+0xd2 #4 0xc07040ff at vget+0xf0 #5 0xc0645702 at devfs_allocv+0x43 #6 0xc064680e at devfs_lookupx+0x5f5 #7 0xc064685b at devfs_lookup+0x3e #8 0xc08dea25 at VOP_LOOKUP_APV+0xa4 #9 0xc06fbce7 at lookup+0x4ed #10 0xc06fb521 at namei+0x43c #11 0xc070ba21 at kern_lstat+0x4f #12 0xc070b9ad at lstat+0x2f #13 0xc08cbb89 at syscall+0x31f #14 0xc08b890f at Xint0x80_syscall+0x1f After this the system still works, but it's unable to perform operations on the filesystem, like launching a new process or saving to disk. When this happens, the new process calls at some point a syscall (like open or chflags, for example) which goes through devfs_root() (namei -> lookup -> devfs_root -> devfs_allocv) and the vnode with the VV_ROOT flag gets its refcount and pending status incremented, having the process waiting there forever. >How-To-Repeat: This bug is cumbersome to reproduce. I'm mostly available to try whatever fixes or commands or debugging code people want me to try, but I'm explaining here how to reproduce it in case I'm MIA. I ported a path sandbox application to FreeBSD from Gentoo Linux which triggered this bug randomly. This means it can trigger it only 10 seconds after starting running programs inside the sandbox or it can be quite a lot of hours compiling software inside it without triggering the bug (both have happened). However I've seen this enough times at different points to know that the path sandbox makes it much easier to trigger it (just think that the sandbox-wrapped syscalls multiply the real number of fs-related system calls performed overall, mainly to check access permissions). Compiling lots of packages is probably the best way to get it to trigger the bug. Building kernel and world can also help. Note that this doesn't mean you can't get the same results by some other means. Just having some specific tests stressing the system long enough should also work. You can reproduce it by running Gentoo/FreeBSD, which btw *doesn't* modify FreeBSD sources, and unmasking and installing latest sandbox version, OR you can do so under a vanilla FreeBSD install. If the latter, you can install and run the path sandbox by following these steps: - Download http://unleashed.kicks-ass.org/gentoo/sandbox/sandbox-1.2.20alpha2.tar.bz2 --or download it from Gentoo mirrors-- and make sure you installed bash. - Make /bin/bash point to the real bash executable, if not already there. - Extract the tarball and run "./configure --host=i386-unknown-freebsd6.1 --build=i386-unknown-freebsd6.1 --prefix=/usr/local/sandbox --sysconfdir=/usr/local/sandbox/etc --datadir=/usr/local/sandbox/usr/share --mandir=/usr/local/sandbox/usr/share/man --infodir=/usr/local/sandbox/usr/share/info --localstatedir=/usr/local/sandbox/var/lib --libdir=/usr/local/sandbox/usr/lib && gmake && gmake install && mkdir /var/log/sandbox" in the new directory. Make sure you have created the directory structure specified in the config options you want to use. - Run /usr/local/sandbox/bin/sandbox. The bash prompt will change, starting with [s], so you know the sandbox is active. You can optionally play running the path sandbox using some environment variables specifying a space-separated list of directories where it should allow/disallow accesses (SANDBOX_DENY, SANDBOX_READ, SANDBOX_WRITE, SANDBOX_PREDICT) and activating debug info (SANDBOX_DEBUG=1). >From here on doesn't matter where you're trying to reproduce this: your best bet is to start compiling software compulsively until the system's disk apparently freezes and no new program can be launched (you can have "top" running permanently and look for processes stalled in "devfs" and "devfsm" waitchannels whenever you think the bug has been triggered). >Fix: >Release-Note: >Audit-Trail: >Unformatted: