目次


パフォーマンスの目

ガーベジ・コレクションを調整する

100MBのガーベジを50MBの中に詰め込む

Comments

コンテンツシリーズ

このコンテンツは全#シリーズのパート#です: パフォーマンスの目

このシリーズの続きに乞うご期待。

このコンテンツはシリーズの一部分です:パフォーマンスの目

このシリーズの続きに乞うご期待。

公開日記としてのblogの人気が高まるにつれ、blogのホストが急速に増加しています。Blog-Cityの人々にとっては、自分たちのサイトを進化させ成長させる必要があるのは自明でした。要求の増大に対応するためBlog-Cityではつい最近、Blog-City version 2.0をリリースしました。ところが新しいアプリケーションが実稼働に入る場合にはよくあることですが、色々な要因から、新しいバージョンのパフォーマンスが期待したように上がりません。しかも一見不規則に、アプリケーションが突然長い間ハングアップしたように見える期間があるのです。

Blog-Cityはその核の部分をBlue Dragonサーブレット・エンジン(CFMLエンジンの一つ)とデータベースに依存しています。驚いたことに、このソフトウェアを全て、かなり古いP3マシンでRed Hat Linuxを実行することでホストしているのです。このマシンにはハードディスクが1台と512MBのRAMがついており、これまでの負荷には十分強力だったのですが、急速に増大する負荷に息切れしていました。Blog-Cityは自らの成功の犠牲となったわけです。とはいっても当面使えるのはこのハードウェアだけなのです。

問題を定義する

最初のステップは、なぜアプリケーションが突然遅くなってしまうのかの原因を特定することでした。容疑者リストの一番はガーベジ・コレクションです。前回のコラムで示したように、ガーベジ・コレクションとメモリ利用の問題がアプリケーションのパフォーマンスにマイナスの影響を与えているかどうかを判断するには、JVMオプションの-verbose:gcを設定し、ログ出力を調べてみることです。そこで私たちは冗長ガーベジ・コレクション・ログをオンにしてアプリケーションを再起動し、パフォーマンスが低下するまで辛抱強く待ちました。辛抱の甲斐あってGCログファイルから驚くようなことが分かったのです。

ログファイルの解析を始めた時から、このアプリケーションではガーベジ・コレクションがボトルネックとなっていることは明らかでした。GCの頻度、持続時間、そして全体的なGC効率がその証拠としてあげられます。通常以上の頻度でGCが起きるのは普通、ヒープの大きさが現在使われている生きたオブジェクト(live objects)全てをようやく収容できる程度しかなく、生成されつつある新しいオブジェクトを収容するほどには大きくない場合です。アプリケーションが自分の消費する以上のヒープを消費してしまうのにはいくつもの理由がありますが、十分なメモリが無い場合にはガーベジ・コレクターが現在の必要に応じようとして、もがき回ることになります。言い換えれば、アプリケーションが新しいオブジェクトを割り付けようとして失敗し、失敗する時にガーベジ・コレクションをトリガーするのです。そのGCが十分なメモリを回復できない場合には、別の、より高価なGCを強制するのです。たとえGCがとりあえずの要求を満足するのに十分なスペースを回復しても、まず確実にアプリケーションが間もなく再び割り付け失敗を起こし、また別のGCをトリガーしてしまいます。その結果JVMはアプリケーションをサービスする代わりに、空きのあるヒープ空間を繰り返し求め続けるという、実りのない作業に専念してしまうのです。

アプリケーションが使用可能なヒープ空間を全部消費してしまうのには多くの理由がありますが、便宜的には、(メモリがあるのであれば)より大きなヒープを設定すればよいわけです。アプリケーションにメモリ・リーク(あるいは、意図せずに保持されたオブジェクト(unintentionally retained objects)と呼びたいのですが)が無いとすれば、そのアプリケーションは「自然な」ヒープ消費量レベルを見つけるので、GCはそのレベルを問題なく維持できます(オブジェクト生成が速すぎ、GCが追いつこうとして動き続けるのでない限り)。この場合には、また意図せずに保持されたオブジェクトの場合には、何らかの改善を得るにはアプリケーションに変更を加える必要があります。

そんなに簡単だったら良いのですが

残念なことに、非常にやっかいだと言わざるを得ませんでした。このマシンには512MBのRAMしかないのです。さらに悪いことにそのRAMスペースを、データベースや、そのマシンで実行する他のプロセスと共有しなければならないのです。なぜこれが致命的に重要かを理解するには、ガーベジ・コレクションの基本、つまりその下にあるオペレーティング・システムとの相互動作を理解する必要があります。

仮想メモリはもはや友達ではありません

