When other IO is running sync times go to 10 to 20 minutes
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #22 from Michael Godfrey <[email protected]> 2010-04-02 05:41:26 --- I tried another test with 2.6.32.10-90.fc12.x86_64. I did
not expect an improvement. But, the results were actually
a lot worse. After starting an rsync which transferred a
few 100GB through NFS, I started a sync using time sync.
This caused a number of the usual 2 minute timeout messages. But, also
it did not close until about 20 minutes after the rsync had
completed. All together it ran for several hours. By the
way it was not possible to kill the sync using kill -9.
This is clearly hopeless.
Will anything be done about this in 2.6.33 for fc13?
Will the fact that Google is going with ext4 possibly help?
Michael
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #23 from Eric Sandeen <[email protected]> 2010-04-02 16:41:39 --- The patch in comment #18 is still not upstream. Jan, what's the status of that?
Michael, I did discover one issue upstream related to fsync, see:
http://marc.info/?l=linux-ext4&m=126987658403214&w=2
This was very inefficient scanning of large files for sync. However, for sys_sync, I didn't see the problem because the loop was limited in that case, so it may not be related.
(In reply to comment #3)
Quoted 7 lines
Quoted 4 lines
This problem prevents production use of systems using this kernel.
evokes a question: Do you have a kernel which behaved better for you? Which one?
Yes. RHEL5.4 does not show this problem. It is the production system that works in this environment.
RHEL5.4 on ext3 or ext4?
Quoted 2 lines
The response above is disappointing. Is sync response of 20 minutes, including several task timeouts to be considered "normal?"
Probably not, but it really depends. If you have a system with massive amounts of memory, and a slow path to the disk, then sure, if you have to flush many many gigabytes it will be slow. But that's extreme, and I don't think you're in that case. You do have a 12G box though, so that's potentially a lot of memory to flush. OTOH your storage should probably be reasonably fast.
It does seem like something else is going on here.
(In reply to comment #22)
Quoted 10 lines
I tried another test with 2.6.32.10-90.fc12.x86_64. I did not expect an improvement. But, the results were actually
a lot worse. After starting an rsync which transferred a few 100GB through NFS, I started a sync using time sync. This caused a number of the usual 2 minute timeout messages. But, also it did not close until about 20 minutes after the rsync had completed. All together it ran for several hours. By the way it was not possible to kill the sync using kill -9.This is clearly hopeless.
Hm, don't give up quite yet ;)
Can you describe this test a little more explicitly; which box was the nfs server vs. client, which boxes were the rsync servers/clients, which box ran sync? I just don't want to make wrong assumptions in trying to recreate this.
Quoted 1 line
Will anything be done about this in 2.6.33 for fc13?
we still have to get to the bottom of the problem before we can talk about fixes, I'm afraid.
Quoted 1 line
Will the fact that Google is going with ext4 possibly help?
I don't think so.
One thing that may be interesting is to run blktrace (or use seekwatcher to do that for you) during the sync call that is stalling out, to get an idea of what is happening at the block layer and when.
--- Comment #24 from Eric Sandeen <[email protected]> 2010-04-02 21:23:21 --- For what it's worth, assuming I have replicated the behavior properly, the long-running sync doesn't seem unique to ext4 at all.
I can replicate it by running a script which creates 4G files in sequence, putting it in the background, sleeping for a while, and typing "sync" - which never returns.
I see the same behavior on ext4 as well as xfs and ext3.
I applied Jan's patch from comment #18, and the behavior is unchanged.
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #25 from Jan Kara <[email protected]> 2010-04-06 16:46:52 --- As I'm reading through wb_writeback, it could happen that the flushing thread gets stuck in background flushing and thus we never gets to processing the work for sync(1) and thus sync(1) never finishes. The attached patch should fix that.
Eric, could you please test whether this patch together with the patch from comment 18 fixes your testcase?
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #26 from Jan Kara <[email protected]> 2010-04-06 16:47:54 --- Created an attachment (id=25882)
--> (https://bugzilla.kernel.org/attachment.cgi?id=25882)
Patch to stop background writeback when other IO is in progress
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
Jan Kara <[email protected]> changed:
What |Removed |Added
----------------------------------------------------------------------------
Attachment #25882|Patch to stop background |Patch to stop background
description|writeback when other IO is |writeback when other work
|in progress |is queued for the thread--- Comment #26 from Jan Kara <[email protected]> 2010-04-06 16:47:54 --- Created an attachment (id=25882)
--> (https://bugzilla.kernel.org/attachment.cgi?id=25882)
Patch to stop background writeback when other IO is in progress
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #27 from Eric Sandeen <[email protected]> 2010-04-06 16:52:28 --- Jan, will do after lunch. Thanks for looking into this!
-Eric
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
Jan Kara <[email protected]> changed:
What |Removed |Added
----------------------------------------------------------------------------
Attachment #25882|0 |1
is obsolete| |
--- Comment #28 from Jan Kara <[email protected]> 2010-04-06 16:55:10 --- Created an attachment (id=25883)
--> (https://bugzilla.kernel.org/attachment.cgi?id=25883)
Patch to stop background writeback when other work is queued for the thread
Oops, attached a wrong patch. This is the right one.
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #29 from Eric Sandeen <[email protected]> 2010-04-06 22:59:27 --- A quick test on ext3 looks good; ext4 still seems to run away on sync :(
But I need to be a bit more methodical, and test a few more filesystems; will let you know.
I'm not familiar enough with all the new writeback code; does this mean that a sync will return as soon as any new IO is queued post-sync? That seems odd if so - but maybe I misunderstand.
Thanks,
-Eric
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #29 from Eric Sandeen <[email protected]> 2010-04-06 22:59:27 --- A quick test on ext3 looks good; ext4 still seems to run away on sync :(
But I need to be a bit more methodical, and test a few more filesystems; will let you know.
I'm not familiar enough with all the new writeback code; does this mean that a sync will return as soon as any new IO is queued post-sync? That seems odd if so - but maybe I misunderstand.
Thanks,
-Eric
--- Comment #30 from Eric Sandeen <[email protected]> 2010-04-06 23:05:57 --- Hm maybe I spoke too soon, had a couple runs on ext3 that looked good but now it's been syncing for many minutes ...
(this is the test where I create 4G files in a loop, let it go for a while, then time sync - on a 16g box)
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #31 from Jan Kara <[email protected]> 2010-04-07 09:33:00 --- (In reply to comment #29)
Quoted 3 lines
I'm not familiar enough with all the new writeback code; does this mean that a sync will return as soon as any new IO is queued post-sync? That seems odd if so - but maybe I misunderstand.
No. The patch means that writeback thread stops doing pdflush-style writeback
when it sees new work queued - work does not mean IO. It means that someone asks writeback thread to do some kind of writeout... Now I'm still not sure my patch is the right approach to the problem but I just wanted to checkout whether it
at least solves the problem of this particular workload.
If you still see the problem (only less often) even with ext3, then we
probably have also some other work that is livelockable and thus we never get to work submitted by sync(1). I guess I'll have to find a machine with enough disks and memory to try this out...
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #32 from Eric Sandeen <[email protected]> 2010-04-07 15:09:56 --- I'm doing this on a machine with a single spare disk, dedicated to the test, so
disks aren't an issue. I haven't tried to replicate with less memory.
I'll try to poke at it a bit more today...
-Eric
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
Neil Broomfield <[email protected]> changed:
What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected] | |om
--- Comment #33 from Neil Broomfield <[email protected]> 2010-04-15 08:44:13 --- I think I might be seeing the same/similar issue, see "dmesg | tail" below, it seams fairly repeatable and occurs usually when I move a file from my download drive to my raid array 5 (5 disk, 6TB), I'm running Ubuntu 9.10 with all the latest official patches.
[301080.930044] INFO: task kjournald2:1583 blocked for more than 120 seconds. [301080.930048] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [301080.930051] kjournald2 D ffff88007734e8e0 0 1583 2 0x00000000 [301080.930056] ffff88006c38dd10 0000000000000046 ffff88005695d850 0000000000015880 [301080.930060] ffff880070d247c0 0000000000015880 0000000000015880 0000000000015880 [301080.930063] 0000000000015880 ffff880070d247c0 0000000000015880 0000000000015880 [301080.930066] Call Trace: [301080.930075] [<ffffffff811f096a>] jbd2_journal_commit_transaction+0x1aa/0x1120 [301080.930080] [<ffffffff8127c336>] ? rb_erase+0xd6/0x160 [301080.930085] [<ffffffff81010785>] ? __switch_to+0x1e5/0x370 [301080.930088] [<ffffffff8104f075>] ? finish_task_switch+0x65/0x120 [301080.930093] [<ffffffff8152c98a>] ? _spin_lock_irqsave+0x2a/0x40 [301080.930097] [<ffffffff8106af57>] ? lock_timer_base+0x37/0x70 [301080.930101] [<ffffffff81078a30>] ? autoremove_wake_function+0x0/0x40 [301080.930105] [<ffffffff811f6963>] kjournald2+0x103/0x270 [301080.930108] [<ffffffff81078a30>] ? autoremove_wake_function+0x0/0x40 [301080.930111] [<ffffffff811f6860>] ? kjournald2+0x0/0x270 [301080.930114] [<ffffffff81078646>] kthread+0xa6/0xb0 [301080.930117] [<ffffffff8101316a>] child_rip+0xa/0x20 [301080.930120] [<ffffffff810785a0>] ? kthread+0x0/0xb0 [301080.930123] [<ffffffff81013160>] ? child_rip+0x0/0x20 [301080.930145] INFO: task mv:2005 blocked for more than 120 seconds. [301080.930146] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [301080.930148] mv D ffff880079705928 0 2005 2464 0x00000000 [301080.930152] ffff8800210f9868 0000000000000086 ffff8800210f97e8 0000000000015880 [301080.930155] ffff880003b747c0 0000000000015880 0000000000015880 0000000000015880 [301080.930159] 0000000000015880 ffff880003b747c0 0000000000015880 0000000000015880 [301080.930162] Call Trace: [301080.930165] [<ffffffff8152c87d>] __down_read+0x8d/0xc6 [301080.930169] [<ffffffff8152bc49>] down_read+0x19/0x20 [301080.930172] [<ffffffff811b5fe2>] ext4_get_blocks+0x52/0x210 [301080.930175] [<ffffffff811b62e7>] ext4_da_get_block_prep+0x77/0x100 [301080.930179] [<ffffffff81148663>] __block_prepare_write+0x1c3/0x560 [301080.930182] [<ffffffff811b6270>] ? ext4_da_get_block_prep+0x0/0x100 [301080.930185] [<ffffffff81148b9f>] block_write_begin+0x5f/0x100 [301080.930188] [<ffffffff811b8a0d>] ext4_da_write_begin+0x12d/0x260 [301080.930191] [<ffffffff811b6270>] ? ext4_da_get_block_prep+0x0/0x100 [301080.930194] [<ffffffff8104f075>] ? finish_task_switch+0x65/0x120 [301080.930198] [<ffffffff810da1a2>] generic_perform_write+0xb2/0x1d0 [301080.930202] [<ffffffff811e4dbb>] ? ext4_xattr_get+0x5b/0x90 [301080.930206] [<ffffffff810dafd3>] generic_file_buffered_write+0x83/0x140 [301080.930209] [<ffffffff810dc950>] __generic_file_aio_write_nolock+0x240/0x470 [301080.930213] [<ffffffff811348f3>] ? touch_atime+0x33/0x150 [301080.930216] [<ffffffff810dcca0>] generic_file_aio_write+0x70/0xf0 [301080.930221] [<ffffffff811ae7f9>] ext4_file_write+0x49/0x160 [301080.930225] [<ffffffff8111f342>] do_sync_write+0xf2/0x130 [301080.930229] [<ffffffff811511db>] ? fsnotify+0xfb/0x140 [301080.930232] [<ffffffff81078a30>] ? autoremove_wake_function+0x0/0x40 [301080.930235] [<ffffffff81133333>] ? dput+0xc3/0x190 [301080.930239] [<ffffffff81224a11>] ? security_file_permission+0x11/0x20 [301080.930242] [<ffffffff8111f628>] vfs_write+0xb8/0x1a0 [301080.930245] [<ffffffff811200dc>] sys_write+0x4c/0x80 [301080.930249] [<ffffffff81012082>] system_call_fastpath+0x16/0x1b
Let me know if I can be of any further assistance? If you require more info / test running, I'm happy to help.
Neil
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
Dave Chinner <[email protected]> changed:
What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]
--- Comment #34 from Dave Chinner <[email protected]> 2010-04-20 02:49:34 --- See:
http://marc.info/?l=linux-fsdevel&m=127166071530948&w=2
Sync is acting as designed right now. I agree it's not ideal, but it's now defaulting to slow-but-safe behaviour rather than the previous behaviour of potentially not syncing everything that was dirty at the time of the sync call.
Cheers,
Dave.
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #35 from Michael Godfrey <[email protected]> 2010-04-20 03:46:28 --- Dave (above) said:
"Sync is acting as designed right now. I agree it's not ideal, but it's now defaulting to slow-but-safe behaviour rather than the previous behaviour of potentially not syncing everything that was dirty at the time of the sync call.
Dave,"
Are you aware that this blocks other IO so that a user who requests a read of some data may have to wait for something like 20 minutes before getting a response? This includes, for instance, just typing vi xxx. Take a look at the reports above which show nfsd being effectively blocked for periods of more than 20 minutes.
For me this is not just "not ideal" but simply useless. I do not see how a system with this behavior can be used.
I also do not see why sync completing with dirty data is a problem. In an active system there will be new dirty data within milliseconds of sync completion no matter what it does.
I am well-aware that this is not a simple problem. But, a solution that is consistent with the usability of the system is necessary.
Michael
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #38 from Michael Godfrey <[email protected]> 2010-04-30 06:02:32 --- Just a couple of comments on the posts above:
1. In our environment, home directories are NFS mounted, so vi cannot read .vimrc. It appears that this is where it hangs. The important thing is that nothing appears on the user's screen after typing vi.
2. We do not have an XFS filesystem, so I cannot comment on whether these problems exist for XFS.
3. The comments indicate that, as usual, there is more than one problem. I am hopeful that the ext4 problem that Eric Sandeen is fixing and proposed fixes for sync will make a significant difference.
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
Ritesh Raj Sarraf <[email protected]> changed:
What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]
--- Comment #36 from Dave Chinner <[email protected]> 2010-04-20 05:24:39 --- (In reply to comment #35)
Quoted 4 lines
Are you aware that this blocks other IO so that a user who requests a read of some data may have to wait for something like 20 minutes before getting a response? This includes, for instance, just typing vi xxx.
That's not a just a read - vi(m) writes a backup file when you open it. So it's blocking on writes.
However, that sort of antisocial behaviour under heavy write loads is usually caused by a filesystem concurrency limitation or a IO scheduler problem, not sync. However, unless you can reproduce the read hangs on XFS when sync is running, then I'm not the expert you're looking for to debug them. ;)
But I do know the endless sync problem is filesystem independent and I'm trying to do something about mitigating it's effects:
http://lkml.org/lkml/2010/4/19/410
Quoted 2 lines
Take a look at the reports above which show nfsd being effectively blocked for periods of more than 20 minutes.
Can't say I've heard of any such recent problems on XFS....
Cheers,
Dave.
--- Comment #37 from Neil Broomfield <[email protected]> 2010-04-20 09:00:28 --- "Can't say I've heard of any such recent problems on XFS...."
Are these not effectivly the same issue?:
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/276476
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/494476
Neil
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
Justin Maggard <[email protected]> changed:
What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]
--- Comment #39 from Justin Maggard <[email protected]> 2010-05-20 02:11:11 --- (In reply to comment #28)
Quoted 1 line
Created an attachment (id=25883)
--> (https://bugzilla.kernel.org/attachment.cgi?id=25883) [details]
Quoted 3 lines
Patch to stop background writeback when other work is queued for the thread
Oops, attached a wrong patch. This is the right one.
I ran into this issue recently (extra long sync times) and have been trying the patches attached in this thread. The above patch specifically causes a pretty significant performance regression for me doing a simple sequential dd write on a dual-core Atom system running 2.6.33.4 x86_64. This command:
dd bs=1M conv=fsync if=/dev/zero of=test_file count=10000
went from 135 MB/sec to all the way down to 92.9 MB/sec. Is this expected?
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
Jan Kara <[email protected]> changed:
What |Removed |Added
----------------------------------------------------------------------------
Attachment #25883|0 |1
is obsolete| |
--- Comment #40 from Jan Kara <[email protected]> 2010-05-20 11:11:41 --- Created an attachment (id=26456)
--> (https://bugzilla.kernel.org/attachment.cgi?id=26456)
Patch to stop background writeback when other work is queued for the thread
Ah, there's a bug in the condition in the original patch and thus it stops background writeback when there it *no* other work queued instead when there *is*. Could you please test this fixed version?
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
--- Comment #41 from Justin Maggard <[email protected]> 2010-05-20 17:53:08 --- Ah, much better. :) Performance for me with this version is now just about the same as without the patch.
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
Alan <[email protected]> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |RESOLVED
CC| |[email protected]
Resolution| |OBSOLETESignature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.
https://bugzilla.kernel.org/show_bug.cgi?id=14830
Alan <[email protected]> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|RESOLVED |CLOSED
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching the assignee of the bug.