Re: CFQ read performance regression

From: Corrado Zoccolo
Date: Tue Apr 20 2010 - 16:50:21 EST

On Mon, Apr 19, 2010 at 1:46 PM, Miklos Szeredi <mszeredi@xxxxxxx> wrote:
> Hi Corrado,
>
> On Sat, 2010-04-17 at 14:46 +0200, Corrado Zoccolo wrote:
>> I don't think this is related to CFQ. I've made a graph of the
>> accessed (read) sectors (see attached).
>> You can see that the green cloud (2.6.16) is much more concentrated,
>> while the red one (2.6.32) is split in two, and you can better
>> recognize the different lines.
>> This means that the FS put more distance between the blocks of the
>> files written by the tio threads, and the read time is therefore
>> impacted, since the disk head has to perform longer seeks. On the
>> other hand, if you read those files sequentially with a single thread,
>> the performance may be better with the new layout, so YMMV. When
>> testing 2.6.32 and up, you should consider testing also with
>> low_latency setting disabled, since tuning for latency can negatively
>> affect throughput.
Hi Miklos,
can you give more information about the setup?
How much memory do you have, what is the disk configuration (is this a
hw raid?) and so on.
>
> low_latency is set to zero in all tests.
>
> The layout difference doesn't explain why setting the scheduler to
> "noop" consistently speeds up read throughput in 8-thread tiobench to
> almost twice. ÂThis fact alone pretty clearly indicates that the I/O
> scheduler is the culprit.
From the attached btt output, I see that a lot of time is spent
waiting to allocate new request structures.
> S2G 0.022460311 6.581680621 23.144763751 15
Since noop doesn't attach fancy data to each request, it can save
those allocations, thus resulting in no sleeps.
The delays in allocation, though, may not be completely imputable to
the I/O scheduler, and working in constrained memory conditions will
negatively affect it.

> There are other indications, see the attached btt output for both
> traces. ÂFrom there it appears that 2.6.16 does more and longer seeks,
> yet it's getting an overall better performance.
I see less seeks for 2.6.16, but longer on average.
It seems that 2.6.16 allows more requests from the same process to be
streamed to disk before switching to an other process.
Since the timeslice is the same, it might be that we are limiting the
number of requests per queue due to memory congestion.

> I've also tested with plain "dd" instead of tiobench where the
> filesystem layout stayed exactly the same between tests. ÂStill the
> speed difference is there.
Does dropping caches before the read test change the situation?

