All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
@ 2012-01-24 17:40 Jeff Layton
  2012-01-25 11:48 ` Boaz Harrosh
                   ` (2 more replies)
  0 siblings, 3 replies; 11+ messages in thread
From: Jeff Layton @ 2012-01-24 17:40 UTC (permalink / raw)
  To: trond.myklebust; +Cc: linux-nfs

The debugobjects code will sometimes pop a warning like this when the
queue_timeout job is queued to a workqueue:

[ 5157.128514] WARNING: at lib/debugobjects.c:262 debug_print_object+0x8c/0xb0()
[ 5157.128742] Hardware name: Bochs
[ 5157.128742] ODEBUG: activate not available (active state 0) object type: timer_list hint: stub_timer+0x0/0x20
[ 5157.128742] Modules linked in: nfsd(O) nfs_acl auth_rpcgss lockd sunrpc floppy virtio_net i2c_piix4 i2c_core virtio_balloon joydev pcspkr virtio_blk [last unloaded: nfsd]
[ 5157.128742] Pid: 1312, comm: rpc.nfsd Tainted: G        W  O 3.3.0-rc1+ #1
[ 5157.128742] Call Trace:
[ 5157.128742]  [<ffffffff8106135f>] warn_slowpath_common+0x7f/0xc0
[ 5157.128742]  [<ffffffff81061456>] warn_slowpath_fmt+0x46/0x50
[ 5157.128742]  [<ffffffff8132ba2c>] debug_print_object+0x8c/0xb0
[ 5157.128742]  [<ffffffff81070db0>] ? timer_debug_hint+0x10/0x10
[ 5157.128742]  [<ffffffff8132c02b>] debug_object_activate+0xfb/0x190
[ 5157.128742]  [<ffffffff81072728>] ? lock_timer_base.isra.24+0x38/0x70
[ 5157.128742]  [<ffffffff81074676>] mod_timer+0xf6/0x450
[ 5157.128742]  [<ffffffff810749e8>] add_timer+0x18/0x20
[ 5157.128742]  [<ffffffff8108168e>] queue_delayed_work_on+0xbe/0x140
[ 5157.128742]  [<ffffffff81084441>] queue_delayed_work+0x21/0x40
[ 5157.128742]  [<ffffffffa006e568>] rpc_queue_upcall+0xe8/0x100 [sunrpc]
[ 5157.128742]  [<ffffffffa012a121>] __cld_pipe_upcall+0x61/0xc0 [nfsd]
[ 5157.128742]  [<ffffffffa012ad98>] nfsd4_cld_init+0x48/0x140 [nfsd]
[ 5157.128742]  [<ffffffffa012b22a>] nfsd4_client_tracking_init+0x2a/0xc0 [nfsd]
[ 5157.128742]  [<ffffffff8169797e>] ? mutex_unlock+0xe/0x10
[ 5157.128742]  [<ffffffffa01266fa>] nfs4_state_start+0x1a/0x100 [nfsd]
[ 5157.128742]  [<ffffffffa01028c5>] nfsd_svc+0x135/0x200 [nfsd]
[ 5157.128742]  [<ffffffffa0103df0>] ? write_maxblksize+0x130/0x130 [nfsd]
[ 5157.128742]  [<ffffffffa0103e6d>] write_threads+0x7d/0xd0 [nfsd]
[ 5157.128742]  [<ffffffff811dd16a>] ? simple_transaction_get+0xca/0xe0
[ 5157.128742]  [<ffffffffa0102ee7>] nfsctl_transaction_write+0x57/0x90 [nfsd]
[ 5157.128742]  [<ffffffff811b4c9f>] vfs_write+0xaf/0x190
[ 5157.128742]  [<ffffffff811b4fdd>] sys_write+0x4d/0x90
[ 5157.128742]  [<ffffffff816a3469>] system_call_fastpath+0x16/0x1b

This occurs when an rpc_inode object is recycled. The slab constructor
routine doesn't necessarily get called on it again, so the debugobjects
code isn't aware that it's already initialized.

Work around this problem by initializing the delayed work every time
an inode is allocated out of the slab, not just when a new slab is.

Cc: Boaz Harrosh <bharrosh@panasas.com>
Signed-off-by: Jeff Layton <jlayton@redhat.com>
---
 net/sunrpc/rpc_pipe.c |    4 ++--
 1 files changed, 2 insertions(+), 2 deletions(-)

diff --git a/net/sunrpc/rpc_pipe.c b/net/sunrpc/rpc_pipe.c
index 63a7a7a..58e1dd1 100644
--- a/net/sunrpc/rpc_pipe.c
+++ b/net/sunrpc/rpc_pipe.c
@@ -178,6 +178,8 @@ rpc_alloc_inode(struct super_block *sb)
 	rpci = (struct rpc_inode *)kmem_cache_alloc(rpc_inode_cachep, GFP_KERNEL);
 	if (!rpci)
 		return NULL;
+
+	INIT_DELAYED_WORK(&rpci->queue_timeout, rpc_timeout_upcall_queue);
 	return &rpci->vfs_inode;
 }
 
@@ -1073,8 +1075,6 @@ init_once(void *foo)
 	INIT_LIST_HEAD(&rpci->pipe);
 	rpci->pipelen = 0;
 	init_waitqueue_head(&rpci->waitq);
-	INIT_DELAYED_WORK(&rpci->queue_timeout,
-			    rpc_timeout_upcall_queue);
 	rpci->ops = NULL;
 }
 
-- 
1.7.7.5


^ permalink raw reply related	[flat|nested] 11+ messages in thread

