2009-02-06 17:35:18

by Alexander Beregalov

[permalink] [raw]
Subject: next-20090206: deadlock on ext4

Hi

I run dbench on ext4 on loop device.

EXT4-fs: barriers enabled
kjournald2 starting: pid 2420, dev loop0:8, commit interval 5 seconds
EXT4 FS on loop0, internal journal on loop0:8
EXT4-fs: delayed allocation enabled
EXT4-fs: file extents enabled
EXT4-fs: mballoc enabled
EXT4-fs: mounted filesystem loop0 with ordered data mode
JBD: barrier-based sync failed on loop0:8 - disabling barriers

INFO: task pdflush:2339 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
pdflush D 0000000000000002 3112 2339 2
ffff88007d861990 0000000000000046 ffff88007d861940 ffffffff802971c6
ffff88007d8618f8 0000000000004000 0000000000000000 ffff8800790bce40
ffff880035c7ce40 ffff8800790bd1d8 00000000790bce40 0000000000000282
Call Trace:
[<ffffffff802971c6>] ? mempool_alloc+0x56/0x150
[<ffffffff8062dbd5>] ? _spin_unlock_irqrestore+0x65/0x80
[<ffffffff8062ac47>] ? io_schedule+0x37/0x50
[<ffffffff8062abe3>] schedule+0x13/0x40
[<ffffffff8062ac47>] io_schedule+0x37/0x50
[<ffffffff8029442d>] sync_page+0x6d/0x80
[<ffffffff8062af52>] __wait_on_bit_lock+0x52/0xb0
[<ffffffff802943c0>] ? sync_page+0x0/0x80
[<ffffffff802943a4>] __lock_page+0x64/0x70
[<ffffffff80259460>] ? wake_bit_function+0x0/0x40
[<ffffffff8029e252>] ? pagevec_lookup_tag+0x22/0x30
[<ffffffff8029c687>] write_cache_pages+0x247/0x4a0
[<ffffffff8032b540>] ? __mpage_da_writepage+0x0/0x1b0
[<ffffffff8034cafe>] ? jbd2_journal_start+0xce/0x140
[<ffffffff8032b1e3>] ext4_da_writepages+0x263/0x4e0
[<ffffffff80269f65>] ? print_lock_contention_bug+0x25/0x120
[<ffffffff80269f65>] ? print_lock_contention_bug+0x25/0x120
[<ffffffff80269f65>] ? print_lock_contention_bug+0x25/0x120
[<ffffffff80269f65>] ? print_lock_contention_bug+0x25/0x120
[<ffffffff8032d090>] ? ext4_da_get_block_write+0x0/0x190
[<ffffffff8029c93b>] do_writepages+0x2b/0x50
[<ffffffff802e56a1>] __writeback_single_inode+0xa1/0x3f0
[<ffffffff802e5ee2>] ? generic_sync_sb_inodes+0x3a2/0x420
[<ffffffff802e5e88>] generic_sync_sb_inodes+0x348/0x420
[<ffffffff802e6145>] writeback_inodes+0x65/0x100
[<ffffffff8029d050>] background_writeout+0xb0/0xe0
[<ffffffff8029d840>] pdflush+0x110/0x1f0
[<ffffffff8029cfa0>] ? background_writeout+0x0/0xe0
[<ffffffff8029d730>] ? pdflush+0x0/0x1f0
[<ffffffff8029d730>] ? pdflush+0x0/0x1f0
[<ffffffff80258f76>] kthread+0x56/0x90
[<ffffffff8020ce5a>] child_rip+0xa/0x20
[<ffffffff80235759>] ? finish_task_switch+0x89/0x110
[<ffffffff8062db46>] ? _spin_unlock_irq+0x36/0x60
[<ffffffff8020c840>] ? restore_args+0x0/0x30
[<ffffffff80258f20>] ? kthread+0x0/0x90
[<ffffffff8020ce50>] ? child_rip+0x0/0x20
INFO: lockdep is turned off.
INFO: task kjournald2:2420 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kjournald2 D ffff88007b8d2090 4776 2420 2
ffff88003d117d40 0000000000000046 0000000000000000 ffff88007b8d2358
ffff8800790ba720 0000000000004000 0000000000000002 ffff8800790ba720
ffff88007c820000 ffff8800790baab8 000000028062dbd5 0000000000000286
Call Trace:
[<ffffffff8026bf69>] ? trace_hardirqs_on_caller+0x29/0x1e0
[<ffffffff8034e794>] ? jbd2_journal_commit_transaction+0x1d4/0x19b0
[<ffffffff8034e799>] ? jbd2_journal_commit_transaction+0x1d9/0x19b0
[<ffffffff8062abe3>] schedule+0x13/0x40
[<ffffffff8034e799>] jbd2_journal_commit_transaction+0x1d9/0x19b0
[<ffffffff8062dba8>] ? _spin_unlock_irqrestore+0x38/0x80
[<ffffffff80268709>] ? trace_hardirqs_off_caller+0x29/0xe0
[<ffffffff802358a0>] ? sub_preempt_count+0xc0/0x130
[<ffffffff80259420>] ? autoremove_wake_function+0x0/0x40
[<ffffffff8024cefc>] ? try_to_del_timer_sync+0x7c/0x90
[<ffffffff80354577>] kjournald2+0x117/0x380
[<ffffffff80259420>] ? autoremove_wake_function+0x0/0x40
[<ffffffff80354460>] ? kjournald2+0x0/0x380
[<ffffffff80258f76>] kthread+0x56/0x90
[<ffffffff8020ce5a>] child_rip+0xa/0x20
[<ffffffff80235759>] ? finish_task_switch+0x89/0x110
[<ffffffff8062db46>] ? _spin_unlock_irq+0x36/0x60
[<ffffffff8020c840>] ? restore_args+0x0/0x30
[<ffffffff80258f20>] ? kthread+0x0/0x90
[<ffffffff8020ce50>] ? child_rip+0x0/0x20
INFO: lockdep is turned off.
INFO: task dbench:2685 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
dbench D 0000000000000001 3296 2685 1
ffff8800793f9a18 0000000000000046 0000000000000000 ffff88007b8d21c8
ffff880035c78000 0000000000004000 0000000000000003 ffff880035c78000
ffff88007d2ace40 ffff880035c78398 000000038062dbd5 0000000000000286
Call Trace:
[<ffffffff8026bf69>] ? trace_hardirqs_on_caller+0x29/0x1e0
[<ffffffff8034c6a7>] ? start_this_handle+0x3b7/0x5e0
[<ffffffff8034c6ac>] ? start_this_handle+0x3bc/0x5e0
[<ffffffff8062abe3>] schedule+0x13/0x40
[<ffffffff8034c6ac>] start_this_handle+0x3bc/0x5e0
[<ffffffff80259420>] ? autoremove_wake_function+0x0/0x40
[<ffffffff8034caf7>] jbd2_journal_start+0xc7/0x140
[<ffffffff8029d5e5>] ? balance_dirty_pages_ratelimited_nr+0x365/0x3f0
[<ffffffff80336575>] ext4_journal_start_sb+0x55/0x90
[<ffffffff80329ef3>] ext4_da_write_begin+0xf3/0x260
[<ffffffff802965d7>] generic_file_buffered_write+0x137/0x340
[<ffffffff80296c19>] __generic_file_aio_write_nolock+0x269/0x470
[<ffffffff80296f29>] generic_file_aio_write+0x69/0xd0
[<ffffffff80325838>] ext4_file_write+0x58/0x170
[<ffffffff802c66a1>] do_sync_write+0xf1/0x140
[<ffffffff80259420>] ? autoremove_wake_function+0x0/0x40
[<ffffffff8026bf69>] ? trace_hardirqs_on_caller+0x29/0x1e0
[<ffffffff80250a72>] ? sys_kill+0xa2/0x1c0
[<ffffffff802c6d0b>] vfs_write+0xcb/0x170
[<ffffffff802c6e42>] sys_pwrite64+0x92/0xa0
[<ffffffff8020bddb>] system_call_fastpath+0x16/0x1b