仮想メモリは長年、多くのオペレーティング・システムで使われています。ご存じの通り、仮想メモリによってOSには実際よりも多くのメモリあるように見え、使用可能な物理RAMに収まりきらないようなプログラムであっても、メモリに入りきらない部分をディスクに保持しておくことによって実行できるようになります。さらなる単純化として、OSはメモリを、一度に一ページ操作します。ページは通常512バイトから8KBであり、全部のページを組み合わせて仮想アドレス空間を構成します。OSは仮想アドレスを物理アドレスにマップするテーブルを持っています。アプリケーションが、あるメモリ位置の内容を要求すると、OS(またはハードウェア)はその仮想アドレスを含むページを特定します。OSは次にそのページがメモリ内にあるかどうかを判別し、無い場合にはページ・フォールトが出されます。ページ・フォールトの処理には多くの方法がありますが、最終的な結果として、そのページをディスクからメモリにロードする必要があります。そうなって初めてアプリケーションは要求した仮想アドレスの内容にアクセスできるのです。

もし関連したオブジェクトが常にメモリ中の同じページにまとまっていれば、ほとんど困難もなくGCを進められるでしょう。ところが現実の世界では、関連したオブジェクトがまとまっていることは(あったとしても)非常に稀です。結果として仮想メモリに依存するシステムでは、オペレーティング・システムがマーク付けしながらメモリ内外にあるページを次々に取り換えて行き、次にヒープ空間を掃いて回ることになります。その間GCは実際にメモリを埋めるための時間よりも長い時間を、ページがディスクから取り出されてくるのを待つために費やすことになります。ですからアプリケーションがGCを待ち、GCがディスクを待っている間、実際の作業は何も進まないことになります。一般的で健全な助言として、JVMヒープの大きさは、利用可能な物理メモリから他のプロセスが使用する分を差し引いた大きさ以上にならないようにすべきです。このシステムにはディスクが1台しかなく、データベースもサポートする必要があることを考慮すると、私たちは非常に困難な状況にありました。GCの頻度を減らすためにメモリ量を増やす必要がある一方で、データベースとの共存を図る必要もありました。データベースもメモリを大量に要求するのです。ですから私たちは、このアプリケーションが最低限必要とするメモリ量を理解する必要がありました。

前回書いた通り、この情報は冗長GCログの中に既に含まれています。私たちはこの情報を探すためにログを懸命にたどることはせず、無料のJTuneツール(参考文献)を使って冗長GCログを分析しました。図1は-Xmxを256 MBに設定した時の、GC後のメモリ利用グラフです。

図1. GC後のメモリ利用
Figure 1. Memory utilization after GC
Figure 1. Memory utilization after GC

verbose:gc出力を解析する

図1で青色の部分は部分GCを表します。オレンジ色の部分はフルGCを表し、ピンクの四角は2つのフルGCが1ミリ秒以内の間隔で起きていることを表しています。この要約を見てみると、12,823回のスカベンジ(scavenge)が行われ、その平均は0.257秒です。345回のフルGCが行われ、44回は連続で起きています。フルGCの平均持続時間は7.303秒であり、これはガーベジ・コレクションが費やす実行時間の9.36%です。この値は高いことは高いですが、一般的に目標とされる10%以下にはなっています。ですからこの例に関して言うと、GCはシステムに負荷を与えていますが、程度は深刻なものではありません。真の問題はメモリ・リークが起きていることで、これはヒープ利用が徐々に上昇傾向にあることから分かります。

このリークは50MBのメモリを消費するのですが、長い期間に渡って起こるため、短期間のテストでは気が付きにくいものです。メモリ・リークの実際的な影響としては、JVMが(そして結果的にOSが)ページングを開始せざるを得なくなる点にまでJVMのメモリ消費を押し上げてしまうことです。その証拠が図2です。55,000秒の直後から、各GCサイクルの持続時間が突然、連続して増加している事に注意してください。

図2. GC持続時間
Figure 2. GC duration
Figure 2. GC duration

ご想像の通り、「stop-the-world(世界よ止まれ)」という性格を持つガーベジ・コレクションのおかげでユーザー・スレッドを処理する時間が減少するにつれ、ユーザー応答時間は増加を始めます。ログの最後の方10,000秒間では、フルGC(全部で15回)がそれぞれ30秒以上を要しており、平均持続時間が約70秒にも達しています。これはフルGCに割り当てられた処理時間の10%をはるかに上回っています。部分GC(1000回を少し上回る回数あります)も似たようなもので、一回の呼び出し毎に1.24秒を要しており、それ以前に行われた11,800回でのスカベンジの平均0.25秒から激増しています。

世代別ガーベジ・コレクション

世代別GC(generational GC)の詳細には触れませんが(世代別GCの詳細は参考文献を見てください)、世代別ヒープ空間の結果、「若い」オブジェクトと「古い」オブジェクトが別々のヒープ空間にあることになります。この構成では、若い世代別空間と古い世代別空間が別々のGCアルゴリズムとストラテジーに維持管理されることになり、全体的なGCパフォーマンスが向上します。

そうしたストラテジーの一つとしては、1回以上のGCで生き延びる若いオブジェクトに対して、若い世代をさらに分割し、Edenと呼ばれる生成空間と生存者空間に分けることです。Edenに十分なメモリがあり、新しいオブジェクトの生成を収容できるだけの余裕があれば、これはうまく動作します。そうでない場合には、新しいオブジェクトは古いオブジェクト空間に生成されます。また生存者空間が一杯の場合には、オブジェクトは古い世代の空間に移されます。こうした事実を踏まえて、我々のチューニングの問題を考えてみましょう。