* Re: [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
  2012-01-24 17:40 [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation Jeff Layton
@ 2012-01-25 11:48 ` Boaz Harrosh
  2012-01-30 20:43 ` Steve Dickson
  2012-02-29 16:56 ` Jeff Layton
  2 siblings, 0 replies; 11+ messages in thread
From: Boaz Harrosh @ 2012-01-25 11:48 UTC (permalink / raw)
  To: Jeff Layton; +Cc: trond.myklebust, linux-nfs

On 01/24/2012 07:40 PM, Jeff Layton wrote:
> The debugobjects code will sometimes pop a warning like this when the
> queue_timeout job is queued to a workqueue:
> 
> [ 5157.128514] WARNING: at lib/debugobjects.c:262 debug_print_object+0x8c/0xb0()
> [ 5157.128742] Hardware name: Bochs
> [ 5157.128742] ODEBUG: activate not available (active state 0) object type: timer_list hint: stub_timer+0x0/0x20
> [ 5157.128742] Modules linked in: nfsd(O) nfs_acl auth_rpcgss lockd sunrpc floppy virtio_net i2c_piix4 i2c_core virtio_balloon joydev pcspkr virtio_blk [last unloaded: nfsd]
> [ 5157.128742] Pid: 1312, comm: rpc.nfsd Tainted: G        W  O 3.3.0-rc1+ #1
> [ 5157.128742] Call Trace:
> [ 5157.128742]  [<ffffffff8106135f>] warn_slowpath_common+0x7f/0xc0
> [ 5157.128742]  [<ffffffff81061456>] warn_slowpath_fmt+0x46/0x50
> [ 5157.128742]  [<ffffffff8132ba2c>] debug_print_object+0x8c/0xb0
> [ 5157.128742]  [<ffffffff81070db0>] ? timer_debug_hint+0x10/0x10
> [ 5157.128742]  [<ffffffff8132c02b>] debug_object_activate+0xfb/0x190
> [ 5157.128742]  [<ffffffff81072728>] ? lock_timer_base.isra.24+0x38/0x70
> [ 5157.128742]  [<ffffffff81074676>] mod_timer+0xf6/0x450
> [ 5157.128742]  [<ffffffff810749e8>] add_timer+0x18/0x20
> [ 5157.128742]  [<ffffffff8108168e>] queue_delayed_work_on+0xbe/0x140
> [ 5157.128742]  [<ffffffff81084441>] queue_delayed_work+0x21/0x40
> [ 5157.128742]  [<ffffffffa006e568>] rpc_queue_upcall+0xe8/0x100 [sunrpc]
> [ 5157.128742]  [<ffffffffa012a121>] __cld_pipe_upcall+0x61/0xc0 [nfsd]
> [ 5157.128742]  [<ffffffffa012ad98>] nfsd4_cld_init+0x48/0x140 [nfsd]
> [ 5157.128742]  [<ffffffffa012b22a>] nfsd4_client_tracking_init+0x2a/0xc0 [nfsd]
> [ 5157.128742]  [<ffffffff8169797e>] ? mutex_unlock+0xe/0x10
> [ 5157.128742]  [<ffffffffa01266fa>] nfs4_state_start+0x1a/0x100 [nfsd]
> [ 5157.128742]  [<ffffffffa01028c5>] nfsd_svc+0x135/0x200 [nfsd]
> [ 5157.128742]  [<ffffffffa0103df0>] ? write_maxblksize+0x130/0x130 [nfsd]
> [ 5157.128742]  [<ffffffffa0103e6d>] write_threads+0x7d/0xd0 [nfsd]
> [ 5157.128742]  [<ffffffff811dd16a>] ? simple_transaction_get+0xca/0xe0
> [ 5157.128742]  [<ffffffffa0102ee7>] nfsctl_transaction_write+0x57/0x90 [nfsd]
> [ 5157.128742]  [<ffffffff811b4c9f>] vfs_write+0xaf/0x190
> [ 5157.128742]  [<ffffffff811b4fdd>] sys_write+0x4d/0x90
> [ 5157.128742]  [<ffffffff816a3469>] system_call_fastpath+0x16/0x1b
> 
> This occurs when an rpc_inode object is recycled. The slab constructor
> routine doesn't necessarily get called on it again, so the debugobjects
> code isn't aware that it's already initialized.
> 
> Work around this problem by initializing the delayed work every time
> an inode is allocated out of the slab, not just when a new slab is.
> 
> Cc: Boaz Harrosh <bharrosh@panasas.com>

Looks good. I agree with this patch. It seems that's the way
workqueues and the objects debugger where meant to be used.

Thanks
Boaz

> Signed-off-by: Jeff Layton <jlayton@redhat.com>
> ---
>  net/sunrpc/rpc_pipe.c |    4 ++--
>  1 files changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/net/sunrpc/rpc_pipe.c b/net/sunrpc/rpc_pipe.c
> index 63a7a7a..58e1dd1 100644
> --- a/net/sunrpc/rpc_pipe.c
> +++ b/net/sunrpc/rpc_pipe.c
> @@ -178,6 +178,8 @@ rpc_alloc_inode(struct super_block *sb)
>  	rpci = (struct rpc_inode *)kmem_cache_alloc(rpc_inode_cachep, GFP_KERNEL);
>  	if (!rpci)
>  		return NULL;
> +
> +	INIT_DELAYED_WORK(&rpci->queue_timeout, rpc_timeout_upcall_queue);
>  	return &rpci->vfs_inode;
>  }
>  
> @@ -1073,8 +1075,6 @@ init_once(void *foo)
>  	INIT_LIST_HEAD(&rpci->pipe);
>  	rpci->pipelen = 0;
>  	init_waitqueue_head(&rpci->waitq);
> -	INIT_DELAYED_WORK(&rpci->queue_timeout,
> -			    rpc_timeout_upcall_queue);
>  	rpci->ops = NULL;
>  }
>  


^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
  2012-01-24 17:40 [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation Jeff Layton
  2012-01-25 11:48 ` Boaz Harrosh
@ 2012-01-30 20:43 ` Steve Dickson
  2012-01-30 21:07   ` Myklebust, Trond
  2012-02-29 16:56 ` Jeff Layton
  2 siblings, 1 reply; 11+ messages in thread
From: Steve Dickson @ 2012-01-30 20:43 UTC (permalink / raw)
  To: Jeff Layton; +Cc: trond.myklebust, linux-nfs



On 01/24/2012 12:40 PM, Jeff Layton wrote:
> The debugobjects code will sometimes pop a warning like this when the
> queue_timeout job is queued to a workqueue:
> 
> [ 5157.128514] WARNING: at lib/debugobjects.c:262 debug_print_object+0x8c/0xb0()
> [ 5157.128742] Hardware name: Bochs
> [ 5157.128742] ODEBUG: activate not available (active state 0) object type: timer_list hint: stub_timer+0x0/0x20
> [ 5157.128742] Modules linked in: nfsd(O) nfs_acl auth_rpcgss lockd sunrpc floppy virtio_net i2c_piix4 i2c_core virtio_balloon joydev pcspkr virtio_blk [last unloaded: nfsd]
> [ 5157.128742] Pid: 1312, comm: rpc.nfsd Tainted: G        W  O 3.3.0-rc1+ #1
> [ 5157.128742] Call Trace:
> [ 5157.128742]  [<ffffffff8106135f>] warn_slowpath_common+0x7f/0xc0
> [ 5157.128742]  [<ffffffff81061456>] warn_slowpath_fmt+0x46/0x50
> [ 5157.128742]  [<ffffffff8132ba2c>] debug_print_object+0x8c/0xb0
> [ 5157.128742]  [<ffffffff81070db0>] ? timer_debug_hint+0x10/0x10
> [ 5157.128742]  [<ffffffff8132c02b>] debug_object_activate+0xfb/0x190
> [ 5157.128742]  [<ffffffff81072728>] ? lock_timer_base.isra.24+0x38/0x70
> [ 5157.128742]  [<ffffffff81074676>] mod_timer+0xf6/0x450
> [ 5157.128742]  [<ffffffff810749e8>] add_timer+0x18/0x20
> [ 5157.128742]  [<ffffffff8108168e>] queue_delayed_work_on+0xbe/0x140
> [ 5157.128742]  [<ffffffff81084441>] queue_delayed_work+0x21/0x40
> [ 5157.128742]  [<ffffffffa006e568>] rpc_queue_upcall+0xe8/0x100 [sunrpc]
> [ 5157.128742]  [<ffffffffa012a121>] __cld_pipe_upcall+0x61/0xc0 [nfsd]
> [ 5157.128742]  [<ffffffffa012ad98>] nfsd4_cld_init+0x48/0x140 [nfsd]
> [ 5157.128742]  [<ffffffffa012b22a>] nfsd4_client_tracking_init+0x2a/0xc0 [nfsd]
> [ 5157.128742]  [<ffffffff8169797e>] ? mutex_unlock+0xe/0x10
> [ 5157.128742]  [<ffffffffa01266fa>] nfs4_state_start+0x1a/0x100 [nfsd]
> [ 5157.128742]  [<ffffffffa01028c5>] nfsd_svc+0x135/0x200 [nfsd]
> [ 5157.128742]  [<ffffffffa0103df0>] ? write_maxblksize+0x130/0x130 [nfsd]
> [ 5157.128742]  [<ffffffffa0103e6d>] write_threads+0x7d/0xd0 [nfsd]
> [ 5157.128742]  [<ffffffff811dd16a>] ? simple_transaction_get+0xca/0xe0
> [ 5157.128742]  [<ffffffffa0102ee7>] nfsctl_transaction_write+0x57/0x90 [nfsd]
> [ 5157.128742]  [<ffffffff811b4c9f>] vfs_write+0xaf/0x190
> [ 5157.128742]  [<ffffffff811b4fdd>] sys_write+0x4d/0x90
> [ 5157.128742]  [<ffffffff816a3469>] system_call_fastpath+0x16/0x1b
> 
> This occurs when an rpc_inode object is recycled. The slab constructor
> routine doesn't necessarily get called on it again, so the debugobjects
> code isn't aware that it's already initialized.
> 
> Work around this problem by initializing the delayed work every time
> an inode is allocated out of the slab, not just when a new slab is.
> 
> Cc: Boaz Harrosh <bharrosh@panasas.com>
> Signed-off-by: Jeff Layton <jlayton@redhat.com>
I was seeing this warning as well and this patch did remove that warning...

Tested-by: Steve Dickson <steved@redhat.com>

steved.

> ---
>  net/sunrpc/rpc_pipe.c |    4 ++--
>  1 files changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/net/sunrpc/rpc_pipe.c b/net/sunrpc/rpc_pipe.c
> index 63a7a7a..58e1dd1 100644
> --- a/net/sunrpc/rpc_pipe.c
> +++ b/net/sunrpc/rpc_pipe.c
> @@ -178,6 +178,8 @@ rpc_alloc_inode(struct super_block *sb)
>  	rpci = (struct rpc_inode *)kmem_cache_alloc(rpc_inode_cachep, GFP_KERNEL);
>  	if (!rpci)
>  		return NULL;
> +
> +	INIT_DELAYED_WORK(&rpci->queue_timeout, rpc_timeout_upcall_queue);
>  	return &rpci->vfs_inode;
>  }
>  
> @@ -1073,8 +1075,6 @@ init_once(void *foo)
>  	INIT_LIST_HEAD(&rpci->pipe);
>  	rpci->pipelen = 0;
>  	init_waitqueue_head(&rpci->waitq);
> -	INIT_DELAYED_WORK(&rpci->queue_timeout,
> -			    rpc_timeout_upcall_queue);
>  	rpci->ops = NULL;
>  }
>  

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
  2012-01-30 20:43 ` Steve Dickson
@ 2012-01-30 21:07   ` Myklebust, Trond
  2012-01-30 23:57     ` Jeff Layton
  0 siblings, 1 reply; 11+ messages in thread
From: Myklebust, Trond @ 2012-01-30 21:07 UTC (permalink / raw)
  To: Steve Dickson; +Cc: Jeff Layton, linux-nfs

T24gTW9uLCAyMDEyLTAxLTMwIGF0IDE1OjQzIC0wNTAwLCBTdGV2ZSBEaWNrc29uIHdyb3RlOg0K
PiANCj4gT24gMDEvMjQvMjAxMiAxMjo0MCBQTSwgSmVmZiBMYXl0b24gd3JvdGU6DQo+ID4gVGhl
IGRlYnVnb2JqZWN0cyBjb2RlIHdpbGwgc29tZXRpbWVzIHBvcCBhIHdhcm5pbmcgbGlrZSB0aGlz
IHdoZW4gdGhlDQo+ID4gcXVldWVfdGltZW91dCBqb2IgaXMgcXVldWVkIHRvIGEgd29ya3F1ZXVl
Og0KPiA+IA0KPiA+IFsgNTE1Ny4xMjg1MTRdIFdBUk5JTkc6IGF0IGxpYi9kZWJ1Z29iamVjdHMu
YzoyNjIgZGVidWdfcHJpbnRfb2JqZWN0KzB4OGMvMHhiMCgpDQo+ID4gWyA1MTU3LjEyODc0Ml0g
SGFyZHdhcmUgbmFtZTogQm9jaHMNCj4gPiBbIDUxNTcuMTI4NzQyXSBPREVCVUc6IGFjdGl2YXRl
IG5vdCBhdmFpbGFibGUgKGFjdGl2ZSBzdGF0ZSAwKSBvYmplY3QgdHlwZTogdGltZXJfbGlzdCBo
aW50OiBzdHViX3RpbWVyKzB4MC8weDIwDQo+ID4gWyA1MTU3LjEyODc0Ml0gTW9kdWxlcyBsaW5r
ZWQgaW46IG5mc2QoTykgbmZzX2FjbCBhdXRoX3JwY2dzcyBsb2NrZCBzdW5ycGMgZmxvcHB5IHZp
cnRpb19uZXQgaTJjX3BpaXg0IGkyY19jb3JlIHZpcnRpb19iYWxsb29uIGpveWRldiBwY3Nwa3Ig
dmlydGlvX2JsayBbbGFzdCB1bmxvYWRlZDogbmZzZF0NCj4gPiBbIDUxNTcuMTI4NzQyXSBQaWQ6
IDEzMTIsIGNvbW06IHJwYy5uZnNkIFRhaW50ZWQ6IEcgICAgICAgIFcgIE8gMy4zLjAtcmMxKyAj
MQ0KPiA+IFsgNTE1Ny4xMjg3NDJdIENhbGwgVHJhY2U6DQo+ID4gWyA1MTU3LjEyODc0Ml0gIFs8
ZmZmZmZmZmY4MTA2MTM1Zj5dIHdhcm5fc2xvd3BhdGhfY29tbW9uKzB4N2YvMHhjMA0KPiA+IFsg
NTE1Ny4xMjg3NDJdICBbPGZmZmZmZmZmODEwNjE0NTY+XSB3YXJuX3Nsb3dwYXRoX2ZtdCsweDQ2
LzB4NTANCj4gPiBbIDUxNTcuMTI4NzQyXSAgWzxmZmZmZmZmZjgxMzJiYTJjPl0gZGVidWdfcHJp
bnRfb2JqZWN0KzB4OGMvMHhiMA0KPiA+IFsgNTE1Ny4xMjg3NDJdICBbPGZmZmZmZmZmODEwNzBk
YjA+XSA/IHRpbWVyX2RlYnVnX2hpbnQrMHgxMC8weDEwDQo+ID4gWyA1MTU3LjEyODc0Ml0gIFs8
ZmZmZmZmZmY4MTMyYzAyYj5dIGRlYnVnX29iamVjdF9hY3RpdmF0ZSsweGZiLzB4MTkwDQo+ID4g
WyA1MTU3LjEyODc0Ml0gIFs8ZmZmZmZmZmY4MTA3MjcyOD5dID8gbG9ja190aW1lcl9iYXNlLmlz
cmEuMjQrMHgzOC8weDcwDQo+ID4gWyA1MTU3LjEyODc0Ml0gIFs8ZmZmZmZmZmY4MTA3NDY3Nj5d
IG1vZF90aW1lcisweGY2LzB4NDUwDQo+ID4gWyA1MTU3LjEyODc0Ml0gIFs8ZmZmZmZmZmY4MTA3
NDllOD5dIGFkZF90aW1lcisweDE4LzB4MjANCj4gPiBbIDUxNTcuMTI4NzQyXSAgWzxmZmZmZmZm
ZjgxMDgxNjhlPl0gcXVldWVfZGVsYXllZF93b3JrX29uKzB4YmUvMHgxNDANCj4gPiBbIDUxNTcu
MTI4NzQyXSAgWzxmZmZmZmZmZjgxMDg0NDQxPl0gcXVldWVfZGVsYXllZF93b3JrKzB4MjEvMHg0
MA0KPiA+IFsgNTE1Ny4xMjg3NDJdICBbPGZmZmZmZmZmYTAwNmU1Njg+XSBycGNfcXVldWVfdXBj
YWxsKzB4ZTgvMHgxMDAgW3N1bnJwY10NCj4gPiBbIDUxNTcuMTI4NzQyXSAgWzxmZmZmZmZmZmEw
MTJhMTIxPl0gX19jbGRfcGlwZV91cGNhbGwrMHg2MS8weGMwIFtuZnNkXQ0KPiA+IFsgNTE1Ny4x
Mjg3NDJdICBbPGZmZmZmZmZmYTAxMmFkOTg+XSBuZnNkNF9jbGRfaW5pdCsweDQ4LzB4MTQwIFtu
ZnNkXQ0KPiA+IFsgNTE1Ny4xMjg3NDJdICBbPGZmZmZmZmZmYTAxMmIyMmE+XSBuZnNkNF9jbGll
bnRfdHJhY2tpbmdfaW5pdCsweDJhLzB4YzAgW25mc2RdDQo+ID4gWyA1MTU3LjEyODc0Ml0gIFs8
ZmZmZmZmZmY4MTY5Nzk3ZT5dID8gbXV0ZXhfdW5sb2NrKzB4ZS8weDEwDQo+ID4gWyA1MTU3LjEy
ODc0Ml0gIFs8ZmZmZmZmZmZhMDEyNjZmYT5dIG5mczRfc3RhdGVfc3RhcnQrMHgxYS8weDEwMCBb
bmZzZF0NCj4gPiBbIDUxNTcuMTI4NzQyXSAgWzxmZmZmZmZmZmEwMTAyOGM1Pl0gbmZzZF9zdmMr
MHgxMzUvMHgyMDAgW25mc2RdDQo+ID4gWyA1MTU3LjEyODc0Ml0gIFs8ZmZmZmZmZmZhMDEwM2Rm
MD5dID8gd3JpdGVfbWF4Ymxrc2l6ZSsweDEzMC8weDEzMCBbbmZzZF0NCj4gPiBbIDUxNTcuMTI4
NzQyXSAgWzxmZmZmZmZmZmEwMTAzZTZkPl0gd3JpdGVfdGhyZWFkcysweDdkLzB4ZDAgW25mc2Rd
DQo+ID4gWyA1MTU3LjEyODc0Ml0gIFs8ZmZmZmZmZmY4MTFkZDE2YT5dID8gc2ltcGxlX3RyYW5z
YWN0aW9uX2dldCsweGNhLzB4ZTANCj4gPiBbIDUxNTcuMTI4NzQyXSAgWzxmZmZmZmZmZmEwMTAy
ZWU3Pl0gbmZzY3RsX3RyYW5zYWN0aW9uX3dyaXRlKzB4NTcvMHg5MCBbbmZzZF0NCj4gPiBbIDUx
NTcuMTI4NzQyXSAgWzxmZmZmZmZmZjgxMWI0YzlmPl0gdmZzX3dyaXRlKzB4YWYvMHgxOTANCj4g
PiBbIDUxNTcuMTI4NzQyXSAgWzxmZmZmZmZmZjgxMWI0ZmRkPl0gc3lzX3dyaXRlKzB4NGQvMHg5
MA0KPiA+IFsgNTE1Ny4xMjg3NDJdICBbPGZmZmZmZmZmODE2YTM0Njk+XSBzeXN0ZW1fY2FsbF9m
YXN0cGF0aCsweDE2LzB4MWINCj4gPiANCj4gPiBUaGlzIG9jY3VycyB3aGVuIGFuIHJwY19pbm9k
ZSBvYmplY3QgaXMgcmVjeWNsZWQuIFRoZSBzbGFiIGNvbnN0cnVjdG9yDQo+ID4gcm91dGluZSBk
b2Vzbid0IG5lY2Vzc2FyaWx5IGdldCBjYWxsZWQgb24gaXQgYWdhaW4sIHNvIHRoZSBkZWJ1Z29i
amVjdHMNCj4gPiBjb2RlIGlzbid0IGF3YXJlIHRoYXQgaXQncyBhbHJlYWR5IGluaXRpYWxpemVk
Lg0KPiA+IA0KPiA+IFdvcmsgYXJvdW5kIHRoaXMgcHJvYmxlbSBieSBpbml0aWFsaXppbmcgdGhl
IGRlbGF5ZWQgd29yayBldmVyeSB0aW1lDQo+ID4gYW4gaW5vZGUgaXMgYWxsb2NhdGVkIG91dCBv
ZiB0aGUgc2xhYiwgbm90IGp1c3Qgd2hlbiBhIG5ldyBzbGFiIGlzLg0KPiA+IA0KPiA+IENjOiBC
b2F6IEhhcnJvc2ggPGJoYXJyb3NoQHBhbmFzYXMuY29tPg0KPiA+IFNpZ25lZC1vZmYtYnk6IEpl
ZmYgTGF5dG9uIDxqbGF5dG9uQHJlZGhhdC5jb20+DQo+IEkgd2FzIHNlZWluZyB0aGlzIHdhcm5p
bmcgYXMgd2VsbCBhbmQgdGhpcyBwYXRjaCBkaWQgcmVtb3ZlIHRoYXQgd2FybmluZy4uLg0KPiAN
Cj4gVGVzdGVkLWJ5OiBTdGV2ZSBEaWNrc29uIDxzdGV2ZWRAcmVkaGF0LmNvbT4NCg0KT0ssIGJ1
dCB3aHkgYXJlIHdlIHNlZWluZyB0aGUgd2FybmluZyBpbiB0aGUgZmlyc3QgcGxhY2U/IFdoeSBp
cyBhIHRpbWVyDQp0aGF0IHdhcyBpbml0aWFsaXNlZCBzdWRkZW5seSBmaW5kaW5nIGl0c2VsZiBp
biBhIG5vbi1pbml0aWFsaXNlZCBzdGF0ZT8NCg0KLS0gDQpUcm9uZCBNeWtsZWJ1c3QNCkxpbnV4
IE5GUyBjbGllbnQgbWFpbnRhaW5lcg0KDQpOZXRBcHANClRyb25kLk15a2xlYnVzdEBuZXRhcHAu
Y29tDQp3d3cubmV0YXBwLmNvbQ0KDQo=

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
  2012-01-30 21:07   ` Myklebust, Trond
@ 2012-01-30 23:57     ` Jeff Layton
  2012-01-31 14:54       ` Boaz Harrosh
  0 siblings, 1 reply; 11+ messages in thread
From: Jeff Layton @ 2012-01-30 23:57 UTC (permalink / raw)
  To: Myklebust, Trond; +Cc: Steve Dickson, linux-nfs, Thomas Gleixner

On Mon, 30 Jan 2012 21:07:37 +0000
"Myklebust, Trond" <Trond.Myklebust@netapp.com> wrote:

> On Mon, 2012-01-30 at 15:43 -0500, Steve Dickson wrote:
> > 
> > On 01/24/2012 12:40 PM, Jeff Layton wrote:
> > > The debugobjects code will sometimes pop a warning like this when the
> > > queue_timeout job is queued to a workqueue:
> > > 
> > > [ 5157.128514] WARNING: at lib/debugobjects.c:262 debug_print_object+0x8c/0xb0()
> > > [ 5157.128742] Hardware name: Bochs
> > > [ 5157.128742] ODEBUG: activate not available (active state 0) object type: timer_list hint: stub_timer+0x0/0x20
> > > [ 5157.128742] Modules linked in: nfsd(O) nfs_acl auth_rpcgss lockd sunrpc floppy virtio_net i2c_piix4 i2c_core virtio_balloon joydev pcspkr virtio_blk [last unloaded: nfsd]
> > > [ 5157.128742] Pid: 1312, comm: rpc.nfsd Tainted: G        W  O 3.3.0-rc1+ #1
> > > [ 5157.128742] Call Trace:
> > > [ 5157.128742]  [<ffffffff8106135f>] warn_slowpath_common+0x7f/0xc0
> > > [ 5157.128742]  [<ffffffff81061456>] warn_slowpath_fmt+0x46/0x50
> > > [ 5157.128742]  [<ffffffff8132ba2c>] debug_print_object+0x8c/0xb0
> > > [ 5157.128742]  [<ffffffff81070db0>] ? timer_debug_hint+0x10/0x10
> > > [ 5157.128742]  [<ffffffff8132c02b>] debug_object_activate+0xfb/0x190
> > > [ 5157.128742]  [<ffffffff81072728>] ? lock_timer_base.isra.24+0x38/0x70
> > > [ 5157.128742]  [<ffffffff81074676>] mod_timer+0xf6/0x450
> > > [ 5157.128742]  [<ffffffff810749e8>] add_timer+0x18/0x20
> > > [ 5157.128742]  [<ffffffff8108168e>] queue_delayed_work_on+0xbe/0x140
> > > [ 5157.128742]  [<ffffffff81084441>] queue_delayed_work+0x21/0x40
> > > [ 5157.128742]  [<ffffffffa006e568>] rpc_queue_upcall+0xe8/0x100 [sunrpc]
> > > [ 5157.128742]  [<ffffffffa012a121>] __cld_pipe_upcall+0x61/0xc0 [nfsd]
> > > [ 5157.128742]  [<ffffffffa012ad98>] nfsd4_cld_init+0x48/0x140 [nfsd]
> > > [ 5157.128742]  [<ffffffffa012b22a>] nfsd4_client_tracking_init+0x2a/0xc0 [nfsd]
> > > [ 5157.128742]  [<ffffffff8169797e>] ? mutex_unlock+0xe/0x10
> > > [ 5157.128742]  [<ffffffffa01266fa>] nfs4_state_start+0x1a/0x100 [nfsd]
> > > [ 5157.128742]  [<ffffffffa01028c5>] nfsd_svc+0x135/0x200 [nfsd]
> > > [ 5157.128742]  [<ffffffffa0103df0>] ? write_maxblksize+0x130/0x130 [nfsd]
> > > [ 5157.128742]  [<ffffffffa0103e6d>] write_threads+0x7d/0xd0 [nfsd]
> > > [ 5157.128742]  [<ffffffff811dd16a>] ? simple_transaction_get+0xca/0xe0
> > > [ 5157.128742]  [<ffffffffa0102ee7>] nfsctl_transaction_write+0x57/0x90 [nfsd]
> > > [ 5157.128742]  [<ffffffff811b4c9f>] vfs_write+0xaf/0x190
> > > [ 5157.128742]  [<ffffffff811b4fdd>] sys_write+0x4d/0x90
> > > [ 5157.128742]  [<ffffffff816a3469>] system_call_fastpath+0x16/0x1b
> > > 
> > > This occurs when an rpc_inode object is recycled. The slab constructor
> > > routine doesn't necessarily get called on it again, so the debugobjects
> > > code isn't aware that it's already initialized.
> > > 
> > > Work around this problem by initializing the delayed work every time
> > > an inode is allocated out of the slab, not just when a new slab is.
> > > 
> > > Cc: Boaz Harrosh <bharrosh@panasas.com>
> > > Signed-off-by: Jeff Layton <jlayton@redhat.com>
> > I was seeing this warning as well and this patch did remove that warning...
> > 
> > Tested-by: Steve Dickson <steved@redhat.com>
> 
> OK, but why are we seeing the warning in the first place? Why is a timer
> that was initialised suddenly finding itself in a non-initialised state?
> 

(cc'ing Thomas)

It's not uninitialized, but the debugobjects code doesn't realize that.

IIUC, the debugobjects code creates some tracking objects for the timer
when it's first initialized and then frees them on kmem_cache_free. The
problem here is that we're just initializing the timer once when the
slab is first added to the cache (via the slabcache ctor). When the object
is recycled, the timer isn't being reinitialized so debugobjects has no
longer has a record of it.

This really looks like a bug (design flaw?) in the debugobjects code,
but I'm not sure if or when Thomas is planning to fix it. There was a
bit of discussion recently in this thread:

    WARNING: at lib/debugobjects.c:262 debug_print_object+0x8c/0xb0()

For now, this patch is really just papering over that problem, but it
should be "mostly harmless". That said, I'm ok with dropping it if
Thomas is planning to fix this in the debugobjects code however.

-- 
Jeff Layton <jlayton@redhat.com>

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
  2012-01-30 23:57     ` Jeff Layton
@ 2012-01-31 14:54       ` Boaz Harrosh
  2012-01-31 15:03         ` Myklebust, Trond
  2012-01-31 15:12         ` Jeff Layton
  0 siblings, 2 replies; 11+ messages in thread
From: Boaz Harrosh @ 2012-01-31 14:54 UTC (permalink / raw)
  To: Jeff Layton; +Cc: Myklebust, Trond, Steve Dickson, linux-nfs, Thomas Gleixner

On 01/31/2012 01:57 AM, Jeff Layton wrote:
>     WARNING: at lib/debugobjects.c:262 debug_print_object+0x8c/0xb0()
> 
> For now, this patch is really just papering over that problem, but it
> should be "mostly harmless". That said, I'm ok with dropping it if
> Thomas is planning to fix this in the debugobjects code however.
> 

I disagree it's harmless. What if kmem_cache_free/kmem_cache_alloc deploys
a poisoning schema, in debug mode. Which stumps over memory. Is it
initialized then?

What was the last state of the timer, is it safe for resume?

For us this is a new object we should initialize it.

Boaz

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
  2012-01-31 14:54       ` Boaz Harrosh
@ 2012-01-31 15:03         ` Myklebust, Trond
  2012-01-31 15:12         ` Jeff Layton
  1 sibling, 0 replies; 11+ messages in thread
From: Myklebust, Trond @ 2012-01-31 15:03 UTC (permalink / raw)
  To: Boaz Harrosh; +Cc: Jeff Layton, Steve Dickson, linux-nfs, Thomas Gleixner

T24gVHVlLCAyMDEyLTAxLTMxIGF0IDE2OjU0ICswMjAwLCBCb2F6IEhhcnJvc2ggd3JvdGU6DQo+
IE9uIDAxLzMxLzIwMTIgMDE6NTcgQU0sIEplZmYgTGF5dG9uIHdyb3RlOg0KPiA+ICAgICBXQVJO
SU5HOiBhdCBsaWIvZGVidWdvYmplY3RzLmM6MjYyIGRlYnVnX3ByaW50X29iamVjdCsweDhjLzB4
YjAoKQ0KPiA+IA0KPiA+IEZvciBub3csIHRoaXMgcGF0Y2ggaXMgcmVhbGx5IGp1c3QgcGFwZXJp
bmcgb3ZlciB0aGF0IHByb2JsZW0sIGJ1dCBpdA0KPiA+IHNob3VsZCBiZSAibW9zdGx5IGhhcm1s
ZXNzIi4gVGhhdCBzYWlkLCBJJ20gb2sgd2l0aCBkcm9wcGluZyBpdCBpZg0KPiA+IFRob21hcyBp
cyBwbGFubmluZyB0byBmaXggdGhpcyBpbiB0aGUgZGVidWdvYmplY3RzIGNvZGUgaG93ZXZlci4N
Cj4gPiANCj4gDQo+IEkgZGlzYWdyZWUgaXQncyBoYXJtbGVzcy4gV2hhdCBpZiBrbWVtX2NhY2hl
X2ZyZWUva21lbV9jYWNoZV9hbGxvYyBkZXBsb3lzDQo+IGEgcG9pc29uaW5nIHNjaGVtYSwgaW4g
ZGVidWcgbW9kZS4gV2hpY2ggc3R1bXBzIG92ZXIgbWVtb3J5LiBJcyBpdA0KPiBpbml0aWFsaXpl
ZCB0aGVuPw0KDQpJZiB0aGF0IHdlcmUgdGhlIGNhc2UsIHRoZW4gdGhlIGVudGlyZSBpbm9kZSB3
b3VsZCBiZSB1c2VsZXNzIHRvIHVzLiBXZQ0KcmVseSBvbiBpbml0aWFsaXNhdGlvbiBpbiBpbml0
X29uY2UoKSBmb3IgYSBidW5jaCBvZiBvdGhlciBzdHVmZg0KaW5jbHVkaW5nIGxpc3QgaGVhZHMs
IHdhaXRxdWV1ZSBoZWFkcywgZXRjLg0KDQo+IFdoYXQgd2FzIHRoZSBsYXN0IHN0YXRlIG9mIHRo
ZSB0aW1lciwgaXMgaXQgc2FmZSBmb3IgcmVzdW1lPw0KDQpJbml0aWFsaXNlZCwgYW5kIHllcy4N
Cg0KPiBGb3IgdXMgdGhpcyBpcyBhIG5ldyBvYmplY3Qgd2Ugc2hvdWxkIGluaXRpYWxpemUgaXQu
DQoNCk5vIGl0IGlzIGRlZmluaXRlbHkgbm90IGEgbmV3IG9iamVjdC4uLg0KDQotLSANClRyb25k
IE15a2xlYnVzdA0KTGludXggTkZTIGNsaWVudCBtYWludGFpbmVyDQoNCk5ldEFwcA0KVHJvbmQu
TXlrbGVidXN0QG5ldGFwcC5jb20NCnd3dy5uZXRhcHAuY29tDQoNCg==

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
  2012-01-31 14:54       ` Boaz Harrosh
  2012-01-31 15:03         ` Myklebust, Trond
@ 2012-01-31 15:12         ` Jeff Layton
  2012-01-31 21:56             ` Thomas Gleixner
  1 sibling, 1 reply; 11+ messages in thread
From: Jeff Layton @ 2012-01-31 15:12 UTC (permalink / raw)
  To: Boaz Harrosh; +Cc: Myklebust, Trond, Steve Dickson, linux-nfs, Thomas Gleixner

On Tue, 31 Jan 2012 16:54:44 +0200
Boaz Harrosh <bharrosh@panasas.com> wrote:

> On 01/31/2012 01:57 AM, Jeff Layton wrote:
> >     WARNING: at lib/debugobjects.c:262 debug_print_object+0x8c/0xb0()
> > 
> > For now, this patch is really just papering over that problem, but it
> > should be "mostly harmless". That said, I'm ok with dropping it if
> > Thomas is planning to fix this in the debugobjects code however.
> > 
> 
> I disagree it's harmless. What if kmem_cache_free/kmem_cache_alloc deploys
> a poisoning schema, in debug mode. Which stumps over memory. Is it
> initialized then?
> 

Different slab allocators handle that differently. As best I can tell:

SLAB: calls ctor on the poisoned object before handing it back out

SLUB: avoids poisoning the object if there's a ->ctor defined

SLOB: I'm not sure -- haven't looked at it

> What was the last state of the timer, is it safe for resume?
> 

Yes, either way it's safe to reuse the recycled object, aside from the
problem with debugobjects. If it's not then that's clearly a bug in the
slab allocator.

> For us this is a new object we should initialize it.
> 

I tend to agree that not relying on slab ctor functions is preferable.
They are widely used though so this problem almost assuredly exists in
other places besides just rpc_pipefs. If it's not fixed in the
debugobjects code (or the slab allocators) then I wouldn't be surprised
if this popped up again in another area.

-- 
Jeff Layton <jlayton@redhat.com>

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
  2012-01-31 15:12         ` Jeff Layton
@ 2012-01-31 21:56             ` Thomas Gleixner
  0 siblings, 0 replies; 11+ messages in thread
From: Thomas Gleixner @ 2012-01-31 21:56 UTC (permalink / raw)
  To: Jeff Layton
  Cc: Boaz Harrosh, Myklebust, Trond, Steve Dickson, linux-nfs,
	Peter Zijlstra, linux-mm

On Tue, 31 Jan 2012, Jeff Layton wrote:

> On Tue, 31 Jan 2012 16:54:44 +0200
> Boaz Harrosh <bharrosh@panasas.com> wrote:
> 
> > On 01/31/2012 01:57 AM, Jeff Layton wrote:
> > >     WARNING: at lib/debugobjects.c:262 debug_print_object+0x8c/0xb0()
> > > 
> > > For now, this patch is really just papering over that problem, but it
> > > should be "mostly harmless". That said, I'm ok with dropping it if
> > > Thomas is planning to fix this in the debugobjects code however.
> > > 
> > 
> > I disagree it's harmless. What if kmem_cache_free/kmem_cache_alloc deploys
> > a poisoning schema, in debug mode. Which stumps over memory. Is it
> > initialized then?
> > 
> 
> Different slab allocators handle that differently. As best I can tell:
> 
> SLAB: calls ctor on the poisoned object before handing it back out
> 
> SLUB: avoids poisoning the object if there's a ->ctor defined

Brilliant. Preventing debug code from catching bugs is really a great
idea. This needs to be fixed ASAP.
 
> SLOB: I'm not sure -- haven't looked at it
> 
> > What was the last state of the timer, is it safe for resume?
> > 
> 
> Yes, either way it's safe to reuse the recycled object, aside from the
> problem with debugobjects. If it's not then that's clearly a bug in the
> slab allocator.
> > For us this is a new object we should initialize it.
> > 
> 
> I tend to agree that not relying on slab ctor functions is preferable.
> They are widely used though so this problem almost assuredly exists in
> other places besides just rpc_pipefs. If it's not fixed in the
> debugobjects code (or the slab allocators) then I wouldn't be surprised
> if this popped up again in another area.

There is nothing the debugobjects code can do about this. The
indication for removing the object from the hash is the
kmem_cache_free() operation and from that point on the object is not
longer usable. That's correct and it's not going to change.

The correct solution to this problem is to do the following:

Extend the kmemcache with a debug_ctor() callback. 

In case of slab poisoning make it call ctor().

In case of debugobjects (w/o slab poisoning) make it a function which
reinitializes the timer or what ever subobject which needs an explicit
state check. In case of timers this should be a separate function
(e.g. timer_reinit()) which soleley makes the timer known to the debug
code again.

Thanks,

	tglx


^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
@ 2012-01-31 21:56             ` Thomas Gleixner
  0 siblings, 0 replies; 11+ messages in thread
From: Thomas Gleixner @ 2012-01-31 21:56 UTC (permalink / raw)
  To: Jeff Layton
  Cc: Boaz Harrosh, Myklebust, Trond, Steve Dickson, linux-nfs,
	Peter Zijlstra, linux-mm

On Tue, 31 Jan 2012, Jeff Layton wrote:

> On Tue, 31 Jan 2012 16:54:44 +0200
> Boaz Harrosh <bharrosh@panasas.com> wrote:
> 
> > On 01/31/2012 01:57 AM, Jeff Layton wrote:
> > >     WARNING: at lib/debugobjects.c:262 debug_print_object+0x8c/0xb0()
> > > 
> > > For now, this patch is really just papering over that problem, but it
> > > should be "mostly harmless". That said, I'm ok with dropping it if
> > > Thomas is planning to fix this in the debugobjects code however.
> > > 
> > 
> > I disagree it's harmless. What if kmem_cache_free/kmem_cache_alloc deploys
> > a poisoning schema, in debug mode. Which stumps over memory. Is it
> > initialized then?
> > 
> 
> Different slab allocators handle that differently. As best I can tell:
> 
> SLAB: calls ctor on the poisoned object before handing it back out
> 
> SLUB: avoids poisoning the object if there's a ->ctor defined

Brilliant. Preventing debug code from catching bugs is really a great
idea. This needs to be fixed ASAP.
 
> SLOB: I'm not sure -- haven't looked at it
> 
> > What was the last state of the timer, is it safe for resume?
> > 
> 
> Yes, either way it's safe to reuse the recycled object, aside from the
> problem with debugobjects. If it's not then that's clearly a bug in the
> slab allocator.
> > For us this is a new object we should initialize it.
> > 
> 
> I tend to agree that not relying on slab ctor functions is preferable.
> They are widely used though so this problem almost assuredly exists in
> other places besides just rpc_pipefs. If it's not fixed in the
> debugobjects code (or the slab allocators) then I wouldn't be surprised
> if this popped up again in another area.

There is nothing the debugobjects code can do about this. The
indication for removing the object from the hash is the
kmem_cache_free() operation and from that point on the object is not
longer usable. That's correct and it's not going to change.

The correct solution to this problem is to do the following:

Extend the kmemcache with a debug_ctor() callback. 

In case of slab poisoning make it call ctor().

In case of debugobjects (w/o slab poisoning) make it a function which
reinitializes the timer or what ever subobject which needs an explicit
state check. In case of timers this should be a separate function
(e.g. timer_reinit()) which soleley makes the timer known to the debug
code again.

Thanks,

	tglx

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to majordomo@kvack.org.  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Fight unfair telecom internet charges in Canada: sign http://stopthemeter.ca/
Don't email: <a href=mailto:"dont@kvack.org"> email@kvack.org </a>

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation
  2012-01-24 17:40 [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation Jeff Layton
  2012-01-25 11:48 ` Boaz Harrosh
  2012-01-30 20:43 ` Steve Dickson
@ 2012-02-29 16:56 ` Jeff Layton
  2 siblings, 0 replies; 11+ messages in thread
From: Jeff Layton @ 2012-02-29 16:56 UTC (permalink / raw)
  To: Jeff Layton; +Cc: trond.myklebust, linux-nfs

On Tue, 24 Jan 2012 12:40:50 -0500
Jeff Layton <jlayton@redhat.com> wrote:

> The debugobjects code will sometimes pop a warning like this when the
> queue_timeout job is queued to a workqueue:
> 
> [ 5157.128514] WARNING: at lib/debugobjects.c:262 debug_print_object+0x8c/0xb0()
> [ 5157.128742] Hardware name: Bochs
> [ 5157.128742] ODEBUG: activate not available (active state 0) object type: timer_list hint: stub_timer+0x0/0x20
> [ 5157.128742] Modules linked in: nfsd(O) nfs_acl auth_rpcgss lockd sunrpc floppy virtio_net i2c_piix4 i2c_core virtio_balloon joydev pcspkr virtio_blk [last unloaded: nfsd]
> [ 5157.128742] Pid: 1312, comm: rpc.nfsd Tainted: G        W  O 3.3.0-rc1+ #1
> [ 5157.128742] Call Trace:
> [ 5157.128742]  [<ffffffff8106135f>] warn_slowpath_common+0x7f/0xc0
> [ 5157.128742]  [<ffffffff81061456>] warn_slowpath_fmt+0x46/0x50
> [ 5157.128742]  [<ffffffff8132ba2c>] debug_print_object+0x8c/0xb0
> [ 5157.128742]  [<ffffffff81070db0>] ? timer_debug_hint+0x10/0x10
> [ 5157.128742]  [<ffffffff8132c02b>] debug_object_activate+0xfb/0x190
> [ 5157.128742]  [<ffffffff81072728>] ? lock_timer_base.isra.24+0x38/0x70
> [ 5157.128742]  [<ffffffff81074676>] mod_timer+0xf6/0x450
> [ 5157.128742]  [<ffffffff810749e8>] add_timer+0x18/0x20
> [ 5157.128742]  [<ffffffff8108168e>] queue_delayed_work_on+0xbe/0x140
> [ 5157.128742]  [<ffffffff81084441>] queue_delayed_work+0x21/0x40
> [ 5157.128742]  [<ffffffffa006e568>] rpc_queue_upcall+0xe8/0x100 [sunrpc]
> [ 5157.128742]  [<ffffffffa012a121>] __cld_pipe_upcall+0x61/0xc0 [nfsd]
> [ 5157.128742]  [<ffffffffa012ad98>] nfsd4_cld_init+0x48/0x140 [nfsd]
> [ 5157.128742]  [<ffffffffa012b22a>] nfsd4_client_tracking_init+0x2a/0xc0 [nfsd]
> [ 5157.128742]  [<ffffffff8169797e>] ? mutex_unlock+0xe/0x10
> [ 5157.128742]  [<ffffffffa01266fa>] nfs4_state_start+0x1a/0x100 [nfsd]
> [ 5157.128742]  [<ffffffffa01028c5>] nfsd_svc+0x135/0x200 [nfsd]
> [ 5157.128742]  [<ffffffffa0103df0>] ? write_maxblksize+0x130/0x130 [nfsd]
> [ 5157.128742]  [<ffffffffa0103e6d>] write_threads+0x7d/0xd0 [nfsd]
> [ 5157.128742]  [<ffffffff811dd16a>] ? simple_transaction_get+0xca/0xe0
> [ 5157.128742]  [<ffffffffa0102ee7>] nfsctl_transaction_write+0x57/0x90 [nfsd]
> [ 5157.128742]  [<ffffffff811b4c9f>] vfs_write+0xaf/0x190
> [ 5157.128742]  [<ffffffff811b4fdd>] sys_write+0x4d/0x90
> [ 5157.128742]  [<ffffffff816a3469>] system_call_fastpath+0x16/0x1b
> 
> This occurs when an rpc_inode object is recycled. The slab constructor
> routine doesn't necessarily get called on it again, so the debugobjects
> code isn't aware that it's already initialized.
> 
> Work around this problem by initializing the delayed work every time
> an inode is allocated out of the slab, not just when a new slab is.
> 
> Cc: Boaz Harrosh <bharrosh@panasas.com>
> Signed-off-by: Jeff Layton <jlayton@redhat.com>
> ---
>  net/sunrpc/rpc_pipe.c |    4 ++--
>  1 files changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/net/sunrpc/rpc_pipe.c b/net/sunrpc/rpc_pipe.c
> index 63a7a7a..58e1dd1 100644
> --- a/net/sunrpc/rpc_pipe.c
> +++ b/net/sunrpc/rpc_pipe.c
> @@ -178,6 +178,8 @@ rpc_alloc_inode(struct super_block *sb)
>  	rpci = (struct rpc_inode *)kmem_cache_alloc(rpc_inode_cachep, GFP_KERNEL);
>  	if (!rpci)
>  		return NULL;
> +
> +	INIT_DELAYED_WORK(&rpci->queue_timeout, rpc_timeout_upcall_queue);
>  	return &rpci->vfs_inode;
>  }
>  
> @@ -1073,8 +1075,6 @@ init_once(void *foo)
>  	INIT_LIST_HEAD(&rpci->pipe);
>  	rpci->pipelen = 0;
>  	init_waitqueue_head(&rpci->waitq);
> -	INIT_DELAYED_WORK(&rpci->queue_timeout,
> -			    rpc_timeout_upcall_queue);
>  	rpci->ops = NULL;
>  }
>  

It looks like Stanislav's proposed namespace patches for rpc_pipefs
should also fix this problem as well. Assuming those are slated for
3.4, I think we can drop this patch.

Thanks,
-- 
Jeff Layton <jlayton@redhat.com>

^ permalink raw reply	[flat|nested] 11+ messages in thread

end of thread, other threads:[~2012-02-29 17:10 UTC | newest]

Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-01-24 17:40 [PATCH] sunrpc: initialize delayed work on each rpc_inode allocation Jeff Layton
2012-01-25 11:48 ` Boaz Harrosh
2012-01-30 20:43 ` Steve Dickson
2012-01-30 21:07   ` Myklebust, Trond
2012-01-30 23:57     ` Jeff Layton
2012-01-31 14:54       ` Boaz Harrosh
2012-01-31 15:03         ` Myklebust, Trond
2012-01-31 15:12         ` Jeff Layton
2012-01-31 21:56           ` Thomas Gleixner
2012-01-31 21:56             ` Thomas Gleixner
2012-02-29 16:56 ` Jeff Layton

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.