2009-01-08 20:37:00

by J. Bruce Fields

[permalink] [raw]
Subject: nfs client lockdep warning

I'm seeing this on my test client; I haven't tried to investigate.

--b.

Jan 8 15:29:17 ying3 kernel: =======================================================
Jan 8 15:29:17 ying3 kernel: [ INFO: possible circular locking dependency detected ]
Jan 8 15:29:17 ying3 kernel: 2.6.28-07532-g393a64e #71
Jan 8 15:29:17 ying3 kernel: -------------------------------------------------------
Jan 8 15:29:17 ying3 kernel: tlocklfs/3527 is trying to acquire lock:
Jan 8 15:29:17 ying3 kernel: (sk_lock-AF_INET-RPC){--..}, at: [<c076609c>] tcp_sendmsg+0x1c/0xa80
Jan 8 15:29:17 ying3 kernel:
Jan 8 15:29:17 ying3 kernel: but task is already holding lock:
Jan 8 15:29:17 ying3 kernel: (&mm->mmap_sem){----}, at: [<c0835fb7>] do_page_fault+0xc7/0x820
Jan 8 15:29:17 ying3 kernel:
Jan 8 15:29:17 ying3 kernel: which lock already depends on the new lock.
Jan 8 15:29:17 ying3 kernel:
Jan 8 15:29:17 ying3 kernel:
Jan 8 15:29:17 ying3 kernel: the existing dependency chain (in reverse order) is:
Jan 8 15:29:17 ying3 kernel:
Jan 8 15:29:17 ying3 kernel: -> #1 (&mm->mmap_sem){----}:
Jan 8 15:29:17 ying3 kernel: [<c024900d>] __lock_acquire+0xfcd/0x18e0
Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
Jan 8 15:29:17 ying3 kernel: [<c027dffb>] might_fault+0x7b/0xa0
Jan 8 15:29:17 ying3 kernel: [<c054bb26>] copy_from_user+0x36/0x90
Jan 8 15:29:17 ying3 kernel: [<c0737800>] memcpy_fromiovecend+0x60/0x90
Jan 8 15:29:17 ying3 kernel: [<c075ce9f>] ip_generic_getfrag+0x9f/0xb0
Jan 8 15:29:17 ying3 kernel: [<c075cb6b>] ip_append_data+0x6bb/0x950
Jan 8 15:29:17 ying3 kernel: [<c077cb0d>] udp_sendmsg+0x2bd/0x680
Jan 8 15:29:17 ying3 kernel: [<c07835f9>] inet_sendmsg+0x39/0x70
Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
Jan 8 15:29:17 ying3 kernel: [<c07dab30>] xs_udp_send_request+0x40/0x120
Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
Jan 8 15:29:17 ying3 kernel: [<c07d7860>] rpc_call_sync+0x40/0x70
Jan 8 15:29:17 ying3 kernel: [<c07e5312>] rpcb_register_call+0xa2/0xd0
Jan 8 15:29:17 ying3 kernel: [<c07e53d2>] rpcb_register+0x92/0xe0
Jan 8 15:29:17 ying3 kernel: [<c07e0446>] svc_unregister+0x66/0xe0
Jan 8 15:29:17 ying3 kernel: [<c07e0c66>] __svc_create+0x1c6/0x1f0
Jan 8 15:29:17 ying3 kernel: [<c07e0e13>] svc_create+0x23/0x30
Jan 8 15:29:17 ying3 kernel: [<c0396293>] nfs_callback_up+0x73/0x1b0
Jan 8 15:29:17 ying3 kernel: [<c036bb95>] nfs_get_client+0x2d5/0x410
Jan 8 15:29:17 ying3 kernel: [<c036bd15>] nfs4_set_client+0x45/0x1e0
Jan 8 15:29:17 ying3 kernel: [<c036c57e>] nfs4_create_server+0xae/0x430
Jan 8 15:29:17 ying3 kernel: [<c0376fda>] nfs4_get_sb+0x34a/0x5d0
Jan 8 15:29:17 ying3 kernel: [<c029663e>] vfs_kern_mount+0x5e/0x130
Jan 8 15:29:17 ying3 kernel: [<c029676e>] do_kern_mount+0x3e/0xe0
Jan 8 15:29:17 ying3 kernel: [<c02aca44>] do_mount+0x434/0x7b0
Jan 8 15:29:17 ying3 kernel: [<c02ace51>] sys_mount+0x91/0xc0
Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
Jan 8 15:29:17 ying3 kernel: [<ffffffff>] 0xffffffff
Jan 8 15:29:17 ying3 kernel:
Jan 8 15:29:17 ying3 kernel: -> #0 (sk_lock-AF_INET-RPC){--..}:
Jan 8 15:29:17 ying3 kernel: [<c024923d>] __lock_acquire+0x11fd/0x18e0
Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
Jan 8 15:29:17 ying3 kernel: [<c0731574>] lock_sock_nested+0xc4/0xe0
Jan 8 15:29:17 ying3 kernel: [<c076609c>] tcp_sendmsg+0x1c/0xa80
Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
Jan 8 15:29:17 ying3 kernel: [<c07da9d8>] xs_tcp_send_request+0x58/0x170
Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
Jan 8 15:29:17 ying3 kernel: [<c037c924>] nfs_read_rpcsetup+0x174/0x1f0
Jan 8 15:29:17 ying3 kernel: [<c037ce8e>] nfs_pagein_one+0x9e/0xe0
Jan 8 15:29:17 ying3 kernel: [<c037a73a>] nfs_pageio_doio+0x3a/0x80
Jan 8 15:29:17 ying3 kernel: [<c037a78d>] nfs_pageio_complete+0xd/0x10
Jan 8 15:29:17 ying3 kernel: [<c037c21c>] nfs_readpages+0xec/0x1d0
Jan 8 15:29:17 ying3 kernel: [<c02735cc>] __do_page_cache_readahead+0x1bc/0x280
Jan 8 15:29:17 ying3 kernel: [<c02736e0>] do_page_cache_readahead+0x50/0x70
Jan 8 15:29:17 ying3 kernel: [<c026b82f>] filemap_fault+0x31f/0x470
Jan 8 15:29:17 ying3 kernel: [<c027e370>] __do_fault+0x40/0x3d0
Jan 8 15:29:17 ying3 kernel: [<c027ff91>] handle_mm_fault+0x111/0x610
Jan 8 15:29:17 ying3 kernel: [<c0836105>] do_page_fault+0x215/0x820
Jan 8 15:29:17 ying3 kernel: [<c0834347>] error_code+0x6f/0x74
Jan 8 15:29:17 ying3 kernel: [<c02caff5>] load_elf_binary+0x8e5/0x1a20
Jan 8 15:29:17 ying3 kernel: [<c02990a3>] search_binary_handler+0x173/0x2f0
Jan 8 15:29:17 ying3 kernel: [<c029a31d>] do_execve+0x1cd/0x220
Jan 8 15:29:17 ying3 kernel: [<c0201793>] sys_execve+0x43/0x70
Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
Jan 8 15:29:17 ying3 kernel: [<ffffffff>] 0xffffffff
Jan 8 15:29:17 ying3 kernel:
Jan 8 15:29:17 ying3 kernel: other info that might help us debug this:
Jan 8 15:29:17 ying3 kernel:
Jan 8 15:29:17 ying3 kernel: 2 locks held by tlocklfs/3527:
Jan 8 15:29:17 ying3 kernel: #0: (&p->cred_exec_mutex){--..}, at: [<c029a1bb>] do_execve+0x6b/0x220
Jan 8 15:29:17 ying3 kernel: #1: (&mm->mmap_sem){----}, at: [<c0835fb7>] do_page_fault+0xc7/0x820
Jan 8 15:29:17 ying3 kernel:
Jan 8 15:29:17 ying3 kernel: stack backtrace:
Jan 8 15:29:17 ying3 kernel: Pid: 3527, comm: tlocklfs Not tainted 2.6.28-07532-g393a64e #71
Jan 8 15:29:17 ying3 kernel: Call Trace:
Jan 8 15:29:17 ying3 kernel: [<c083091a>] ? printk+0x1d/0x1f
Jan 8 15:29:17 ying3 kernel: [<c0247c18>] print_circular_bug_tail+0xc8/0xd0
Jan 8 15:29:17 ying3 kernel: [<c024923d>] __lock_acquire+0x11fd/0x18e0
Jan 8 15:29:17 ying3 kernel: [<c07314dc>] ? lock_sock_nested+0x2c/0xe0
Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
Jan 8 15:29:17 ying3 kernel: [<c076609c>] ? tcp_sendmsg+0x1c/0xa80
Jan 8 15:29:17 ying3 kernel: [<c0731574>] lock_sock_nested+0xc4/0xe0
Jan 8 15:29:17 ying3 kernel: [<c076609c>] ? tcp_sendmsg+0x1c/0xa80
Jan 8 15:29:17 ying3 kernel: [<c0270934>] ? free_hot_cold_page+0x174/0x2a0
Jan 8 15:29:17 ying3 kernel: [<c076609c>] tcp_sendmsg+0x1c/0xa80
Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
Jan 8 15:29:17 ying3 kernel: [<c0270b86>] ? free_pages+0x46/0x50
Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
Jan 8 15:29:17 ying3 kernel: [<c0239280>] ? autoremove_wake_function+0x0/0x50
Jan 8 15:29:17 ying3 kernel: [<c0248ea0>] ? __lock_acquire+0xe60/0x18e0
Jan 8 15:29:17 ying3 kernel: [<c0248ea0>] ? __lock_acquire+0xe60/0x18e0
Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
Jan 8 15:29:17 ying3 kernel: [<c055020f>] ? debug_object_deactivate+0xbf/0x100
Jan 8 15:29:17 ying3 kernel: [<c07da9d8>] xs_tcp_send_request+0x58/0x170
Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
Jan 8 15:29:17 ying3 kernel: [<c0392760>] ? nfs4_xdr_enc_read+0x0/0x110
Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
Jan 8 15:29:17 ying3 kernel: [<c07dd297>] ? rpc_set_active+0x67/0x80
Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
Jan 8 15:29:17 ying3 kernel: [<c037c924>] nfs_read_rpcsetup+0x174/0x1f0
Jan 8 15:29:17 ying3 kernel: [<c0290b61>] ? kmem_cache_alloc+0xd1/0x140
Jan 8 15:29:17 ying3 kernel: [<c026d583>] ? mempool_alloc_slab+0x13/0x20
Jan 8 15:29:17 ying3 last message repeated 2 times
Jan 8 15:29:17 ying3 kernel: [<c037ce8e>] nfs_pagein_one+0x9e/0xe0
Jan 8 15:29:17 ying3 kernel: [<c037a73a>] nfs_pageio_doio+0x3a/0x80
Jan 8 15:29:17 ying3 kernel: [<c037a78d>] nfs_pageio_complete+0xd/0x10
Jan 8 15:29:17 ying3 kernel: [<c037c21c>] nfs_readpages+0xec/0x1d0
Jan 8 15:29:17 ying3 kernel: [<c02711c3>] ? __alloc_pages_internal+0xc3/0x4d0
Jan 8 15:29:17 ying3 kernel: [<c037cdf0>] ? nfs_pagein_one+0x0/0xe0
Jan 8 15:29:17 ying3 kernel: [<c037c130>] ? nfs_readpages+0x0/0x1d0
Jan 8 15:29:17 ying3 kernel: [<c02735cc>] __do_page_cache_readahead+0x1bc/0x280
Jan 8 15:29:17 ying3 kernel: [<c02734d5>] ? __do_page_cache_readahead+0xc5/0x280
Jan 8 15:29:17 ying3 kernel: [<c02736e0>] do_page_cache_readahead+0x50/0x70
Jan 8 15:29:17 ying3 kernel: [<c026b82f>] filemap_fault+0x31f/0x470
Jan 8 15:29:17 ying3 kernel: [<c027e370>] __do_fault+0x40/0x3d0
Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
Jan 8 15:29:17 ying3 kernel: [<c027ff91>] handle_mm_fault+0x111/0x610
Jan 8 15:29:17 ying3 kernel: [<c0835fb7>] ? do_page_fault+0xc7/0x820
Jan 8 15:29:17 ying3 kernel: [<c023cd8d>] ? down_read_trylock+0x5d/0x70
Jan 8 15:29:17 ying3 kernel: [<c0836105>] do_page_fault+0x215/0x820
Jan 8 15:29:17 ying3 kernel: [<c0546741>] ? prio_tree_insert+0x211/0x290
Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
Jan 8 15:29:17 ying3 kernel: [<c0283a52>] ? vma_link+0x82/0xa0
Jan 8 15:29:17 ying3 kernel: [<c0284fd2>] ? mmap_region+0x2d2/0x4f0
Jan 8 15:29:17 ying3 kernel: [<c027dfca>] ? might_fault+0x4a/0xa0
Jan 8 15:29:17 ying3 kernel: [<c0835ef0>] ? do_page_fault+0x0/0x820
Jan 8 15:29:17 ying3 kernel: [<c0834347>] error_code+0x6f/0x74
Jan 8 15:29:17 ying3 kernel: [<c027007b>] ? __free_pages_ok+0x27b/0x480
Jan 8 15:29:17 ying3 kernel: [<c054b9b7>] ? clear_user+0x47/0x60
Jan 8 15:29:17 ying3 kernel: [<c02caff5>] load_elf_binary+0x8e5/0x1a20
Jan 8 15:29:17 ying3 kernel: [<c0247411>] ? mark_held_locks+0x41/0x80
Jan 8 15:29:17 ying3 kernel: [<c0833a55>] ? _spin_unlock_irqrestore+0x55/0x70
Jan 8 15:29:17 ying3 kernel: [<c0247651>] ? trace_hardirqs_on_caller+0x141/0x1a0
Jan 8 15:29:17 ying3 kernel: [<c0298f8f>] ? search_binary_handler+0x5f/0x2f0
Jan 8 15:29:17 ying3 kernel: [<c02990a3>] search_binary_handler+0x173/0x2f0
Jan 8 15:29:17 ying3 kernel: [<c02ca710>] ? load_elf_binary+0x0/0x1a20
Jan 8 15:29:17 ying3 kernel: [<c029a31d>] do_execve+0x1cd/0x220
Jan 8 15:29:17 ying3 kernel: [<c0201793>] sys_execve+0x43/0x70
Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
Jan 8 15:29:26 ying3 kernel: tlocklfs used greatest stack depth: 4252 bytes left
Jan 8 15:29:55 ying3 kernel: aoe: 00188b809a6e e2.3 v400f has 2048000 sectors
Jan 8 15:29:55 ying3 kernel: etherd/e2.3: unknown partition table


