Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
For bugs related to Red Hat Enterprise Linux 5 product line. The current stable release is 5.10. For Red Hat Enterprise Linux 6 and above, please visit Red Hat JIRA https://issues.redhat.com/secure/CreateIssue!default.jspa?pid=12332745 to report new issues.

Bug 483541

Summary: gfs2 blocked after recovery
Product: Red Hat Enterprise Linux 5 Reporter: Steve Whitehouse <swhiteho>
Component: kernelAssignee: Steve Whitehouse <swhiteho>
Status: CLOSED ERRATA QA Contact: Cluster QE <mspqa-list>
Severity: medium Docs Contact:
Priority: high    
Version: 5.4CC: adas, agk, cfeist, czhang, dzickus, fdinitto, lwang, nstraz, rpeterso, sghosh, swhiteho
Target Milestone: rc   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: 482760 Environment:
Last Closed: 2009-09-02 08:36:24 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 482760    
Bug Blocks: 483701, 514700    
Attachments:
Description Flags
RHEL5 version of the above patch none

Description Steve Whitehouse 2009-02-02 10:18:34 UTC 
+++ This bug was initially created as a clone of Bug #482760 +++

Description of problem:

Running 2.6.29-rc2, STABLE3 branch of cluster.git.

make_panic running on four nodes, kill one, recovery happens,
make_panic and any other fs access stilll blocked.

bull-01

INFO: task glock_workqueue:8787 blocked for more than 480 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
glock_workque D 0000000000000001     0  8787      2
 ffff8801395ebbf0 0000000000000046 ffff8801395ebba0 0000000000000046
 0000000000000002 ffff880137cbc440 ffff88007f6ac240 ffff880137cbc7b8
 0000000100338513 0000000028028ec0 0000000000000282 0000000000000282
Call Trace:
 [<ffffffffa046b4a0>] just_schedule+0x9/0xd [gfs2]
 [<ffffffff804cf101>] __wait_on_bit+0x45/0x76
 [<ffffffffa046b497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffffa046b497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffff804cf1a0>] out_of_line_wait_on_bit+0x6e/0x7b
 [<ffffffff8024f7e0>] ? wake_bit_function+0x0/0x2a
 [<ffffffffa046b490>] gfs2_glock_wait+0x42/0x49 [gfs2]
 [<ffffffffa046cf3a>] gfs2_glock_nq+0x279/0x289 [gfs2]
 [<ffffffffa0482352>] gfs2_trans_begin+0xd6/0x142 [gfs2]
 [<ffffffffa046d6b0>] gfs2_ail_empty_gl+0x33/0x142 [gfs2]
 [<ffffffffa046da1f>] meta_go_sync+0x43/0x47 [gfs2]
 [<ffffffffa046c9fa>] do_xmote+0xd0/0x1a6 [gfs2]
 [<ffffffffa046d0af>] ? glock_work_func+0x0/0xf8 [gfs2]
 [<ffffffffa046d0af>] ? glock_work_func+0x0/0xf8 [gfs2]
 [<ffffffffa046cc20>] run_queue+0x150/0x184 [gfs2]
 [<ffffffffa046d0f2>] ? glock_work_func+0x43/0xf8 [gfs2]
 [<ffffffffa046d193>] glock_work_func+0xe4/0xf8 [gfs2]
 [<ffffffff8024bc54>] run_workqueue+0xf5/0x1fd
 [<ffffffff8024bbfe>] ? run_workqueue+0x9f/0x1fd
 [<ffffffff8024c937>] worker_thread+0xdb/0xe8
 [<ffffffff8024f7a8>] ? autoremove_wake_function+0x0/0x38
 [<ffffffff8024c85c>] ? worker_thread+0x0/0xe8
 [<ffffffff8024f685>] kthread+0x49/0x78
 [<ffffffff8020d0fa>] child_rip+0xa/0x20
 [<ffffffff8024f63c>] ? kthread+0x0/0x78
 [<ffffffff8020d0f0>] ? child_rip+0x0/0x20
INFO: lockdep is turned off.
INFO: task gfs2_quotad:9224 blocked for more than 480 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
gfs2_quotad   D 0000000000000000     0  9224      2
 ffff880075837c70 0000000000000046 ffff880075837c20 0000000000000046
 0000000000000002 ffff88007597c580 ffffffff806194c0 ffff88007597c8f8
 000000010033815c 00000000280126c0 0000000000000286 0000000000000286
