Java排他処理のボトルネックの発見方法

“Javaメソッドトレース”を自作すれば、処理時間が長いメソッドを絞り込むことができることを紹介しました。
今回は排他処理によるボトルネックを解析する方法を紹介します。

複数スレッドで同時に処理を行うとデータが壊れてしまうような場合に排他制御を行います。Javaでは排他制御をsynchronized節を用いて簡単に実現することができるため、マルチスレッドプログラミングが比較的簡単にできるわけですね。

しかし外注先で、64個のコア(CPU)を搭載したマシンを使って、64個のスレッドをフルに動かして大量処理を行うJavaアプリケーションの性能測定を行った結果、思うように性能が上がらず、CPUの使用率も60%程度に留まることが判り、問題視された経験があります。

“-verbose:gc”オプションを付けてもFullGCが走った形跡がなく、何が原因で性能低下が発生したのかを誰も実証することができませんでした。Javaメソッドトレースではメソッドの実行時間を測定することができても、CPU使用率の低下を実証することはできません。外注先はとうとう原因を究明することができず、私にヘルプを求めてきました。

私も少し苦しみましたが、“JDK 5.0 Documentation”と睨めっこしていたら、java.lang.managementにThreadMXBeanとThreadInfoがあり、スレッドの状態、スレッドのブロック時間、ロックのモニタ、そして、スタックトレースなどを取得することができそうではありませんか！早速、プロファイリングを行うツールを自作しました。

性能測定の対象となるJavaアプリケーションを“-Dcom.sun.management.jmxremote”などのオプションを付けてJMXエージェントを有効にさせれば、別マシンからプロファイリングを行うことができます。自作プロファイリングツールでは、ThreadMXBean.getAllThreadIds()で全スレッドのIDを取得し、ThreadMXBean.getThreadInfo(long)でThreadInfoオブジェクトを取得し、ログ出力を行うといった処理を、長時間、何回も繰り返して行いました。ThreadInfo#getThreadState()がThread.State.BLOCKEDを返す場合は、スタックトレースも採取しました。つまりBLOCKED状態となった箇所の統計を取ることにより、排他制御が発生しやすい箇所が判るわけです。

次に、排他制御が発生しやすい処理をスキップする（処理しない）ようにJavaアプリケーションを仮修正して、再度、性能測定を行ったところ、なんとCPU使用率が約60%→約95%に向上し、もちろん処理性能も著しく向上しました。

Java SE 5.0で追加されたJMX機能およびjava.lang.managementパッケージにあるMXBeanを使ってプロファイリングを行うのは、非常に有効な手段です。MXBeanを使ってアプリケーションのメモリ消費量を監視するツールも自作しましたが、これまた有効でした。ちなみにJDK 6以降では“-Dcom.sun.management.jmxremote”オプションを付けなくてもtools.jarにあるAPIを使って、プロファイリングツールから特定のJava VMにアタッチしてJMX通信を行うことができます。

またテスト用MBeanを自作して、外部ツールからそのMBeanと通信してJavaアプリケーションのテストを行うことも容易にできるようになります。アイデア次第ではJavaアプリケーションの可能性が広がりそうです。ぜひJMX、MBeanおよび、MXBeanに関心を持っていただきたいと思います。