Bug 423381 - GFS2 - Filesystem withdraw when running postmark/benchp13 tests
Summary: GFS2 - Filesystem withdraw when running postmark/benchp13 tests
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Red Hat Enterprise Linux 5
Classification: Red Hat
Component: kernel
Version: 5.2
Hardware: All
OS: Linux
low
low
Target Milestone: rc
: ---
Assignee: Robert Peterson
QA Contact: GFS Bugs
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2007-12-13 13:22 UTC by Kiersten (Kerri) Anderson
Modified: 2009-05-28 03:37 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2008-01-07 17:08:16 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
Bob's Port of the trans_add_gl patch (9.03 KB, patch)
2007-12-13 18:02 UTC, Robert Peterson
no flags Details | Diff
Upstream umount patch (744 bytes, patch)
2007-12-14 20:20 UTC, Robert Peterson
no flags Details | Diff
Patch that seems to fix the problem (30.79 KB, patch)
2007-12-17 20:35 UTC, Robert Peterson
no flags Details | Diff
Patch that seems to fix the problem--try #2 (31.92 KB, patch)
2007-12-17 21:45 UTC, Robert Peterson
no flags Details | Diff

Description Kiersten (Kerri) Anderson 2007-12-13 13:22:06 UTC
Description of problem:
GFS2: fsid=dm-2.0:   function = glock_lo_after_commit, file =
/builddir/build/BUILD/gfs2-kmod-1.53/_kmod_build_/lops.c, line = 167
GFS2: fsid=dm-2.0: about to withdraw this file system
GFS2: fsid=dm-2.0: telling LM to withdraw
GFS2: fsid=dm-2.0: withdrawn
 [<f8dd32ac>] gfs2_lm_withdraw+0x73/0x7f [gfs2]
 [<f8de3f30>] gfs2_assert_withdraw_i+0x1e/0x30 [gfs2]
 [<f8dd4e5d>] glock_lo_after_commit+0x42/0x84 [gfs2]
 [<f8dd4314>] gfs2_log_flush+0x374/0x40c [gfs2]
 [<c0436031>] autoremove_wake_function+0x0/0x2d
 [<f8dc855b>] gfs2_logd+0x92/0x13f [gfs2]
 [<c041f7ea>] complete+0x2b/0x3d
 [<f8dc84c9>] gfs2_logd+0x0/0x13f [gfs2]
 [<c0435f65>] kthread+0xc0/0xeb
 [<c0435ea5>] kthread+0x0/0xeb
 [<c0405c3b>] kernel_thread_helper+0x7/0x10
 =======================
 [<f8de3f3a>] gfs2_assert_withdraw_i+0x28/0x30 [gfs2]
 [<f8dd4e5d>] glock_lo_after_commit+0x42/0x84 [gfs2]
 [<f8dd4314>] gfs2_log_flush+0x374/0x40c [gfs2]
 [<c0436031>] autoremove_wake_function+0x0/0x2d
 [<f8dc855b>] gfs2_logd+0x92/0x13f [gfs2]
 [<c041f7ea>] complete+0x2b/0x3d
 [<f8dc84c9>] gfs2_logd+0x0/0x13f [gfs2]
 [<c0435f65>] kthread+0xc0/0xeb
 [<c0435ea5>] kthread+0x0/0xeb
 [<c0405c3b>] kernel_thread_helper+0x7/0x10
 =======================
 [<f8de3f3a>] gfs2_assert_withdraw_i+0x28/0x30 [gfs2]
 [<f8dd49ce>] gfs2_unpin+0x3d/0x101 [gfs2]
 [<f8dd4ec9>] buf_lo_after_commit+0x2a/0x64 [gfs2]
 [<f8dd4314>] gfs2_log_flush+0x374/0x40c [gfs2]
 [<c0436031>] autoremove_wake_function+0x0/0x2d
 [<f8dc855b>] gfs2_logd+0x92/0x13f [gfs2]
 [<c041f7ea>] complete+0x2b/0x3d
 [<f8dc84c9>] gfs2_logd+0x0/0x13f [gfs2]
 [<c0435f65>] kthread+0xc0/0xeb
 [<c0435ea5>] kthread+0x0/0xeb
 [<c0405c3b>] kernel_thread_helper+0x7/0x10
 =======================