Call Trace:
 [<ffffffffa046b4a0>] just_schedule+0x9/0xd [gfs2]
 [<ffffffff804cf101>] __wait_on_bit+0x45/0x76
 [<ffffffffa046b497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffffa046b497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffff804cf1a0>] out_of_line_wait_on_bit+0x6e/0x7b
 [<ffffffff8024f7e0>] ? wake_bit_function+0x0/0x2a
 [<ffffffffa046b490>] gfs2_glock_wait+0x42/0x49 [gfs2]
 [<ffffffffa046cf3a>] gfs2_glock_nq+0x279/0x289 [gfs2]
 [<ffffffffa0481261>] gfs2_statfs_sync+0x5c/0x217 [gfs2]
 [<ffffffffa0481259>] ? gfs2_statfs_sync+0x54/0x217 [gfs2]
 [<ffffffffa047b463>] quotad_check_timeo+0x21/0x84 [gfs2]
 [<ffffffffa047ce3b>] gfs2_quotad+0x9e/0x3f1 [gfs2]
 [<ffffffff8024f7a8>] ? autoremove_wake_function+0x0/0x38
 [<ffffffffa047cd9d>] ? gfs2_quotad+0x0/0x3f1 [gfs2]
 [<ffffffff8024f685>] kthread+0x49/0x78
 [<ffffffff8020d0fa>] child_rip+0xa/0x20
 [<ffffffff8024f63c>] ? kthread+0x0/0x78
 [<ffffffff8020d0f0>] ? child_rip+0x0/0x20
INFO: lockdep is turned off.
INFO: task make_panic:9238 blocked for more than 480 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
make_panic    D 0000000000000001     0  9238   3276
 ffff88013951dae8 0000000000000046 ffff88013951da98 0000000000000046
 0000000000000002 ffff88013951eb40 ffff88007dc46a80 ffff88013951eeb8
 ffff88008362a3f0 ffff88008362a3f0 0000000000000292 0000000000000292
Call Trace:
 [<ffffffffa046b4a0>] just_schedule+0x9/0xd [gfs2]
 [<ffffffff804cf101>] __wait_on_bit+0x45/0x76
 [<ffffffffa046b497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffffa046b497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffff804cf1a0>] out_of_line_wait_on_bit+0x6e/0x7b
 [<ffffffff8024f7e0>] ? wake_bit_function+0x0/0x2a
 [<ffffffffa046b490>] gfs2_glock_wait+0x42/0x49 [gfs2]
 [<ffffffffa046cf3a>] gfs2_glock_nq+0x279/0x289 [gfs2]
 [<ffffffffa0478906>] gfs2_permission+0xeb/0x109 [gfs2]
 [<ffffffffa04788fe>] ? gfs2_permission+0xe3/0x109 [gfs2]
 [<ffffffff802b4e5c>] inode_permission+0x69/0x97
 [<ffffffff802b6c75>] __link_path_walk+0x160/0xcb3
 [<ffffffff8022dd3f>] ? __wake_up+0x43/0x4f
 [<ffffffff8025a692>] ? print_lock_contention_bug+0x1b/0xe1
 [<ffffffff802b7816>] path_walk+0x4e/0x97
 [<ffffffff802b7a00>] do_path_lookup+0x118/0x175
 [<ffffffff802b85dd>] path_lookup_open+0x5a/0x9b
 [<ffffffff802b8872>] do_filp_open+0xb9/0x822
 [<ffffffff8025a692>] ? print_lock_contention_bug+0x1b/0xe1
 [<ffffffff802c1013>] ? alloc_fd+0x33/0x11e
 [<ffffffff804d0dc9>] ? _spin_unlock+0x26/0x2a
 [<ffffffff802c10ef>] ? alloc_fd+0x10f/0x11e
 [<ffffffff802ac104>] do_sys_open+0x4f/0x89
 [<ffffffff802ac167>] sys_open+0x1b/0x1d
 [<ffffffff8020c05b>] system_call_fastpath+0x16/0x1b