2009-02-06 17:42:09

by Eric Sandeen

[permalink] [raw]
Subject: Re: next-20090206: deadlock on ext4

Alexander Beregalov wrote:
> Hi
>
> I run dbench on ext4 on loop device.
>
> EXT4-fs: barriers enabled
> kjournald2 starting: pid 2420, dev loop0:8, commit interval 5 seconds
> EXT4 FS on loop0, internal journal on loop0:8
> EXT4-fs: delayed allocation enabled
> EXT4-fs: file extents enabled
> EXT4-fs: mballoc enabled
> EXT4-fs: mounted filesystem loop0 with ordered data mode
> JBD: barrier-based sync failed on loop0:8 - disabling barriers
>
> INFO: task pdflush:2339 blocked for more than 120 seconds.

Looks a lot like a bug I filed:

http://bugzilla.kernel.org/show_bug.cgi?id=12579

but I'm having trouble reproducing it, now. I'll try dbench!

-Eric

2009-02-06 18:04:10

by Alexander Beregalov

[permalink] [raw]
Subject: Re: next-20090206: deadlock on ext4

2009/2/6 Eric Sandeen <[email protected]>:
> Alexander Beregalov wrote:
>> Hi
>>
>> I run dbench on ext4 on loop device.
>>
>> EXT4-fs: barriers enabled
>> kjournald2 starting: pid 2420, dev loop0:8, commit interval 5 seconds
>> EXT4 FS on loop0, internal journal on loop0:8
>> EXT4-fs: delayed allocation enabled
>> EXT4-fs: file extents enabled
>> EXT4-fs: mballoc enabled
>> EXT4-fs: mounted filesystem loop0 with ordered data mode
>> JBD: barrier-based sync failed on loop0:8 - disabling barriers
>>
>> INFO: task pdflush:2339 blocked for more than 120 seconds.
>
> Looks a lot like a bug I filed:
>
> http://bugzilla.kernel.org/show_bug.cgi?id=12579
>
> but I'm having trouble reproducing it, now. I'll try dbench!
Yes, I can reproduce it easy with dbench.

