diff mbox

[3.10.4] NFS locking panic, plus persisting NFS shutdown panic from 3.9.*

Message ID 1375719301.7337.14.camel@leira.trondhjem.org (mailing list archive)
State New, archived
Headers show

Commit Message

Trond Myklebust Aug. 5, 2013, 4:15 p.m. UTC
On Mon, 2013-08-05 at 16:50 +0100, Nix wrote:
> On 5 Aug 2013, Jeff Layton said:

> 

> > On Mon, 5 Aug 2013 11:04:27 -0400

> > Jeff Layton <jlayton@redhat.com> wrote:

> >

> >> On Mon, 05 Aug 2013 15:48:01 +0100

> >> Nix <nix@esperi.org.uk> wrote:

> >> 

> >> > On 5 Aug 2013, Jeff Layton stated:

> >> > 

> >> > > On Sun, 04 Aug 2013 16:40:58 +0100

> >> > > Nix <nix@esperi.org.uk> wrote:

> >> > >

> >> > >> I just got this panic on 3.10.4, in the middle of a large parallel

> >> > >> compilation (of Chromium, as it happens) over NFSv3:

> >> > >> 

> >> > >> [16364.527516] BUG: unable to handle kernel NULL pointer dereference at 0000000000000008

> >> > >> [16364.527571] IP: [<ffffffff81245157>] nlmclnt_setlockargs+0x55/0xcf

> >> > >> [16364.527611] PGD 0 

> >> > >> [16364.527626] Oops: 0000 [#1] PREEMPT SMP 

> >> > >> [16364.527656] Modules linked in: [last unloaded: microcode] 

> >> > >> [16364.527690] CPU: 0 PID: 17034 Comm: flock Not tainted 3.10.4-05315-gf4ce424-dirty #1

> >> > >> [16364.527730] Hardware name: System manufacturer System Product Name/P8H61-MX USB3, BIOS 0506 08/10/2012

> >> > >> [16364.527775] task: ffff88041a97ad60 ti: ffff8803501d4000 task.ti: ffff8803501d4000

> >> > >> [16364.527813] RIP: 0010:[<ffffffff81245157>] [<ffffffff81245157>] nlmclnt_setlockargs+0x55/0xcf

> >> > >> [16364.527860] RSP: 0018:ffff8803501d5c58  EFLAGS: 00010282

> >> > >> [16364.527889] RAX: ffff88041a97ad60 RBX: ffff8803e49c8800 RCX: 0000000000000000

> >> > >> [16364.527926] RDX: 0000000000000000 RSI: 000000000000004a RDI: ffff8803e49c8b54

> >> > >> [16364.527962] RBP: ffff8803501d5c68 R08: 0000000000015720 R09: 0000000000000000

> >> > >> [16364.527998] R10: 00007ffffffff000 R11: ffff8803501d5d58 R12: ffff8803501d5d58

> >> > >> [16364.528034] R13: ffff88041bd2bc00 R14: 0000000000000000 R15: ffff8803fc9e2900

> >> > >> [16364.528070] FS:  0000000000000000(0000) GS:ffff88042fa00000(0000) knlGS:0000000000000000

> >> > >> [16364.528111] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033

> >> > >> [16364.528142] CR2: 0000000000000008 CR3: 0000000001c0b000 CR4: 00000000001407f0

> >> > >> [16364.528177] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000

> >> > >> [16364.528214] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400

> >> > >> [16364.528303] Stack:

> >> > >> [16364.528316]  ffff8803501d5d58 ffff8803e49c8800 ffff8803501d5cd8 ffffffff81245418 

> >> > >> [16364.528369]  0000000000000000 ffff8803516f0bc0 ffff8803d7b7b6c0 ffffffff81215c81 

> >> > >> [16364.528418]  ffff880300000007 ffff88041bd2bdc8 ffff8801aabe9650 ffff8803fc9e2900 

> >> > >> [16364.528467] Call Trace:

> >> > >> [16364.528485]  [<ffffffff81245418>] nlmclnt_proc+0x148/0x5fb

> >> > >> [16364.528516]  [<ffffffff81215c81>] ? nfs_put_lock_context+0x69/0x6e

> >> > >> [16364.528550]  [<ffffffff812209a2>] nfs3_proc_lock+0x21/0x23

> >> > >> [16364.528581]  [<ffffffff812149dd>] do_unlk+0x96/0xb2

> >> > >> [16364.528608]  [<ffffffff81214b41>] nfs_flock+0x5a/0x71

> >> > >> [16364.528637]  [<ffffffff8119a747>] locks_remove_flock+0x9e/0x113

> >> > >> [16364.528668]  [<ffffffff8115cc68>] __fput+0xb6/0x1e6

> >> > >> [16364.528695]  [<ffffffff8115cda6>] ____fput+0xe/0x10

> >> > >> [16364.528724]  [<ffffffff810998da>] task_work_run+0x7e/0x98

> >> > >> [16364.528754]  [<ffffffff81082bc5>] do_exit+0x3cc/0x8fa

> >> > >> [16364.528782]  [<ffffffff81083501>] ? SyS_wait4+0xa5/0xc2

> >> > >> [16364.528811]  [<ffffffff8108328d>] do_group_exit+0x6f/0xa2

> >> > >> [16364.528843]  [<ffffffff810832d7>] SyS_exit_group+0x17/0x17

> >> > >> [16364.528876]  [<ffffffff81613e92>] system_call_fastpath+0x16/0x1b

> >> > >> [16364.528907] Code: 00 00 65 48 8b 04 25 c0 b8 00 00 48 8b 72 20 48 81 ee c0 01 00 00 f3 a4 48 8d bb 54 03 00 00 be 4a 00 00 00 48 8b 90 68 05 00 00 <48> 8b 52 08 48 89 bb d0 00 00 00 48 83 c2 45 48 89 53 38 48 8b 

> >> > >> [16364.529176] RIP [<ffffffff81245157>] nlmclnt_setlockargs+0x55/0xcf

> >> > >> [16364.529264]  RSP <ffff8803501d5c58>

> >> > >> [16364.529283] CR2: 0000000000000008

> >> > >> [16364.539039] ---[ end trace 5a73fddf23441377 ]---

> [...]

> > The listing and disassembly from nlmclnt_proc is not terribly

> > interesting unfortunately. You really want to do the listing and

> > disassembly of the RIP at panic time (nlmclnt_setlockargs+0x55).

> 

> Oh, sorry! Wrong end of the oops :)