INFO: lockdep is turned off.
INFO: task pdflush:298 blocked for more than 480 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
pdflush       D 0000000000000000     0   298      2
 ffff88007eaadb70 0000000000000046 ffff88007eaadb20 0000000000000046
 0000000000000002 ffff88007eaaa940 ffffffff806194c0 ffff88007eaaacb8
 000000010032f63c 00000000280176c0 0000000000000286 0000000000000286
Call Trace:
 [<ffffffffa046b4a0>] just_schedule+0x9/0xd [gfs2]
 [<ffffffff804cf101>] __wait_on_bit+0x45/0x76
 [<ffffffffa046b497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffffa046b497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffff804cf1a0>] out_of_line_wait_on_bit+0x6e/0x7b
 [<ffffffff8024f7e0>] ? wake_bit_function+0x0/0x2a
 [<ffffffffa046b490>] gfs2_glock_wait+0x42/0x49 [gfs2]
 [<ffffffffa046cf3a>] gfs2_glock_nq+0x279/0x289 [gfs2]
 [<ffffffffa047b325>] gfs2_write_inode+0x67/0x16a [gfs2]
 [<ffffffffa047b31d>] ? gfs2_write_inode+0x5f/0x16a [gfs2]
 [<ffffffff802c7765>] __writeback_single_inode+0x19a/0x29f
 [<ffffffff804d0d6a>] ? _read_unlock+0x26/0x2b
 [<ffffffff802c7c54>] generic_sync_sb_inodes+0x1c5/0x317
 [<ffffffff802c7daf>] sync_sb_inodes+0x9/0xb
 [<ffffffff802c7f80>] writeback_inodes+0x7b/0xca
 [<ffffffff80285944>] wb_kupdate+0x9f/0x10d
 [<ffffffff80285d2d>] ? pdflush+0x0/0x1fc
 [<ffffffff80285e78>] pdflush+0x14b/0x1fc
 [<ffffffff802858a5>] ? wb_kupdate+0x0/0x10d
 [<ffffffff8024f685>] kthread+0x49/0x78
 [<ffffffff8020d0fa>] child_rip+0xa/0x20
 [<ffffffff8024f63c>] ? kthread+0x0/0x78
 [<ffffffff8020d0f0>] ? child_rip+0x0/0x20


bull-02

INFO: task pdflush:298 blocked for more than 480 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
pdflush       D 0000000000000000     0   298      2
 ffff88007ebabb70 0000000000000046 ffff88007ebabb20 0000000000000046
 0000000000000002 ffff88007eba8940 ffffffff806194c0 ffff88007eba8cb8
 00000001001aaa0b 00000000280176c0 0000000000000286 0000000000000286
Call Trace:
 [<ffffffffa03cf4a0>] just_schedule+0x9/0xd [gfs2]
 [<ffffffff804ce941>] __wait_on_bit+0x45/0x76
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffff804ce9e0>] out_of_line_wait_on_bit+0x6e/0x7b
 [<ffffffff8024f5ac>] ? wake_bit_function+0x0/0x2a
 [<ffffffffa03cf490>] gfs2_glock_wait+0x42/0x49 [gfs2]
 [<ffffffffa03d0f32>] gfs2_glock_nq+0x279/0x289 [gfs2]
 [<ffffffffa03df312>] gfs2_write_inode+0x67/0x169 [gfs2]
 [<ffffffffa03df30a>] ? gfs2_write_inode+0x5f/0x169 [gfs2]
 [<ffffffff802c735f>] __writeback_single_inode+0x1a0/0x2a5
 [<ffffffff804d05aa>] ? _read_unlock+0x26/0x2b
 [<ffffffff802c784d>] generic_sync_sb_inodes+0x1c5/0x317
 [<ffffffff802c79a8>] sync_sb_inodes+0x9/0xb
 [<ffffffff802c7b79>] writeback_inodes+0x7b/0xca
 [<ffffffff80285588>] wb_kupdate+0x9f/0x10d
 [<ffffffff80285971>] ? pdflush+0x0/0x1fc
 [<ffffffff80285abc>] pdflush+0x14b/0x1fc
 [<ffffffff802854e9>] ? wb_kupdate+0x0/0x10d
 [<ffffffff8024f451>] kthread+0x49/0x78
 [<ffffffff8020d0fa>] child_rip+0xa/0x20
 [<ffffffff8024f408>] ? kthread+0x0/0x78
 [<ffffffff8020d0f0>] ? child_rip+0x0/0x20
