* client hang in lock_flocks()
@ 2011-03-31 16:52 Jim Rees
[not found] ` <20110331165258.GA3048-8f4Pc2RrbJmHXe+LvDLADg@public.gmane.org>
0 siblings, 1 reply; 4+ messages in thread
From: Jim Rees @ 2011-03-31 16:52 UTC (permalink / raw)
To: linux-nfs; +Cc: peter honeyman
I have reported here before on a NFS client hang that we see in
multi-threaded iozone testing on various kernel and NFS versions. What
looks like the same bug has been reported against RHEL here:
https://bugzilla.redhat.com/show_bug.cgi?id=672305
After applying the suggested fix from that bug report I'm getting a
different hang, at least with Benny's pnfs-all-latest and NFS 4.1 (no
pnfs). Does this ring a bell with anyone?
INFO: task iozone:2666 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
iozone D ffff88024cdf1aa0 0 2666 1 0x00000080
ffff880246be7c50 0000000000000082 0000000000000000 0000000000000000
ffff880246be6010 ffff880246be7fd8 00000000000136c0 ffff88024cdf16f0
ffff88024cdf1aa8 ffff88024cdf1aa0 00000000000136c0 00000000000136c0
Call Trace:
[<ffffffff8113978a>] ? lock_flocks+0x10/0x12
[<ffffffff8143dc37>] rwsem_down_failed_common+0xd3/0x105
[<ffffffff8143dc90>] rwsem_down_read_failed+0x12/0x14
[<ffffffff81209f54>] call_rwsem_down_read_failed+0x14/0x30
[<ffffffff8143d377>] ? down_read+0x32/0x36
[<ffffffffa03dbd20>] nfs4_proc_lock+0x224/0x342 [nfs]
[<ffffffffa03c19af>] do_setlk+0x61/0xd5 [nfs]
[<ffffffffa03c1c4a>] nfs_lock+0x170/0x17f [nfs]
[<ffffffff8113af72>] vfs_lock_file+0x24/0x38
[<ffffffff8113b2b9>] fcntl_setlk+0x15e/0x2a6
[<ffffffff811056d7>] ? fsnotify_access+0x5d/0x65
[<ffffffff81112ad6>] sys_fcntl+0x30e/0x4af
[<ffffffff8143e890>] ? do_device_not_available+0x9/0xb
[<ffffffff8100aa52>] system_call_fastpath+0x16/0x1b
^ permalink raw reply [flat|nested] 4+ messages in thread[parent not found: <20110331165258.GA3048-8f4Pc2RrbJmHXe+LvDLADg@public.gmane.org>]
* Re: client hang in lock_flocks() [not found] ` <20110331165258.GA3048-8f4Pc2RrbJmHXe+LvDLADg@public.gmane.org> @ 2011-04-03 1:37 ` Peng Tao 2011-04-03 15:12 ` Jim Rees 0 siblings, 1 reply; 4+ messages in thread From: Peng Tao @ 2011-04-03 1:37 UTC (permalink / raw) To: Jim Rees; +Cc: linux-nfs, peter honeyman Hi, Jim, Would you please send the complete trace log, or maybe open a bugzilla entry and attach it there? -- Thanks, -Bergwolf ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: client hang in lock_flocks() 2011-04-03 1:37 ` Peng Tao @ 2011-04-03 15:12 ` Jim Rees 2011-04-03 17:02 ` Peng Tao 0 siblings, 1 reply; 4+ messages in thread From: Jim Rees @ 2011-04-03 15:12 UTC (permalink / raw) To: Peng Tao; +Cc: linux-nfs, peter honeyman Peng Tao wrote: Would you please send the complete trace log, or maybe open a bugzilla entry and attach it there? Here is everything that was reported to me. I can ask for rpc info and a tcpdump if that would be useful. Note that the second set of traces seems to be a different problem but I've included it in case they are related. Mar 24 17:21:08 r38-13-78 kernel: INFO: task iozone:2657 blocked for more than 120 seconds. Mar 24 17:21:08 r38-13-78 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 24 17:21:08 r38-13-78 kernel: iozone D ffff88024ac55f70 0 2657 1 0x00000080 Mar 24 17:21:08 r38-13-78 kernel: ffff88024cc65c50 0000000000000082 0000000000000000 0000000000000000 Mar 24 17:21:08 r38-13-78 kernel: ffff88024cc64010 ffff88024cc65fd8 00000000000136c0 ffff88024ac55bc0 Mar 24 17:21:08 r38-13-78 kernel: ffff88024ac55f78 ffff88024ac55f70 00000000000136c0 00000000000136c0 Mar 24 17:21:08 r38-13-78 kernel: Call Trace: Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff81139c1d>] ? lock_flocks+0x10/0x12 Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff8143e287>] rwsem_down_failed_common+0xd3/0x105 Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff8143e2e0>] rwsem_down_read_failed+0x12/0x14 Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff8120a5b4>] call_rwsem_down_read_failed+0x14/0x30 Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff8143d9c7>] ? down_read+0x32/0x36 Mar 24 17:21:08 r38-13-78 kernel: [<ffffffffa03ddca6>] nfs4_proc_lock+0x224/0x342 [nfs] Mar 24 17:21:08 r38-13-78 kernel: [<ffffffffa03c39cb>] do_setlk+0x61/0xd5 [nfs] Mar 24 17:21:08 r38-13-78 kernel: [<ffffffffa03c3c66>] nfs_lock+0x170/0x17f [nfs] Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff8113b4dc>] vfs_lock_file+0x24/0x38 Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff8113b823>] fcntl_setlk+0x15e/0x2a6 Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff811058bb>] ? fsnotify_access+0x5d/0x65 Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff81112dc6>] sys_fcntl+0x30e/0x4af Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff8143eed0>] ? do_device_not_available+0x9/0xb Mar 24 17:21:08 r38-13-78 kernel: [<ffffffff8100aa52>] system_call_fastpath+0x16/0x1b Mar 24 17:23:08 r38-13-78 kernel: INFO: task iozone:2657 blocked for more than 120 seconds. Mar 24 17:23:08 r38-13-78 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 24 17:23:08 r38-13-78 kernel: iozone D ffff88024ac55f70 0 2657 1 0x00000080 Mar 24 17:23:08 r38-13-78 kernel: ffff88024cc65c50 0000000000000082 0000000000000000 0000000000000000 Mar 24 17:23:08 r38-13-78 kernel: ffff88024cc64010 ffff88024cc65fd8 00000000000136c0 ffff88024ac55bc0 Mar 24 17:23:08 r38-13-78 kernel: ffff88024ac55f78 ffff88024ac55f70 00000000000136c0 00000000000136c0 Mar 24 17:23:08 r38-13-78 kernel: Call Trace: Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff81139c1d>] ? lock_flocks+0x10/0x12 Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff8143e287>] rwsem_down_failed_common+0xd3/0x105 Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff8143e2e0>] rwsem_down_read_failed+0x12/0x14 Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff8120a5b4>] call_rwsem_down_read_failed+0x14/0x30 Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff8143d9c7>] ? down_read+0x32/0x36 Mar 24 17:23:08 r38-13-78 kernel: [<ffffffffa03ddca6>] nfs4_proc_lock+0x224/0x342 [nfs] Mar 24 17:23:08 r38-13-78 kernel: [<ffffffffa03c39cb>] do_setlk+0x61/0xd5 [nfs] Mar 24 17:23:08 r38-13-78 kernel: [<ffffffffa03c3c66>] nfs_lock+0x170/0x17f [nfs] Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff8113b4dc>] vfs_lock_file+0x24/0x38 Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff8113b823>] fcntl_setlk+0x15e/0x2a6 Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff811058bb>] ? fsnotify_access+0x5d/0x65 Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff81112dc6>] sys_fcntl+0x30e/0x4af Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff8143eed0>] ? do_device_not_available+0x9/0xb Mar 24 17:23:08 r38-13-78 kernel: [<ffffffff8100aa52>] system_call_fastpath+0x16/0x1b Mar 24 17:25:08 r38-13-78 kernel: INFO: task iozone:2657 blocked for more than 120 seconds. Mar 24 17:25:08 r38-13-78 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 24 17:25:08 r38-13-78 kernel: iozone D ffff88024ac55f70 0 2657 1 0x00000080 Mar 24 17:25:08 r38-13-78 kernel: ffff88024cc65c50 0000000000000082 0000000000000000 0000000000000000 Mar 24 17:25:08 r38-13-78 kernel: ffff88024cc64010 ffff88024cc65fd8 00000000000136c0 ffff88024ac55bc0 Mar 24 17:25:08 r38-13-78 kernel: ffff88024ac55f78 ffff88024ac55f70 00000000000136c0 00000000000136c0 Mar 24 17:25:08 r38-13-78 kernel: Call Trace: Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff81139c1d>] ? lock_flocks+0x10/0x12 Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff8143e287>] rwsem_down_failed_common+0xd3/0x105 Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff8143e2e0>] rwsem_down_read_failed+0x12/0x14 Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff8120a5b4>] call_rwsem_down_read_failed+0x14/0x30 Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff8143d9c7>] ? down_read+0x32/0x36 Mar 24 17:25:08 r38-13-78 kernel: [<ffffffffa03ddca6>] nfs4_proc_lock+0x224/0x342 [nfs] Mar 24 17:25:08 r38-13-78 kernel: [<ffffffffa03c39cb>] do_setlk+0x61/0xd5 [nfs] Mar 24 17:25:08 r38-13-78 kernel: [<ffffffffa03c3c66>] nfs_lock+0x170/0x17f [nfs] Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff8113b4dc>] vfs_lock_file+0x24/0x38 Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff8113b823>] fcntl_setlk+0x15e/0x2a6 Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff811058bb>] ? fsnotify_access+0x5d/0x65 Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff81112dc6>] sys_fcntl+0x30e/0x4af Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff8143eed0>] ? do_device_not_available+0x9/0xb Mar 24 17:25:08 r38-13-78 kernel: [<ffffffff8100aa52>] system_call_fastpath+0x16/0x1b ************************** Mar 24 17:48:18 r38-13-78 kernel: INFO: task iozone:2718 blocked for more than 120 seconds. Mar 24 17:48:18 r38-13-78 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 24 17:48:18 r38-13-78 kernel: iozone D ffff88024b72b190 0 2718 1 0x00000080 Mar 24 17:48:18 r38-13-78 kernel: ffff88024b8cfb08 0000000000000082 ffff88024b8cfa88 ffffffffa03f4d00 Mar 24 17:48:18 r38-13-78 kernel: ffff88024b8ce010 ffff88024b8cffd8 00000000000136c0 ffff88024b72ade0 Mar 24 17:48:18 r38-13-78 kernel: ffff88024b72b198 ffff88024b72b190 00000000000136c0 00000000000136c0 Mar 24 17:48:18 r38-13-78 kernel: Call Trace: Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff810c0fab>] ? sync_page+0x0/0x48 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff8143cd96>] io_schedule+0x6b/0xae Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff810c0fef>] sync_page+0x44/0x48 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff8143d2e3>] __wait_on_bit+0x43/0x76 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff810c114b>] wait_on_page_bit+0x6d/0x74 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff81067d3b>] ? wake_bit_function+0x0/0x2e Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff810c95f0>] ? pagevec_lookup_tag+0x20/0x29 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff810c145d>] filemap_fdatawait_range+0x9f/0x179 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff810c15e3>] filemap_write_and_wait_range+0x3e/0x51 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff81126f65>] vfs_fsync_range+0x30/0x75 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff81126fe6>] generic_write_sync+0x3c/0x3e Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff810c1a53>] generic_file_aio_write+0x83/0xa1 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffffa03c6ef4>] nfs_file_write+0xd4/0x169 [nfs] Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff81105c26>] do_sync_write+0xc6/0x103 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff81067d02>] ? wake_up_bit+0x20/0x25 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff810f88cd>] ? slab_pre_alloc_hook+0x28/0x2c Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff811c800a>] ? security_file_permission+0x29/0x2e Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff811065b6>] vfs_write+0xa9/0x105 Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff811066cb>] sys_write+0x45/0x6c Mar 24 17:48:18 r38-13-78 kernel: [<ffffffff8100aa52>] system_call_fastpath+0x16/0x1b Mar 24 17:49:44 r38-13-78 ntpd[1161]: 0.0.0.0 c612 02 freq_set kernel 37.872 PPM Mar 24 17:49:44 r38-13-78 ntpd[1161]: 0.0.0.0 c615 05 clock_sync Mar 24 17:50:18 r38-13-78 kernel: INFO: task iozone:2718 blocked for more than 120 seconds. Mar 24 17:50:18 r38-13-78 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 24 17:50:18 r38-13-78 kernel: iozone D ffff88024b72b190 0 2718 1 0x00000080 Mar 24 17:50:18 r38-13-78 kernel: ffff88024b8cfb08 0000000000000082 ffff88024b8cfa88 ffffffffa03f4d00 Mar 24 17:50:18 r38-13-78 kernel: ffff88024b8ce010 ffff88024b8cffd8 00000000000136c0 ffff88024b72ade0 Mar 24 17:50:18 r38-13-78 kernel: ffff88024b72b198 ffff88024b72b190 00000000000136c0 00000000000136c0 Mar 24 17:50:18 r38-13-78 kernel: Call Trace: Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff810c0fab>] ? sync_page+0x0/0x48 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff8143cd96>] io_schedule+0x6b/0xae Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff810c0fef>] sync_page+0x44/0x48 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff8143d2e3>] __wait_on_bit+0x43/0x76 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff810c114b>] wait_on_page_bit+0x6d/0x74 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff81067d3b>] ? wake_bit_function+0x0/0x2e Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff810c95f0>] ? pagevec_lookup_tag+0x20/0x29 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff810c145d>] filemap_fdatawait_range+0x9f/0x179 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff810c15e3>] filemap_write_and_wait_range+0x3e/0x51 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff81126f65>] vfs_fsync_range+0x30/0x75 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff81126fe6>] generic_write_sync+0x3c/0x3e Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff810c1a53>] generic_file_aio_write+0x83/0xa1 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffffa03c6ef4>] nfs_file_write+0xd4/0x169 [nfs] Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff81105c26>] do_sync_write+0xc6/0x103 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff81067d02>] ? wake_up_bit+0x20/0x25 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff810f88cd>] ? slab_pre_alloc_hook+0x28/0x2c Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff811c800a>] ? security_file_permission+0x29/0x2e Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff811065b6>] vfs_write+0xa9/0x105 Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff811066cb>] sys_write+0x45/0x6c Mar 24 17:50:18 r38-13-78 kernel: [<ffffffff8100aa52>] system_call_fastpath+0x16/0x1b Mar 24 17:52:18 r38-13-78 kernel: INFO: task iozone:2718 blocked for more than 120 seconds. Mar 24 17:52:18 r38-13-78 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 24 17:52:18 r38-13-78 kernel: iozone D ffff88024b72b190 0 2718 1 0x00000080 Mar 24 17:52:18 r38-13-78 kernel: ffff88024b8cfb08 0000000000000082 ffff88024b8cfa88 ffffffffa03f4d00 Mar 24 17:52:18 r38-13-78 kernel: ffff88024b8ce010 ffff88024b8cffd8 00000000000136c0 ffff88024b72ade0 Mar 24 17:52:18 r38-13-78 kernel: ffff88024b72b198 ffff88024b72b190 00000000000136c0 00000000000136c0 Mar 24 17:52:18 r38-13-78 kernel: Call Trace: Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff810c0fab>] ? sync_page+0x0/0x48 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff8143cd96>] io_schedule+0x6b/0xae Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff810c0fef>] sync_page+0x44/0x48 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff8143d2e3>] __wait_on_bit+0x43/0x76 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff810c114b>] wait_on_page_bit+0x6d/0x74 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff81067d3b>] ? wake_bit_function+0x0/0x2e Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff810c95f0>] ? pagevec_lookup_tag+0x20/0x29 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff810c145d>] filemap_fdatawait_range+0x9f/0x179 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff810c15e3>] filemap_write_and_wait_range+0x3e/0x51 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff81126f65>] vfs_fsync_range+0x30/0x75 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff81126fe6>] generic_write_sync+0x3c/0x3e Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff810c1a53>] generic_file_aio_write+0x83/0xa1 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffffa03c6ef4>] nfs_file_write+0xd4/0x169 [nfs] Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff81105c26>] do_sync_write+0xc6/0x103 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff81067d02>] ? wake_up_bit+0x20/0x25 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff810f88cd>] ? slab_pre_alloc_hook+0x28/0x2c Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff811c800a>] ? security_file_permission+0x29/0x2e Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff811065b6>] vfs_write+0xa9/0x105 Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff811066cb>] sys_write+0x45/0x6c Mar 24 17:52:18 r38-13-78 kernel: [<ffffffff8100aa52>] system_call_fastpath+0x16/0x1b ************************** Mar 30 23:47:07 r38-13-78 xinetd[1144]: START: shell pid=2604 from=::ffff:10.244.76.80 Mar 30 23:47:07 r38-13-78 rshd[2606]: root@r38-15-80 as root: cmd='/opt/iozone/bin/iozone -+s -t 1 -r 4 -s 4 -+c r38-15-80 ' Mar 30 23:47:07 r38-13-78 xinetd[1144]: EXIT: shell status=0 pid=2604 duration=0(sec) Mar 30 23:47:12 r38-13-78 xinetd[1144]: START: shell pid=2625 from=::ffff:10.244.76.80 Mar 30 23:47:12 r38-13-78 rshd[2626]: root@r38-15-80 as root: cmd='/opt/iozone/bin/iozone -+s -t 1 -r 4 -s 4 -+c r38-15-80 ' Mar 30 23:47:12 r38-13-78 xinetd[1144]: EXIT: shell status=0 pid=2625 duration=0(sec) Mar 30 23:47:49 r38-13-78 xinetd[1144]: START: shell pid=2648 from=::ffff:10.244.76.80 Mar 30 23:47:49 r38-13-78 rshd[2649]: root@r38-15-80 as root: cmd='/opt/iozone/bin/iozone -+s -t 1 -r 4 -s 4 -+c r38-15-80 ' Mar 30 23:47:49 r38-13-78 xinetd[1144]: EXIT: shell status=0 pid=2648 duration=0(sec) Mar 30 23:47:54 r38-13-78 xinetd[1144]: START: shell pid=2669 from=::ffff:10.244.76.80 Mar 30 23:47:54 r38-13-78 rshd[2670]: root@r38-15-80 as root: cmd='/opt/iozone/bin/iozone -+s -t 1 -r 4 -s 4 -+c r38-15-80 ' Mar 30 23:47:54 r38-13-78 xinetd[1144]: EXIT: shell status=0 pid=2669 duration=0(sec) Mar 30 23:51:26 r38-13-78 kernel: INFO: task iozone:2666 blocked for more than 120 seconds. Mar 30 23:51:26 r38-13-78 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 30 23:51:26 r38-13-78 kernel: iozone D ffff88024cdf1aa0 0 2666 1 0x00000080 Mar 30 23:51:26 r38-13-78 kernel: ffff880246be7c50 0000000000000082 0000000000000000 0000000000000000 Mar 30 23:51:26 r38-13-78 kernel: ffff880246be6010 ffff880246be7fd8 00000000000136c0 ffff88024cdf16f0 Mar 30 23:51:26 r38-13-78 kernel: ffff88024cdf1aa8 ffff88024cdf1aa0 00000000000136c0 00000000000136c0 Mar 30 23:51:26 r38-13-78 kernel: Call Trace: Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff8113978a>] ? lock_flocks+0x10/0x12 Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff8143dc37>] rwsem_down_failed_common+0xd3/0x105 Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff8143dc90>] rwsem_down_read_failed+0x12/0x14 Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff81209f54>] call_rwsem_down_read_failed+0x14/0x30 Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff8143d377>] ? down_read+0x32/0x36 Mar 30 23:51:26 r38-13-78 kernel: [<ffffffffa03dbd20>] nfs4_proc_lock+0x224/0x342 [nfs] Mar 30 23:51:26 r38-13-78 kernel: [<ffffffffa03c19af>] do_setlk+0x61/0xd5 [nfs] Mar 30 23:51:26 r38-13-78 kernel: [<ffffffffa03c1c4a>] nfs_lock+0x170/0x17f [nfs] Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff8113af72>] vfs_lock_file+0x24/0x38 Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff8113b2b9>] fcntl_setlk+0x15e/0x2a6 Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff811056d7>] ? fsnotify_access+0x5d/0x65 Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff81112ad6>] sys_fcntl+0x30e/0x4af Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff8143e890>] ? do_device_not_available+0x9/0xb Mar 30 23:51:26 r38-13-78 kernel: [<ffffffff8100aa52>] system_call_fastpath+0x16/0x1b Mar 30 23:52:54 r38-13-78 ntpd[1153]: 0.0.0.0 c612 02 freq_set kernel 37.606 PPM Mar 30 23:52:54 r38-13-78 ntpd[1153]: 0.0.0.0 c615 05 clock_sync Mar 30 23:53:26 r38-13-78 kernel: INFO: task iozone:2666 blocked for more than 120 seconds. Mar 30 23:53:26 r38-13-78 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 30 23:53:26 r38-13-78 kernel: iozone D ffff88024cdf1aa0 0 2666 1 0x00000080 Mar 30 23:53:26 r38-13-78 kernel: ffff880246be7c50 0000000000000082 0000000000000000 0000000000000000 Mar 30 23:53:26 r38-13-78 kernel: ffff880246be6010 ffff880246be7fd8 00000000000136c0 ffff88024cdf16f0 Mar 30 23:53:26 r38-13-78 kernel: ffff88024cdf1aa8 ffff88024cdf1aa0 00000000000136c0 00000000000136c0 Mar 30 23:53:26 r38-13-78 kernel: Call Trace: Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff8113978a>] ? lock_flocks+0x10/0x12 Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff8143dc37>] rwsem_down_failed_common+0xd3/0x105 Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff8143dc90>] rwsem_down_read_failed+0x12/0x14 Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff81209f54>] call_rwsem_down_read_failed+0x14/0x30 Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff8143d377>] ? down_read+0x32/0x36 Mar 30 23:53:26 r38-13-78 kernel: [<ffffffffa03dbd20>] nfs4_proc_lock+0x224/0x342 [nfs] Mar 30 23:53:26 r38-13-78 kernel: [<ffffffffa03c19af>] do_setlk+0x61/0xd5 [nfs] Mar 30 23:53:26 r38-13-78 kernel: [<ffffffffa03c1c4a>] nfs_lock+0x170/0x17f [nfs] Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff8113af72>] vfs_lock_file+0x24/0x38 Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff8113b2b9>] fcntl_setlk+0x15e/0x2a6 Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff811056d7>] ? fsnotify_access+0x5d/0x65 Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff81112ad6>] sys_fcntl+0x30e/0x4af Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff8143e890>] ? do_device_not_available+0x9/0xb Mar 30 23:53:26 r38-13-78 kernel: [<ffffffff8100aa52>] system_call_fastpath+0x16/0x1b Mar 30 23:55:26 r38-13-78 kernel: INFO: task iozone:2666 blocked for more than 120 seconds. ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: client hang in lock_flocks() 2011-04-03 15:12 ` Jim Rees @ 2011-04-03 17:02 ` Peng Tao 0 siblings, 0 replies; 4+ messages in thread From: Peng Tao @ 2011-04-03 17:02 UTC (permalink / raw) To: Jim Rees; +Cc: linux-nfs, peter honeyman Hi, Jim, On Sun, Apr 3, 2011 at 11:12 PM, Jim Rees <rees@umich.edu> wrote: > Peng Tao wrote: > > Would you please send the complete trace log, or maybe open a bugzilla > entry and attach it there? > > Here is everything that was reported to me. I can ask for rpc info and a > tcpdump if that would be useful. Yes, rpc info is helpful. Please do 'echo 0 > /proc/sys/sunrpc/rpc_debug' when the hang happens and upload /var/log/messages. And corresponding nfs.ko and sunrpc.ko would help analysis too. -- Thanks, -Bergwolf ^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2011-04-03 17:02 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2011-03-31 16:52 client hang in lock_flocks() Jim Rees
[not found] ` <20110331165258.GA3048-8f4Pc2RrbJmHXe+LvDLADg@public.gmane.org>
2011-04-03 1:37 ` Peng Tao
2011-04-03 15:12 ` Jim Rees
2011-04-03 17:02 ` Peng Tao
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).