はじめに

現在のWebシステム開発・運用で踏まえるべき新しい技術的な取り組みについて，日立Cosminexusの製品群を題材として取り上げながら解説する本連載の前回では，トラブルシューティング実践編の第1回としてシステムスローダウンとDB周りのトラブルシューティングを解説しました。

最終回の今回は，トラブルシューティング実践編②として，具体的な事例をベースに，メモリ周りのトラブルシューティングの流れを説明します。

ログイン数の多さによるGC多発

あるWebシステムでは，通常であれば数秒以内で応答が返ってきます。ところが，業務処理の締めである月末を迎えると，応答時間が数十秒から数分かかるようになりました。業務がスムーズに行われなくなり，会社全体の作業効率が低下してしまいます。数百人から数千人のユーザが接続すると，スローダウンが発生します（図1⁠）⁠。

原因の特定から解決まで

システムへのアクセスが集中するとリクエストの応答時間が大幅に遅くなっている現象からWeb/APサーバ内部でメモリが圧迫されていることが考えられるため，まずはWeb/APサーバの実行基盤であるJava VMのメモリ管理領域（Javaヒープ）の使用状況を見ます。このケースでは同時ログイン数が増えると，HTTPセッションの総量も増加しています。JavaヒープにはHTTPセッションが存在し，これに圧迫されてFull GC（ガベージコレクション）が発生し，業務効率性能に影響していました。

続いて，Javaヒープの使用量を詳細に見ます（図2⁠）⁠。

ログイン数増加に伴いHTTPセッションの総量が増えていき，Javaヒープの閾値（いきち）を超える9時半以降に，Full GCが多発しています。なお，この閾値はFull GCの発生条件の一つである「New領域の使用サイズ＞Old領域の空きサイズ」の条件が満たされるラインです。-Xmxは最大ヒープサイズ，-XX:NewRatio，New世代とOld世代領域を示すものとすると，ラインは図2中の①の計算式で求められます。例えば-Xmx指定値が768m，-XX:NewRatio指定値が2の場合は，768×2÷（2＋1）＝512Mバイトとなります。

GC処理時間の散布グラフ（図3）を見ると，Copy GCの処理時間が0.5秒未満なのに対して，Full GCでは4秒以上かかっていて，しかも発生頻度も多くなっていることがわかります。

1分間あたりの発生頻度を比較したところ，Copy GCは最大で6回／分，Full GCは同7回／分でした。Copy CGは処理時間が小さいためパフォーマンスにはほとんど影響しませんが，Full GCは処理時間が長いため，多発するとパフォーマンスが劣化してしまいます。GC処理によって業務処理にCPUが割り当てられない時間の割合をGCの占有率といいます。1分ごとのCopy GCとFull GCの占有率をグラフ化したところ，Copy GCの占有率はほとんど確認できませんが，Full GCの占有率は30～60％とかなり大きくなっています（図4⁠）⁠。図4のGCの占有率は，経験から2％以下は安全，5％超えは要注意，15％を超えるとユーザからのクレームが増えます。GCの占有率とスループットとは大きく関係します。

GCの多発はアプリケーション全体の性能に影響しますが，特定の業務処理に起因する問題ではないため，PRFトレース（注1）

ではボトルネックを見つけることができません。その場合には，メモリやCPUなどリソース面でネックになっていないかを調査する必要があります。

CosminexusではGCログをCSV形式で出力可能であり，MS Excelなどを使えば簡単にグラフ化できるため，Javaヒープ使用量やGCの発生頻度を視覚的に分析することで，通常は半日かかる原因究明も数時間程度で終了しました。

今回のケースでは，通常は閾値を超えないようログイン数を制限する設定が適切にされていないため，トラブルが発生しました。

対策として，マシンの台数を増やすことでシステムの負荷を分散させて，無事解決に至りました。

注1）

ブラウザ操作からアプリケーションサーバ，DBに至るまでのトレースを突き合わせ，ミドルウェアの中の動作を可視化できるCosminexus独自の機能です。