INFO: lockdep is turned off.
INFO: task make_panic:9449 blocked for more than 480 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
make_panic    D 0000000000000001     0  9449   3511
 ffff88013383dae8 0000000000000046 ffff88013383da98 0000000000000046
 0000000000000002 ffff880130446c80 ffff8801339a6200 ffff880130446ff8
 ffff88008362a3f0 ffff88008362a3f0 0000000000000292 0000000000000292
Call Trace:
 [<ffffffffa03cf4a0>] just_schedule+0x9/0xd [gfs2]
 [<ffffffff804ce941>] __wait_on_bit+0x45/0x76
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffff804ce9e0>] out_of_line_wait_on_bit+0x6e/0x7b
 [<ffffffff8024f5ac>] ? wake_bit_function+0x0/0x2a
 [<ffffffffa03cf490>] gfs2_glock_wait+0x42/0x49 [gfs2]
 [<ffffffffa03d0f32>] gfs2_glock_nq+0x279/0x289 [gfs2]
 [<ffffffffa03dc8fe>] gfs2_permission+0xeb/0x109 [gfs2]
 [<ffffffffa03dc8f6>] ? gfs2_permission+0xe3/0x109 [gfs2]
 [<ffffffff802b4a44>] inode_permission+0x69/0x97
 [<ffffffff802b685d>] __link_path_walk+0x160/0xcb2
 [<ffffffff8022dd2f>] ? __wake_up+0x43/0x4f
 [<ffffffff8025a45f>] ? print_lock_contention_bug+0x1b/0xe1
 [<ffffffff802b73fd>] path_walk+0x4e/0x97
 [<ffffffff802b75e7>] do_path_lookup+0x118/0x175
 [<ffffffff802b81c4>] path_lookup_open+0x5a/0x9b
 [<ffffffff802b8459>] do_filp_open+0xb9/0x822
 [<ffffffff8025a45f>] ? print_lock_contention_bug+0x1b/0xe1
 [<ffffffff802c0bff>] ? alloc_fd+0x33/0x11e
 [<ffffffff804d0609>] ? _spin_unlock+0x26/0x2a
 [<ffffffff802c0cdb>] ? alloc_fd+0x10f/0x11e
 [<ffffffff802abcf4>] do_sys_open+0x4f/0x89
 [<ffffffff802abd57>] sys_open+0x1b/0x1d
 [<ffffffff8020c05b>] system_call_fastpath+0x16/0x1b
INFO: lockdep is turned off.
INFO: task gfs2_quotad:9440 blocked for more than 480 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
gfs2_quotad   D 0000000000000001     0  9440      2
 ffff88013189bc70 0000000000000046 ffff88013189bc20 0000000000000046
 0000000000000002 ffff8801319e2480 ffff8801338e82c0 ffff8801319e27f8
 ffff8800836307f0 ffff8800836307f0 0000000000000286 0000000000000286
Call Trace:
 [<ffffffffa03cf4a0>] just_schedule+0x9/0xd [gfs2]
 [<ffffffff804ce941>] __wait_on_bit+0x45/0x76
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffff804ce9e0>] out_of_line_wait_on_bit+0x6e/0x7b
 [<ffffffff8024f5ac>] ? wake_bit_function+0x0/0x2a
 [<ffffffffa03cf490>] gfs2_glock_wait+0x42/0x49 [gfs2]
 [<ffffffffa03d0f32>] gfs2_glock_nq+0x279/0x289 [gfs2]
 [<ffffffffa03e524d>] gfs2_statfs_sync+0x5c/0x217 [gfs2]
 [<ffffffffa03e5245>] ? gfs2_statfs_sync+0x54/0x217 [gfs2]
 [<ffffffffa03df44f>] quotad_check_timeo+0x21/0x84 [gfs2]
 [<ffffffffa03e0e24>] gfs2_quotad+0x9e/0x3f1 [gfs2]
 [<ffffffff8024f574>] ? autoremove_wake_function+0x0/0x38
 [<ffffffffa03e0d86>] ? gfs2_quotad+0x0/0x3f1 [gfs2]
 [<ffffffff8024f451>] kthread+0x49/0x78
 [<ffffffff8020d0fa>] child_rip+0xa/0x20
 [<ffffffff8024f408>] ? kthread+0x0/0x78
 [<ffffffff8020d0f0>] ? child_rip+0x0/0x20