2009-02-06 20:07:18

by Eric Sandeen

[permalink] [raw]
Subject: Re: next-20090206: deadlock on ext4

Alexander Beregalov wrote:
> 2009/2/6 Eric Sandeen <[email protected]>:
>> Alexander Beregalov wrote:
>>> Hi
>>>
>>> I run dbench on ext4 on loop device.
>>>
>>> EXT4-fs: barriers enabled
>>> kjournald2 starting: pid 2420, dev loop0:8, commit interval 5 seconds
>>> EXT4 FS on loop0, internal journal on loop0:8
>>> EXT4-fs: delayed allocation enabled
>>> EXT4-fs: file extents enabled
>>> EXT4-fs: mballoc enabled
>>> EXT4-fs: mounted filesystem loop0 with ordered data mode
>>> JBD: barrier-based sync failed on loop0:8 - disabling barriers
>>>
>>> INFO: task pdflush:2339 blocked for more than 120 seconds.
>> Looks a lot like a bug I filed:
>>
>> http://bugzilla.kernel.org/show_bug.cgi?id=12579
>>
>> but I'm having trouble reproducing it, now. I'll try dbench!
> Yes, I can reproduce it easy with dbench.

Do you only hit it on loopback? What is the filesystem hosting the loop
file?

Thanks,
-Eric

2009-02-09 12:01:13

by Alexander Beregalov

[permalink] [raw]
Subject: Re: next-20090206: deadlock on ext4

2009/2/6 Eric Sandeen <[email protected]>:
> Alexander Beregalov wrote:
>> 2009/2/6 Eric Sandeen <[email protected]>:
>>> Alexander Beregalov wrote:
>>>> Hi
>>>>
>>>> I run dbench on ext4 on loop device.
>>>>
>>>> EXT4-fs: barriers enabled
>>>> kjournald2 starting: pid 2420, dev loop0:8, commit interval 5 seconds
>>>> EXT4 FS on loop0, internal journal on loop0:8
>>>> EXT4-fs: delayed allocation enabled
>>>> EXT4-fs: file extents enabled
>>>> EXT4-fs: mballoc enabled
>>>> EXT4-fs: mounted filesystem loop0 with ordered data mode
>>>> JBD: barrier-based sync failed on loop0:8 - disabling barriers
>>>>
>>>> INFO: task pdflush:2339 blocked for more than 120 seconds.
>>> Looks a lot like a bug I filed:
>>>
>>> http://bugzilla.kernel.org/show_bug.cgi?id=12579
>>>
>>> but I'm having trouble reproducing it, now. I'll try dbench!
>> Yes, I can reproduce it easy with dbench.
>
> Do you only hit it on loopback? What is the filesystem hosting the loop
> file?

I have reproduced it with 2.6.29-rc4.
Loop file was on XFS.
I can not reproduce it on ext4 on raw device.
Let me know if I can do anything else to help resolving it.

2009-02-13 22:21:50

by Eric Sandeen

[permalink] [raw]
Subject: Re: next-20090206: deadlock on ext4

Alexander Beregalov wrote:

> I have reproduced it with 2.6.29-rc4.
> Loop file was on XFS.
> I can not reproduce it on ext4 on raw device.
> Let me know if I can do anything else to help resolving it.
>
Can you try this patch from Aneesh? Works for me...

Thanks,
-Eric

From: Aneesh Kumar K.V <[email protected]>
Subject: [PATCH] ext4: Don't use the range_cylic mode implemented by
write_cache_pages

With delayed allocation we lock the page in write_cache_pages and
try to build an in memory extent of contiguous blocks. This is
needed so that we can get a large contiguous blocks request. Now
with range_cyclic mode in write_cache_pages if we have not done an
I/O we loop back to 0 index and try to write the page. That would
imply we will attempt to take page lock of lower index page holding
the page lock of higher index page. This can cause a dead lock with
other writeback thread.

Signed-off-by: Aneesh Kumar K.V <[email protected]>
Reviewed-by: Eric Sandeen <[email protected]>
Tested-by: Eric Sandeen <[email protected]>
---
fs/ext4/inode.c | 20 ++++++++++++++++++--
1 files changed, 18 insertions(+), 2 deletions(-)