> 

> 0xffffffff81245157 is in nlmclnt_setlockargs (fs/lockd/clntproc.c:131).

> 126             struct nlm_args *argp = &req->a_args;

> 127             struct nlm_lock *lock = &argp->lock;

> 128

> 129             nlmclnt_next_cookie(&argp->cookie);

> 130             memcpy(&lock->fh, NFS_FH(file_inode(fl->fl_file)), sizeof(struct nfs_fh));

> 131             lock->caller  = utsname()->nodename;

> 132             lock->oh.data = req->a_owner;

> 133             lock->oh.len  = snprintf(req->a_owner, sizeof(req->a_owner), "%u@%s",

> 134                                     (unsigned int)fl->fl_u.nfs_fl.owner->pid,

> 135                                     utsname()->nodename);

> 

>    0xffffffff81245102 <+0>:     callq  0xffffffff81613b00 <__fentry__>

>    0xffffffff81245107 <+5>:     push   %rbp

>    0xffffffff81245108 <+6>:     mov    %rsp,%rbp

>    0xffffffff8124510b <+9>:     push   %r12

>    0xffffffff8124510d <+11>:    mov    %rsi,%r12

>    0xffffffff81245110 <+14>:    push   %rbx

>    0xffffffff81245111 <+15>:    mov    %rdi,%rbx

>    0xffffffff81245114 <+18>:    lea    0x10(%rdi),%rdi

>    0xffffffff81245118 <+22>:    callq  0xffffffff812450df <nlmclnt_next_cookie>

>    0xffffffff8124511d <+27>:    mov    0x60(%r12),%rdx

>    0xffffffff81245122 <+32>:    lea    0x44(%rbx),%rax

>    0xffffffff81245126 <+36>:    mov    %rax,%rdi

>    0xffffffff81245129 <+39>:    mov    $0x82,%ecx

>    0xffffffff8124512e <+44>:    mov    %gs:0xb8c0,%rax