INFO: lockdep is turned off.

bull-04

INFO: task pdflush:298 blocked for more than 480 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
pdflush       D 0000000000000001     0   298      2
 ffff88007ebabb70 0000000000000046 ffff88007ebabb20 0000000000000046
 0000000000000002 ffff88007eba8940 ffff880078126bc0 ffff88007eba8cb8
 ffff8800280176c0 ffff8800280176c0 0000000000000286 0000000000000286
Call Trace:
 [<ffffffffa03cf4a0>] just_schedule+0x9/0xd [gfs2]
 [<ffffffff804ce941>] __wait_on_bit+0x45/0x76
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffff804ce9e0>] out_of_line_wait_on_bit+0x6e/0x7b
 [<ffffffff8024f5ac>] ? wake_bit_function+0x0/0x2a
 [<ffffffffa03cf490>] gfs2_glock_wait+0x42/0x49 [gfs2]
 [<ffffffffa03d0f32>] gfs2_glock_nq+0x279/0x289 [gfs2]
 [<ffffffffa03df312>] gfs2_write_inode+0x67/0x169 [gfs2]
 [<ffffffffa03df30a>] ? gfs2_write_inode+0x5f/0x169 [gfs2]
 [<ffffffff802c735f>] __writeback_single_inode+0x1a0/0x2a5
 [<ffffffff804d05aa>] ? _read_unlock+0x26/0x2b
 [<ffffffff802c784d>] generic_sync_sb_inodes+0x1c5/0x317
 [<ffffffff802c79a8>] sync_sb_inodes+0x9/0xb
 [<ffffffff802c7b79>] writeback_inodes+0x7b/0xca
 [<ffffffff80285588>] wb_kupdate+0x9f/0x10d
 [<ffffffff80285971>] ? pdflush+0x0/0x1fc
 [<ffffffff80285abc>] pdflush+0x14b/0x1fc
 [<ffffffff802854e9>] ? wb_kupdate+0x0/0x10d
 [<ffffffff8024f451>] kthread+0x49/0x78
 [<ffffffff8020d0fa>] child_rip+0xa/0x20
 [<ffffffff8024f408>] ? kthread+0x0/0x78
 [<ffffffff8020d0f0>] ? child_rip+0x0/0x20
INFO: lockdep is turned off.
INFO: task gfs2_quotad:9368 blocked for more than 480 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
gfs2_quotad   D 0000000000000003     0  9368      2
 ffff880055095c70 0000000000000046 ffff880055095c20 0000000000000046
 0000000000000002 ffff8800550920c0 ffff88007f712400 ffff880055092438
 00000001001b4a3d 0000000028012710 0000000000000286 0000000000000286
Call Trace:
 [<ffffffffa03cf4a0>] just_schedule+0x9/0xd [gfs2]
 [<ffffffff804ce941>] __wait_on_bit+0x45/0x76
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffff804ce9e0>] out_of_line_wait_on_bit+0x6e/0x7b
 [<ffffffff8024f5ac>] ? wake_bit_function+0x0/0x2a
 [<ffffffffa03cf490>] gfs2_glock_wait+0x42/0x49 [gfs2]
 [<ffffffffa03d0f32>] gfs2_glock_nq+0x279/0x289 [gfs2]
 [<ffffffffa03e524d>] gfs2_statfs_sync+0x5c/0x217 [gfs2]
 [<ffffffffa03e5245>] ? gfs2_statfs_sync+0x54/0x217 [gfs2]
 [<ffffffffa03df44f>] quotad_check_timeo+0x21/0x84 [gfs2]
 [<ffffffffa03e0e24>] gfs2_quotad+0x9e/0x3f1 [gfs2]
 [<ffffffff8024f574>] ? autoremove_wake_function+0x0/0x38
 [<ffffffffa03e0d86>] ? gfs2_quotad+0x0/0x3f1 [gfs2]
 [<ffffffff8024f451>] kthread+0x49/0x78
 [<ffffffff8020d0fa>] child_rip+0xa/0x20
 [<ffffffff8024f408>] ? kthread+0x0/0x78
 [<ffffffff8020d0f0>] ? child_rip+0x0/0x20
