From owner-freebsd-current@FreeBSD.ORG Sat Nov 22 14:44:48 2008 Return-Path: Delivered-To: current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 88B261065672 for ; Sat, 22 Nov 2008 14:44:48 +0000 (UTC) (envelope-from onemda@gmail.com) Received: from hs-out-0708.google.com (hs-out-0708.google.com [64.233.178.244]) by mx1.freebsd.org (Postfix) with ESMTP id 241C28FC17 for ; Sat, 22 Nov 2008 14:44:47 +0000 (UTC) (envelope-from onemda@gmail.com) Received: by hs-out-0708.google.com with SMTP id 54so643693hsz.11 for ; Sat, 22 Nov 2008 06:44:47 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:message-id:date:from:to :subject:cc:in-reply-to:mime-version:content-type :content-transfer-encoding:content-disposition:references; bh=jR6PqsB4Do5rFF12t+L8Ivb/Ej8cuHz9ufGySmo9Y0o=; b=c3gBykVN4Yz5hxuodMHpjaAyFa8vTh1VWCWZYJ6y7mmTRP5xFM8Lg6SCeUKt8ffiow HzVO41/JnV7XPehMopDiZ64f/mdKnt5PkRP8DYitJeAGzu7zcIK1RNwxrVS8tjrpQQag M2MmLfnAWdBFu5SdTwk9aLPrqccwdWAAU6Tnc= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:to:subject:cc:in-reply-to:mime-version :content-type:content-transfer-encoding:content-disposition :references; b=himSLUXnfSsoW8zA6DndLawuSe0MrmmvoJNLBEb2xAj+jMxkZrq7u+NADyvyb8u2K2 c+honrAKdPYiQBigvwn0H+1nOKWWqehdSh7yE0N/xMFozKekY7RNT2R60rsvA/48bzo3 884168dxWiwImDXuosWa+UsGjEw++OqvoAJ44= Received: by 10.231.35.193 with SMTP id q1mr32422ibd.13.1227365087228; Sat, 22 Nov 2008 06:44:47 -0800 (PST) Received: by 10.231.11.7 with HTTP; Sat, 22 Nov 2008 06:44:47 -0800 (PST) Message-ID: <3a142e750811220644v19acf60g7b0b0683fe73a1af@mail.gmail.com> Date: Sat, 22 Nov 2008 15:44:47 +0100 From: "Paul B. Mahol" To: "John Baldwin" In-Reply-To: <3a142e750811211602h3855e912g573f53b00f6ce452@mail.gmail.com> MIME-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Content-Disposition: inline References: <200811201627.58289.jhb@freebsd.org> <3a142e750811201532u6e697488w2747242e0a8614a9@mail.gmail.com> <200811211452.02545.jhb@freebsd.org> <3a142e750811211602h3855e912g573f53b00f6ce452@mail.gmail.com> Cc: scottl@freebsd.org, current@freebsd.org Subject: Re: [PATCH] Make udf(4) MPSAFE and use shared lookups X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 22 Nov 2008 14:44:48 -0000 On 11/22/08, Paul B. Mahol wrote: > On 11/21/08, John Baldwin wrote: >> On Thursday 20 November 2008 06:32:25 pm Paul B. Mahol wrote: >>> On 11/20/08, John Baldwin wrote: >>> > So this patch is fairly minimal since udf(4) is currently read-only. >>> > The >>> > changes include: >>> > >>> > * Set VV_ROOT in udf_vget() if we ever return a vnode instead of doing >>> > it >>> > only >>> > in udf_root(). This matches the behavior of other operating systems >>> > and >>> > correctly tags the root vnode with VV_ROOT in the unlikely case that >>> > we >>> > create the vnode during a call to ufs_vget() that does not come from >>> > ufs_root(). >>> > * If the hash lookup in ufs_vget() fails, ensure an exclusive vnode >>> > lock >>> > >> is >>> > used while creating the new vnode (same as UFS). >>> > * Allow lock recursion (XXX: not really sure this is needed actually). >>> > * Allow shared vnode locks on non-fifos. >>> > * Honor the requested locking flags (shared vs exclusive) instead of >> always >>> > using exclusive vnode locks during a lookup operation. >>> > * Handle "." lookups the same way other filesystems do by just bumping >>> > the >>> > reference on 'dvp' rather than calling udf_vget(). >>> > >>> > http://www.FreeBSD.org/~jhb/patches/udf_mpsafe.patch >>> > >>> > I have only verified that this compiles and would appreciate it if some >>> > folks >>> > could test this, preferable with INVARIANTS and DEBUG_VFS_LOCKS >>> > enabled. >>> >>> I lightly tested it with md(4) on 47M size iso created with k3b >>> (it contains two files) >>> >>> I only got this lor related to udf: >>> >>> lock order reversal: >>> 1st 0xc4449270 udf (udf) @ /usr/src/sys/kern/vfs_lookup.c:442 >>> 2nd 0xd7d10850 bufwait (bufwait) @ /usr/src/sys/kern/vfs_bio.c:2443 >>> 3rd 0xc4399488 udf (udf) @ >>> /usr/src/sys/modules/udf/../../fs/udf/udf_vfsops.c:625 >> >> I've updated the patch at the same URL above to fix this LOR. >> >> -- >> John Baldwin >> > > Some bad news, using new patch (did not tested agains old one) I was able > to reliable panic system with 3.4GB iso, trying to play music files via > cplay. > > here is backtrack, from textdump: > > db:1:lockinfo> show locks > db:1:locks> show alllocks > Process 977 (python) thread 0xc43b4d80 (100087) > db:1:alllocks> show lockedvnods > Locked vnodes > db:0:kdb.enter.panic> show pcpu > cpuid = 1 > curthread = 0xc43b4d80: pid 977 "initial thread" > curpcb = 0xc3b67d90 > fpcurthread = none > idlethread = 0xc3d2ad80: pid 10 "idle: cpu1" > APIC ID = 1 > currentldt = 0x50 > spin locks held: > db:0:kdb.enter.panic> bt > Tracing pid 977 tid 100087 td 0xc43b4d80 > kdb_enter(c069b0df,c069b0df,c06a5d32,c3b67968,1,...) at kdb_enter+0x3a > panic(c06a5d32,10800,10000,c0686786,c3b679d0,...) at panic+0x131 > getblk(c4e0e10c,424,0,10800,0,...) at getblk+0x2d > breadn(c4e0e10c,424,0,10800,0,...) at breadn+0x44 > bread(c4e0e10c,424,0,10800,0,...) at bread+0x4c > udf_readatoffset(1a18,0,c50568d8,c50568dc,0,...) at udf_readatoffset+0xbb > udf_getfid(c4694680,ffffffff,c3b67cf8,c06a8594,c3b67c24,...) at > udf_getfid+0x1ca > udf_readdir(c3b67c24,0,c4555648,0,c3b67c5c,...) at udf_readdir+0xdc > VOP_READDIR_APV(c4faf280,c3b67c24,c06a8594,ff3,1a18,...) at > VOP_READDIR_APV+0xa0 > kern_getdirentries(c43b4d80,46,2844c000,1000,c3b67c78,...) at > kern_getdirentries+0x1bd > getdirentries(c43b4d80,c3b67cf8,10,c06a1b96,c06cfbe0,...) at > getdirentries+0x31 > syscall(c3b67d38) at syscall+0x261 > Xint0x80_syscall() at Xint0x80_syscall+0x20 > --- syscall (196, FreeBSD ELF32, getdirentries), eip = 0x28251e4b, esp > = 0xbfbfe27c, ebp = 0xbfbfe2a8 --- > > > and panic message: > > uiomove returned -1 > panic: getblk: size(67584) > MAXBSIZE(65536) > > cpuid = 1 > KDB: enter: panic > exclusive lockmgr udf (udf) r = 0 (0xc45556a0) locked @ > /usr/src/sys/kern/vfs_syscalls.c:4083 > exclusive lockmgr udf (udf) r = 0 (0xc45556a0) locked @ > /usr/src/sys/kern/vfs_syscalls.c:4083 > > 0xc4555648: tag udf, type VDIR > usecount 1, writecount 0, refcount 1 mountedhere 0 > flags () > v_object 0xc479ac98 ref 0 pages 0 > lock type udf: EXCL by thread 0xc43b4d80 (pid 977) More bad news, panic is not introduced with patches it was here from the start: db:0:kdb.enter.panic> show pcpu cpuid = 1 curthread = 0xc4866240: pid 864 "initial thread" curpcb = 0xc3b61d90 fpcurthread = none idlethread = 0xc3d2ad80: pid 10 "idle: cpu1" APIC ID = 1 currentldt = 0x50 spin locks held: db:0:kdb.enter.panic> bt Tracing pid 864 tid 100085 td 0xc4866240 kdb_enter(c069b2ff,c069b2ff,c06a5f73,c3b61968,1,...) at kdb_enter+0x3a panic(c06a5f73,10800,10000,c06869a6,c3b619d0,...) at panic+0x131 getblk(c4f08648,424,0,10800,0,...) at getblk+0x2d breadn(c4f08648,424,0,10800,0,...) at breadn+0x44 bread(c4f08648,424,0,10800,0,...) at bread+0x4c udf_readatoffset(1a18,0,c5183038,c518303c,0,...) at udf_readatoffset+0xbb udf_getfid(c4f02200,c06a034f,527,c06a87d5,c3b61c24,...) at udf_getfid+0x1ca udf_readdir(c3b61c24,0,c4f05a78,0,c3b61c5c,...) at udf_readdir+0xdc VOP_READDIR_APV(c517f280,c3b61c24,c06a87d5,ff3,1a18,...) at VOP_READDIR_APV+0xa0 kern_getdirentries(c4866240,46,2844c000,1000,c3b61c78,...) at kern_getdirentries+0x1bd getdirentries(c4866240,c3b61cf8,10,c06a1dd7,c06cfe00,...) at getdirentries+0x31 syscall(c3b61d38) at syscall+0x261 Xint0x80_syscall() at Xint0x80_syscall+0x20 --- syscall (196, FreeBSD ELF32, getdirentries), eip = 0x28251e4b, esp = 0xbfbfdcbc, ebp = 0xbfbfdce8 --- lock order reversal: 1st 0xc4f06488 udf (udf) @ /usr/src/sys/kern/vfs_subr.c:2053 2nd 0xd7d9d490 bufwait (bufwait) @ /usr/src/sys/kern/vfs_bio.c:2443 3rd 0xc4f057ac udf (udf) @ /usr/src/sys/modules/udf/../../fs/udf/udf_vfsops.c:616 KDB: stack backtrace: db_trace_self_wrapper(c069e457,c3b61824,c04e7a2f,4,c0699b7b,...) at db_trace_self_wrapper+0x26 kdb_backtrace(4,c0699b7b,c3cb7538,c3cb9d08,c3b61880,...) at kdb_backtrace+0x29 _witness_debugger(c06a1124,c4f057ac,c517e9dc,c3cb9d08,c517e956,...) at _witness_debugger+0x1e witness_checkorder(c4f057ac,9,c517e956,268,0,...) at witness_checkorder+0x811 __lockmgr_args(c4f057ac,80000,0,0,0,...) at __lockmgr_args+0x762 udf_vget(c4990280,c1,80000,c3b619bc,0,...) at udf_vget+0x137 udf_lookup(c3b619fc,c4f06430,c3b61bb4,c4f06430,c3b61a1c,...) at udf_lookup+0x26c VOP_CACHEDLOOKUP_APV(c517f280,c3b619fc,c3b61bb4,c3b61ba0,c06fa3e0,...) at VOP_CACHEDLOOKUP_APV+0xa0 vfs_cache_lookup(c3b61a7c,c3b61a7c,0,200000,c4f06430,...) at vfs_cache_lookup+0xc3 VOP_LOOKUP_APV(c517f280,c3b61a7c,c06a6e55,2cc,c3b61ba0,...) at VOP_LOOKUP_APV+0xaa lookup(c3b61b88,0,c06a6e55,ec,c41fe42c,...) at lookup+0x507 namei(c3b61b88,c04e780b,c06b6dc4,c06a0b67,3,...) at namei+0x45b kern_statat(c4866240,0,ffffff9c,28307450,0,...) at kern_statat+0x66 kern_stat(c4866240,28307450,0,c3b61c1c,44f,...) at kern_stat+0x36 stat(c4866240,c3b61cf8,8,c06a259b,c06cfd40,...) at stat+0x2b syscall(c3b61d38) at syscall+0x261 Xint0x80_syscall() at Xint0x80_syscall+0x20 --- syscall (188, FreeBSD ELF32, stat), eip = 0x2825c34b, esp = 0xbfbfe0bc, ebp = 0xbfbfe158 --- uiomove returned -1 uiomove returned -1 uiomove returned -1 uiomove returned -1 uiomove returned -1 panic: getblk: size(67584) > MAXBSIZE(65536) cpuid = 1 KDB: enter: panic exclusive lockmgr udf (udf) r = 0 (0xc4f05ad0) locked @ /usr/src/sys/kern/vfs_syscalls.c:4083 exclusive sleep mutex Giant (Giant) r = 0 (0xc0710cf0) locked @ /usr/src/sys/kern/vfs_syscalls.c:4068 exclusive lockmgr udf (udf) r = 0 (0xc4f05ad0) locked @ /usr/src/sys/kern/vfs_syscalls.c:4083 exclusive sleep mutex Giant (Giant) r = 0 (0xc0710cf0) locked @ /usr/src/sys/kern/vfs_syscalls.c:4068 0xc4f05a78: tag udf, type VDIR usecount 1, writecount 0, refcount 1 mountedhere 0 flags () v_object 0xc50b907c ref 0 pages 0 lock type udf: EXCL by thread 0xc4866240 (pid 864) This is recent kernel: Sat Nov 22 15:17:29 CET 2008 (without patches from @current) -- Paul