Re: [Bug 9546] New: Huge latency in concurrent I/O when using data=ordered

[Christian Casteyde <casteyde.christian@free.fr>]

OK for reply to all. I'm using the first mail received.

> Interesting that data=writeback helped this.  You don't give a lot of
> details, but I assume that data=writeback made a large difference here?

Well, my measures were taken by counting seconds from the desktop clock,
so the precision is roughly 1s. Here are the effective results from the 3 
journaling modes I have done yesterday :

Times in seconds:
ordered mode :	17	5	38	19	33
journal mode :		6	1	5	6	5
writeback mode :	4	1	7	6	8

I do not remember exactly the operation sequence, but the beginning was 
opening Konqueror, opening the bookmarks menu, loading a page, and opening 
another tab.

As you can see anyway, ordered is completely broken, opening the menu is near 
1s in journal and writeback mode, which is perfectly acceptable for a user 
(after all, the computer is loaded, and interactivity is not simply running 
interactive tasks at real time priority, so the the user can understand it 
reacts slower). Launching Konqueror in 4 to 6 seconds is a good time, given 
that the cache is poisoned by the writing process. Opening another tab or a 
web page is tolerable within 5-6s, even if this is still a little too long, 
specially for opening another tab of an already running process (2-3s would 
be a perfect value I think, but this is another story to get this). Certainly 
5-6s of latency is due to the block size used by the writing process, and 
tuning the kernel to get lower results would be dangerous for general 
performances. I could do tests by asking dd to write more but smaller blocks 
to check this idea.

As far as writeback is concerned, the latency reduction was not clear as you 
can see, at least with my mesurement procedure. For performance of the 
**writing process**, it was nearly the same as ordered. I havn't written the 
timings results for the writing process, since I was still investigating at 
that time. But I used :

time dowrite.sh

to time it, and I got real time, as well as dd output (records written, MB/s, 
and journal was half as ordered). So writeback and ordered seemed the same at 
this level, and journal mode was effectively twice slower. It was clear there 
was twice as most write operations, that was the expected behaviour.

I could redo the tests, with a more formal approach (that is: fixing the 
operations order done in Konqueror, and noting the times for the writing 
process), it's easy. In fact, I'm considering doing another script simulating 
Konqueror / user activities and timing them automatically, just to get a 
reproduceable benchmark suite.

Please note that not all programs are affected (for instance kmail was quite 
quick), so the kernel does a good job to run programs that do not many I/Os 
when the fs is stressed by another process. The difference with konqueror is 
it is opening several files (block dump says), so my guess is that processes 
doing small I/O operations are not given "journal access" fairly enough in 
ordered mode.

Indeed, I imagine (without knowing any internals of course) that the data 
writing is indeed scheduled correctly by the disk scheduler, and that the 
writing process is throttled, but the priority informations are lost when 
metadata are written in ordered mode, because all I/Os are mixed for 
metadata. Therefore, the writing process manages to fill the journal quite 
easily. With journal and writeback mode, all data may be written 
sequentially, in the context of the issuing process, so priorities may be 
tracked on the whole writing process. Then the writing process is prempted 
correctly to the benefits of Konqueror. This is of course just "black box" 
hypothesis...

CC