フルGCの数を減らす

Blog-Cityが経験していた問題は、不規則に発生する長い休止時間でした。一旦アプリケーションがおかしくなり始めると、再起動をかけない限り元に戻すことは出来ませんでした。長い休止時間は長いGCに直接関連しているように思えたので、若い世代のオブジェクトをより長期間保持することで、フルGCの数を減らせないだろうかと考えました。フルGCはあまりにも高くつくので、より多くのオブジェクトを若い世代に集めることで休止時間は短くなるかも知れないのです。これを実現するために、ガーベジ・コレクションのパラメーターの一部、生存者比率(survivor ratio)と殿堂入りしきい値(tenuring threshold)を調整してみました。

生存者比率は、若い世代空間全体としてのサイズに対する生存者空間のサイズを設定します。生存者比率が8(Intelでのデフォルト)であれば、生存者空間はそれぞれEdenのサイズの1/8になります。言い方を変えると、若い世代が10に分割されてそれぞれが同じサイズの値を持ち、その内Edenには8が割り当てられ、各生存者空間は1の割り当てを受ける、となります。

私たちが仮定として考えたのは、生存者空間における空間不足のためオブジェクトが古い世代に格上げされるのが早すぎてしまう問題を、生存者比率を下げることによって減少できるのではないか、ということです。別の手段としては、殿堂入りしきい値を上げ、より多くのGCイベントを生き抜かないと格上げされないようにすることです。これを念頭に置いた上で、Blog-Cityを新しい設定、-XX:SurvivorRatio=4で再起動してみました。

休止時間の短いガーベジ・コレクション・アルゴリズムを選択する

この技術チューニングの目標の一つは休止時間を減少することなので、私たちはデフォルトの単一スレッドでmark-and-sweep方式のガーベジ・コレクションを避けることにしました。代わりにフラグXX:+UseParallelGCを使って選択できる並列コピーGC(parallel copying collector)を使います。これに関しても、アルゴリズムの詳細は参考文献に挙げておきますが、このフラグによってマルチスレッドのGCが呼び出されることを言っておけば十分でしょう。スレッド数はCPUの数に設定されます。これからすると、単一スレッドの並列コピーGCが伝統的なmark-and-sweep方式のGCよりもうまく動作するのは何故なのか、よく理解できません。ただし、一定のパフォーマンス向上が図られることは確認できているのです。

図3と図4はフラグ-XX:SurvivorRatio=4 +XX:+UseParallelGC -server -Xmx256Mを使用して実行した結果を示しています。

図3. 新しい設定でのメモリ・プロファイル
Figure 3. Memory Profile under the new configuration
Figure 3. Memory Profile under the new configuration

結果のグラフを見ると、大きな違いがあることが分かります。まだメモリ・リークはありますが、全体的なメモリ使用は最初の図の場合よりもずっと低くなっています。GCの持続時間をざっと比べてみると、若い世代と古い世代の全体的なGC持続時間が大幅に減少しています。

図4. 新しい設定でのGC持続時間
Figure 4. GC Durations under the new configuration
Figure 4. GC Durations under the new configuration

意図的、非意図的なオブジェクト拘束

このアプリケーションはメモリに制約されるので、メモリ・リークを追跡して除去することがさらに重要になってきます。この場合ではキャッシング・ストラテジー(caching strategy)のサポートに使われているコンポーネントが主なリークの原因であることが特定されました。主なメモリ・リークが除去された最終的なメモリ・プロファイル(図3)を見ると、まだ別の「低レベル」のリークがあります。ただしこのリークは十分に小さく、次のリリースまで無視できる程度のものです。

最後に

ここで行った作業には多くの困難が伴いました。まず、実稼働中のアプリケーションを調整するということから、変更が行える機会は限定されています。2番目として、操作は遠隔からIRCチャットを使って行う必要がありました。こうした作業で必要とされるような品質の通信をチャットに望むのは困難です。しかしこの場合では、チームのメンバーがチャットの限界を熟知しており、その限界の範囲内で作業することに大した困難はありませんでした。

最終的に最も困難だったのはハードウェアの制約です。いくつかの理由から、ともかくシステムに新しいハードウェアを追加することは不可能でした。最大の問題はシステム上にある物理RAMの量と、JVMとMySQLで要求されるRAMの量との関係でした。しかしいくつかの変更をシステム的に、一度に一つだけ加え、またその結果を測定することによって、少しずつ少しずつ、全体的なシステム・パフォーマンスを向上させることに成功したのです。


ダウンロード可能なリソース


関連トピック


コメント

コメントを登録するにはサインインあるいは登録してください。

static.content.url=http://www.ibm.com/developerworks/js/artrating/
SITE_ID=60
Zone=Java technology
ArticleID=218900
ArticleTitle=パフォーマンスの目: ガーベジ・コレクションを調整する
publish-date=06302004