Index: linux-2.6.28.x86_64/fs/ext4/inode.c
===================================================================
--- linux-2.6.28.x86_64.orig/fs/ext4/inode.c
+++ linux-2.6.28.x86_64/fs/ext4/inode.c
@@ -2437,6 +2437,7 @@ static int ext4_da_writepages(struct add
int no_nrwrite_index_update;
int pages_written = 0;
long pages_skipped;
+ int range_cyclic = 0, cycled = 1, io_done = 0;
int needed_blocks, ret = 0, nr_to_writebump = 0;
struct ext4_sb_info *sbi = EXT4_SB(mapping->host->i_sb);

@@ -2488,9 +2489,14 @@ static int ext4_da_writepages(struct add
if (wbc->range_start == 0 && wbc->range_end == LLONG_MAX)
range_whole = 1;

- if (wbc->range_cyclic)
+ if (wbc->range_cyclic) {
index = mapping->writeback_index;
- else
+ wbc->range_start = index << PAGE_CACHE_SHIFT;
+ wbc->range_end = LLONG_MAX;
+ wbc->range_cyclic = 0;
+ range_cyclic = 1;
+ cycled = 0;
+ } else
index = wbc->range_start >> PAGE_CACHE_SHIFT;

mpd.wbc = wbc;
@@ -2504,6 +2510,7 @@ static int ext4_da_writepages(struct add
wbc->no_nrwrite_index_update = 1;
pages_skipped = wbc->pages_skipped;

+retry:
while (!ret && wbc->nr_to_write > 0) {

/*
@@ -2546,6 +2553,7 @@ static int ext4_da_writepages(struct add
pages_written += mpd.pages_written;
wbc->pages_skipped = pages_skipped;
ret = 0;
+ io_done = 1;
} else if (wbc->nr_to_write)
/*
* There is no more writeout needed
@@ -2554,6 +2562,13 @@ static int ext4_da_writepages(struct add
*/
break;
}
+ if (!io_done && !cycled) {
+ cycled = 1;
+ index = 0;
+ wbc->range_start = index << PAGE_CACHE_SHIFT;
+ wbc->range_end = mapping->writeback_index - 1;
+ goto retry;
+ }
if (pages_skipped != wbc->pages_skipped)
printk(KERN_EMERG "This should not happen leaving %s "
"with nr_to_write = %ld ret = %d\n",
@@ -2561,6 +2576,7 @@ static int ext4_da_writepages(struct add

/* Update index */
index += pages_written;
+ wbc->range_cyclic = range_cyclic;
if (wbc->range_cyclic || (range_whole && wbc->nr_to_write > 0))
/*
* set the writeback_index so that range_cyclic

2009-02-18 09:56:33

by Alexander Beregalov

[permalink] [raw]
Subject: Re: next-20090206: deadlock on ext4

2009/2/14 Eric Sandeen <[email protected]>:
> Alexander Beregalov wrote:
>
>> I have reproduced it with 2.6.29-rc4.
>> Loop file was on XFS.
>> I can not reproduce it on ext4 on raw device.
>> Let me know if I can do anything else to help resolving it.
>>
> Can you try this patch from Aneesh? Works for me...
>

Yes, it works, I can not reproduce the bug on
2.6.29-rc5-00122-g5955c7a which contains 2acf2c261b82
"ext4: Implement range_cyclic in ext4_da_writepages instead of
write_cache_pages"

Thanks

2009-02-18 10:18:06

by Ralf Hildebrandt

[permalink] [raw]
Subject: Re: next-20090206: deadlock on ext4

> Yes, it works, I can not reproduce the bug on
> 2.6.29-rc5-00122-g5955c7a which contains 2acf2c261b82
> "ext4: Implement range_cyclic in ext4_da_writepages instead of
> write_cache_pages"

Will there be a backport for 2.6.28.x ?
I'm suffering here.

--
Ralf Hildebrandt [email protected]
Charite - Universitätsmedizin Berlin Tel. +49 (0)30-450 570-155
Geschäftsbereich IT | Abt. Netzwerk Fax. +49 (0)30-450 570-962
Hindenburgdamm 30 | 12200 Berlin

2009-02-18 14:01:32

by Theodore Ts'o

[permalink] [raw]
Subject: Re: next-20090206: deadlock on ext4

On Wed, Feb 18, 2009 at 11:12:18AM +0100, Ralf Hildebrandt wrote:
> > Yes, it works, I can not reproduce the bug on
> > 2.6.29-rc5-00122-g5955c7a which contains 2acf2c261b82
> > "ext4: Implement range_cyclic in ext4_da_writepages instead of
> > write_cache_pages"
>
> Will there be a backport for 2.6.28.x ?
> I'm suffering here.

The patch just hit mainline, so yes, I'll get a backport series set up.

- Ted