Bug 991443

Summary: nfs: dd blocked for more than 120 seconds. nfs server not responding
Product: [Red Hat Storage] Red Hat Gluster Storage Reporter: spandura
Component: glusterfsAssignee: santosh pradhan <spradhan>
Status: CLOSED CURRENTRELEASE QA Contact: spandura
Severity: medium Docs Contact:
Priority: medium    
Version: 2.1CC: rhs-bugs, shaines, spandura, vagarwal, vbellur
Target Milestone: ---Keywords: ZStream
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-09-24 15:53:15 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description spandura 2013-08-02 12:09:36 UTC
Description of problem:
========================
On a replicate volume dd on nfs mount got blocked for sometime. Following is the dmesg output

Jul 25 17:31:50 darrel kernel: INFO: task dd:10309 blocked for more than 120 seconds.
Jul 25 17:31:50 darrel kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 25 17:31:50 darrel kernel: dd            D 0000000000000000     0 10309  10231 0x00000080
Jul 25 17:31:50 darrel kernel: ffff88010866fc88 0000000000000082 0000000000000000 0000000000000212
Jul 25 17:31:50 darrel kernel: ffff88010866fc68 ffffffff8132242b ffff880100000014 ffff88010866fdb8
Jul 25 17:31:50 darrel kernel: ffff88011c80f058 ffff88010866ffd8 000000000000fb88 ffff88011c80f058
Jul 25 17:31:50 darrel kernel: Call Trace:
Jul 25 17:31:50 darrel kernel: [<ffffffff8132242b>] ? mix_pool_bytes_extract+0x16b/0x180
Jul 25 17:31:50 darrel kernel: [<ffffffff8150f1ee>] __mutex_lock_slowpath+0x13e/0x180
Jul 25 17:31:50 darrel kernel: [<ffffffff8150f08b>] mutex_lock+0x2b/0x50
Jul 25 17:31:50 darrel kernel: [<ffffffff8111c461>] generic_file_aio_write+0x71/0x100
Jul 25 17:31:50 darrel kernel: [<ffffffffa0209f9e>] nfs_file_write+0xde/0x1f0 [nfs]
Jul 25 17:31:50 darrel kernel: [<ffffffff81180d7a>] do_sync_write+0xfa/0x140
Jul 25 17:31:50 darrel kernel: [<ffffffff81096ca0>] ? autoremove_wake_function+0x0/0x40
Jul 25 17:31:50 darrel kernel: [<ffffffff813230bf>] ? extract_entropy_user+0xbf/0x130
Jul 25 17:31:50 darrel kernel: [<ffffffff81228d5b>] ? selinux_file_permission+0xfb/0x150
Jul 25 17:31:50 darrel kernel: [<ffffffff8121bc36>] ? security_file_permission+0x16/0x20
Jul 25 17:31:50 darrel kernel: [<ffffffff81181078>] vfs_write+0xb8/0x1a0
Jul 25 17:31:50 darrel kernel: [<ffffffff81181971>] sys_write+0x51/0x90
Jul 25 17:31:50 darrel kernel: [<ffffffff810dc645>] ? __audit_syscall_exit+0x265/0x290
Jul 25 17:31:50 darrel kernel: [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Jul 25 17:31:50 darrel kernel: INFO: task dd:10310 blocked for more than 120 seconds.
Jul 25 17:31:50 darrel kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 25 17:31:50 darrel kernel: dd            D 0000000000000000     0 10310   7785 0x00000080
Jul 25 17:31:50 darrel kernel: ffff88010863b978 0000000000000082 ffff8801ffffffff 00203398417876c0
Jul 25 17:31:50 darrel kernel: ffff880116a0d4f0 ffff880118a6dde0 000000000127025c ffffffffae11ffd2
Jul 25 17:31:50 darrel kernel: ffff88011935d058 ffff88010863bfd8 000000000000fb88 ffff88011935d058
Jul 25 17:31:50 darrel kernel: Call Trace:
Jul 25 17:31:50 darrel kernel: [<ffffffff810a1ac9>] ? ktime_get_ts+0xa9/0xe0
Jul 25 17:31:50 darrel kernel: [<ffffffff81119db0>] ? sync_page+0x0/0x50
Jul 25 17:31:50 darrel kernel: [<ffffffff8150e323>] io_schedule+0x73/0xc0
Jul 25 17:31:50 darrel kernel: [<ffffffff81119ded>] sync_page+0x3d/0x50
Jul 25 17:31:50 darrel kernel: [<ffffffff8150ecdf>] __wait_on_bit+0x5f/0x90
Jul 25 17:31:50 darrel kernel: [<ffffffffa0219e61>] ? nfs_writepage_locked+0x91/0xc0 [nfs]
Jul 25 17:31:50 darrel kernel: [<ffffffff8111a023>] wait_on_page_bit+0x73/0x80
Jul 25 17:31:50 darrel kernel: [<ffffffff81096ce0>] ? wake_bit_function+0x0/0x50
Jul 25 17:31:50 darrel kernel: [<ffffffffa021bc04>] nfs_wb_page+0xb4/0xd0 [nfs]
Jul 25 17:31:50 darrel kernel: [<ffffffffa0219b90>] ? nfs_page_find_request+0x50/0x70 [nfs]
Jul 25 17:31:50 darrel kernel: [<ffffffffa021c14f>] nfs_flush_incompatible+0x4f/0x90 [nfs]
Jul 25 17:31:50 darrel kernel: [<ffffffffa0209293>] nfs_write_begin+0x93/0x220 [nfs]
Jul 25 17:31:50 darrel kernel: [<ffffffff8100bb8e>] ? apic_timer_interrupt+0xe/0x20
Jul 25 17:31:50 darrel kernel: [<ffffffff8111a753>] generic_file_buffered_write+0x123/0x2e0
Jul 25 17:31:50 darrel kernel: [<ffffffff8111c1c0>] __generic_file_aio_write+0x260/0x490
Jul 25 17:31:50 darrel kernel: [<ffffffff813229ff>] ? extract_buf+0x9f/0x130
Jul 25 17:31:50 darrel kernel: [<ffffffff8111c478>] generic_file_aio_write+0x88/0x100
Jul 25 17:31:50 darrel kernel: [<ffffffffa0209f9e>] nfs_file_write+0xde/0x1f0 [nfs]
Jul 25 17:31:50 darrel kernel: [<ffffffff81180d7a>] do_sync_write+0xfa/0x140
Jul 25 17:31:50 darrel kernel: [<ffffffff81096ca0>] ? autoremove_wake_function+0x0/0x40
Jul 25 17:31:50 darrel kernel: [<ffffffff813230bf>] ? extract_entropy_user+0xbf/0x130
Jul 25 17:31:50 darrel kernel: [<ffffffff81228d5b>] ? selinux_file_permission+0xfb/0x150
Jul 25 17:31:50 darrel kernel: [<ffffffff8121bc36>] ? security_file_permission+0x16/0x20
Jul 25 17:31:50 darrel kernel: [<ffffffff81181078>] vfs_write+0xb8/0x1a0
Jul 25 17:31:50 darrel kernel: [<ffffffff81181971>] sys_write+0x51/0x90
Jul 25 17:31:50 darrel kernel: [<ffffffff810dc645>] ? __audit_syscall_exit+0x265/0x290
Jul 25 17:31:50 darrel kernel: [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Jul 25 17:33:50 darrel kernel: INFO: task dd:10309 blocked for more than 120 seconds.
Jul 25 17:33:50 darrel kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 25 17:33:50 darrel kernel: dd            D 0000000000000000     0 10309  10231 0x00000080
Jul 25 17:33:50 darrel kernel: ffff88010866fc88 0000000000000082 0000000000000000 0000000000000212
Jul 25 17:33:50 darrel kernel: ffff88010866fc68 ffffffff8132242b ffff880100000014 ffff88010866fdb8
Jul 25 17:33:50 darrel kernel: ffff88011c80f058 ffff88010866ffd8 000000000000fb88 ffff88011c80f058
Jul 25 17:33:50 darrel kernel: Call Trace:
Jul 25 17:33:50 darrel kernel: [<ffffffff8132242b>] ? mix_pool_bytes_extract+0x16b/0x180
Jul 25 17:33:50 darrel kernel: [<ffffffff8150f1ee>] __mutex_lock_slowpath+0x13e/0x180
Jul 25 17:33:50 darrel kernel: [<ffffffff8150f08b>] mutex_lock+0x2b/0x50
Jul 25 17:33:50 darrel kernel: [<ffffffff8111c461>] generic_file_aio_write+0x71/0x100
Jul 25 17:33:50 darrel kernel: [<ffffffffa0209f9e>] nfs_file_write+0xde/0x1f0 [nfs]
Jul 25 17:33:50 darrel kernel: [<ffffffff81180d7a>] do_sync_write+0xfa/0x140
Jul 25 17:33:50 darrel kernel: [<ffffffff81096ca0>] ? autoremove_wake_function+0x0/0x40
Jul 25 17:33:50 darrel kernel: [<ffffffff813230bf>] ? extract_entropy_user+0xbf/0x130
Jul 25 17:33:50 darrel kernel: [<ffffffff81228d5b>] ? selinux_file_permission+0xfb/0x150
Jul 25 17:33:50 darrel kernel: [<ffffffff8121bc36>] ? security_file_permission+0x16/0x20
Jul 25 17:33:50 darrel kernel: [<ffffffff81181078>] vfs_write+0xb8/0x1a0
Jul 25 17:33:50 darrel kernel: [<ffffffff81181971>] sys_write+0x51/0x90
Jul 25 17:33:50 darrel kernel: [<ffffffff810dc645>] ? __audit_syscall_exit+0x265/0x290
Jul 25 17:33:50 darrel kernel: [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Jul 25 17:33:50 darrel kernel: INFO: task dd:10310 blocked for more than 120 seconds.
Jul 25 17:33:50 darrel kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 25 17:33:50 darrel kernel: dd            D 0000000000000000     0 10310   7785 0x00000080
Jul 25 17:33:50 darrel kernel: ffff88010863b978 0000000000000082 ffff8801ffffffff 00203398417876c0
Jul 25 17:33:50 darrel kernel: ffff880116a0d4f0 ffff880118a6dde0 000000000127025c ffffffffae11ffd2
Jul 25 17:33:50 darrel kernel: ffff88011935d058 ffff88010863bfd8 000000000000fb88 ffff88011935d058
Jul 25 17:33:50 darrel kernel: Call Trace:
Jul 25 17:33:50 darrel kernel: [<ffffffff810a1ac9>] ? ktime_get_ts+0xa9/0xe0
Jul 25 17:33:50 darrel kernel: [<ffffffff81119db0>] ? sync_page+0x0/0x50
Jul 25 17:33:50 darrel kernel: [<ffffffff8150e323>] io_schedule+0x73/0xc0
Jul 25 17:33:50 darrel kernel: [<ffffffff81119ded>] sync_page+0x3d/0x50
Jul 25 17:33:50 darrel kernel: [<ffffffff8150ecdf>] __wait_on_bit+0x5f/0x90
Jul 25 17:33:50 darrel kernel: [<ffffffffa0219e61>] ? nfs_writepage_locked+0x91/0xc0 [nfs]
Jul 25 17:33:50 darrel kernel: [<ffffffff8111a023>] wait_on_page_bit+0x73/0x80
Jul 25 17:33:50 darrel kernel: [<ffffffff81096ce0>] ? wake_bit_function+0x0/0x50
Jul 25 17:33:50 darrel kernel: [<ffffffffa021bc04>] nfs_wb_page+0xb4/0xd0 [nfs]
Jul 25 17:33:50 darrel kernel: [<ffffffffa0219b90>] ? nfs_page_find_request+0x50/0x70 [nfs]
Jul 25 17:33:50 darrel kernel: [<ffffffffa021c14f>] nfs_flush_incompatible+0x4f/0x90 [nfs]
Jul 25 17:33:50 darrel kernel: [<ffffffffa0209293>] nfs_write_begin+0x93/0x220 [nfs]
Jul 25 17:33:50 darrel kernel: [<ffffffff8100bb8e>] ? apic_timer_interrupt+0xe/0x20
Jul 25 17:33:50 darrel kernel: [<ffffffff8111a753>] generic_file_buffered_write+0x123/0x2e0
Jul 25 17:33:50 darrel kernel: [<ffffffff8111c1c0>] __generic_file_aio_write+0x260/0x490
Jul 25 17:33:50 darrel kernel: [<ffffffff813229ff>] ? extract_buf+0x9f/0x130
Jul 25 17:33:50 darrel kernel: [<ffffffff8111c478>] generic_file_aio_write+0x88/0x100
Jul 25 17:33:50 darrel kernel: [<ffffffffa0209f9e>] nfs_file_write+0xde/0x1f0 [nfs]
Jul 25 17:33:50 darrel kernel: [<ffffffff81180d7a>] do_sync_write+0xfa/0x140
Jul 25 17:33:50 darrel kernel: [<ffffffff81096ca0>] ? autoremove_wake_function+0x0/0x40
Jul 25 17:33:50 darrel kernel: [<ffffffff813230bf>] ? extract_entropy_user+0xbf/0x130
Jul 25 17:33:50 darrel kernel: [<ffffffff81228d5b>] ? selinux_file_permission+0xfb/0x150
Jul 25 17:33:50 darrel kernel: [<ffffffff8121bc36>] ? security_file_permission+0x16/0x20
Jul 25 17:33:50 darrel kernel: [<ffffffff81181078>] vfs_write+0xb8/0x1a0
Jul 25 17:33:50 darrel kernel: [<ffffffff81181971>] sys_write+0x51/0x90
Jul 25 17:33:50 darrel kernel: [<ffffffff810dc645>] ? __audit_syscall_exit+0x265/0x290
Jul 25 17:33:50 darrel kernel: [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Jul 25 17:35:50 darrel kernel: INFO: task dd:10309 blocked for more than 120 seconds.
Jul 25 17:35:50 darrel kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 25 17:35:50 darrel kernel: dd            D 0000000000000000     0 10309  10231 0x00000080
Jul 25 17:35:50 darrel kernel: ffff88010866fc88 0000000000000082 0000000000000000 0000000000000212
Jul 25 17:35:50 darrel kernel: ffff88010866fc68 ffffffff8132242b ffff880100000014 ffff88010866fdb8
Jul 25 17:35:50 darrel kernel: ffff88011c80f058 ffff88010866ffd8 000000000000fb88 ffff88011c80f058
Jul 25 17:35:50 darrel kernel: Call Trace:
Jul 25 17:35:50 darrel kernel: [<ffffffff8132242b>] ? mix_pool_bytes_extract+0x16b/0x180
Jul 25 17:35:50 darrel kernel: [<ffffffff8150f1ee>] __mutex_lock_slowpath+0x13e/0x180
Jul 25 17:35:50 darrel kernel: [<ffffffff8150f08b>] mutex_lock+0x2b/0x50
Jul 25 17:35:50 darrel kernel: [<ffffffff8111c461>] generic_file_aio_write+0x71/0x100
Jul 25 17:35:50 darrel kernel: [<ffffffffa0209f9e>] nfs_file_write+0xde/0x1f0 [nfs]
Jul 25 17:35:50 darrel kernel: [<ffffffff81180d7a>] do_sync_write+0xfa/0x140
Jul 25 17:35:50 darrel kernel: [<ffffffff81096ca0>] ? autoremove_wake_function+0x0/0x40
Jul 25 17:35:50 darrel kernel: [<ffffffff813230bf>] ? extract_entropy_user+0xbf/0x130
Jul 25 17:35:50 darrel kernel: [<ffffffff81228d5b>] ? selinux_file_permission+0xfb/0x150
Jul 25 17:35:50 darrel kernel: [<ffffffff8121bc36>] ? security_file_permission+0x16/0x20
Jul 25 17:35:50 darrel kernel: [<ffffffff81181078>] vfs_write+0xb8/0x1a0
Jul 25 17:35:50 darrel kernel: [<ffffffff81181971>] sys_write+0x51/0x90
Jul 25 17:35:50 darrel kernel: [<ffffffff810dc645>] ? __audit_syscall_exit+0x265/0x290
Jul 25 17:35:50 darrel kernel: [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Jul 25 17:35:50 darrel kernel: INFO: task dd:10310 blocked for more than 120 seconds.
Jul 25 17:35:50 darrel kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 25 17:35:50 darrel kernel: dd            D 0000000000000000     0 10310   7785 0x00000080
Jul 25 17:35:50 darrel kernel: ffff88010863b978 0000000000000082 ffff8801ffffffff 00203398417876c0
Jul 25 17:35:50 darrel kernel: ffff880116a0d4f0 ffff880118a6dde0 000000000127025c ffffffffae11ffd2
Jul 25 17:35:50 darrel kernel: ffff88011935d058 ffff88010863bfd8 000000000000fb88 ffff88011935d058
Jul 25 17:35:50 darrel kernel: Call Trace:
Jul 25 17:35:50 darrel kernel: [<ffffffff810a1ac9>] ? ktime_get_ts+0xa9/0xe0
Jul 25 17:35:50 darrel kernel: [<ffffffff81119db0>] ? sync_page+0x0/0x50
Jul 25 17:35:50 darrel kernel: [<ffffffff8150e323>] io_schedule+0x73/0xc0
Jul 25 17:35:50 darrel kernel: [<ffffffff81119ded>] sync_page+0x3d/0x50
Jul 25 17:35:50 darrel kernel: [<ffffffff8150ecdf>] __wait_on_bit+0x5f/0x90
Jul 25 17:35:50 darrel kernel: [<ffffffffa0219e61>] ? nfs_writepage_locked+0x91/0xc0 [nfs]
Jul 25 17:35:50 darrel kernel: [<ffffffff8111a023>] wait_on_page_bit+0x73/0x80
Jul 25 17:35:50 darrel kernel: [<ffffffff81096ce0>] ? wake_bit_function+0x0/0x50
Jul 25 17:35:50 darrel kernel: [<ffffffffa021bc04>] nfs_wb_page+0xb4/0xd0 [nfs]
Jul 25 17:35:50 darrel kernel: [<ffffffffa0219b90>] ? nfs_page_find_request+0x50/0x70 [nfs]
Jul 25 17:35:50 darrel kernel: [<ffffffffa021c14f>] nfs_flush_incompatible+0x4f/0x90 [nfs]
Jul 25 17:35:50 darrel kernel: [<ffffffffa0209293>] nfs_write_begin+0x93/0x220 [nfs]
Jul 25 17:35:50 darrel kernel: [<ffffffff8100bb8e>] ? apic_timer_interrupt+0xe/0x20
Jul 25 17:35:50 darrel kernel: [<ffffffff8111a753>] generic_file_buffered_write+0x123/0x2e0
Jul 25 17:35:50 darrel kernel: [<ffffffff8111c1c0>] __generic_file_aio_write+0x260/0x490
Jul 25 17:35:50 darrel kernel: [<ffffffff813229ff>] ? extract_buf+0x9f/0x130
Jul 25 17:35:50 darrel kernel: [<ffffffff8111c478>] generic_file_aio_write+0x88/0x100
Jul 25 17:35:50 darrel kernel: [<ffffffffa0209f9e>] nfs_file_write+0xde/0x1f0 [nfs]
Jul 25 17:35:50 darrel kernel: [<ffffffff81180d7a>] do_sync_write+0xfa/0x140
Jul 25 17:35:50 darrel kernel: [<ffffffff81096ca0>] ? autoremove_wake_function+0x0/0x40
Jul 25 17:35:50 darrel kernel: [<ffffffff813230bf>] ? extract_entropy_user+0xbf/0x130
Jul 25 17:35:50 darrel kernel: [<ffffffff81228d5b>] ? selinux_file_permission+0xfb/0x150
Jul 25 17:35:50 darrel kernel: [<ffffffff8121bc36>] ? security_file_permission+0x16/0x20
Jul 25 17:35:50 darrel kernel: [<ffffffff81181078>] vfs_write+0xb8/0x1a0
Jul 25 17:35:50 darrel kernel: [<ffffffff81181971>] sys_write+0x51/0x90
Jul 25 17:35:50 darrel kernel: [<ffffffff810dc645>] ? __audit_syscall_exit+0x265/0x290
Jul 25 17:35:50 darrel kernel: [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Jul 25 17:37:50 darrel kernel: INFO: task dd:10309 blocked for more than 120 seconds.
Jul 25 17:37:50 darrel kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 25 17:37:50 darrel kernel: dd            D 0000000000000000     0 10309  10231 0x00000080
Jul 25 17:37:50 darrel kernel: ffff88010866fc88 0000000000000082 0000000000000000 0000000000000212
Jul 25 17:37:50 darrel kernel: ffff88010866fc68 ffffffff8132242b ffff880100000014 ffff88010866fdb8
Jul 25 17:37:50 darrel kernel: ffff88011c80f058 ffff88010866ffd8 000000000000fb88 ffff88011c80f058
Jul 25 17:37:50 darrel kernel: Call Trace:
Jul 25 17:37:50 darrel kernel: [<ffffffff8132242b>] ? mix_pool_bytes_extract+0x16b/0x180
Jul 25 17:37:50 darrel kernel: [<ffffffff8150f1ee>] __mutex_lock_slowpath+0x13e/0x180
Jul 25 17:37:50 darrel kernel: [<ffffffff8150f08b>] mutex_lock+0x2b/0x50
Jul 25 17:37:50 darrel kernel: [<ffffffff8111c461>] generic_file_aio_write+0x71/0x100
Jul 25 17:37:50 darrel kernel: [<ffffffffa0209f9e>] nfs_file_write+0xde/0x1f0 [nfs]
Jul 25 17:37:50 darrel kernel: [<ffffffff81180d7a>] do_sync_write+0xfa/0x140
Jul 25 17:37:50 darrel kernel: [<ffffffff81096ca0>] ? autoremove_wake_function+0x0/0x40
Jul 25 17:37:50 darrel kernel: [<ffffffff813230bf>] ? extract_entropy_user+0xbf/0x130
Jul 25 17:37:50 darrel kernel: [<ffffffff81228d5b>] ? selinux_file_permission+0xfb/0x150
Jul 25 17:37:50 darrel kernel: [<ffffffff8121bc36>] ? security_file_permission+0x16/0x20
Jul 25 17:37:50 darrel kernel: [<ffffffff81181078>] vfs_write+0xb8/0x1a0
Jul 25 17:37:50 darrel kernel: [<ffffffff81181971>] sys_write+0x51/0x90
Jul 25 17:37:50 darrel kernel: [<ffffffff810dc645>] ? __audit_syscall_exit+0x265/0x290
Jul 25 17:37:50 darrel kernel: [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Jul 25 17:37:50 darrel kernel: INFO: task dd:10310 blocked for more than 120 seconds.
Jul 25 17:37:50 darrel kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 25 17:37:50 darrel kernel: dd            D 0000000000000000     0 10310   7785 0x00000080
Jul 25 17:37:50 darrel kernel: ffff88010863b978 0000000000000082 ffff8801ffffffff 00203398417876c0
Jul 25 17:37:50 darrel kernel: ffff880116a0d4f0 ffff880118a6dde0 000000000127025c ffffffffae11ffd2
Jul 25 17:37:50 darrel kernel: ffff88011935d058 ffff88010863bfd8 000000000000fb88 ffff88011935d058
Jul 25 17:37:50 darrel kernel: Call Trace:
Jul 25 17:37:50 darrel kernel: [<ffffffff810a1ac9>] ? ktime_get_ts+0xa9/0xe0
Jul 25 17:37:50 darrel kernel: [<ffffffff81119db0>] ? sync_page+0x0/0x50
Jul 25 17:37:50 darrel kernel: [<ffffffff8150e323>] io_schedule+0x73/0xc0
Jul 25 17:37:50 darrel kernel: [<ffffffff81119ded>] sync_page+0x3d/0x50
Jul 25 17:37:50 darrel kernel: [<ffffffff8150ecdf>] __wait_on_bit+0x5f/0x90
Jul 25 17:37:50 darrel kernel: [<ffffffffa0219e61>] ? nfs_writepage_locked+0x91/0xc0 [nfs]
Jul 25 17:37:50 darrel kernel: [<ffffffff8111a023>] wait_on_page_bit+0x73/0x80
Jul 25 17:37:50 darrel kernel: [<ffffffff81096ce0>] ? wake_bit_function+0x0/0x50
Jul 25 17:37:50 darrel kernel: [<ffffffffa021bc04>] nfs_wb_page+0xb4/0xd0 [nfs]
Jul 25 17:37:50 darrel kernel: [<ffffffffa0219b90>] ? nfs_page_find_request+0x50/0x70 [nfs]
Jul 25 17:37:50 darrel kernel: [<ffffffffa021c14f>] nfs_flush_incompatible+0x4f/0x90 [nfs]
Jul 25 17:37:50 darrel kernel: [<ffffffffa0209293>] nfs_write_begin+0x93/0x220 [nfs]
Jul 25 17:37:50 darrel kernel: [<ffffffff8100bb8e>] ? apic_timer_interrupt+0xe/0x20
Jul 25 17:37:50 darrel kernel: [<ffffffff8111a753>] generic_file_buffered_write+0x123/0x2e0
Jul 25 17:37:50 darrel kernel: [<ffffffff8111c1c0>] __generic_file_aio_write+0x260/0x490
Jul 25 17:37:50 darrel kernel: [<ffffffff813229ff>] ? extract_buf+0x9f/0x130
Jul 25 17:37:50 darrel kernel: [<ffffffff8111c478>] generic_file_aio_write+0x88/0x100
Jul 25 17:37:50 darrel kernel: [<ffffffffa0209f9e>] nfs_file_write+0xde/0x1f0 [nfs]
Jul 25 17:37:50 darrel kernel: [<ffffffff81180d7a>] do_sync_write+0xfa/0x140
Jul 25 17:37:50 darrel kernel: [<ffffffff81096ca0>] ? autoremove_wake_function+0x0/0x40
Jul 25 17:37:50 darrel kernel: [<ffffffff813230bf>] ? extract_entropy_user+0xbf/0x130
Jul 25 17:37:50 darrel kernel: [<ffffffff81228d5b>] ? selinux_file_permission+0xfb/0x150
Jul 25 17:37:50 darrel kernel: [<ffffffff8121bc36>] ? security_file_permission+0x16/0x20
Jul 25 17:37:50 darrel kernel: [<ffffffff81181078>] vfs_write+0xb8/0x1a0
Jul 25 17:37:50 darrel kernel: [<ffffffff81181971>] sys_write+0x51/0x90
Jul 25 17:37:50 darrel kernel: [<ffffffff810dc645>] ? __audit_syscall_exit+0x265/0x290
Jul 25 17:37:50 darrel kernel: [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b

Version-Release number of selected component (if applicable):
==============================================================
root@rhs-client13 [Jul-26-2013-15:20:41] >rpm -qa | grep glusterfs-server
glusterfs-server-3.4.0.12rhs.beta6-1.el6rhs.x86_64

root@rhs-client13 [Jul-26-2013-15:20:44] >gluster --version
glusterfs 3.4.0.12rhs.beta6 built on Jul 23 2013 16:20:03

How reproducible:
=================

Steps to Reproduce:
=====================
1. Create a 1 x 2 replicate volume with 2 storage nodes and 1 brick per storage node. set the background-self-heal-count to 0, data-self-heal "off", self-heal-daemon off

2. create fuse and nfs mount. create fuse and nfs directories from any mount point

3. from fuse mount cd to fuse directory and execute "dd if=/dev/urandom of=test bs=1M count=10240" 

4. from nfs mount cd to nfs directory and execute "dd if=/dev/urandom of=test bs=1M count=10240" 

5. while the dd on both the mount points is in progress , killall the gluster process from storage_node2

6. delete the brick directory and recreate the brick directory on storage_node2. 

7. after a while when dd is still in progress, start glusterd on storage_node2. (this will start the brick, nfs process)

Additional info: 
==================
Found this issue while recreating the bug 928172 . Please refer comment 12 to comment 14 of the bug 928172.

Comment 2 santosh pradhan 2013-08-05 09:20:16 UTC
1. Not able to reproduce the issue in my setup (I followed the steps mentioned above).

2. There could be multiple reasons why dd hanged for 120 seconds. If the flushing of the caches in the server side takes more than 120 secs, then client ll see this traces in syslog. Either the size of the cache is high (VM tunables) or the disk performance is slow (takes longer to write the data).

Or there could be network issues which congests the NFS traffic. (nfsstat -rc will confirm if there is more retransmissions). Also the netstat -s ll tell if there is any network issue. Because there ll be lots of network packets going on (dd on fuse and nfs). The server should be able to handle the network pressure.

Will work with Shwetha to reproduce the issue in my setup.

Comment 3 santosh pradhan 2013-08-05 09:21:20 UTC
Again I would like to know if the dd failed ? If not, it's not an issue.

Comment 4 santosh pradhan 2013-08-06 11:31:13 UTC

Hi Shwetha,

I guess server (where NFS server runs) might be with low memory (~4GB) or so and the disk I/O is not faster. As you are doing I/O (write) both from FUSE and NFS mount point, the I/O is not getting flushed faster (as we would like) and builds back pressure on the NFS client.

If the flushing of the caches in server takes more than 120 seconds, then all subsequent NFS write op would be in sync behaviour which ll make the performance even worse and dumps the stacktraces in the syslog as you got.

(In server side)Also you need to check netstat -s output if the pressure is too much in the TCP/IP stack which would result of packets pruned or dropped or data lost.

In client side, nfsstat -v3 would show rpc retransmissions which means server is not writing the data fast enough to disk and causing the issues.

I would suggest you try NFS and FUSE I/O separately to narrow down the issue. Let me know if you still see the issue.

Also I would like to know if the dd on NFS mount point failed?

Because both mount point ll write the data to same bricks/disks.

Thanks,
Santosh

Comment 5 santosh pradhan 2013-08-26 08:11:25 UTC

This has been lying in "needinfo" state since a long time. Can I have a update please?

Comment 7 spandura 2013-09-24 12:41:45 UTC
Executed the case on build : glusterfs 3.4.0.33rhs built on Sep  8 2013 13:20:26

In this run executed the case only on nfs  mount. 

Test case:-
===============
1. Create a 1 x 2 replicate volume with 2 storage nodes and 1 brick per storage node. set the background-self-heal-count to 0, data-self-heal "off", self-heal-daemon off

2. create 4 nfs mount. 

3. from nfs mount cd to nfs directory and execute "dd if=/dev/urandom of=test bs=1M count=10240" 

4. while the dd on both the mount points is in progress , killall the gluster process from storage_node2

5. delete the brick directory and recreate the brick directory on storage_node2. 

6. after a while when dd is still in progress, start glusterd on storage_node2. (this will start the brick, nfs process)

Unable to recreate the issue.

Comment 8 santosh pradhan 2013-09-24 15:53:15 UTC

Lets close the issue then.