EXT4 panic at jbd2_journal_put_journal_head() in 3.9+

EXT4 panic at jbd2_journal_put_journal_head() in 3.9+

[EUNBONG SONG]

Hello.
In my board, i ran the iozone with multi-thread option. 
My board has 8 cores and i enabled CONFIG_SMP. 
the iozone command as follow: iozone -l 20 -u 20 -r 64k -s 5m -o -F /user/f1 /user/f2 /user/f3 /user/f4 /user/f5 /user/f6 /user/f7 /user/f8 /user/f9 /user/f10 /user/f11 /user/f12 /user/f13 /user/f14 /user/f15 /user/f16 /user/f17 /user/f18 /user/f19 /user/f20

mount info as follow
cat /proc/mounts
/dev/sda3 /user ext4 rw,noatime,nodiratime,errors=panic,barrier=1,data=ordered 0 0

I got a message as below every time i ran iozone test. 


[ 4876.293124] [<ffffffff80272d18>] show_stack+0x68/0x80
[ 4876.309411] [<ffffffff802bde4c>] notifier_call_chain+0x5c/0xa8
[ 4876.315245] [<ffffffff802be524>] __atomic_notifier_call_chain+0x3c/0x58
[ 4876.321860] [<ffffffff802be588>] notify_die+0x38/0x48
[ 4876.326913] [<ffffffff80272548>] do_trap_or_bp+0x48/0x1a8
[ 4876.332312] [<ffffffff8026cfe4>] resume_userspace_check+0x0/0x10
[ 4876.338323] [<ffffffff80462994>] jbd2_journal_put_journal_head+0xcc/0x250
[ 4876.345111] [<ffffffff804603b4>] __jbd2_journal_remove_checkpoint+0x54/0x130
[ 4876.352160] [<ffffffff8045e630>] jbd2_journal_commit_transaction+0x1318/0x1ad0
[ 4876.359383] [<ffffffff80463f4c>] kjournald2+0x114/0x450
[ 4876.364611] [<ffffffff802b8160>] kthread+0xb8/0xc0
[ 4876.369402] [<ffffffff8026d060>] ret_from_kernel_thread+0x10/0x18

When i ran without multi-thread option, the problem was not ocurred.


Thanks. 

Re: EXT4 panic at jbd2_journal_put_journal_head() in 3.9+