GFS2: fsid=dm-3.0: fatal: invalid metadata block
GFS2: fsid=dm-3.0:   bh = 262146 (type: exp=3, found=4)
GFS2: fsid=dm-3.0:   function = gfs2_rgrp_bh_get, file =
/builddir/build/BUILD/gfs2-kmod-1.53/_kmod_build_/rgrp.c, line = 722
GFS2: fsid=dm-3.0: about to withdraw this file system
GFS2: fsid=dm-3.0: telling LM to withdraw
GFS2: fsid=dm-3.0: withdrawn
 [<f8dd32ac>] gfs2_lm_withdraw+0x73/0x7f [gfs2]
 [<f8de3e2a>] gfs2_metatype_check_ii+0x32/0x3e [gfs2]
 [<f8de1894>] gfs2_rgrp_bh_get+0x138/0x254 [gfs2]
 [<f8dcedb4>] gfs2_glock_put+0x1e/0x109 [gfs2]
 [<f8dcfd70>] glock_wait_internal+0x193/0x1ec [gfs2]
 [<f8dcff37>] gfs2_glock_nq+0x16e/0x18e [gfs2]
 [<f8de0e3a>] gfs2_inplace_reserve_i+0x33b/0x57d [gfs2]
 [<f8dc8e91>] gfs2_dirent_search+0xaa/0x17b [gfs2]
 [<f8dca04a>] gfs2_dirent_find_space+0x0/0x56 [gfs2]
 [<f8dc8eba>] gfs2_dirent_search+0xd3/0x17b [gfs2]
 [<f8dca04a>] gfs2_dirent_find_space+0x0/0x56 [gfs2]
 [<f8dd2f32>] gfs2_createi+0xc39/0xdd4 [gfs2]
 [<f8dd0076>] gfs2_glmutex_lock+0xf/0x7e [gfs2]
 [<f8ddbd2f>] gfs2_mkdir+0x4c/0x3b5 [gfs2]
 [<f8dd0183>] gfs2_glock_dq+0x9e/0xb2 [gfs2]
 [<f8dcedb4>] gfs2_glock_put+0x1e/0x109 [gfs2]
 [<f8dd2351>] gfs2_createi+0x58/0xdd4 [gfs2]
 [<f8dd031b>] gfs2_glock_nq_num+0x31/0x54 [gfs2]
 [<c047b30a>] permission+0xa2/0xb5
 [<c047b687>] vfs_mkdir+0xbe/0x122
 [<c047dca9>] sys_mkdirat+0x87/0xb6
 [<c044abd9>] audit_syscall_entry+0x11c/0x14e
 [<c047dce7>] sys_mkdir+0xf/0x13
 [<c0404eff>] syscall_call+0x7/0xb
 =======================
 [<f8de3f3a>] gfs2_assert_withdraw_i+0x28/0x30 [gfs2]
 [<f8dd4e5d>] glock_lo_after_commit+0x42/0x84 [gfs2]
 [<f8dd4314>] gfs2_log_flush+0x374/0x40c [gfs2]
 [<c0436031>] autoremove_wake_function+0x0/0x2d
 [<f8dc855b>] gfs2_logd+0x92/0x13f [gfs2]
 [<f8dc84c9>] gfs2_logd+0x0/0x13f [gfs2]
 [<c0435f65>] kthread+0xc0/0xeb
 [<c0435ea5>] kthread+0x0/0xeb
 [<c0405c3b>] kernel_thread_helper+0x7/0x10
 =======================
 [<f8de3f3a>] gfs2_assert_withdraw_i+0x28/0x30 [gfs2]
 [<f8dd49ce>] gfs2_unpin+0x3d/0x101 [gfs2]
 [<f8dd4ec9>] buf_lo_after_commit+0x2a/0x64 [gfs2]
 [<f8dd4314>] gfs2_log_flush+0x374/0x40c [gfs2]
 [<c0436031>] autoremove_wake_function+0x0/0x2d
 [<f8dc855b>] gfs2_logd+0x92/0x13f [gfs2]
 [<f8dc84c9>] gfs2_logd+0x0/0x13f [gfs2]
 [<c0435f65>] kthread+0xc0/0xeb
 [<c0435ea5>] kthread+0x0/0xeb
 [<c0405c3b>] kernel_thread_helper+0x7/0x10

Version-Release number of selected component (if applicable):
kmod-gfs2-1.53-4.3.3.i686.rpm

How reproducible:
Very

Steps to Reproduce:
1.Run either postmark or the benchp13 tests.
2.
3.
  
Actual results:


Expected results:


Additional info:

Comment 1 Robert Peterson 2007-12-13 14:01:51 UTC
I just ran postmark on my patch alone and it was successful:

[root@roth-01 /mnt/gfs2]# /home/bob/postmark-1.51/postmark 
PostMark v1.51 : 8/14/01
pm>set transactions 100000
pm>set number 100000
pm>run
Creating files...Done
Performing transactions..........Done
Deleting files...Done
Time:
        828 seconds total
        711 seconds of transactions (140 per second)