INFO: lockdep is turned off.
INFO: task make_panic:9374 blocked for more than 480 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
make_panic    D 0000000000000000     0  9374   3439
 ffff8801389f5bf8 0000000000000046 ffff8801389f5ba8 0000000000000046
 0000000000000002 ffff880137556280 ffffffff806194c0 ffff8801375565f8
 00000001001ad4aa 0000000083636bf0 0000000000000296 0000000000000296
Call Trace:
 [<ffffffffa03cf4a0>] just_schedule+0x9/0xd [gfs2]
 [<ffffffff804ce941>] __wait_on_bit+0x45/0x76
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffffa03cf497>] ? just_schedule+0x0/0xd [gfs2]
 [<ffffffff804ce9e0>] out_of_line_wait_on_bit+0x6e/0x7b
 [<ffffffff8024f5ac>] ? wake_bit_function+0x0/0x2a
 [<ffffffffa03cf490>] gfs2_glock_wait+0x42/0x49 [gfs2]
 [<ffffffffa03d0f32>] gfs2_glock_nq+0x279/0x289 [gfs2]
 [<ffffffffa03dccc7>] gfs2_unlink+0xeb/0x1c2 [gfs2]
 [<ffffffffa03dcc4e>] ? gfs2_unlink+0x72/0x1c2 [gfs2]
 [<ffffffffa03dcc6f>] ? gfs2_unlink+0x93/0x1c2 [gfs2]
 [<ffffffffa03dcc95>] ? gfs2_unlink+0xb9/0x1c2 [gfs2]
 [<ffffffffa03e3a1f>] ? gfs2_rindex_hold+0x34/0x153 [gfs2]
 [<ffffffff802b5746>] vfs_unlink+0xad/0x105
 [<ffffffff802b7a86>] do_unlinkat+0xc6/0x178
 [<ffffffff802b0c00>] ? sys_newlstat+0x31/0x3c
 [<ffffffff8026f0a0>] ? audit_syscall_entry+0x16b/0x19e
 [<ffffffff802b7b49>] sys_unlink+0x11/0x13
 [<ffffffff8020c05b>] system_call_fastpath+0x16/0x1b



Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:


Additional info:

--- Additional comment from teigland on 2009-01-27 17:28:44 EDT ---

Created an attachment (id=330162)
lockdump

--- Additional comment from teigland on 2009-01-27 17:29:31 EDT ---

Created an attachment (id=330163)
gfs lockdump 2

--- Additional comment from teigland on 2009-01-27 17:30:20 EDT ---

Created an attachment (id=330164)
gfs lockdump 3

--- Additional comment from teigland on 2009-01-27 17:32:31 EDT ---

Created an attachment (id=330165)
dlm lockdebug from all three nodes

--- Additional comment from swhiteho on 2009-01-28 04:06:08 EDT ---

Do you have a stack trace for pid 9238? It looks like that task is blocked due to something holding up the glock workqueue. There are two locks stuck doing a demotion in the lockdump of comment #1, in fact one of those has received a reply but it has not been processed due to the blocked glock workqueue. I'm just not sure why yet.

--- Additional comment from swhiteho on 2009-01-28 04:14:58 EDT ---

Ah, now I can see it, sorry.

So it looks like the workqueue has got stuck trying to do a log flush (due to a glock demote) and that has prevented the completion of the locks upon which make_panic is waiting. Is this a single cpu machine by any chance? I'm guessing that the issue might be that there is only a single workqueue thread in this case. I have a feeling that with multiple workqueue threads, that this wouldn't occur.

--- Additional comment from teigland on 2009-01-28 11:28:42 EDT ---

[root@bull-01 ~]# cat /proc/cpuinfo  | grep processor
processor       : 0
processor       : 1
processor       : 2
processor       : 3

[root@bull-02 ~]# cat /proc/cpuinfo  | grep processor
processor       : 0
processor       : 1
processor       : 2
processor       : 3

[root@bull-04 ~]# cat /proc/cpuinfo  | grep processor
processor       : 0
processor       : 1
processor       : 2
processor       : 3

Feel free to log into these nodes if you need more info, they're still
stuck in this state.

--- Additional comment from swhiteho on 2009-01-28 12:03:45 EDT ---

Ok. I've had a look, and I think I can see whats going on now.