2009-01-12 12:02:11

by Peter Zijlstra

[permalink] [raw]
Subject: Re: nfs client lockdep warning

On Fri, 2009-01-09 at 15:29 -0500, J. Bruce Fields wrote:

> > > > Is there anything pinning that user-space page, if not its free to
> > > > fault, which would mean its a real warning...
> > >
> > > It's kernel memory, not user memory. See xs_udp_send_request in
> > > net/sunrpc.

> > ---
> > diff --git a/mm/memory.c b/mm/memory.c
> > index 7b9db65..a2ed52e 100644
> > --- a/mm/memory.c
> > +++ b/mm/memory.c
> > @@ -3079,6 +3079,9 @@ void print_vma_addr(char *prefix, unsigned long ip)
> > #ifdef CONFIG_PROVE_LOCKING
> > void might_fault(void)
> > {
> > + if (get_fs() == KERNEL_DS)
>
> Looks like that should be
>
> if ((segment_eq(get_fs(), KERNEL_DS))
>
> ? Anyway, with that, sure, that eliminates the lockdep warning.

Right, thanks!

---
Subject: lockdep,mm: fix might_fault() annotation

Some code (nfs/sunrpc) uses socket ops on kernel memory while holding
the mmap_sem, this is safe because kernel memory doesn't get paged out,
therefore we'll never actually fault, and the might_fault() annotations
will generate false positives.

Signed-off-by: Peter Zijlstra <[email protected]>
---
mm/memory.c | 9 +++++++++
1 files changed, 9 insertions(+), 0 deletions(-)

diff --git a/mm/memory.c b/mm/memory.c
index e009ce8..c2d4c47 100644
--- a/mm/memory.c
+++ b/mm/memory.c
@@ -3165,6 +3165,15 @@ void print_vma_addr(char *prefix, unsigned long ip)
#ifdef CONFIG_PROVE_LOCKING
void might_fault(void)
{
+ /*
+ * Some code (nfs/sunrpc) uses socket ops on kernel memory while
+ * holding the mmap_sem, this is safe because kernel memory doesn't
+ * get paged out, therefore we'll never actually fault, and the
+ * below annotations will generate false positives.
+ */
+ if (segment_eq(get_fs(), KERNEL_DS))
+ return;
+
might_sleep();
/*
* it would be nicer only to annotate paths which are not under



2009-01-12 12:11:03

by Ingo Molnar

[permalink] [raw]
Subject: Re: nfs client lockdep warning


* Peter Zijlstra <[email protected]> wrote:

> Subject: lockdep,mm: fix might_fault() annotation
>
> Some code (nfs/sunrpc) uses socket ops on kernel memory while holding
> the mmap_sem, this is safe because kernel memory doesn't get paged out,
> therefore we'll never actually fault, and the might_fault() annotations
> will generate false positives.
>
> Signed-off-by: Peter Zijlstra <[email protected]>

applied to tip/core/urgent, thanks guys!

I also added a:

Reported-by: "J. Bruce Fields" <[email protected]>

line as we always want to preserve the chain of bug reports and attribute
them.

Ingo

2009-01-08 20:49:16

by Myklebust, Trond

[permalink] [raw]
Subject: Re: nfs client lockdep warning

Looks more like one for the networking folks. All this appears to be
going on deep down in the tcp stack...

Trond


On Thu, 2009-01-08 at 15:36 -0500, J. Bruce Fields wrote:
> I'm seeing this on my test client; I haven't tried to investigate.
>
> --b.
>
> Jan 8 15:29:17 ying3 kernel: =======================================================
> Jan 8 15:29:17 ying3 kernel: [ INFO: possible circular locking dependency detected ]
> Jan 8 15:29:17 ying3 kernel: 2.6.28-07532-g393a64e #71
> Jan 8 15:29:17 ying3 kernel: -------------------------------------------------------
> Jan 8 15:29:17 ying3 kernel: tlocklfs/3527 is trying to acquire lock:
> Jan 8 15:29:17 ying3 kernel: (sk_lock-AF_INET-RPC){--..}, at: [<c076609c>] tcp_sendmsg+0x1c/0xa80
> Jan 8 15:29:17 ying3 kernel:
> Jan 8 15:29:17 ying3 kernel: but task is already holding lock:
> Jan 8 15:29:17 ying3 kernel: (&mm->mmap_sem){----}, at: [<c0835fb7>] do_page_fault+0xc7/0x820
> Jan 8 15:29:17 ying3 kernel:
> Jan 8 15:29:17 ying3 kernel: which lock already depends on the new lock.
> Jan 8 15:29:17 ying3 kernel:
> Jan 8 15:29:17 ying3 kernel:
> Jan 8 15:29:17 ying3 kernel: the existing dependency chain (in reverse order) is:
> Jan 8 15:29:17 ying3 kernel:
> Jan 8 15:29:17 ying3 kernel: -> #1 (&mm->mmap_sem){----}:
> Jan 8 15:29:17 ying3 kernel: [<c024900d>] __lock_acquire+0xfcd/0x18e0
> Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
> Jan 8 15:29:17 ying3 kernel: [<c027dffb>] might_fault+0x7b/0xa0
> Jan 8 15:29:17 ying3 kernel: [<c054bb26>] copy_from_user+0x36/0x90
> Jan 8 15:29:17 ying3 kernel: [<c0737800>] memcpy_fromiovecend+0x60/0x90
> Jan 8 15:29:17 ying3 kernel: [<c075ce9f>] ip_generic_getfrag+0x9f/0xb0
> Jan 8 15:29:17 ying3 kernel: [<c075cb6b>] ip_append_data+0x6bb/0x950
> Jan 8 15:29:17 ying3 kernel: [<c077cb0d>] udp_sendmsg+0x2bd/0x680
> Jan 8 15:29:17 ying3 kernel: [<c07835f9>] inet_sendmsg+0x39/0x70
> Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> Jan 8 15:29:17 ying3 kernel: [<c07dab30>] xs_udp_send_request+0x40/0x120
> Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
> Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
> Jan 8 15:29:17 ying3 kernel: [<c07d7860>] rpc_call_sync+0x40/0x70
> Jan 8 15:29:17 ying3 kernel: [<c07e5312>] rpcb_register_call+0xa2/0xd0
> Jan 8 15:29:17 ying3 kernel: [<c07e53d2>] rpcb_register+0x92/0xe0
> Jan 8 15:29:17 ying3 kernel: [<c07e0446>] svc_unregister+0x66/0xe0
> Jan 8 15:29:17 ying3 kernel: [<c07e0c66>] __svc_create+0x1c6/0x1f0
> Jan 8 15:29:17 ying3 kernel: [<c07e0e13>] svc_create+0x23/0x30
> Jan 8 15:29:17 ying3 kernel: [<c0396293>] nfs_callback_up+0x73/0x1b0
> Jan 8 15:29:17 ying3 kernel: [<c036bb95>] nfs_get_client+0x2d5/0x410
> Jan 8 15:29:17 ying3 kernel: [<c036bd15>] nfs4_set_client+0x45/0x1e0
> Jan 8 15:29:17 ying3 kernel: [<c036c57e>] nfs4_create_server+0xae/0x430
> Jan 8 15:29:17 ying3 kernel: [<c0376fda>] nfs4_get_sb+0x34a/0x5d0
> Jan 8 15:29:17 ying3 kernel: [<c029663e>] vfs_kern_mount+0x5e/0x130
> Jan 8 15:29:17 ying3 kernel: [<c029676e>] do_kern_mount+0x3e/0xe0
> Jan 8 15:29:17 ying3 kernel: [<c02aca44>] do_mount+0x434/0x7b0
> Jan 8 15:29:17 ying3 kernel: [<c02ace51>] sys_mount+0x91/0xc0
> Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
> Jan 8 15:29:17 ying3 kernel: [<ffffffff>] 0xffffffff
> Jan 8 15:29:17 ying3 kernel:
> Jan 8 15:29:17 ying3 kernel: -> #0 (sk_lock-AF_INET-RPC){--..}:
> Jan 8 15:29:17 ying3 kernel: [<c024923d>] __lock_acquire+0x11fd/0x18e0
> Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
> Jan 8 15:29:17 ying3 kernel: [<c0731574>] lock_sock_nested+0xc4/0xe0
> Jan 8 15:29:17 ying3 kernel: [<c076609c>] tcp_sendmsg+0x1c/0xa80
> Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> Jan 8 15:29:17 ying3 kernel: [<c07da9d8>] xs_tcp_send_request+0x58/0x170
> Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
> Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
> Jan 8 15:29:17 ying3 kernel: [<c037c924>] nfs_read_rpcsetup+0x174/0x1f0
> Jan 8 15:29:17 ying3 kernel: [<c037ce8e>] nfs_pagein_one+0x9e/0xe0
> Jan 8 15:29:17 ying3 kernel: [<c037a73a>] nfs_pageio_doio+0x3a/0x80
> Jan 8 15:29:17 ying3 kernel: [<c037a78d>] nfs_pageio_complete+0xd/0x10
> Jan 8 15:29:17 ying3 kernel: [<c037c21c>] nfs_readpages+0xec/0x1d0
> Jan 8 15:29:17 ying3 kernel: [<c02735cc>] __do_page_cache_readahead+0x1bc/0x280
> Jan 8 15:29:17 ying3 kernel: [<c02736e0>] do_page_cache_readahead+0x50/0x70
> Jan 8 15:29:17 ying3 kernel: [<c026b82f>] filemap_fault+0x31f/0x470
> Jan 8 15:29:17 ying3 kernel: [<c027e370>] __do_fault+0x40/0x3d0
> Jan 8 15:29:17 ying3 kernel: [<c027ff91>] handle_mm_fault+0x111/0x610
> Jan 8 15:29:17 ying3 kernel: [<c0836105>] do_page_fault+0x215/0x820
> Jan 8 15:29:17 ying3 kernel: [<c0834347>] error_code+0x6f/0x74
> Jan 8 15:29:17 ying3 kernel: [<c02caff5>] load_elf_binary+0x8e5/0x1a20
> Jan 8 15:29:17 ying3 kernel: [<c02990a3>] search_binary_handler+0x173/0x2f0
> Jan 8 15:29:17 ying3 kernel: [<c029a31d>] do_execve+0x1cd/0x220
> Jan 8 15:29:17 ying3 kernel: [<c0201793>] sys_execve+0x43/0x70
> Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
> Jan 8 15:29:17 ying3 kernel: [<ffffffff>] 0xffffffff
> Jan 8 15:29:17 ying3 kernel:
> Jan 8 15:29:17 ying3 kernel: other info that might help us debug this:
> Jan 8 15:29:17 ying3 kernel:
> Jan 8 15:29:17 ying3 kernel: 2 locks held by tlocklfs/3527:
> Jan 8 15:29:17 ying3 kernel: #0: (&p->cred_exec_mutex){--..}, at: [<c029a1bb>] do_execve+0x6b/0x220
> Jan 8 15:29:17 ying3 kernel: #1: (&mm->mmap_sem){----}, at: [<c0835fb7>] do_page_fault+0xc7/0x820
> Jan 8 15:29:17 ying3 kernel:
> Jan 8 15:29:17 ying3 kernel: stack backtrace:
> Jan 8 15:29:17 ying3 kernel: Pid: 3527, comm: tlocklfs Not tainted 2.6.28-07532-g393a64e #71
> Jan 8 15:29:17 ying3 kernel: Call Trace:
> Jan 8 15:29:17 ying3 kernel: [<c083091a>] ? printk+0x1d/0x1f
> Jan 8 15:29:17 ying3 kernel: [<c0247c18>] print_circular_bug_tail+0xc8/0xd0
> Jan 8 15:29:17 ying3 kernel: [<c024923d>] __lock_acquire+0x11fd/0x18e0
> Jan 8 15:29:17 ying3 kernel: [<c07314dc>] ? lock_sock_nested+0x2c/0xe0
> Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
> Jan 8 15:29:17 ying3 kernel: [<c076609c>] ? tcp_sendmsg+0x1c/0xa80
> Jan 8 15:29:17 ying3 kernel: [<c0731574>] lock_sock_nested+0xc4/0xe0
> Jan 8 15:29:17 ying3 kernel: [<c076609c>] ? tcp_sendmsg+0x1c/0xa80
> Jan 8 15:29:17 ying3 kernel: [<c0270934>] ? free_hot_cold_page+0x174/0x2a0
> Jan 8 15:29:17 ying3 kernel: [<c076609c>] tcp_sendmsg+0x1c/0xa80
> Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
> Jan 8 15:29:17 ying3 kernel: [<c0270b86>] ? free_pages+0x46/0x50
> Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
> Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
> Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> Jan 8 15:29:17 ying3 kernel: [<c0239280>] ? autoremove_wake_function+0x0/0x50
> Jan 8 15:29:17 ying3 kernel: [<c0248ea0>] ? __lock_acquire+0xe60/0x18e0
> Jan 8 15:29:17 ying3 kernel: [<c0248ea0>] ? __lock_acquire+0xe60/0x18e0
> Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> Jan 8 15:29:17 ying3 kernel: [<c055020f>] ? debug_object_deactivate+0xbf/0x100
> Jan 8 15:29:17 ying3 kernel: [<c07da9d8>] xs_tcp_send_request+0x58/0x170
> Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> Jan 8 15:29:17 ying3 kernel: [<c0392760>] ? nfs4_xdr_enc_read+0x0/0x110
> Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
> Jan 8 15:29:17 ying3 kernel: [<c07dd297>] ? rpc_set_active+0x67/0x80
> Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
> Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
> Jan 8 15:29:17 ying3 kernel: [<c037c924>] nfs_read_rpcsetup+0x174/0x1f0
> Jan 8 15:29:17 ying3 kernel: [<c0290b61>] ? kmem_cache_alloc+0xd1/0x140
> Jan 8 15:29:17 ying3 kernel: [<c026d583>] ? mempool_alloc_slab+0x13/0x20
> Jan 8 15:29:17 ying3 last message repeated 2 times
> Jan 8 15:29:17 ying3 kernel: [<c037ce8e>] nfs_pagein_one+0x9e/0xe0
> Jan 8 15:29:17 ying3 kernel: [<c037a73a>] nfs_pageio_doio+0x3a/0x80
> Jan 8 15:29:17 ying3 kernel: [<c037a78d>] nfs_pageio_complete+0xd/0x10
> Jan 8 15:29:17 ying3 kernel: [<c037c21c>] nfs_readpages+0xec/0x1d0
> Jan 8 15:29:17 ying3 kernel: [<c02711c3>] ? __alloc_pages_internal+0xc3/0x4d0
> Jan 8 15:29:17 ying3 kernel: [<c037cdf0>] ? nfs_pagein_one+0x0/0xe0
> Jan 8 15:29:17 ying3 kernel: [<c037c130>] ? nfs_readpages+0x0/0x1d0
> Jan 8 15:29:17 ying3 kernel: [<c02735cc>] __do_page_cache_readahead+0x1bc/0x280
> Jan 8 15:29:17 ying3 kernel: [<c02734d5>] ? __do_page_cache_readahead+0xc5/0x280
> Jan 8 15:29:17 ying3 kernel: [<c02736e0>] do_page_cache_readahead+0x50/0x70
> Jan 8 15:29:17 ying3 kernel: [<c026b82f>] filemap_fault+0x31f/0x470
> Jan 8 15:29:17 ying3 kernel: [<c027e370>] __do_fault+0x40/0x3d0
> Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
> Jan 8 15:29:17 ying3 kernel: [<c027ff91>] handle_mm_fault+0x111/0x610
> Jan 8 15:29:17 ying3 kernel: [<c0835fb7>] ? do_page_fault+0xc7/0x820
> Jan 8 15:29:17 ying3 kernel: [<c023cd8d>] ? down_read_trylock+0x5d/0x70
> Jan 8 15:29:17 ying3 kernel: [<c0836105>] do_page_fault+0x215/0x820
> Jan 8 15:29:17 ying3 kernel: [<c0546741>] ? prio_tree_insert+0x211/0x290
> Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
> Jan 8 15:29:17 ying3 kernel: [<c0283a52>] ? vma_link+0x82/0xa0
> Jan 8 15:29:17 ying3 kernel: [<c0284fd2>] ? mmap_region+0x2d2/0x4f0
> Jan 8 15:29:17 ying3 kernel: [<c027dfca>] ? might_fault+0x4a/0xa0
> Jan 8 15:29:17 ying3 kernel: [<c0835ef0>] ? do_page_fault+0x0/0x820
> Jan 8 15:29:17 ying3 kernel: [<c0834347>] error_code+0x6f/0x74
> Jan 8 15:29:17 ying3 kernel: [<c027007b>] ? __free_pages_ok+0x27b/0x480
> Jan 8 15:29:17 ying3 kernel: [<c054b9b7>] ? clear_user+0x47/0x60
> Jan 8 15:29:17 ying3 kernel: [<c02caff5>] load_elf_binary+0x8e5/0x1a20
> Jan 8 15:29:17 ying3 kernel: [<c0247411>] ? mark_held_locks+0x41/0x80
> Jan 8 15:29:17 ying3 kernel: [<c0833a55>] ? _spin_unlock_irqrestore+0x55/0x70
> Jan 8 15:29:17 ying3 kernel: [<c0247651>] ? trace_hardirqs_on_caller+0x141/0x1a0
> Jan 8 15:29:17 ying3 kernel: [<c0298f8f>] ? search_binary_handler+0x5f/0x2f0
> Jan 8 15:29:17 ying3 kernel: [<c02990a3>] search_binary_handler+0x173/0x2f0
> Jan 8 15:29:17 ying3 kernel: [<c02ca710>] ? load_elf_binary+0x0/0x1a20
> Jan 8 15:29:17 ying3 kernel: [<c029a31d>] do_execve+0x1cd/0x220
> Jan 8 15:29:17 ying3 kernel: [<c0201793>] sys_execve+0x43/0x70
> Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
> Jan 8 15:29:26 ying3 kernel: tlocklfs used greatest stack depth: 4252 bytes left
> Jan 8 15:29:55 ying3 kernel: aoe: 00188b809a6e e2.3 v400f has 2048000 sectors
> Jan 8 15:29:55 ying3 kernel: etherd/e2.3: unknown partition table
--
Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
http://www.netapp.com

2009-01-08 21:20:58

by J. Bruce Fields

[permalink] [raw]
Subject: Re: nfs client lockdep warning

Is this something known?

--b.

On Thu, Jan 08, 2009 at 03:48:27PM -0500, Trond Myklebust wrote:
> Looks more like one for the networking folks. All this appears to be
> going on deep down in the tcp stack...
>
> Trond
>
>
> On Thu, 2009-01-08 at 15:36 -0500, J. Bruce Fields wrote:
> > I'm seeing this on my test client; I haven't tried to investigate.
> >
> > --b.
> >
> > Jan 8 15:29:17 ying3 kernel: =======================================================
> > Jan 8 15:29:17 ying3 kernel: [ INFO: possible circular locking dependency detected ]
> > Jan 8 15:29:17 ying3 kernel: 2.6.28-07532-g393a64e #71
> > Jan 8 15:29:17 ying3 kernel: -------------------------------------------------------
> > Jan 8 15:29:17 ying3 kernel: tlocklfs/3527 is trying to acquire lock:
> > Jan 8 15:29:17 ying3 kernel: (sk_lock-AF_INET-RPC){--..}, at: [<c076609c>] tcp_sendmsg+0x1c/0xa80
> > Jan 8 15:29:17 ying3 kernel:
> > Jan 8 15:29:17 ying3 kernel: but task is already holding lock:
> > Jan 8 15:29:17 ying3 kernel: (&mm->mmap_sem){----}, at: [<c0835fb7>] do_page_fault+0xc7/0x820
> > Jan 8 15:29:17 ying3 kernel:
> > Jan 8 15:29:17 ying3 kernel: which lock already depends on the new lock.
> > Jan 8 15:29:17 ying3 kernel:
> > Jan 8 15:29:17 ying3 kernel:
> > Jan 8 15:29:17 ying3 kernel: the existing dependency chain (in reverse order) is:
> > Jan 8 15:29:17 ying3 kernel:
> > Jan 8 15:29:17 ying3 kernel: -> #1 (&mm->mmap_sem){----}:
> > Jan 8 15:29:17 ying3 kernel: [<c024900d>] __lock_acquire+0xfcd/0x18e0
> > Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
> > Jan 8 15:29:17 ying3 kernel: [<c027dffb>] might_fault+0x7b/0xa0
> > Jan 8 15:29:17 ying3 kernel: [<c054bb26>] copy_from_user+0x36/0x90
> > Jan 8 15:29:17 ying3 kernel: [<c0737800>] memcpy_fromiovecend+0x60/0x90
> > Jan 8 15:29:17 ying3 kernel: [<c075ce9f>] ip_generic_getfrag+0x9f/0xb0
> > Jan 8 15:29:17 ying3 kernel: [<c075cb6b>] ip_append_data+0x6bb/0x950
> > Jan 8 15:29:17 ying3 kernel: [<c077cb0d>] udp_sendmsg+0x2bd/0x680
> > Jan 8 15:29:17 ying3 kernel: [<c07835f9>] inet_sendmsg+0x39/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> > Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> > Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> > Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> > Jan 8 15:29:17 ying3 kernel: [<c07dab30>] xs_udp_send_request+0x40/0x120
> > Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> > Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> > Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> > Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
> > Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c07d7860>] rpc_call_sync+0x40/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c07e5312>] rpcb_register_call+0xa2/0xd0
> > Jan 8 15:29:17 ying3 kernel: [<c07e53d2>] rpcb_register+0x92/0xe0
> > Jan 8 15:29:17 ying3 kernel: [<c07e0446>] svc_unregister+0x66/0xe0
> > Jan 8 15:29:17 ying3 kernel: [<c07e0c66>] __svc_create+0x1c6/0x1f0
> > Jan 8 15:29:17 ying3 kernel: [<c07e0e13>] svc_create+0x23/0x30
> > Jan 8 15:29:17 ying3 kernel: [<c0396293>] nfs_callback_up+0x73/0x1b0
> > Jan 8 15:29:17 ying3 kernel: [<c036bb95>] nfs_get_client+0x2d5/0x410
> > Jan 8 15:29:17 ying3 kernel: [<c036bd15>] nfs4_set_client+0x45/0x1e0
> > Jan 8 15:29:17 ying3 kernel: [<c036c57e>] nfs4_create_server+0xae/0x430
> > Jan 8 15:29:17 ying3 kernel: [<c0376fda>] nfs4_get_sb+0x34a/0x5d0
> > Jan 8 15:29:17 ying3 kernel: [<c029663e>] vfs_kern_mount+0x5e/0x130
> > Jan 8 15:29:17 ying3 kernel: [<c029676e>] do_kern_mount+0x3e/0xe0
> > Jan 8 15:29:17 ying3 kernel: [<c02aca44>] do_mount+0x434/0x7b0
> > Jan 8 15:29:17 ying3 kernel: [<c02ace51>] sys_mount+0x91/0xc0
> > Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
> > Jan 8 15:29:17 ying3 kernel: [<ffffffff>] 0xffffffff
> > Jan 8 15:29:17 ying3 kernel:
> > Jan 8 15:29:17 ying3 kernel: -> #0 (sk_lock-AF_INET-RPC){--..}:
> > Jan 8 15:29:17 ying3 kernel: [<c024923d>] __lock_acquire+0x11fd/0x18e0
> > Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
> > Jan 8 15:29:17 ying3 kernel: [<c0731574>] lock_sock_nested+0xc4/0xe0
> > Jan 8 15:29:17 ying3 kernel: [<c076609c>] tcp_sendmsg+0x1c/0xa80
> > Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> > Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> > Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> > Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> > Jan 8 15:29:17 ying3 kernel: [<c07da9d8>] xs_tcp_send_request+0x58/0x170
> > Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> > Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> > Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> > Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
> > Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c037c924>] nfs_read_rpcsetup+0x174/0x1f0
> > Jan 8 15:29:17 ying3 kernel: [<c037ce8e>] nfs_pagein_one+0x9e/0xe0
> > Jan 8 15:29:17 ying3 kernel: [<c037a73a>] nfs_pageio_doio+0x3a/0x80
> > Jan 8 15:29:17 ying3 kernel: [<c037a78d>] nfs_pageio_complete+0xd/0x10
> > Jan 8 15:29:17 ying3 kernel: [<c037c21c>] nfs_readpages+0xec/0x1d0
> > Jan 8 15:29:17 ying3 kernel: [<c02735cc>] __do_page_cache_readahead+0x1bc/0x280
> > Jan 8 15:29:17 ying3 kernel: [<c02736e0>] do_page_cache_readahead+0x50/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c026b82f>] filemap_fault+0x31f/0x470
> > Jan 8 15:29:17 ying3 kernel: [<c027e370>] __do_fault+0x40/0x3d0
> > Jan 8 15:29:17 ying3 kernel: [<c027ff91>] handle_mm_fault+0x111/0x610
> > Jan 8 15:29:17 ying3 kernel: [<c0836105>] do_page_fault+0x215/0x820
> > Jan 8 15:29:17 ying3 kernel: [<c0834347>] error_code+0x6f/0x74
> > Jan 8 15:29:17 ying3 kernel: [<c02caff5>] load_elf_binary+0x8e5/0x1a20
> > Jan 8 15:29:17 ying3 kernel: [<c02990a3>] search_binary_handler+0x173/0x2f0
> > Jan 8 15:29:17 ying3 kernel: [<c029a31d>] do_execve+0x1cd/0x220
> > Jan 8 15:29:17 ying3 kernel: [<c0201793>] sys_execve+0x43/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
> > Jan 8 15:29:17 ying3 kernel: [<ffffffff>] 0xffffffff
> > Jan 8 15:29:17 ying3 kernel:
> > Jan 8 15:29:17 ying3 kernel: other info that might help us debug this:
> > Jan 8 15:29:17 ying3 kernel:
> > Jan 8 15:29:17 ying3 kernel: 2 locks held by tlocklfs/3527:
> > Jan 8 15:29:17 ying3 kernel: #0: (&p->cred_exec_mutex){--..}, at: [<c029a1bb>] do_execve+0x6b/0x220
> > Jan 8 15:29:17 ying3 kernel: #1: (&mm->mmap_sem){----}, at: [<c0835fb7>] do_page_fault+0xc7/0x820
> > Jan 8 15:29:17 ying3 kernel:
> > Jan 8 15:29:17 ying3 kernel: stack backtrace:
> > Jan 8 15:29:17 ying3 kernel: Pid: 3527, comm: tlocklfs Not tainted 2.6.28-07532-g393a64e #71
> > Jan 8 15:29:17 ying3 kernel: Call Trace:
> > Jan 8 15:29:17 ying3 kernel: [<c083091a>] ? printk+0x1d/0x1f
> > Jan 8 15:29:17 ying3 kernel: [<c0247c18>] print_circular_bug_tail+0xc8/0xd0
> > Jan 8 15:29:17 ying3 kernel: [<c024923d>] __lock_acquire+0x11fd/0x18e0
> > Jan 8 15:29:17 ying3 kernel: [<c07314dc>] ? lock_sock_nested+0x2c/0xe0
> > Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
> > Jan 8 15:29:17 ying3 kernel: [<c076609c>] ? tcp_sendmsg+0x1c/0xa80
> > Jan 8 15:29:17 ying3 kernel: [<c0731574>] lock_sock_nested+0xc4/0xe0
> > Jan 8 15:29:17 ying3 kernel: [<c076609c>] ? tcp_sendmsg+0x1c/0xa80
> > Jan 8 15:29:17 ying3 kernel: [<c0270934>] ? free_hot_cold_page+0x174/0x2a0
> > Jan 8 15:29:17 ying3 kernel: [<c076609c>] tcp_sendmsg+0x1c/0xa80
> > Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
> > Jan 8 15:29:17 ying3 kernel: [<c0270b86>] ? free_pages+0x46/0x50
> > Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
> > Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
> > Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> > Jan 8 15:29:17 ying3 kernel: [<c0239280>] ? autoremove_wake_function+0x0/0x50
> > Jan 8 15:29:17 ying3 kernel: [<c0248ea0>] ? __lock_acquire+0xe60/0x18e0
> > Jan 8 15:29:17 ying3 kernel: [<c0248ea0>] ? __lock_acquire+0xe60/0x18e0
> > Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> > Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> > Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> > Jan 8 15:29:17 ying3 kernel: [<c055020f>] ? debug_object_deactivate+0xbf/0x100
> > Jan 8 15:29:17 ying3 kernel: [<c07da9d8>] xs_tcp_send_request+0x58/0x170
> > Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> > Jan 8 15:29:17 ying3 kernel: [<c0392760>] ? nfs4_xdr_enc_read+0x0/0x110
> > Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> > Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> > Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
> > Jan 8 15:29:17 ying3 kernel: [<c07dd297>] ? rpc_set_active+0x67/0x80
> > Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
> > Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c037c924>] nfs_read_rpcsetup+0x174/0x1f0
> > Jan 8 15:29:17 ying3 kernel: [<c0290b61>] ? kmem_cache_alloc+0xd1/0x140
> > Jan 8 15:29:17 ying3 kernel: [<c026d583>] ? mempool_alloc_slab+0x13/0x20
> > Jan 8 15:29:17 ying3 last message repeated 2 times
> > Jan 8 15:29:17 ying3 kernel: [<c037ce8e>] nfs_pagein_one+0x9e/0xe0
> > Jan 8 15:29:17 ying3 kernel: [<c037a73a>] nfs_pageio_doio+0x3a/0x80
> > Jan 8 15:29:17 ying3 kernel: [<c037a78d>] nfs_pageio_complete+0xd/0x10
> > Jan 8 15:29:17 ying3 kernel: [<c037c21c>] nfs_readpages+0xec/0x1d0
> > Jan 8 15:29:17 ying3 kernel: [<c02711c3>] ? __alloc_pages_internal+0xc3/0x4d0
> > Jan 8 15:29:17 ying3 kernel: [<c037cdf0>] ? nfs_pagein_one+0x0/0xe0
> > Jan 8 15:29:17 ying3 kernel: [<c037c130>] ? nfs_readpages+0x0/0x1d0
> > Jan 8 15:29:17 ying3 kernel: [<c02735cc>] __do_page_cache_readahead+0x1bc/0x280
> > Jan 8 15:29:17 ying3 kernel: [<c02734d5>] ? __do_page_cache_readahead+0xc5/0x280
> > Jan 8 15:29:17 ying3 kernel: [<c02736e0>] do_page_cache_readahead+0x50/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c026b82f>] filemap_fault+0x31f/0x470
> > Jan 8 15:29:17 ying3 kernel: [<c027e370>] __do_fault+0x40/0x3d0
> > Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
> > Jan 8 15:29:17 ying3 kernel: [<c027ff91>] handle_mm_fault+0x111/0x610
> > Jan 8 15:29:17 ying3 kernel: [<c0835fb7>] ? do_page_fault+0xc7/0x820
> > Jan 8 15:29:17 ying3 kernel: [<c023cd8d>] ? down_read_trylock+0x5d/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c0836105>] do_page_fault+0x215/0x820
> > Jan 8 15:29:17 ying3 kernel: [<c0546741>] ? prio_tree_insert+0x211/0x290
> > Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
> > Jan 8 15:29:17 ying3 kernel: [<c0283a52>] ? vma_link+0x82/0xa0
> > Jan 8 15:29:17 ying3 kernel: [<c0284fd2>] ? mmap_region+0x2d2/0x4f0
> > Jan 8 15:29:17 ying3 kernel: [<c027dfca>] ? might_fault+0x4a/0xa0
> > Jan 8 15:29:17 ying3 kernel: [<c0835ef0>] ? do_page_fault+0x0/0x820
> > Jan 8 15:29:17 ying3 kernel: [<c0834347>] error_code+0x6f/0x74
> > Jan 8 15:29:17 ying3 kernel: [<c027007b>] ? __free_pages_ok+0x27b/0x480
> > Jan 8 15:29:17 ying3 kernel: [<c054b9b7>] ? clear_user+0x47/0x60
> > Jan 8 15:29:17 ying3 kernel: [<c02caff5>] load_elf_binary+0x8e5/0x1a20
> > Jan 8 15:29:17 ying3 kernel: [<c0247411>] ? mark_held_locks+0x41/0x80
> > Jan 8 15:29:17 ying3 kernel: [<c0833a55>] ? _spin_unlock_irqrestore+0x55/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c0247651>] ? trace_hardirqs_on_caller+0x141/0x1a0
> > Jan 8 15:29:17 ying3 kernel: [<c0298f8f>] ? search_binary_handler+0x5f/0x2f0
> > Jan 8 15:29:17 ying3 kernel: [<c02990a3>] search_binary_handler+0x173/0x2f0
> > Jan 8 15:29:17 ying3 kernel: [<c02ca710>] ? load_elf_binary+0x0/0x1a20
> > Jan 8 15:29:17 ying3 kernel: [<c029a31d>] do_execve+0x1cd/0x220
> > Jan 8 15:29:17 ying3 kernel: [<c0201793>] sys_execve+0x43/0x70
> > Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
> > Jan 8 15:29:26 ying3 kernel: tlocklfs used greatest stack depth: 4252 bytes left
> > Jan 8 15:29:55 ying3 kernel: aoe: 00188b809a6e e2.3 v400f has 2048000 sectors
> > Jan 8 15:29:55 ying3 kernel: etherd/e2.3: unknown partition table
> --
> Trond Myklebust
> Linux NFS client maintainer
>
> NetApp
> [email protected]
> http://www.netapp.com

2009-01-09 04:33:24

by Herbert Xu

[permalink] [raw]
Subject: Re: nfs client lockdep warning

On Thu, Jan 08, 2009 at 09:20:56PM +0000, J. Bruce Fields wrote:
>
> > > Jan 8 15:29:17 ying3 kernel: =======================================================
> > > Jan 8 15:29:17 ying3 kernel: [ INFO: possible circular locking dependency detected ]
> > > Jan 8 15:29:17 ying3 kernel: 2.6.28-07532-g393a64e #71
> > > Jan 8 15:29:17 ying3 kernel: -------------------------------------------------------
> > > Jan 8 15:29:17 ying3 kernel: tlocklfs/3527 is trying to acquire lock:
> > > Jan 8 15:29:17 ying3 kernel: (sk_lock-AF_INET-RPC){--..}, at: [<c076609c>] tcp_sendmsg+0x1c/0xa80
> > > Jan 8 15:29:17 ying3 kernel:
> > > Jan 8 15:29:17 ying3 kernel: but task is already holding lock:
> > > Jan 8 15:29:17 ying3 kernel: (&mm->mmap_sem){----}, at: [<c0835fb7>] do_page_fault+0xc7/0x820
> > > Jan 8 15:29:17 ying3 kernel:
> > > Jan 8 15:29:17 ying3 kernel: which lock already depends on the new lock.
> > > Jan 8 15:29:17 ying3 kernel:
> > > Jan 8 15:29:17 ying3 kernel:
> > > Jan 8 15:29:17 ying3 kernel: the existing dependency chain (in reverse order) is:
> > > Jan 8 15:29:17 ying3 kernel:
> > > Jan 8 15:29:17 ying3 kernel: -> #1 (&mm->mmap_sem){----}:
> > > Jan 8 15:29:17 ying3 kernel: [<c024900d>] __lock_acquire+0xfcd/0x18e0
> > > Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
> > > Jan 8 15:29:17 ying3 kernel: [<c027dffb>] might_fault+0x7b/0xa0

This is a false positive introduced by might_fault. As this is
a send request from the kernel, it should never fault.

> > > Jan 8 15:29:17 ying3 kernel: [<c054bb26>] copy_from_user+0x36/0x90
> > > Jan 8 15:29:17 ying3 kernel: [<c0737800>] memcpy_fromiovecend+0x60/0x90
> > > Jan 8 15:29:17 ying3 kernel: [<c075ce9f>] ip_generic_getfrag+0x9f/0xb0
> > > Jan 8 15:29:17 ying3 kernel: [<c075cb6b>] ip_append_data+0x6bb/0x950
> > > Jan 8 15:29:17 ying3 kernel: [<c077cb0d>] udp_sendmsg+0x2bd/0x680
> > > Jan 8 15:29:17 ying3 kernel: [<c07835f9>] inet_sendmsg+0x39/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> > > Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> > > Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> > > Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> > > Jan 8 15:29:17 ying3 kernel: [<c07dab30>] xs_udp_send_request+0x40/0x120
> > > Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> > > Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> > > Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> > > Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
> > > Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c07d7860>] rpc_call_sync+0x40/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c07e5312>] rpcb_register_call+0xa2/0xd0
> > > Jan 8 15:29:17 ying3 kernel: [<c07e53d2>] rpcb_register+0x92/0xe0
> > > Jan 8 15:29:17 ying3 kernel: [<c07e0446>] svc_unregister+0x66/0xe0
> > > Jan 8 15:29:17 ying3 kernel: [<c07e0c66>] __svc_create+0x1c6/0x1f0
> > > Jan 8 15:29:17 ying3 kernel: [<c07e0e13>] svc_create+0x23/0x30
> > > Jan 8 15:29:17 ying3 kernel: [<c0396293>] nfs_callback_up+0x73/0x1b0
> > > Jan 8 15:29:17 ying3 kernel: [<c036bb95>] nfs_get_client+0x2d5/0x410
> > > Jan 8 15:29:17 ying3 kernel: [<c036bd15>] nfs4_set_client+0x45/0x1e0
> > > Jan 8 15:29:17 ying3 kernel: [<c036c57e>] nfs4_create_server+0xae/0x430
> > > Jan 8 15:29:17 ying3 kernel: [<c0376fda>] nfs4_get_sb+0x34a/0x5d0
> > > Jan 8 15:29:17 ying3 kernel: [<c029663e>] vfs_kern_mount+0x5e/0x130
> > > Jan 8 15:29:17 ying3 kernel: [<c029676e>] do_kern_mount+0x3e/0xe0
> > > Jan 8 15:29:17 ying3 kernel: [<c02aca44>] do_mount+0x434/0x7b0
> > > Jan 8 15:29:17 ying3 kernel: [<c02ace51>] sys_mount+0x91/0xc0
> > > Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
> > > Jan 8 15:29:17 ying3 kernel: [<ffffffff>] 0xffffffff
> > > Jan 8 15:29:17 ying3 kernel:
> > > Jan 8 15:29:17 ying3 kernel: -> #0 (sk_lock-AF_INET-RPC){--..}:
> > > Jan 8 15:29:17 ying3 kernel: [<c024923d>] __lock_acquire+0x11fd/0x18e0
> > > Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
> > > Jan 8 15:29:17 ying3 kernel: [<c0731574>] lock_sock_nested+0xc4/0xe0
> > > Jan 8 15:29:17 ying3 kernel: [<c076609c>] tcp_sendmsg+0x1c/0xa80
> > > Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> > > Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> > > Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> > > Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> > > Jan 8 15:29:17 ying3 kernel: [<c07da9d8>] xs_tcp_send_request+0x58/0x170
> > > Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> > > Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> > > Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> > > Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
> > > Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c037c924>] nfs_read_rpcsetup+0x174/0x1f0
> > > Jan 8 15:29:17 ying3 kernel: [<c037ce8e>] nfs_pagein_one+0x9e/0xe0
> > > Jan 8 15:29:17 ying3 kernel: [<c037a73a>] nfs_pageio_doio+0x3a/0x80
> > > Jan 8 15:29:17 ying3 kernel: [<c037a78d>] nfs_pageio_complete+0xd/0x10
> > > Jan 8 15:29:17 ying3 kernel: [<c037c21c>] nfs_readpages+0xec/0x1d0
> > > Jan 8 15:29:17 ying3 kernel: [<c02735cc>] __do_page_cache_readahead+0x1bc/0x280
> > > Jan 8 15:29:17 ying3 kernel: [<c02736e0>] do_page_cache_readahead+0x50/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c026b82f>] filemap_fault+0x31f/0x470
> > > Jan 8 15:29:17 ying3 kernel: [<c027e370>] __do_fault+0x40/0x3d0
> > > Jan 8 15:29:17 ying3 kernel: [<c027ff91>] handle_mm_fault+0x111/0x610
> > > Jan 8 15:29:17 ying3 kernel: [<c0836105>] do_page_fault+0x215/0x820
> > > Jan 8 15:29:17 ying3 kernel: [<c0834347>] error_code+0x6f/0x74
> > > Jan 8 15:29:17 ying3 kernel: [<c02caff5>] load_elf_binary+0x8e5/0x1a20
> > > Jan 8 15:29:17 ying3 kernel: [<c02990a3>] search_binary_handler+0x173/0x2f0
> > > Jan 8 15:29:17 ying3 kernel: [<c029a31d>] do_execve+0x1cd/0x220
> > > Jan 8 15:29:17 ying3 kernel: [<c0201793>] sys_execve+0x43/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
> > > Jan 8 15:29:17 ying3 kernel: [<ffffffff>] 0xffffffff
> > > Jan 8 15:29:17 ying3 kernel:
> > > Jan 8 15:29:17 ying3 kernel: other info that might help us debug this:
> > > Jan 8 15:29:17 ying3 kernel:
> > > Jan 8 15:29:17 ying3 kernel: 2 locks held by tlocklfs/3527:
> > > Jan 8 15:29:17 ying3 kernel: #0: (&p->cred_exec_mutex){--..}, at: [<c029a1bb>] do_execve+0x6b/0x220
> > > Jan 8 15:29:17 ying3 kernel: #1: (&mm->mmap_sem){----}, at: [<c0835fb7>] do_page_fault+0xc7/0x820
> > > Jan 8 15:29:17 ying3 kernel:
> > > Jan 8 15:29:17 ying3 kernel: stack backtrace:
> > > Jan 8 15:29:17 ying3 kernel: Pid: 3527, comm: tlocklfs Not tainted 2.6.28-07532-g393a64e #71
> > > Jan 8 15:29:17 ying3 kernel: Call Trace:
> > > Jan 8 15:29:17 ying3 kernel: [<c083091a>] ? printk+0x1d/0x1f
> > > Jan 8 15:29:17 ying3 kernel: [<c0247c18>] print_circular_bug_tail+0xc8/0xd0
> > > Jan 8 15:29:17 ying3 kernel: [<c024923d>] __lock_acquire+0x11fd/0x18e0
> > > Jan 8 15:29:17 ying3 kernel: [<c07314dc>] ? lock_sock_nested+0x2c/0xe0
> > > Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
> > > Jan 8 15:29:17 ying3 kernel: [<c076609c>] ? tcp_sendmsg+0x1c/0xa80
> > > Jan 8 15:29:17 ying3 kernel: [<c0731574>] lock_sock_nested+0xc4/0xe0
> > > Jan 8 15:29:17 ying3 kernel: [<c076609c>] ? tcp_sendmsg+0x1c/0xa80
> > > Jan 8 15:29:17 ying3 kernel: [<c0270934>] ? free_hot_cold_page+0x174/0x2a0
> > > Jan 8 15:29:17 ying3 kernel: [<c076609c>] tcp_sendmsg+0x1c/0xa80
> > > Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
> > > Jan 8 15:29:17 ying3 kernel: [<c0270b86>] ? free_pages+0x46/0x50
> > > Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
> > > Jan 8 15:29:17 ying3 kernel: [<c02451aa>] ? find_usage_backwards+0xaa/0x120
> > > Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> > > Jan 8 15:29:17 ying3 kernel: [<c0239280>] ? autoremove_wake_function+0x0/0x50
> > > Jan 8 15:29:17 ying3 kernel: [<c0248ea0>] ? __lock_acquire+0xe60/0x18e0
> > > Jan 8 15:29:17 ying3 kernel: [<c0248ea0>] ? __lock_acquire+0xe60/0x18e0
> > > Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> > > Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> > > Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> > > Jan 8 15:29:17 ying3 kernel: [<c055020f>] ? debug_object_deactivate+0xbf/0x100
> > > Jan 8 15:29:17 ying3 kernel: [<c07da9d8>] xs_tcp_send_request+0x58/0x170
> > > Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> > > Jan 8 15:29:17 ying3 kernel: [<c0392760>] ? nfs4_xdr_enc_read+0x0/0x110
> > > Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> > > Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> > > Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
> > > Jan 8 15:29:17 ying3 kernel: [<c07dd297>] ? rpc_set_active+0x67/0x80
> > > Jan 8 15:29:17 ying3 kernel: [<c07ddc0e>] rpc_execute+0x1e/0x30
> > > Jan 8 15:29:17 ying3 kernel: [<c07d7705>] rpc_run_task+0x35/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c037c924>] nfs_read_rpcsetup+0x174/0x1f0
> > > Jan 8 15:29:17 ying3 kernel: [<c0290b61>] ? kmem_cache_alloc+0xd1/0x140
> > > Jan 8 15:29:17 ying3 kernel: [<c026d583>] ? mempool_alloc_slab+0x13/0x20
> > > Jan 8 15:29:17 ying3 last message repeated 2 times
> > > Jan 8 15:29:17 ying3 kernel: [<c037ce8e>] nfs_pagein_one+0x9e/0xe0
> > > Jan 8 15:29:17 ying3 kernel: [<c037a73a>] nfs_pageio_doio+0x3a/0x80
> > > Jan 8 15:29:17 ying3 kernel: [<c037a78d>] nfs_pageio_complete+0xd/0x10
> > > Jan 8 15:29:17 ying3 kernel: [<c037c21c>] nfs_readpages+0xec/0x1d0
> > > Jan 8 15:29:17 ying3 kernel: [<c02711c3>] ? __alloc_pages_internal+0xc3/0x4d0
> > > Jan 8 15:29:17 ying3 kernel: [<c037cdf0>] ? nfs_pagein_one+0x0/0xe0
> > > Jan 8 15:29:17 ying3 kernel: [<c037c130>] ? nfs_readpages+0x0/0x1d0
> > > Jan 8 15:29:17 ying3 kernel: [<c02735cc>] __do_page_cache_readahead+0x1bc/0x280
> > > Jan 8 15:29:17 ying3 kernel: [<c02734d5>] ? __do_page_cache_readahead+0xc5/0x280
> > > Jan 8 15:29:17 ying3 kernel: [<c02736e0>] do_page_cache_readahead+0x50/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c026b82f>] filemap_fault+0x31f/0x470
> > > Jan 8 15:29:17 ying3 kernel: [<c027e370>] __do_fault+0x40/0x3d0
> > > Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
> > > Jan 8 15:29:17 ying3 kernel: [<c027ff91>] handle_mm_fault+0x111/0x610
> > > Jan 8 15:29:17 ying3 kernel: [<c0835fb7>] ? do_page_fault+0xc7/0x820
> > > Jan 8 15:29:17 ying3 kernel: [<c023cd8d>] ? down_read_trylock+0x5d/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c0836105>] do_page_fault+0x215/0x820
> > > Jan 8 15:29:17 ying3 kernel: [<c0546741>] ? prio_tree_insert+0x211/0x290
> > > Jan 8 15:29:17 ying3 kernel: [<c0833a9c>] ? _spin_unlock+0x2c/0x50
> > > Jan 8 15:29:17 ying3 kernel: [<c0283a52>] ? vma_link+0x82/0xa0
> > > Jan 8 15:29:17 ying3 kernel: [<c0284fd2>] ? mmap_region+0x2d2/0x4f0
> > > Jan 8 15:29:17 ying3 kernel: [<c027dfca>] ? might_fault+0x4a/0xa0
> > > Jan 8 15:29:17 ying3 kernel: [<c0835ef0>] ? do_page_fault+0x0/0x820
> > > Jan 8 15:29:17 ying3 kernel: [<c0834347>] error_code+0x6f/0x74
> > > Jan 8 15:29:17 ying3 kernel: [<c027007b>] ? __free_pages_ok+0x27b/0x480
> > > Jan 8 15:29:17 ying3 kernel: [<c054b9b7>] ? clear_user+0x47/0x60
> > > Jan 8 15:29:17 ying3 kernel: [<c02caff5>] load_elf_binary+0x8e5/0x1a20
> > > Jan 8 15:29:17 ying3 kernel: [<c0247411>] ? mark_held_locks+0x41/0x80
> > > Jan 8 15:29:17 ying3 kernel: [<c0833a55>] ? _spin_unlock_irqrestore+0x55/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c0247651>] ? trace_hardirqs_on_caller+0x141/0x1a0
> > > Jan 8 15:29:17 ying3 kernel: [<c0298f8f>] ? search_binary_handler+0x5f/0x2f0
> > > Jan 8 15:29:17 ying3 kernel: [<c02990a3>] search_binary_handler+0x173/0x2f0
> > > Jan 8 15:29:17 ying3 kernel: [<c02ca710>] ? load_elf_binary+0x0/0x1a20
> > > Jan 8 15:29:17 ying3 kernel: [<c029a31d>] do_execve+0x1cd/0x220
> > > Jan 8 15:29:17 ying3 kernel: [<c0201793>] sys_execve+0x43/0x70
> > > Jan 8 15:29:17 ying3 kernel: [<c02034c5>] sysenter_do_call+0x12/0x35
> > > Jan 8 15:29:26 ying3 kernel: tlocklfs used greatest stack depth: 4252 bytes left
> > > Jan 8 15:29:55 ying3 kernel: aoe: 00188b809a6e e2.3 v400f has 2048000 sectors
> > > Jan 8 15:29:55 ying3 kernel: etherd/e2.3: unknown partition table

Cheers,
--
Visit Openswan at http://www.openswan.org/
Email: Herbert Xu ~{PmV>HI~} <[email protected]>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt

2009-01-09 05:58:17

by Peter Zijlstra

[permalink] [raw]
Subject: Re: nfs client lockdep warning

On Fri, 2009-01-09 at 15:33 +1100, Herbert Xu wrote:
> On Thu, Jan 08, 2009 at 09:20:56PM +0000, J. Bruce Fields wrote:
> >
> > > > Jan 8 15:29:17 ying3 kernel: =======================================================
> > > > Jan 8 15:29:17 ying3 kernel: [ INFO: possible circular locking dependency detected ]
> > > > Jan 8 15:29:17 ying3 kernel: 2.6.28-07532-g393a64e #71
> > > > Jan 8 15:29:17 ying3 kernel: -------------------------------------------------------
> > > > Jan 8 15:29:17 ying3 kernel: tlocklfs/3527 is trying to acquire lock:
> > > > Jan 8 15:29:17 ying3 kernel: (sk_lock-AF_INET-RPC){--..}, at: [<c076609c>] tcp_sendmsg+0x1c/0xa80
> > > > Jan 8 15:29:17 ying3 kernel:
> > > > Jan 8 15:29:17 ying3 kernel: but task is already holding lock:
> > > > Jan 8 15:29:17 ying3 kernel: (&mm->mmap_sem){----}, at: [<c0835fb7>] do_page_fault+0xc7/0x820
> > > > Jan 8 15:29:17 ying3 kernel:
> > > > Jan 8 15:29:17 ying3 kernel: which lock already depends on the new lock.
> > > > Jan 8 15:29:17 ying3 kernel:
> > > > Jan 8 15:29:17 ying3 kernel:
> > > > Jan 8 15:29:17 ying3 kernel: the existing dependency chain (in reverse order) is:
> > > > Jan 8 15:29:17 ying3 kernel:
> > > > Jan 8 15:29:17 ying3 kernel: -> #1 (&mm->mmap_sem){----}:
> > > > Jan 8 15:29:17 ying3 kernel: [<c024900d>] __lock_acquire+0xfcd/0x18e0
> > > > Jan 8 15:29:17 ying3 kernel: [<c024997c>] lock_acquire+0x5c/0x80
> > > > Jan 8 15:29:17 ying3 kernel: [<c027dffb>] might_fault+0x7b/0xa0
>
> This is a false positive introduced by might_fault. As this is
> a send request from the kernel, it should never fault.
>
> > > > Jan 8 15:29:17 ying3 kernel: [<c054bb26>] copy_from_user+0x36/0x90
> > > > Jan 8 15:29:17 ying3 kernel: [<c0737800>] memcpy_fromiovecend+0x60/0x90
> > > > Jan 8 15:29:17 ying3 kernel: [<c075ce9f>] ip_generic_getfrag+0x9f/0xb0
> > > > Jan 8 15:29:17 ying3 kernel: [<c075cb6b>] ip_append_data+0x6bb/0x950
> > > > Jan 8 15:29:17 ying3 kernel: [<c077cb0d>] udp_sendmsg+0x2bd/0x680
> > > > Jan 8 15:29:17 ying3 kernel: [<c07835f9>] inet_sendmsg+0x39/0x70
> > > > Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> > > > Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> > > > Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> > > > Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> > > > Jan 8 15:29:17 ying3 kernel: [<c07dab30>] xs_udp_send_request+0x40/0x120
> > > > Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> > > > Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> > > > Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250

Is there anything pinning that user-space page, if not its free to
fault, which would mean its a real warning...


2009-01-09 06:23:43

by Herbert Xu

[permalink] [raw]
Subject: Re: nfs client lockdep warning

On Fri, Jan 09, 2009 at 06:58:17AM +0100, Peter Zijlstra wrote:
>
> > > > > Jan 8 15:29:17 ying3 kernel: [<c054bb26>] copy_from_user+0x36/0x90
> > > > > Jan 8 15:29:17 ying3 kernel: [<c0737800>] memcpy_fromiovecend+0x60/0x90
> > > > > Jan 8 15:29:17 ying3 kernel: [<c075ce9f>] ip_generic_getfrag+0x9f/0xb0
> > > > > Jan 8 15:29:17 ying3 kernel: [<c075cb6b>] ip_append_data+0x6bb/0x950
> > > > > Jan 8 15:29:17 ying3 kernel: [<c077cb0d>] udp_sendmsg+0x2bd/0x680
> > > > > Jan 8 15:29:17 ying3 kernel: [<c07835f9>] inet_sendmsg+0x39/0x70
> > > > > Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> > > > > Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> > > > > Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> > > > > Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> > > > > Jan 8 15:29:17 ying3 kernel: [<c07dab30>] xs_udp_send_request+0x40/0x120
> > > > > Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> > > > > Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> > > > > Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
>
> Is there anything pinning that user-space page, if not its free to
> fault, which would mean its a real warning...

It's kernel memory, not user memory. See xs_udp_send_request in
net/sunrpc.

Cheers,
--
Visit Openswan at http://www.openswan.org/
Email: Herbert Xu ~{PmV>HI~} <[email protected]>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt

2009-01-09 06:51:08

by Peter Zijlstra

[permalink] [raw]
Subject: Re: nfs client lockdep warning

On Fri, 2009-01-09 at 17:23 +1100, Herbert Xu wrote:
> On Fri, Jan 09, 2009 at 06:58:17AM +0100, Peter Zijlstra wrote:
> >
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c054bb26>] copy_from_user+0x36/0x90
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c0737800>] memcpy_fromiovecend+0x60/0x90
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c075ce9f>] ip_generic_getfrag+0x9f/0xb0
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c075cb6b>] ip_append_data+0x6bb/0x950
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c077cb0d>] udp_sendmsg+0x2bd/0x680
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c07835f9>] inet_sendmsg+0x39/0x70
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c07dab30>] xs_udp_send_request+0x40/0x120
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> > > > > > Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> >
> > Is there anything pinning that user-space page, if not its free to
> > fault, which would mean its a real warning...
>
> It's kernel memory, not user memory. See xs_udp_send_request in
> net/sunrpc.

Ahh, so something like this ought to fix it I think...

Signed-off-by: Peter Zijlstra <[email protected]>
---
diff --git a/mm/memory.c b/mm/memory.c
index 7b9db65..a2ed52e 100644
--- a/mm/memory.c
+++ b/mm/memory.c
@@ -3079,6 +3079,9 @@ void print_vma_addr(char *prefix, unsigned long ip)
#ifdef CONFIG_PROVE_LOCKING
void might_fault(void)
{
+ if (get_fs() == KERNEL_DS)
+ return;
+
might_sleep();
/*
* it would be nicer only to annotate paths which are not under



2009-01-09 20:29:50

by J. Bruce Fields

[permalink] [raw]
Subject: Re: nfs client lockdep warning

On Fri, Jan 09, 2009 at 07:51:08AM +0100, Peter Zijlstra wrote:
> On Fri, 2009-01-09 at 17:23 +1100, Herbert Xu wrote:
> > On Fri, Jan 09, 2009 at 06:58:17AM +0100, Peter Zijlstra wrote:
> > >
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c054bb26>] copy_from_user+0x36/0x90
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c0737800>] memcpy_fromiovecend+0x60/0x90
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c075ce9f>] ip_generic_getfrag+0x9f/0xb0
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c075cb6b>] ip_append_data+0x6bb/0x950
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c077cb0d>] udp_sendmsg+0x2bd/0x680
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c07835f9>] inet_sendmsg+0x39/0x70
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c072f0e6>] sock_sendmsg+0xd6/0x100
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c072f485>] kernel_sendmsg+0x35/0x50
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c07da698>] xs_send_kvec+0xa8/0xb0
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c07da711>] xs_sendpages+0x71/0x210
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c07dab30>] xs_udp_send_request+0x40/0x120
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c07d91ff>] xprt_transmit+0x6f/0x280
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c07d6c1f>] call_transmit+0x17f/0x250
> > > > > > > Jan 8 15:29:17 ying3 kernel: [<c07dda13>] __rpc_execute+0x73/0x250
> > >
> > > Is there anything pinning that user-space page, if not its free to
> > > fault, which would mean its a real warning...
> >
> > It's kernel memory, not user memory. See xs_udp_send_request in
> > net/sunrpc.
>
> Ahh, so something like this ought to fix it I think...
>
> Signed-off-by: Peter Zijlstra <[email protected]>
> ---
> diff --git a/mm/memory.c b/mm/memory.c
> index 7b9db65..a2ed52e 100644
> --- a/mm/memory.c
> +++ b/mm/memory.c
> @@ -3079,6 +3079,9 @@ void print_vma_addr(char *prefix, unsigned long ip)
> #ifdef CONFIG_PROVE_LOCKING
> void might_fault(void)
> {
> + if (get_fs() == KERNEL_DS)

Looks like that should be

if ((segment_eq(get_fs(), KERNEL_DS))

? Anyway, with that, sure, that eliminates the lockdep warning.

--b.

> + return;
> +
> might_sleep();
> /*
> * it would be nicer only to annotate paths which are not under
>
>