.NET GC & Memory (2)

上の 2 つの GDNJ のスレッドでもちらほら言及されていますが,現在の CLR 実装では 85000 byte 以上のオブジェクトは Large Object Heap (LOH) に確保され,いきなり第二世代扱いで始まったりコンパクションが行われなかったりと色々特別扱いを受けることになります.実際,上のコードを走らせてみると第二世代 GC の回数がとんでもなく多いことに気付くかと思います.
つまり上のコードは,「通常 0 世代目の GC が頻発する」という仮定が成り立たない,かなり特殊な状況を見ていることになります.似たようなコードは時々お目にかかることがあって,例えば以前 id:Kazzz さんが紹介されていたベンチマーク記事がそれだったりします.

NyaRuRu 『んーと,微妙に長い話を色々書きたくなるようなベンチマークですな. (デバッグビルドしちゃうと IsJITTrackingEnabled とか IsJITOptimizerDisabled が付いちゃうんじゃないとか (Essential .NET 10.5) ,n^2 で文字数が増えていくところとか)

紹介されたリンク先で例として挙げられていたのは,次のようなコードでした.

// Test1
string str = string.Empty;
for (int i = 0; i < times; i++) {
   str += i.ToString();
}

このループでは概ね n^2 のオーダーで文字数が増えていき,i == 10721 あたりで 42500 文字を上回ります*1.

""
"" + "0"
"0" + "1"
"01" + "2"
"012" + "3"
"0123" + "4"
...
"0123...10720" + "10721"

このベンチマークは,単に + 演算子で文字列生成を繰り返すというだけでなく,生成されるオブジェクトが途中から LOH に確保されるほど大きくなるという特殊性を持っています.
比較のために,メモリ周りに注目して似たようなメモリ負荷を意図した Test2 を作ってみました.

// Test2
int length = 0;
for (int i = 0; i < times; i++)
{
    length += (int)Math.Log10(i + 1) + 1;
    char[] buf = new char[length];
    // 最適化で除去されないようにアクセスを行う
    buf[0] = '0';
} 

さらに,ソフトページフォルトを全領域に起こすべく*2もう少しメモリアクセス量を増やしたものが Test3 です.

// Test3
int length = 0;
for (int i = 0; i < times; i++)
{
    length += (int)Math.Log10(i+1)+1;
    char[] buf = new char[length];
    // まじめに全ページでページフォルトを発生させる
    for( int l = 0; l < length; l += 2048 )
    {
        buf[l] = '0';
    }
}

さらに比較用に,確保したメモリ全部を 0 クリアする Test4 です.

// Test4
int length = 0;
for (int i = 0; i < times; i++)
{
    length += (int)Math.Log10(i + 1) + 1;
    char[] buf = new char[length];
    // 比較用に全て 0 クリアもしてみる
    for (int l = 0; l < length; ++l)
    {
        buf[l] = '0';
    }
}

さて,手元の環境*3での実行結果ですが,こんな感じになりました.

テスト 経過時間 Gen0 GC Gen1 GC Gen2 GC ページフォルト
Test1 約 144 秒 33,914 33,423 33,359 4,489,941
Test2 約 6 秒 34,869 33,359 33,359 82,181
Test3 約 55 秒 34,869 33,359 33,359 10,380,720
Test4 約 112 秒 34,869 33,359 33,359 10,437,881

なんというか,あれだけ伏線を張っておいて GC 周りが実行時間に与える影響は結構微妙というのと,なにげにソフトページフォルト周りだけでそこそこの時間を消費していた疑いがあるという結果です.まあこういうことがあるから楽しいわけですけど.
Test2,Test3,Test4 の差なんかを .NET の世界だけで説明しようとすると本当に泥沼に嵌ってしまうんじゃないかと思います.ループ回数は 2048 倍に増えたのに,消費時間は 2 倍ちょっとしか増えないというのは,ソースコードだけを見て推測を巡らすというアプローチから見れば反則もいいところでしょう.
なんというか,あるレイヤーでもっともらしく犯人をでっちあげてみたら,一段下のレイヤー抜きでは説明がつかない現象がちらほら見え隠れする例,ということで.

*1:恐らくこのあたりで 85000 byte を越えると予想

*2:id:NyaRuRu:20051022#p4

*3:Intel XEON(Prestonia)@2.0GHz × 2, DDR DPC2100 ECC 1536MB,Windows XP SP2, .NET Framework 2.0, Visual C# 2005, 最適化ビルド ON