The problem is that the glock workqueue is getting stuck while trying to get the transaction lock. Its trying to get that lock since it needs to start a transaction in order to release a glock (due to GFS2's journalling implementation). Thats then blocking incoming requests from being processed.

Assuming that the reply waiting to be processes happens to be on the same cpu as the stuck thread, then the same thing could happen as in the single thread case.

I need to think about the best way to fix this....

--- Additional comment from swhiteho on 2009-01-30 06:07:49 EDT ---

There seem to be two possible ways to fix this:

1. To change the glock workqueue so that its ok to lock other glocks from the workqueue itself and

2. To change the log code so that we don't need to get a lock at this particular point in time

I've looked into #1 over the last few days, and it seems that its not a good plan as it would be very complicated to do. At the current time I'm hoping that #2 will be better since the only reason we can have got to that particular point in time is because something has been written into the journal. When that happened we grabbed the transaction lock in gfs2_trans_begin() so the obvious solution is to ensure that we don't drop the transaction glock until a later point in time so that we can just "know" that we already hold the lock when a glock is being flushed. We can thus remove the transaction glock from that code path which should resolve the issue and also potentially speed things up a bit.

Although I haven't checked all of the code so far, its even possible that we already hold the transaction glock for long enough already. So in other words, it might be safe just to not take the transaction glock over that critical bit of code. Anyway, I need to check some more things, just to be sure, but it does seem like I'm gradually getting towards a solution now.

--- Additional comment from swhiteho on 2009-01-30 09:53:30 EDT ---

Created an attachment (id=330473)
First go at a patch

So this is an attempt to solve the bug using method #2. Its not quite right yet I think as the calls to gfs2_log_flush can result in writing to the log (just a header block) even if there is nothing in the log, I think. That might cause a block to be written after the transaction lock has been released in case there is a race between the demotion of the transaction glock and the demotion of another glock. Maybe its harmless, but I want to be sure.

This fix also has some other advantages... no longer do we have to wonder about what to do if the transaction cannot be allocated, since we can put that on the stack. Also it should be slightly faster, since we don't need to grab the transaction glock in this case.

The patch relies on the fact that we cache the transaction glock forever, unless:
a) There is a demotion request (which syncs the filesystem as part of its glops code) or
b) Upon umount

We can thus assume that if there is something in the ail list, it must be because we have the transaction glock cached. If we didn't hold it, then that would mean that the filesystem has been synced and further transactions would have been blocked in gfs2_trans_begin() so that the ail list must be empty.
Comment 1 RHEL Program Management 2009-02-03 03:41:18 UTC 
This request was evaluated by Red Hat Product Management for inclusion in a Red
Hat Enterprise Linux maintenance release.  Product Management has requested
further review of this request by Red Hat Engineering, for potential
inclusion in a Red Hat Enterprise Linux Update release for currently deployed
products.  This request is not yet committed for inclusion in an Update
release.
Comment 2 RHEL Program Management 2009-02-16 15:24:30 UTC 
Updating PM score.
Comment 3 Steve Whitehouse 2009-02-17 14:57:51 UTC 
*** Bug 485336 has been marked as a duplicate of this bug. ***
Comment 4 Steve Whitehouse 2009-03-02 11:47:50 UTC 
*** Bug 487215 has been marked as a duplicate of this bug. ***
Comment 5 Abhijith Das 2009-04-16 14:51:40 UTC 
Created attachment 339852 [details]
RHEL5 version of the above patch
Comment 6 Abhijith Das 2009-04-16 15:10:28 UTC 
Posted patch to rhkernel-list.
Comment 7 Steve Whitehouse 2009-04-16 15:21:09 UTC 
We leave the assignee under the new bug system, so returning this to be me.
Comment 8 Don Zickus 2009-04-20 17:11:55 UTC 
in kernel-2.6.18-140.el5
You can download this test kernel from http://people.redhat.com/dzickus/el5

Please do NOT transition this bugzilla state to VERIFIED until our QE team
has sent specific instructions indicating when to do so.  However feel free
to provide a comment indicating that this fix has been verified.
Comment 10 Caspar Zhang 2009-08-03 03:45:34 UTC 
Verified that the patch to this bug is included in the 2.6.18-160.el5, with patch #23856
Comment 12 errata-xmlrpc 2009-09-02 08:36:24 UTC 
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2009-1243.html