Files:
        150087 created (181 per second)
                Creation alone: 100000 files (1351 per second)
                Mixed with transactions: 50087 files (70 per second)
        49995 read (70 per second)
        49991 appended (70 per second)
        150087 deleted (181 per second)
                Deletion alone: 100174 files (2329 per second)
                Mixed with transactions: 49913 files (70 per second)

Data:
        273.42 megabytes read (338.15 kilobytes per second)
        852.13 megabytes written (1.03 megabytes per second)
pm>

Perhaps this is a simple case of a line being missed in Steve's port
from upstream to rhel.  I'll find out if that's the case shortly.


Comment 2 Rob Kenna 2007-12-13 14:22:52 UTC
My trace running postmark.  This fails immediately.
-------------------
Dec 12 22:25:14 rkenna-laptop kernel: GFS2: fsid=dm-4.0: fatal: assertion
"gfs2_glock_is_held_excl(gl)" failed
Dec 12 22:25:14 rkenna-laptop kernel: GFS2: fsid=dm-4.0:   function =
glock_lo_after_commit, file =
/builddir/build/BUILD/gfs2-kmod-1.53/_kmod_build_/lops.c, line = 167
Dec 12 22:25:14 rkenna-laptop kernel: GFS2: fsid=dm-4.0: about to withdraw this
file system
Dec 12 22:25:14 rkenna-laptop kernel: GFS2: fsid=dm-4.0: telling LM to withdraw
Dec 12 22:25:14 rkenna-laptop kernel: GFS2: fsid=dm-4.0: withdrawn
Dec 12 22:25:14 rkenna-laptop kernel:  [<f8e8f2ac>] gfs2_lm_withdraw+0x73/0x7f
[gfs2]
Dec 12 22:25:14 rkenna-laptop kernel:  [<f8e9ff30>]
gfs2_assert_withdraw_i+0x1e/0x30 [gfs2]
Dec 12 22:25:14 rkenna-laptop kernel:  [<f8e90e5d>]
glock_lo_after_commit+0x42/0x84 [gfs2]
Dec 12 22:25:14 rkenna-laptop kernel:  [<f8e90314>] gfs2_log_flush+0x374/0x40c
[gfs2]
Dec 12 22:25:14 rkenna-laptop kernel:  [<c0436031>]
autoremove_wake_function+0x0/0x2d
Dec 12 22:25:14 rkenna-laptop kernel:  [<f8e8455b>] gfs2_logd+0x92/0x13f [gfs2]
Dec 12 22:25:14 rkenna-laptop kernel:  [<c041f7ea>] complete+0x2b/0x3d
Dec 12 22:25:14 rkenna-laptop kernel:  [<f8e844c9>] gfs2_logd+0x0/0x13f [gfs2]
Dec 12 22:25:14 rkenna-laptop kernel:  [<c0435f65>] kthread+0xc0/0xeb
Dec 12 22:25:14 rkenna-laptop kernel:  [<c0435ea5>] kthread+0x0/0xeb
Dec 12 22:25:14 rkenna-laptop kernel:  [<c0405c3b>] kernel_thread_helper+0x7/0x10
Dec 12 22:25:14 rkenna-laptop kernel:  ======================= 

Comment 3 Robert Peterson 2007-12-13 16:28:55 UTC
I didn't find any obvious one-liner omissions from Steve's patch.
However, the upstream gfs2 is significantly different from the RHEL
gfs2 now, and AFAICT not everything can be accounted for by upstream
kernel changes.

The assert that is being triggered has been removed from the upstream
kernel as part of a big change that removed several functions from
lops.c.  Apparently that's a change that Steve did not port to RHEL.
The comments in the git tree relating to its removal from upstream are:

   Don't add glocks to the journal

   The only reason for adding glocks to the journal was to keep track
   of which locks required a log flush prior to release. We add a
   flag to the glock to allow this check to be made in a simpler way.

   This reduces the size of a glock (by 12 bytes on i386, 24 on x86_64)
   and means that we can avoid extra work during the journal flush.

I don't know why Steve did not port that change to RHEL, other than
the fact that it's a fairly big fix, affecting nine parts.


Comment 4 Robert Peterson 2007-12-13 18:02:13 UTC
Created attachment 287721 [details]
Bob's Port of the trans_add_gl patch

Attached is my port of Steve's aforementioned fix, to RHEL5.
It's not a complete solution, because now postmark gives me this:

GFS2 Overlay (built Dec 13 2007 11:39:06) installed
GFS2: fsid=bobs_roth:bobsdb1.0: fatal: assertion "buffer_uptodate(bh)" failed
GFS2: fsid=bobs_roth:bobsdb1.0:   function = gfs2_unpin, file = fs/gfs2/lops.c,
line = 71
GFS2: fsid=bobs_roth:bobsdb1.0: about to withdraw this file system
GFS2: fsid=bobs_roth:bobsdb1.0: telling LM to withdraw
GFS2: fsid=bobs_roth:bobsdb1.0: withdrawn

Call Trace:
 [<ffffffff884823e2>] :gfs2:gfs2_lm_withdraw+0xc1/0xd0
 [<ffffffff8000e563>] __set_page_dirty_nobuffers+0xc6/0xd1
 [<ffffffff884940c6>] :gfs2:gfs2_assert_withdraw_i+0x25/0x37
 [<ffffffff88483ca4>] :gfs2:gfs2_unpin+0x50/0x148
 [<ffffffff8848418d>] :gfs2:buf_lo_after_commit+0x38/0x7e
 [<ffffffff88483547>] :gfs2:__gfs2_log_flush+0x3a8/0x454
 [<ffffffff8009b4c4>] autoremove_wake_function+0x0/0x2e
 [<ffffffff8848294a>] :gfs2:gfs2_ail1_empty+0x36/0x95
 [<ffffffff88477356>] :gfs2:gfs2_logd+0xa2/0x168
 [<ffffffff884772b4>] :gfs2:gfs2_logd+0x0/0x168
 [<ffffffff800321be>] kthread+0xfe/0x132
 [<ffffffff8005bfb1>] child_rip+0xa/0x11
 [<ffffffff8009b301>] keventd_create_kthread+0x0/0x61
 [<ffffffff800320c0>] kthread+0x0/0x132
 [<ffffffff8005bfa7>] child_rip+0x0/0x11

Comment 5 Robert Peterson 2007-12-13 19:12:44 UTC
This assert from comment #4 is unchanged between upstream and RHEL.

I've kompared all the gfs2 code from upstream to rhel.  There are a lot
of small things, but nothing that should account for this, with these
two exceptions:

1. The code in log.c has undergone lots of changes.
   We've got the new log threshold code in upstream that uses the
   logd daemon to do some of its dirty work.
2. RHEL's prepare_write precursor, gfs2_write_lock_start, has
   moved to ops_file.c, called gfs2_page_mkwrite, and it has a helper
   called gfs2_allocate_page_backing.  The functions are similar enough
   that it's not likely to be the cause of the problem.

These are both non-trivial changes.  I'm still investigating.


Comment 6 Robert Peterson 2007-12-13 21:23:14 UTC
I tried compiling the latest upstream gfs2 from the git tree and
running the same postmark test on it.  After a reboot and clean mkfs,
I ran postmark.  much to my dismay, I got a completely different BUG:

GFS2 (built Dec 13 2007 14:57:56) installed
original: gfs2_rindex_hold+0x35/0x16f [gfs2]
new: gfs2_rindex_hold+0x35/0x16f [gfs2]
------------[ cut here ]------------
kernel BUG at fs/gfs2/glock.c:1086!
invalid opcode: 0000 [1] SMP 
CPU 1 
Modules linked in: lock_nolock gfs2
Pid: 3821, comm: postmark Not tainted 2.6.24-rc5 #1
RIP: 0010:[<ffffffff8800baf3>]  [<ffffffff8800baf3>] :gfs2:gfs2_glock_nq+0x102/0x1cc
RSP: 0018:ffff81006716dae8  EFLAGS: 00010292
RAX: 0000000000000020 RBX: ffff8100720ba900 RCX: 0000000000004ff6
RDX: 00000000ffffffff RSI: 0000000000000046 RDI: ffff810061d69700
RBP: ffff81007201f900 R08: 0000000000000000 R09: ffffffff8058cbc0
R10: 0000000000000000 R11: 0000000000000001 R12: ffff810061d69700
R13: ffff810061d69700 R14: 0000000000000000 R15: ffff810061054000
FS:  00002b064054d6f0(0000) GS:ffff81007df32e88(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00002b0641617000 CR3: 00000000799cc000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process postmark (pid: 3821, threadinfo ffff81006716c000, task ffff810069955040)
Stack:  00000000ffffffff ffff810061054000 ffff810061d69700 ffff8100720bb148
 ffff81007201f900 ffff81007201f500 ffff810061054000 ffffffff8801cac6
 ffff81006716db78 ffffffff802468f8 ffff8100798e52b0 ffffffff8022c33e
Call Trace:
 [<ffffffff8801cac6>] :gfs2:gfs2_rindex_hold+0x3d/0x16f
 [<ffffffff802468f8>] autoremove_wake_function+0x9/0x2e
 [<ffffffff8022c33e>] __wake_up_common+0x41/0x74
 [<ffffffff8801ced5>] :gfs2:gfs2_inplace_reserve_i+0xb7/0x6b5
 [<ffffffff8800a7fb>] :gfs2:gfs2_glock_put+0x26/0x104
 [<ffffffff8800e1af>] :gfs2:gfs2_createi+0x497/0xb94
 [<ffffffff802468f8>] autoremove_wake_function+0x9/0x2e
 [<ffffffff8022dfe2>] __wake_up+0x38/0x4f
 [<ffffffff802434a5>] __queue_work+0x23/0x33
 [<ffffffff88017ad8>] :gfs2:gfs2_create+0x65/0x120
 [<ffffffff8800dd7a>] :gfs2:gfs2_createi+0x62/0xb94
 [<ffffffff8028ca51>] vfs_create+0x75/0xba
 [<ffffffff8028f24e>] open_namei+0x197/0x5f7
 [<ffffffff8028421f>] do_filp_open+0x1c/0x38
 [<ffffffff80283f1d>] get_unused_fd_flags+0x72/0x120
 [<ffffffff80284281>] do_sys_open+0x46/0xca
 [<ffffffff8020b66e>] system_call+0x7e/0x83


Code: 0f 0b eb fe 39 70 18 74 10 48 89 d0 48 8b 10 48 39 c8 0f 18 
RIP  [<ffffffff8800baf3>] :gfs2:gfs2_glock_nq+0x102/0x1cc
 RSP <ffff81006716dae8>


Comment 7 Steve Whitehouse 2007-12-14 10:45:30 UTC
RE: comment #5, item 2

gfs2_write_lock_start hasn't moved anywhere in upstream. You can't find it
because it isn't there since the locking order can be correct without that hack,
and thus it is not needed.

gfs2_page_mkwrite is part of what used to be in ops_vm.c, most of that file
isn't needed since the VFS does that for us now (i.e. the ->fault() path).

Comment 8 Steve Whitehouse 2007-12-14 14:44:44 UTC
I've reverted the patch which causes the problem reported in comment #6. I've
also had to fix up another of the patches in the same series. It doesn't look
like they had much testing....

I suspect that you need to add some of the patches relating to the log into RHEL
in order to fix the original problem as reported. Since it occurs right away in
RHEL it will almost certainly be down to one of those patches.



Comment 9 Robert Peterson 2007-12-14 16:13:24 UTC
I pulled the latest git tree and figured out which patch Steve was
talking about in comment #8.  It was my bad and see the problem.
So I need to make the change to my patch to RHEL accordingly.

With Steve's latest and greatest upstream kernel, compiled from a
git tree pull, I was able to run postmark through to completion.
However, when it was finished, I did a sync, then tried to unmount
the volume, and I got this GPF:

general protection fault: 0000 [1] SMP
CPU 0
Modules linked in: lock_nolock gfs2
Pid: 3795, comm: glock_workqueue Not tainted 2.6.24-rc5 #1
RIP: 0010:[<ffffffff8055e188>]  [<ffffffff8055e188>] _read_lock_irq+0x1/0xd
RSP: 0018:ffff810061851d28  EFLAGS: 00010086
RAX: 000000000000000e RBX: 000000000000000e RCX: ffff810061851da0
RDX: 000000000000000e RSI: 0000000000000019 RDI: 6b6b6b6b6b6b6b83
RBP: 6b6b6b6b6b6b6b6b R08: 0000000000000001 R09: ffff81007c8d6a50
R10: 0000000000000001 R11: ffffffff8807800f R12: 0000000000000019
R13: ffff810061851da0 R14: ffffffff88020da0 R15: ffff81007c8d6a50
FS:  0000000000000000(0000) GS:ffffffff80747000(0000) knlGS:0000000000000000
CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 00000039bd094f60 CR3: 0000000038c46000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process glock_workqueue (pid: 3795, threadinfo ffff810061850000, task ffff81007a
cb0870)
Stack:  ffffffff80260302 0000000000000000 ffff810061851d90 0000000000000000
 ffff81005f1fb000 0000000000000019 ffffffff8026616f ffff81007c8d6a50
 ffffffff8800c49b ffff81000000c700 ffffffff8800c9d3 6b6b6b6b6b6b6b6b
Call Trace:
 [<ffffffff80260302>] find_get_pages+0x1e/0x69  
 [<ffffffff8026616f>] pagevec_lookup+0x17/0x1e  
 [<ffffffff8800c49b>] :gfs2:gfs2_foreach_page+0x125/0x140
 [<ffffffff8800c9d3>] :gfs2:gfs2_zap_glock_buffers+0x0/0x25
 [<ffffffff8022c6fc>] update_curr+0x41/0x86
 [<ffffffff8026bea7>] unmap_mapping_range+0x59/0x203
 [<ffffffff8025ed62>] __filemap_fdatawrite_range+0x51/0x5b
 [<ffffffff8800c55f>] :gfs2:gfs2_meta_inval+0x10/0x24
 [<ffffffff8800c6f5>] :gfs2:inode_go_inval+0x13/0x4c
 [<ffffffff8800af7f>] :gfs2:drop_bh+0xbf/0x14c  
 [<ffffffff8800b652>] :gfs2:run_queue+0xa9/0x1ea
 [<ffffffff8800c02d>] :gfs2:glock_work_func+0x39/0x4e
 [<ffffffff8800bff4>] :gfs2:glock_work_func+0x0/0x4e
 [<ffffffff80242f69>] run_workqueue+0x7f/0x10b  
 [<ffffffff80243886>] worker_thread+0x0/0xe4
 [<ffffffff80243960>] worker_thread+0xda/0xe4   
 [<ffffffff802468ef>] autoremove_wake_function+0x0/0x2e
 [<ffffffff802467c7>] kthread+0x47/0x74
 [<ffffffff8020c488>] child_rip+0xa/0x12
 [<ffffffff80246780>] kthread+0x0/0x74
 [<ffffffff8020c47e>] child_rip+0x0/0x12


Code: f0 83 2f 01 79 05 e8 3d 59 df ff c3 9c 58 fa f0 81 2f 00 00
RIP  [<ffffffff8055e188>] _read_lock_irq+0x1/0xd
 RSP <ffff810061851d28>
general protection fault: 0000 [2] SMP
CPU 0
Modules linked in: lock_nolock gfs2
Pid: 3875, comm: umount.gfs2 Tainted: G      D 2.6.24-rc5 #1
RIP: 0010:[<ffffffff80264208>]  [<ffffffff80264208>] write_cache_pages+0x25/0x2aa
RSP: 0018:ffff810074d73c38  EFLAGS: 00010246
RAX: 000000001fe98000 RBX: ffff81005f8e7da0 RCX: ffff81005f8e7da0
RDX: ffffffff8800c7ec RSI: ffff810074d73d38 RDI: 6b6b6b6b6b6b6b6b
RBP: ffff810074d73d38 R08: 6b6b6b6b6b6b6b6b R09: ffff810074d73e28
R10: ffff810074d73e28 R11: 0000000000000040 R12: ffff81005f1fb000
R13: ffff81005f1fb000 R14: 6b6b6b6b6b6b6b6b R15: 0000000000000000
FS:  00002b1c22e056f0(0000) GS:ffffffff80747000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00002b06ee8fc758 CR3: 0000000038c46000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process umount.gfs2 (pid: 3875, threadinfo ffff810074d72000, task ffff81007c8d2770)
Stack:  0000000000000000 ffff81005f8e7da0 ffffffff8800c7ec ffffffff80265916
 0000000000000000 ffffffff8025eca8 0000000000000000 0000000000000000
 0000000000000000 ffffffff8025eca8 0000000000000000 0000000000000000
Call Trace:
 [<ffffffff8800c7ec>] :gfs2:write_meta_pages+0x0/0x8e
 [<ffffffff80265916>] pagevec_lookup_tag+0x1a/0x21
 [<ffffffff8025eca8>] wait_on_page_writeback_range+0xc3/0x10e
 [<ffffffff8025eca8>] wait_on_page_writeback_range+0xc3/0x10e
 [<ffffffff80261722>] get_pageblock_flags_group+0x3e/0x7f
 [<ffffffff80246823>] bit_waitqueue+0x1c/0x99   
 [<ffffffff8800c16c>] :gfs2:clear_glock+0x0/0xb1
 [<ffffffff8800c531>] :gfs2:gfs2_meta_sync+0x7b/0x99
 [<ffffffff8800ca86>] :gfs2:meta_go_sync+0x22/0x2c
 [<ffffffff8800b02b>] :gfs2:gfs2_glock_drop_th+0x1f/0x131
 [<ffffffff8800b652>] :gfs2:run_queue+0xa9/0x1ea
 [<ffffffff8800bc0a>] :gfs2:gfs2_glmutex_unlock+0x2a/0x33
 [<ffffffff8800aac3>] :gfs2:examine_bucket+0x66/0x98
 [<ffffffff8800ab87>] :gfs2:gfs2_gl_hash_clear+0x2b/0x147
 [<ffffffff8801897e>] :gfs2:gfs2_put_super+0x1d3/0x1f4
 [<ffffffff80286fe5>] generic_shutdown_super+0x60/0xf2
 [<ffffffff80287084>] kill_block_super+0xd/0x1e 
 [<ffffffff8028712c>] deactivate_super+0x47/0x60
 [<ffffffff802992b6>] sys_umount+0x1f7/0x22a
 [<ffffffff802a756a>] __blkdev_put+0x136/0x142  
 [<ffffffff80295269>] dput+0x26/0x115
 [<ffffffff802864fd>] __fput+0x147/0x176
 [<ffffffff8023df37>] recalc_sigpending+0xe/0x3c
 [<ffffffff8023e003>] sigprocmask+0x9e/0xc0
 [<ffffffff8023ffdc>] sys_rt_sigprocmask+0xb5/0xce
 [<ffffffff8020b66e>] system_call+0x7e/0x83


Code: 4c 8b 6f 68 74 32 49 8b 45 18 48 85 c0 74 0d 49 8b 7d 20 be
RIP  [<ffffffff80264208>] write_cache_pages+0x25/0x2aa
 RSP <ffff810074d73c38>
WARNING: at kernel/exit.c:917 do_exit()
Pid: 3875, comm: umount.gfs2 Tainted: G      D 2.6.24-rc5 #1

Call Trace:
 [<ffffffff802378fb>] do_exit+0x4f/0x702
 [<ffffffff8055e6ba>] oops_end+0x33/0x50
 [<ffffffff8020ce16>] kernel_math_error+0x0/0x71
 [<ffffffff8055e339>] error_exit+0x0/0x51
 [<ffffffff8800c7ec>] :gfs2:write_meta_pages+0x0/0x8e
 [<ffffffff80264208>] write_cache_pages+0x25/0x2aa
 [<ffffffff8800c7ec>] :gfs2:write_meta_pages+0x0/0x8e
 [<ffffffff80265916>] pagevec_lookup_tag+0x1a/0x21
 [<ffffffff8025eca8>] wait_on_page_writeback_range+0xc3/0x10e
 [<ffffffff8025eca8>] wait_on_page_writeback_range+0xc3/0x10e
 [<ffffffff80261722>] get_pageblock_flags_group+0x3e/0x7f
 [<ffffffff80246823>] bit_waitqueue+0x1c/0x99   
 [<ffffffff8800c16c>] :gfs2:clear_glock+0x0/0xb1
 [<ffffffff8800c531>] :gfs2:gfs2_meta_sync+0x7b/0x99
 [<ffffffff8800ca86>] :gfs2:meta_go_sync+0x22/0x2c
 [<ffffffff8800b02b>] :gfs2:gfs2_glock_drop_th+0x1f/0x131
 [<ffffffff8800b652>] :gfs2:run_queue+0xa9/0x1ea
 [<ffffffff8800bc0a>] :gfs2:gfs2_glmutex_unlock+0x2a/0x33
 [<ffffffff8800aac3>] :gfs2:examine_bucket+0x66/0x98
 [<ffffffff8800ab87>] :gfs2:gfs2_gl_hash_clear+0x2b/0x147
 [<ffffffff8801897e>] :gfs2:gfs2_put_super+0x1d3/0x1f4
 [<ffffffff80286fe5>] generic_shutdown_super+0x60/0xf2
 [<ffffffff80287084>] kill_block_super+0xd/0x1e 
 [<ffffffff8028712c>] deactivate_super+0x47/0x60
 [<ffffffff802992b6>] sys_umount+0x1f7/0x22a
 [<ffffffff802a756a>] __blkdev_put+0x136/0x142  
 [<ffffffff80295269>] dput+0x26/0x115
 [<ffffffff802864fd>] __fput+0x147/0x176
 [<ffffffff8023df37>] recalc_sigpending+0xe/0x3c
 [<ffffffff8023e003>] sigprocmask+0x9e/0xc0
 [<ffffffff8023ffdc>] sys_rt_sigprocmask+0xb5/0xce
 [<ffffffff8020b66e>] system_call+0x7e/0x83


Comment 10 Robert Peterson 2007-12-14 16:19:28 UTC
To summarize:

There's still a problem with the upstream kernel, although it behaves
better than before.

I believe RHEL5 needs:
(1) My port of Steve's trans_add_gl patch (attached below)
(2) The fix to my code mentioned above

Next I'm going to try RHEL with those two and see if there are other issues,
such as the unmounting issue that's in the upstream version.


Comment 11 Steve Whitehouse 2007-12-14 16:50:55 UTC
Actually, you can ignore the last part of comment #8, it looks like the initial
report was the same as one of the upstream bugs.

I suspect that what you are seeing in comment #9 is that due to the different
contexts in which the invalidation takes place with lock_nolock and lock_dlm,
and also due to the recent one-liner fix to iput the sd_meta inode, that its
probable that its being used either after its freed, or when sd_meta is NULL.

Try with lock_dlm and see if that appears to fix it. If it does, then thats
probably the cause.


Comment 12 Robert Peterson 2007-12-14 17:04:09 UTC
I still get this with lock_dlm:

GFS2: fsid=bobs_roth:bobsdb1.0: fatal: assertion "buffer_uptodate(bh)" failed
GFS2: fsid=bobs_roth:bobsdb1.0:   function = gfs2_unpin, file = fs/gfs2/lops.c,
line = 71
GFS2: fsid=bobs_roth:bobsdb1.0: about to withdraw this file system
GFS2: fsid=bobs_roth:bobsdb1.0: telling LM to withdraw


Comment 13 Robert Peterson 2007-12-14 17:05:24 UTC
That is, in rhel.  Trying upstream now.


Comment 14 Robert Peterson 2007-12-14 17:41:05 UTC
I still get the GPF in comment #9, when using lock_dlm.


Comment 15 Robert Peterson 2007-12-14 20:20:39 UTC
Created attachment 289381 [details]
Upstream umount patch

Steve was absolutely right in comment #11.  The upstream umount problem
boiled down to accessing the sd_meta after it had been freed.
The solution is to free is later.  This patch does that, and it passes
postmark, sync, unmount, which was how I killed it before.

Comment 16 Robert Peterson 2007-12-14 23:13:46 UTC
So we still have the single issue described in comment #4 and comment #12.
The upstream code doesn't hit it, but I wonder if that's because the new
log threshold code doesn't flush the log as often.  Or perhaps it just
flushes it at a more convenient time.  So I might be able to make it work
as well as upstream by porting that patch to RHEL as well. That's my theory.
But upstream might still have the same issue if a log flush happens at
an inopportune moment.  I'll have to study these changes closer, as I port.


Comment 17 Kiersten (Kerri) Anderson 2007-12-15 17:00:07 UTC
I went back and started applying the 5 patches in bz 349271.  Patches 1 to 3
applied and tests ran correctly.  After porting/applying patch 4, the panic
above showed up, so seems to be stuff in that patch causing the problems.

Comment 19 Robert Peterson 2007-12-17 20:35:53 UTC
Created attachment 289809 [details]
Patch that seems to fix the problem

This patch is against gfs2-kmod-1.53-4.3.3 and it seems to fix the
problem.  Summary of changes from 4.3.3:

1. Crosswrote a patch from Steve to do log flushes on threshold boundaries
   and log daemon moved to log.c.  This is the bulk of the patch, but
   this does not fix the assert problem of comment #12, however.
2. Change to glock.c so that gfs2_glock_drop_th calls glops->go_xmote_th
   rather than go_drop_th.  I also crosswrote an upstream change that
   removes the go_drop_th callback from rgrp glops and go_drop_th
   callback from gfs2_trans_glops.  Although small, one of these two
   simple changes seemed to fix the assert problem.
3. Change to log_bmap to fix the problem I introduced with my patches.
4. Move iput of sd_meta to fix the umount problem I found with upstream.

Comment 20 Robert Peterson 2007-12-17 21:45:10 UTC
Created attachment 289823 [details]
Patch that seems to fix the problem--try #2

The previous version has some vestigial code that causes an error.
That code is removed in this patch (which makes RHEL even closer to
upstream).

Comment 21 Robert Peterson 2008-01-07 17:08:16 UTC
The original problem was caused by a defective piece of code introduced
by a defective "iozone" performance enhancement for bug #253990.  That
defective code has not been shipped, so this is considered "Not a bug",
and therefore I'm closing the bz.  Note, however, that the patch from
comment #20 is still a viable port of several upstream patches to gfs2.
Eventually we will want to ship this in the name of keeping RHEL in sync
with upstream code, but probably not for 5.2.  Perhaps we should
consider this for 5.3.



Note You need to log in before you can comment on or make changes to this bug.