Re: [PATCH -v2] jbd2: instrument jh on wrong transaction BUG_ON's
From: Curt Wohlgemuth <hidden>
Date: 2011-08-15 16:18:18
Hi Ted: With your latest patch, here's the console output. And no, there are no interesting messages prior to the crash. [ 727.933568] general protection fault: 0000 [#1] SMP [ 727.934001] CPU 2 [ 727.934001] Modules linked in: loop tg3 msr cpuid ipv6 genrtc [ 727.934001] [ 727.934001] Pid: 9238, comm: flush-8:16 Not tainted 3.1.0-smp-ext4_test [ 727.934001] RIP: 0010:[<ffffffff812a159f>] [<ffffffff812a159f>] jbd2_journal_dirty_metadata+0x19f/0x240 ... [ 727.934001] Process flush-8:16 (pid: 9238, threadinfo ffff88076c8ec000, task ffff880852529800) [ 727.934001] Stack: [ 727.934001] ffff88076c8ed840 ffffffff812a9d46 ffffffff8125c87c ffff8808577de540 [ 727.934001] ffff880641c32850 0000000000000000 ffff880641c32850 ffff880663985958 [ 727.934001] 000000000000033d ffffffff81640bea ffff88076c8ed8a0 ffffffff812848b3 [ 727.934001] Call Trace: [ 727.934001] [<ffffffff812a9d46>] ? jbd2_journal_add_journal_head+0x86/0x290 [ 727.934001] [<ffffffff8125c87c>] ? __ext4_journalled_writepage+0xac/0x390 [ 727.934001] [<ffffffff812848b3>] __ext4_handle_dirty_metadata+0x83/0x120 [ 727.934001] [<ffffffff81284c1e>] ? __ext4_journal_get_write_access+0x3e/0x80 [ 727.934001] [<ffffffff8125cac8>] __ext4_journalled_writepage+0x2f8/0x390 [ 727.934001] [<ffffffff8125e264>] ext4_writepage+0x234/0x2f0 [ 727.934001] [<ffffffff81155ad7>] __writepage+0x17/0x40 [ 727.934001] [<ffffffff811574ae>] write_cache_pages+0x29e/0x6d0 [ 727.934001] [<ffffffff813ec4d7>] ? scsi_request_fn+0xd7/0x580 [ 727.934001] [<ffffffff81155ac0>] ? set_page_dirty+0x70/0x70 [ 727.934001] [<ffffffff81157931>] generic_writepages+0x51/0x80 ... where 0xffffffff812a159f is in the printk() , line 1126; it looks like journal->j_committing_transaction is not NULL, but isn't valid either: 0xffffffff812a1597 <+407>: xor %r8d,%r8d ; put 0 into %r8d 0xffffffff812a159a <+410>: test %rcx,%rcx ; %rcx is journal->j_committing_transaction, I think 0xffffffff812a159d <+413>: je 0xffffffff812a15a3 <jbd2_journal_dirty_metadata+419> ; if 0, jump over next instruction 0xffffffff812a159f <+415>: mov 0x8(%rcx),%r8d ; put ->t_tid into %r8d I reformatted/mounted both the main and scratch devices before running the test, and export EXT_MOUNT_OPTIONS="-o block_validity,data=journal" export MKFS_OPTIONS="-t ext4 -O has_journal" Curt On Sun, Aug 14, 2011 at 7:11 PM, Theodore Ts'o [off-list ref] wrote:
quoted hunk ↗ jump to hunk
These assertions have been reported as being tripped. Instrument them so we get more information about what might be going on. Cc: curtw@google.com Signed-off-by: "Theodore Ts'o" <tytso@mit.edu> --- fs/jbd2/transaction.c | 46 +++++++++++++++++++++++++++++++++++++++++----- 1 files changed, 41 insertions(+), 5 deletions(-)diff --git a/fs/jbd2/transaction.c b/fs/jbd2/transaction.c index 2d71094..a242f6f 100644 --- a/fs/jbd2/transaction.c +++ b/fs/jbd2/transaction.c@@ -1093,8 +1093,20 @@ int jbd2_journal_dirty_metadata(handle_t *handle, struct buffer_head *bh)*/ if (jh->b_transaction == transaction && jh->b_jlist == BJ_Metadata) { JBUFFER_TRACE(jh, "fastpath"); - J_ASSERT_JH(jh, jh->b_transaction == - journal->j_running_transaction); + if (unlikely(jh->b_transaction != + journal->j_running_transaction)) { + printk(KERN_EMERG "JBD: %s: " + "jh->b_transaction (%llu, %p, %u) != " + "journal->j_running_transaction (%p, %u)", + journal->j_devname, + (unsigned long long) bh->b_blocknr, + jh->b_transaction, + jh->b_transaction ? jh->b_transaction->t_tid : 0, + journal->j_running_transaction, + journal->j_running_transaction ? + journal->j_running_transaction->t_tid : 0); + BUG_ON(1); + } goto out_unlock_bh; }@@ -1108,9 +1120,33 @@ int jbd2_journal_dirty_metadata(handle_t *handle, struct buffer_head *bh)*/ if (jh->b_transaction != transaction) { JBUFFER_TRACE(jh, "already on other transaction"); - J_ASSERT_JH(jh, jh->b_transaction == - journal->j_committing_transaction); - J_ASSERT_JH(jh, jh->b_next_transaction == transaction); + if (unlikely(jh->b_transaction != + journal->j_committing_transaction)) { + printk(KERN_EMERG "JBD: %s: " + "jh->b_transaction (%llu, %p, %u) != " + "journal->j_committing_transaction (%p, %u)", + journal->j_devname, + (unsigned long long) bh->b_blocknr, + jh->b_transaction, + jh->b_transaction ? jh->b_transaction->t_tid : 0, + journal->j_committing_transaction, + journal->j_committing_transaction ? + journal->j_committing_transaction->t_tid : 0); + BUG_ON(1); + } + if (unlikely(jh->b_next_transaction != transaction)) { + printk(KERN_EMERG "JBD: %s: " + "jh->b_next_transaction (%llu, %p, %u) != " + "transaction (%p, %u)", + journal->j_devname, + (unsigned long long) bh->b_blocknr, + jh->b_next_transaction, + jh->b_next_transaction ? + jh->b_next_transaction->t_tid : 0, + transaction, + transaction ? transaction->t_tid : 0); + BUG_ON(1); + } /* And this case is illegal: we can't reuse another * transaction's data buffer, ever. */ goto out_unlock_bh; -- 1.7.4.1.22.gec8e1.dirty
-- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html