[Theodore Ts'o]

On Thu, May 09, 2013 at 07:59:30AM +0000, EUNBONG SONG wrote:
> 
> I got a message as below every time i ran iozone test. 
> 
> 
> [ 4876.293124] [<ffffffff80272d18>] show_stack+0x68/0x80
> [ 4876.309411] [<ffffffff802bde4c>] notifier_call_chain+0x5c/0xa8
> [ 4876.315245] [<ffffffff802be524>] __atomic_notifier_call_chain+0x3c/0x58
> [ 4876.321860] [<ffffffff802be588>] notify_die+0x38/0x48
> [ 4876.326913] [<ffffffff80272548>] do_trap_or_bp+0x48/0x1a8
> [ 4876.332312] [<ffffffff8026cfe4>] resume_userspace_check+0x0/0x10
> [ 4876.338323] [<ffffffff80462994>] jbd2_journal_put_journal_head+0xcc/0x250
> [ 4876.345111] [<ffffffff804603b4>] __jbd2_journal_remove_checkpoint+0x54/0x130
> [ 4876.352160] [<ffffffff8045e630>] jbd2_journal_commit_transaction+0x1318/0x1ad0
> [ 4876.359383] [<ffffffff80463f4c>] kjournald2+0x114/0x450
> [ 4876.364611] [<ffffffff802b8160>] kthread+0xb8/0xc0
> [ 4876.369402] [<ffffffff8026d060>] ret_from_kernel_thread+0x10/0x18
> 
> When i ran without multi-thread option, the problem was not ocurred.

Can you give us the full crash message, (i.e., the panic, the BUG,
WARN, the registers, etc.), and not the stack trace?

      	  	     	    	    - Ted

Re: EXT4 panic at jbd2_journal_put_journal_head() in 3.9+

[Theodore Ts'o]

Hmm, since you seem to be able to reproduce the problem reliably, any
chance you can try bisecting the problem?  I've looked at the commits
that touch fs/jbd2 and nothing is jumping out at me.

Also, how many CPU's do you have your system, and what kind of storage
device were you using when you were running iozone (5400rpm HDD,
7200RPM HDD, RAID array, SSD, etc.)?

Thanks,

						- Ted

Re: EXT4 panic at jbd2_journal_put_journal_head() in 3.9+

[David Daney]

On 05/10/2013 12:27 PM, Theodore Ts'o wrote:
> Hmm, since you seem to be able to reproduce the problem reliably, any
> chance you can try bisecting the problem?  I've looked at the commits
> that touch fs/jbd2 and nothing is jumping out at me.
>
> Also, how many CPU's do you have your system, and what kind of storage
> device were you using when you were running iozone (5400rpm HDD,
> 7200RPM HDD, RAID array, SSD, etc.)?

I too have seen this.

My system is:

   12 CPU Octeon (MIPS64)
   Root is ext3, mounted via ext4fs on a slow CompactFlash/PIO6

I saw the crash when simply booting  a fairly bare-bones Debian distro, 
although it is somewhat random:
.
.
ata3: PATA max PIO6 cmd 900000001d040000 ctl 900000001d05000d irq 63
.
.
ata3.00: CFA: CF 4GB, 20101001, max UDMA/133
ata3.00: 7847280 sectors, multi 0: LBA
ata3.00: configured for PIO6
.
.
scsi 2:0:0:0: Direct-Access     ATA      CF 4GB           2010 PQ: 0 ANSI: 5
sd 2:0:0:0: [sda] 7847280 512-byte logical blocks: (4.01 GB/3.74 GiB)
sd 2:0:0:0: [sda] Write Protect is off
sd 2:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't 
support DPO or FUA
  sda: sda1 sda2
sd 2:0:0:0: [sda] Attached SCSI disk
EXT4-fs (sda2): mounting ext3 file system using the ext4 subsystem
EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
VFS: Mounted root (ext3 filesystem) readonly on device 8:2.
.
.
.

I have not been able to get it to fail a second time.  So for me 
bisecting might not work.

David Daney


>
> Thanks,
>
> 						- Ted
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/
>
>

Re: EXT4 panic at jbd2_journal_put_journal_head() in 3.9+

[Theodore Ts'o]

On Sun, May 12, 2013 at 07:04:45PM -0700, Tony Luck wrote:
> My git bisect finally competed and points the a finger at:
> 
> commit ae4647fb7654676fc44a97e86eb35f9f06b99f66
> Author: Jan Kara <jack@suse.cz>
> Date:   Fri Apr 12 00:03:42 2013 -0400
> 
>     jbd2: reduce journal_head size
> 
>     Remove unused t_cow_tid field (ext4 copy-on-write support doesn't seem
>     to be happening) and change b_modified and b_jlist to bitfields thus
>     saving 8 bytes in the structure.

Both you and Eunbong Song bisected to the same commit, so presumably
the right thing to do at this point is to revert it.  Have you tried
reverting the commit and demonstrating that the problem goes away
afterwards?

The reason why I ask is that I'm completely at a lost to understand
why this commit could be making a difference.  Loooking at the commit,
we're converting two unsigned fields, neither of which use more than 4
bits or 1 bits, respectively, to use bitfields instead.  Why this
could be causing __journal_remove_journal_head() to fail, especially
in the way that it does, isn't making any sense to me.  We are
technically accessing jh->b_jlist without first locking
jbd2_lock_bh_state(), but (a) it shouldn't make a difference whether
we use a bitfield or 32-bit unsigned value, and (b) by the time we get
to __journal_remove_journal_head(), nothing should be using the
journal head, and we've locked jbd_lock_bh_journal_head(), which
should prevent any one else from starting to use the journal head.

Applying patch where I don't understand how it would make things
better, even if it is a revert, scares me.  If we are going to do
this, and since I haven't yet been able to reproduce it on my testing
setup, could you try taking Linus's just released 3.10-rc1 release,
and revert commit ae4647fb765467, and confirm that this avoids the
crash which you are seeing?

Thanks,

					- Ted

Re: EXT4 panic at jbd2_journal_put_journal_head() in 3.9+

[Theodore Ts'o]

On Sun, May 12, 2013 at 08:11:59PM -0700, Tony Luck wrote:
> 
> My best guess as to why this commit causes problems is that there are places
> where updates to individual fields in this structure used to be independent
> because they were to whole words.  Now we have bitfileds there are races
> between access to different fields in the same word.

Yeah, except we access the fields while holding a lock.... wait a
minute.  We're using bit_spinlocks().... and am I missing something?

Where are the barrier statements to prevent the CPU or the compiler
from reordering statements around bit_spin_lock()?  But if that's the
problem, I would have expected lots of other things to be broken.

	   	      	       	       	     - Ted

Re: EXT4 panic at jbd2_journal_put_journal_head() in 3.9+

[Sidorov, Andrei]

Hi,

Bitfields are likely to be implemented using read-modify-write semantics.
Modifications of either b_jlist or b_jmodified must be done under lock
since they share same uint. I guess this lock is missing somewhere.

Regards,
Andrei.

On 12.05.2013 20:07, Theodore Ts'o wrote:
> On Sun, May 12, 2013 at 07:04:45PM -0700, Tony Luck wrote:
>> My git bisect finally competed and points the a finger at:
>>
>> commit ae4647fb7654676fc44a97e86eb35f9f06b99f66
>> Author: Jan Kara <jack@suse.cz>
>> Date:   Fri Apr 12 00:03:42 2013 -0400
>>
>>     jbd2: reduce journal_head size
>>
>>     Remove unused t_cow_tid field (ext4 copy-on-write support doesn't seem
>>     to be happening) and change b_modified and b_jlist to bitfields thus
>>     saving 8 bytes in the structure.
> Both you and Eunbong Song bisected to the same commit, so presumably
> the right thing to do at this point is to revert it.  Have you tried
> reverting the commit and demonstrating that the problem goes away
> afterwards?
>
> The reason why I ask is that I'm completely at a lost to understand
> why this commit could be making a difference.  Loooking at the commit,
> we're converting two unsigned fields, neither of which use more than 4
> bits or 1 bits, respectively, to use bitfields instead.  Why this
> could be causing __journal_remove_journal_head() to fail, especially
> in the way that it does, isn't making any sense to me.  We are
> technically accessing jh->b_jlist without first locking
> jbd2_lock_bh_state(), but (a) it shouldn't make a difference whether
> we use a bitfield or 32-bit unsigned value, and (b) by the time we get
> to __journal_remove_journal_head(), nothing should be using the
> journal head, and we've locked jbd_lock_bh_journal_head(), which
> should prevent any one else from starting to use the journal head.
>
> Applying patch where I don't understand how it would make things
> better, even if it is a revert, scares me.  If we are going to do
> this, and since I haven't yet been able to reproduce it on my testing
> setup, could you try taking Linus's just released 3.10-rc1 release,
> and revert commit ae4647fb765467, and confirm that this avoids the
> crash which you are seeing?
>
> Thanks,
>
> 					- Ted
> --
> 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
>
>

Re: EXT4 panic at jbd2_journal_put_journal_head() in 3.9+

[Mike Galbraith]

On Sun, 2013-05-12 at 23:36 -0400, Theodore Ts'o wrote: 
> On Sun, May 12, 2013 at 08:11:59PM -0700, Tony Luck wrote:
> > 
> > My best guess as to why this commit causes problems is that there are places
> > where updates to individual fields in this structure used to be independent
> > because they were to whole words.  Now we have bitfileds there are races
> > between access to different fields in the same word.
> 
> Yeah, except we access the fields while holding a lock.... wait a
> minute.  We're using bit_spinlocks().... and am I missing something?
> 
> Where are the barrier statements to prevent the CPU or the compiler
> from reordering statements around bit_spin_lock()?  But if that's the
> problem, I would have expected lots of other things to be broken.

Those use test_and_set_bit(), which per Paul McMemory-Wizard...

ATOMIC OPERATIONS
-----------------

Whilst they are technically interprocessor interaction considerations, atomic
operations are noted specially as some of them imply full memory barriers and
some don't, but they're very heavily relied on as a group throughout the
kernel.

Any atomic operation that modifies some state in memory and returns information
about the state (old or new) implies an SMP-conditional general memory barrier
(smp_mb()) on each side of the actual operation (with the exception of
explicit lock operations, described later).  These include:

        xchg();
        cmpxchg();
        atomic_xchg();
        atomic_cmpxchg();
        atomic_inc_return();
        atomic_dec_return();
        atomic_add_return();
        atomic_sub_return();
        atomic_inc_and_test();
        atomic_dec_and_test();
        atomic_sub_and_test();
        atomic_add_negative();
        atomic_add_unless();    /* when succeeds (returns 1) */
        test_and_set_bit();
        test_and_clear_bit();
        test_and_change_bit();

Re: EXT4 panic at jbd2_journal_put_journal_head() in 3.9+

[Tony Luck]

The 3.10-rc1 with ae4647fb765467 reverted is still running OK. At
3 hours now (only marginally longer that the 2.5 hours that one of
the "bad" runs during the bisect managed).  So I'm about 30% sure
that we have a winner at the moment. I'll leave it running and check
again in the morning. This penguin is heading to bed now.

-Tony