>    0xffffffff81245137 <+53>:    mov    0x20(%rdx),%rsi

>    0xffffffff8124513b <+57>:    sub    $0x1c0,%rsi

>    0xffffffff81245142 <+64>:    rep movsb %ds:(%rsi),%es:(%rdi)

>    0xffffffff81245144 <+66>:    lea    0x354(%rbx),%rdi

>    0xffffffff8124514b <+73>:    mov    $0x4a,%esi

>    0xffffffff81245150 <+78>:    mov    0x568(%rax),%rdx

> -> 0xffffffff81245157 <+85>:    mov    0x8(%rdx),%rdx

>    0xffffffff8124515b <+89>:    mov    %rdi,0xd0(%rbx)

>    0xffffffff81245162 <+96>:    add    $0x45,%rdx

> 

> (aside: wish GDB reported those offsets in hex, or the kernel reported

> them in decimal. Every time I look at these I forget to convert and get

> confused...)

> 

> I wonder if req is NULL (possible if the assignment to argp at the top

> of the function's been pushed down by the optimizer). Time to stick a

> printk() in and find out (after work is over so I can reboot this box

> like billy-o).

> 


Does the attached patch fix the problem?

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Comments

Jeff Layton Aug. 5, 2013, 5:37 p.m. UTC | #1
On Mon, 5 Aug 2013 16:15:01 +0000
"Myklebust, Trond" <Trond.Myklebust@netapp.com> wrote:

> From 3c50ba80105464a28d456d9a1e0f1d81d4af92a8 Mon Sep 17 00:00:00 2001
> From: Trond Myklebust <Trond.Myklebust@netapp.com>
> Date: Mon, 5 Aug 2013 12:06:12 -0400
> Subject: [PATCH] LOCKD: Don't call utsname()->nodename from
>  nlmclnt_setlockargs
> MIME-Version: 1.0
> Content-Type: text/plain; charset=UTF-8
> Content-Transfer-Encoding: 8bit
> 
> Firstly, nlmclnt_setlockargs can be called from a reclaimer thread, in
> which case we're in entirely the wrong namespace.
> Secondly, commit 8aac62706adaaf0fab02c4327761561c8bda9448 (move
> exit_task_namespaces() outside of exit_notify()) now means that
> exit_task_work() is called after exit_task_namespaces(), which
> triggers an Oops when we're freeing up the locks.
> 
> Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
> Cc: Toralf Förster <toralf.foerster@gmx.de>
> Cc: Oleg Nesterov <oleg@redhat.com>
> Cc: Nix <nix@esperi.org.uk>
> Cc: Jeff Layton <jlayton@redhat.com>
> ---
>  fs/lockd/clntproc.c | 5 +++--
>  1 file changed, 3 insertions(+), 2 deletions(-)
> 
> diff --git a/fs/lockd/clntproc.c b/fs/lockd/clntproc.c
> index 9760ecb..acd3947 100644
> --- a/fs/lockd/clntproc.c
> +++ b/fs/lockd/clntproc.c
> @@ -125,14 +125,15 @@ static void nlmclnt_setlockargs(struct nlm_rqst *req, struct file_lock *fl)
>  {
>  	struct nlm_args	*argp = &req->a_args;
>  	struct nlm_lock	*lock = &argp->lock;
> +	char *nodename = req->a_host->h_rpcclnt->cl_nodename;
>  
>  	nlmclnt_next_cookie(&argp->cookie);
>  	memcpy(&lock->fh, NFS_FH(file_inode(fl->fl_file)), sizeof(struct nfs_fh));
> -	lock->caller  = utsname()->nodename;
> +	lock->caller  = nodename;
>  	lock->oh.data = req->a_owner;
>  	lock->oh.len  = snprintf(req->a_owner, sizeof(req->a_owner), "%u@%s",
>  				(unsigned int)fl->fl_u.nfs_fl.owner->pid,
> -				utsname()->nodename);
> +				nodename);
>  	lock->svid = fl->fl_u.nfs_fl.owner->pid;
>  	lock->fl.fl_start = fl->fl_start;
>  	lock->fl.fl_end = fl->fl_end;

Looks good to me...

Reviewed-by: Jeff Layton <jlayton@redhat.com>

Trond, any thoughts on the other oops that Nix posted? The issue there
seems to be that we're trying to do the pathwalk to the rpcbind unix
socket from exit_task_work(), but that's happening after we've already
called exit_fs().

The trivial answer seems to be to simply call exit_task_work() before
exit_fs() there, but it seems like we ought to be doing the upcall to
rpcbind in a mount namespace from which we know we can reach the
socket...
--
To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Nix Aug. 5, 2013, 6:33 p.m. UTC | #2
On 5 Aug 2013, Trond Myklebust told this:
> Does the attached patch fix the problem?

> From 3c50ba80105464a28d456d9a1e0f1d81d4af92a8 Mon Sep 17 00:00:00 2001
> From: Trond Myklebust <Trond.Myklebust@netapp.com>
> Date: Mon, 5 Aug 2013 12:06:12 -0400
> Subject: [PATCH] LOCKD: Don't call utsname()->nodename from
>  nlmclnt_setlockargs
> MIME-Version: 1.0
> Content-Type: text/plain; charset=UTF-8
> Content-Transfer-Encoding: 8bit

It makes it worse. Much, much worse. From a crash every so often when
I'm doing compilations over NFS, I get an immediate panic on startx,
long long before I even try to replicate the earlier panic:

[   83.432358] task: ffff88041aaa5ac0 ti: ffff8804199e2000 task.ti: ffff8804199e2000
[   83.432428] RIP: 0010:[<ffffffff8124af69>] [<ffffffff8124af69>] encode_nlm4_lock+0x26/0xbe
[   83.432512] RSP: 0018:ffff8804199e3a78  EFLAGS: 00010286
[   83.432564] RAX: 0000000000000000 RBX: ffff88041a577038 RCX: ffffffffffffffff
[   83.432630] RDX: ffff8804193b3098 RSI: ffff88041a577038 RDI: 000000000000008c
[   83.432697] RBP: ffff8804199e3aa8 R08: ffff8804193b3098 R09: 0000000000000001
[   83.432763] R10: ffff88042fa12980 R11: ffff88042fa12980 R12: ffff8804199e3ae8
[   83.432830] R13: 000000000000008c R14: ffff8804199e3fd8 R15: ffffffff815de80e
[   83.432898] FS:  00007f594b40c740(0000) GS:ffff88042fa00000(0000) knlGS:0000000000000000
[   83.432974] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   83.433028] CR2: 000000000000008c CR3: 000000041ab3d000 CR4: 00000000001407f0
[   83.433095] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[   83.433176] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[   83.433255] Stack:
[   83.433276]  ffff88041a44fb70 ffff880400000004 ffff8804199e3ae8 ffff88041a577010 
[   83.433360]  ffff8804188e0e00 ffff8804199e3fd8 ffff8804199e3ac8 ffffffff8124b0d7 
[   83.433443]  ffff8804188e0e00 ffffffff8124b086 ffff8804199e3b38 ffffffff815e6032 
[   83.433616] Call Trace:
[   83.433646]  [<ffffffff8124b0d7>] nlm4_xdr_enc_lockargs+0x51/0x76
[   83.433707]  [<ffffffff8124b086>] ? nlm4_xdr_enc_cancargs+0x56/0x56
[   83.433769]  [<ffffffff815e6032>] rpcauth_wrap_req+0x57/0x62
[   83.433826]  [<ffffffff815de98a>] call_transmit+0x17c/0x1f9
[   83.433880]  [<ffffffff815e4e58>] __rpc_execute+0xe8/0x2ca
[   83.433935]  [<ffffffff815e50f9>] rpc_execute+0x76/0x9d
[   83.433986]  [<ffffffff815debc1>] rpc_run_task+0x78/0x80
[   83.434039]  [<ffffffff815decff>] rpc_call_sync+0x88/0x9e
[   83.434092]  [<ffffffff81244b3c>] nlmclnt_call+0xb5/0x240
[   83.434146]  [<ffffffff812454f0>] nlmclnt_proc+0x226/0x5fb
[   83.434226]  [<ffffffff812209a2>] nfs3_proc_lock+0x21/0x23
[   83.434280]  [<ffffffff81214a5e>] do_setlk+0x65/0xee
[   83.434329]  [<ffffffff81214ca6>] nfs_lock+0x14e/0x162
[   83.434382]  [<ffffffff81199661>] vfs_lock_file+0x29/0x35
[   83.434435]  [<ffffffff8119a51d>] fcntl_setlk+0x139/0x2c5
[   83.434490]  [<ffffffff81169621>] SyS_fcntl+0x2b6/0x47d
[   83.434543]  [<ffffffff81613e92>] system_call_fastpath+0x16/0x1b
[   83.434600] Code: 5b 41 5c 5d c3 0f 1f 44 00 00 55 31 c0 48 83 c9 ff 48 89 e5 41 56 41 55 41 54 49 89 fc 53 48 89 f3 48 83 ec 10 4c 8b 2e 4c 89 ef <f2> ae 4c 89 e7 48 f7 d1 4c 8d 71 ff 41 8d 76 04 e8 9f 16 3a 00 
[   83.435077] RIP [<ffffffff8124af69>] encode_nlm4_lock+0x26/0xbe
[   83.435140]  RSP <ffff8804199e3a78>
[   83.435197] CR2: 000000000000008c