Thanks,
Corrado
>
> Thanks,
> Miklos
>
> ************************************************************************
> btt output for 2.6.16:
> ==================== All Devices ====================
>
> Â Â Â Â Â ÂALL Â Â Â Â Â MIN Â Â Â Â Â AVG Â Â Â Â Â MAX Â Â Â Â Â N
> --------------- ------------- ------------- ------------- -----------
>
> Q2Q Â Â Â Â Â Â Â 0.000000047 Â 0.000854417 Â 1.003550405 Â Â Â 67465
> Q2G Â Â Â Â Â Â Â 0.000000458 Â 0.000001211 Â 0.000123527 Â Â Â 46062
> G2I Â Â Â Â Â Â Â 0.000000123 Â 0.000001815 Â 0.000494517 Â Â Â 46074
> Q2M Â Â Â Â Â Â Â 0.000000186 Â 0.000001798 Â 0.000010296 Â Â Â 21404
> I2D Â Â Â Â Â Â Â 0.000000162 Â 0.000158001 Â 0.040794333 Â Â Â 46062
> M2D Â Â Â Â Â Â Â 0.000000878 Â 0.000133130 Â 0.040585566 Â Â Â 21404
> D2C Â Â Â Â Â Â Â 0.000053870 Â 0.023778266 Â 0.234154543 Â Â Â 67466
> Q2C Â Â Â Â Â Â Â 0.000056746 Â 0.023931014 Â 0.234176000 Â Â Â 67466
>
> ==================== Device Overhead ====================
>
> Â Â Â DEV | Â Â Â Q2G Â Â Â G2I Â Â Â Q2M Â Â Â I2D Â Â Â D2C
> ---------- | --------- --------- --------- --------- ---------
> Â( Â8, 64) | Â 0.0035% Â 0.0052% Â 0.0024% Â 0.4508% Â99.3617%
> ---------- | --------- --------- --------- --------- ---------
> Â Overall | Â 0.0035% Â 0.0052% Â 0.0024% Â 0.4508% Â99.3617%
>
> ==================== Device Merge Information ====================
>
>    DEV |    #Q    #D  Ratio |  BLKmin  BLKavg  BLKmax  ÂTotal
> ---------- | -------- -------- ------- | -------- -------- -------- --------
> Â( Â8, 64) | Â Â67466 Â Â46062 Â Â 1.5 | Â Â Â Â8 Â Â Â597 Â Â 1024 27543688
>
> ==================== Device Q2Q Seek Information ====================
>
> Â Â Â DEV | Â Â Â Â ÂNSEEKS Â Â Â Â Â ÂMEAN Â Â Â Â ÂMEDIAN | MODE
> ---------- | --------------- --------------- --------------- | ---------------
> Â( Â8, 64) | Â Â Â Â Â 67466 Â Â Â Â866834.0 Â Â Â Â Â Â Â 0 | 0(34558)
> ---------- | --------------- --------------- --------------- | ---------------
> Â Overall | Â Â Â Â ÂNSEEKS Â Â Â Â Â ÂMEAN Â Â Â Â ÂMEDIAN | MODE
> Â Average | Â Â Â Â Â 67466 Â Â Â Â866834.0 Â Â Â Â Â Â Â 0 | 0(34558)
>
> ==================== Device D2D Seek Information ====================
>
> Â Â Â DEV | Â Â Â Â ÂNSEEKS Â Â Â Â Â ÂMEAN Â Â Â Â ÂMEDIAN | MODE
> ---------- | --------------- --------------- --------------- | ---------------
> Â( Â8, 64) | Â Â Â Â Â 46062 Â Â Â 1265503.9 Â Â Â Â Â Â Â 0 | 0(13242)
> ---------- | --------------- --------------- --------------- | ---------------
> Â Overall | Â Â Â Â ÂNSEEKS Â Â Â Â Â ÂMEAN Â Â Â Â ÂMEDIAN | MODE
> Â Average | Â Â Â Â Â 46062 Â Â Â 1265503.9 Â Â Â Â Â Â Â 0 | 0(13242)
>
> ==================== Plug Information ====================
>
> Â Â Â DEV | Â Â# Plugs # Timer Us Â| % Time Q Plugged
> ---------- | ---------- ---------- Â| ----------------
> Â( Â8, 64) | Â Â Â29271( Â Â Â 533) | Â 3.878105328%
>
>    DEV |  ÂIOs/Unp  IOs/Unp(to)
> ---------- | ---------- Â ----------
> Â( Â8, 64) | Â Â Â 19.2 Â Â Â Â 19.7
> ---------- | ---------- Â ----------
>  Overall |  ÂIOs/Unp  IOs/Unp(to)
> Â Average | Â Â Â 19.2 Â Â Â Â 19.7
>
> ==================== Active Requests At Q Information ====================
>
> Â Â Â DEV | ÂAvg Reqs @ Q
> ---------- | -------------
> Â( Â8, 64) | Â Â Â Â Â 0.8
>
> ==================== I/O Active Period Information ====================
>
>    DEV |   # Live   ÂAvg. Act   Avg. !Act % Live
> ---------- | ---------- ------------- ------------- ------
> Â( Â8, 64) | Â Â Â Â545 Â 0.100012237 Â 0.005766640 Â94.56
> ---------- | ---------- ------------- ------------- ------
> ÂTotal Sys | Â Â Â Â545 Â 0.100012237 Â 0.005766640 Â94.56
>
> ************************************************************************
> btt output for 2.6.32:
>
> ==================== All Devices ====================
>
> Â Â Â Â Â ÂALL Â Â Â Â Â MIN Â Â Â Â Â AVG Â Â Â Â Â MAX Â Â Â Â Â N
> --------------- ------------- ------------- ------------- -----------
>
> Q2Q Â Â Â Â Â Â Â 0.000000279 Â 0.001710581 Â 1.803934429 Â Â Â 69429
> Q2G Â Â Â Â Â Â Â 0.000000908 Â 0.001798735 Â23.144764798 Â Â Â 54940
> S2G Â Â Â Â Â Â Â 0.022460311 Â 6.581680621 Â23.144763751 Â Â Â Â Â15
> G2I Â Â Â Â Â Â Â 0.000000628 Â 0.000001576 Â 0.000120409 Â Â Â 54942
> Q2M Â Â Â Â Â Â Â 0.000000628 Â 0.000001611 Â 0.000013201 Â Â Â 14490
> I2D Â Â Â Â Â Â Â 0.000000768 Â 0.289812035 Â86.820205789 Â Â Â 54940
> M2D Â Â Â Â Â Â Â 0.000005518 Â 0.098208187 Â 0.794441158 Â Â Â 14490
> D2C Â Â Â Â Â Â Â 0.000173141 Â 0.008056256 Â 0.219516385 Â Â Â 69430
> Q2C Â Â Â Â Â Â Â 0.000179077 Â 0.259305605 Â86.820559403 Â Â Â 69430
>
> ==================== Device Overhead ====================
>
> Â Â Â DEV | Â Â Â Q2G Â Â Â G2I Â Â Â Q2M Â Â Â I2D Â Â Â D2C
> ---------- | --------- --------- --------- --------- ---------
> Â( Â8, 64) | Â 0.5489% Â 0.0005% Â 0.0001% Â88.4394% Â 3.1069%
> ---------- | --------- --------- --------- --------- ---------
> Â Overall | Â 0.5489% Â 0.0005% Â 0.0001% Â88.4394% Â 3.1069%
>
> ==================== Device Merge Information ====================
>
>    DEV |    #Q    #D  Ratio |  BLKmin  BLKavg  BLKmax  ÂTotal
> ---------- | -------- -------- ------- | -------- -------- -------- --------
> Â( Â8, 64) | Â Â69430 Â Â54955 Â Â 1.3 | Â Â Â Â8 Â Â Â520 Â Â 2048 28614984
>
> ==================== Device Q2Q Seek Information ====================
>
> Â Â Â DEV | Â Â Â Â ÂNSEEKS Â Â Â Â Â ÂMEAN Â Â Â Â ÂMEDIAN | MODE
> ---------- | --------------- --------------- --------------- | ---------------
> Â( Â8, 64) | Â Â Â Â Â 69430 Â Â Â Â546377.3 Â Â Â Â Â Â Â 0 | 0(50235)
> ---------- | --------------- --------------- --------------- | ---------------
> Â Overall | Â Â Â Â ÂNSEEKS Â Â Â Â Â ÂMEAN Â Â Â Â ÂMEDIAN | MODE
> Â Average | Â Â Â Â Â 69430 Â Â Â Â546377.3 Â Â Â Â Â Â Â 0 | 0(50235)
>
> ==================== Device D2D Seek Information ====================
>
> Â Â Â DEV | Â Â Â Â ÂNSEEKS Â Â Â Â Â ÂMEAN Â Â Â Â ÂMEDIAN | MODE
> ---------- | --------------- --------------- --------------- | ---------------
> Â( Â8, 64) | Â Â Â Â Â 54955 Â Â Â Â565286.3 Â Â Â Â Â Â Â 0 | 0(37535)
> ---------- | --------------- --------------- --------------- | ---------------
> Â Overall | Â Â Â Â ÂNSEEKS Â Â Â Â Â ÂMEAN Â Â Â Â ÂMEDIAN | MODE
> Â Average | Â Â Â Â Â 54955 Â Â Â Â565286.3 Â Â Â Â Â Â Â 0 | 0(37535)
>
> ==================== Plug Information ====================
>
> Â Â Â DEV | Â Â# Plugs # Timer Us Â| % Time Q Plugged
> ---------- | ---------- ---------- Â| ----------------
> Â( Â8, 64) | Â Â Â 2310( Â Â Â Â 0) | Â 0.049353257%
>
>    DEV |  ÂIOs/Unp  IOs/Unp(to)
> ---------- | ---------- Â ----------
> Â( Â8, 64) | Â Â Â Â7.3 Â Â Â Â Â0.0
> ---------- | ---------- Â ----------
>  Overall |  ÂIOs/Unp  IOs/Unp(to)
> Â Average | Â Â Â Â7.3 Â Â Â Â Â0.0
>
> ==================== Active Requests At Q Information ====================
>
> Â Â Â DEV | ÂAvg Reqs @ Q
> ---------- | -------------
> Â( Â8, 64) | Â Â Â Â 132.8
>
> ==================== I/O Active Period Information ====================
>
>    DEV |   # Live   ÂAvg. Act   Avg. !Act % Live
> ---------- | ---------- ------------- ------------- ------
> Â( Â8, 64) | Â Â Â 4835 Â 0.023848998 Â 0.000714665 Â97.09
> ---------- | ---------- ------------- ------------- ------
> ÂTotal Sys | Â Â Â 4835 Â 0.023848998 Â 0.000714665 Â97.09
>
>
>
>
¢éì®&Þ~º&¶¬–+-±éÝ¥Šw®žË±Êâmébžìdz¹Þ)í…æèw*jg¬±¨¶‰šŽŠÝj/êäz¹ÞŠà2ŠÞ¨è­Ú&¢)ß«a¶Úþø®G«éh®æj:+v‰¨Šwè†Ù>Wš±êÞiÛaxPjØm¶Ÿÿà -»+ƒùdš_