On Thu, Apr 08, 2010 at 11:28:50AM +0200, Jan Kara wrote:
So Jen's writeback tracing shows this for a normal cycle during a
large dd:
<...>-6030 [005] 604446.696454: writeback_sched: work=38c0, task=task
flush-253:16-6029 [002] 604446.696492: writeback_exec: work=38c0 pages=9223372036854775807, sb=0, kupdate=0, range_cyclic=-1 for_background=-1
flush-253:16-6029 [002] 604446.696493: writeback_clear: work=ffff88011f1a38c0, refs=1
flush-253:16-6029 [003] 604446.784240: writeback_pages_written: 1024
There were 100 of these traces (102400 pages (400MB) which is exactly 10% of
RAM) before this:
<...>-6030 [000] 604462.346329: writeback_sched: work=6c0, task=task
flush-253:16-6029 [002] 604462.267098: writeback_exec: work=6c0 pages=9223372036854775807, sb=0, kupdate=0, range_cyclic=-1 for_background=-1
flush-253:16-6029 [002] 604462.267101: writeback_clear: work=ffff88011e8006c0, refs=1
flush-253:16-6029 [001] 604465.406331: writeback_pages_written: 160771
which shows 160771 pages written in a single iteration (650MB). I suspect some
interaction between foreground and background writeout is occurring here.
The flusher thread appears to be getting stuck on congestion - the wchan
it is sitting on indicates it is blocking in get_request(). I'm going to
extend this tracing further down into the writeback code so that what is
happening is clearer...
Cheers,
Dave.
--
Dave Chinner
david@fromorbit.com
--