That's here:

(gdb) list *(encode_nlm4_lock+0x26)
0xffffffff8124af69 is in encode_nlm4_lock (fs/lockd/clnt4xdr.c:329).
324      *      string caller_name<LM_MAXSTRLEN>;
325      */
326     static void encode_caller_name(struct xdr_stream *xdr, const char *name)
327     {
328             /* NB: client-side does not set lock->len */
329             u32 length = strlen(name);
330             __be32 *p;
331
332             p = xdr_reserve_space(xdr, 4 + length);
333             xdr_encode_opaque(p, name, length);

   0xffffffff8124af69 <+38>:    repnz scas %es:(%rdi),%al

Pretty clearly, "name" can be NULL after this patch...
diff mbox

Patch

From 3c50ba80105464a28d456d9a1e0f1d81d4af92a8 Mon Sep 17 00:00:00 2001
From: Trond Myklebust <Trond.Myklebust@netapp.com>
Date: Mon, 5 Aug 2013 12:06:12 -0400
Subject: [PATCH] LOCKD: Don't call utsname()->nodename from
 nlmclnt_setlockargs
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

Firstly, nlmclnt_setlockargs can be called from a reclaimer thread, in
which case we're in entirely the wrong namespace.
Secondly, commit 8aac62706adaaf0fab02c4327761561c8bda9448 (move
exit_task_namespaces() outside of exit_notify()) now means that
exit_task_work() is called after exit_task_namespaces(), which
triggers an Oops when we're freeing up the locks.

Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
Cc: Toralf Förster <toralf.foerster@gmx.de>
Cc: Oleg Nesterov <oleg@redhat.com>
Cc: Nix <nix@esperi.org.uk>
Cc: Jeff Layton <jlayton@redhat.com>
---
 fs/lockd/clntproc.c | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/fs/lockd/clntproc.c b/fs/lockd/clntproc.c
index 9760ecb..acd3947 100644
--- a/fs/lockd/clntproc.c
+++ b/fs/lockd/clntproc.c
@@ -125,14 +125,15 @@  static void nlmclnt_setlockargs(struct nlm_rqst *req, struct file_lock *fl)
 {
 	struct nlm_args	*argp = &req->a_args;
 	struct nlm_lock	*lock = &argp->lock;
+	char *nodename = req->a_host->h_rpcclnt->cl_nodename;
 
 	nlmclnt_next_cookie(&argp->cookie);
 	memcpy(&lock->fh, NFS_FH(file_inode(fl->fl_file)), sizeof(struct nfs_fh));
-	lock->caller  = utsname()->nodename;
+	lock->caller  = nodename;
 	lock->oh.data = req->a_owner;
 	lock->oh.len  = snprintf(req->a_owner, sizeof(req->a_owner), "%u@%s",
 				(unsigned int)fl->fl_u.nfs_fl.owner->pid,
-				utsname()->nodename);
+				nodename);
 	lock->svid = fl->fl_u.nfs_fl.owner->pid;
 	lock->fl.fl_start = fl->fl_start;
 	lock->fl.fl_end = fl->fl_end;
-- 
1.8.3.1