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に関心を持っていただきたいと思います。

Javaメソッドトレース

“ソフトウェアの二大ボトルネック ”で2種類のボトルネックがあることを述べました。

Javaアプリケーションについて前者のボトルネックを見つける1つの手法として、“メソッドトレース”があります。具体的には、メソッドの入口と出口に次のようなログ出力のコードを埋め込み、ログからメソッドの実行時間を知るという手法です。(ちなみに精密な性能測定を行う場合は、System.currentTimeMillis()よりもSystem.nanoTime()がお勧め)

System.out.println("a: start: "+System.nanoTime());

小さなアプリケーションならメソッドが少なく、上記コードをゴリゴリ手書きすればよいです。しかし巨大なアプリケーションになると手書きする箇所が膨大になり、現実的ではありません。

そのようなときには、Spring FrameworkなどにあるAOP(Aspect Oriented Programming)機能が役に立ちそうです。AOPを使ってバイトコードにログ出力のコードを埋め込ませ、メソッドトレースを実現するというものです。
 
しかし私はSpring Frameworkをまだ試したことがありません。が、次を使用してメソッドトレースを実現しました。

1. Java SE 5.0で追加されたjava.lang.instrumentパッケージ
2. Javassist

java.lang.instrumentパッケージは、平たく言うと次を提供してくれています。

• アプリケーションのmainメソッドを呼ぶ前に、エージェントのpremainメソッドを呼ぶ仕組み
• アプリケーションの実行に必要なクラスをJava VMが定義する前にクラスファイルを変換する機会

ClassFileTransformerの実装クラスを作って、premainメソッドを持つエージェントでInstrumentation#addTransformer()を使ってClassFileTransformerの実装クラスを登録するだけでよいのです。ところがクラスファイルを変換するAPIはJava SEには含まれていないのです。

そこで必要となるのが、バイトコードを変換するAPIであるjavassistです。バイトコードを変換するAPIとして、他にBCELもありますが、私はjavassistを選択しました。ClassFileTransformerの実装クラスからjavaassistを使ってバイトコードを変換し、ログを出力するコードを埋め込ませるだけです。具体的な作り方は記載しませんが、意外と簡単そうでしょう？

私はこうしてメソッドトレース機能を作り、さらに別途、メソッドトレース機能が出力するログを解析するプログラムも作って、処理時間が長いメソッドを特定できるようになり、巨大なJavaアプリケーションのボトルネック箇所をいくつか見つけることができました。

市販のプロファイラツールは高価だし、自分の思うようなデータを出力してくれない可能性もありますから、メソッドトレース機能を2、3日間で自作したのですが、このメソッドトレース機能は意外と応用範囲が広かったのです。ボトルネック箇所の特定だけでなく、メソッドの呼び出しシーケンス分析や、メソッド実行網羅率の採取などにも活用することができ、非常に便利なツールになっています。

ソフトウェアの二大ボトルネック

ソフトウェアのボトルネックを調べる目的で、性能測定を行うことがありますが、ボトルネックには、大きく2種類があると考えています。

• 不適切な処理ロジックによるボトルネック
• 排他処理によるボトルネック

前者は、一般的に言われているような、狭い意味でのデータ構造やアルゴリズムの問題や、単純に不適切な順次処理をコーディングをした場合のボトルネックです。このケースでは、ボトルネック箇所が判明されば、比較的、修正が簡単です。

後者は、マルチスレッドで動作するソフトウェアにおいて、ハードウェアまたはソフトウェアによる排他処理の影響で、処理待ちが発生し、CPUパワーを十分に活用できないケースです。“アムダールの法則の紹介”に記載したアムダールの法則を使って、排他率（並列処理ができない部分の割合）を求めればよいかと思います。算出した排他率を見てソフトウェアの修正が必要かどうかを判断します。

どちらのボトルネックにしても、ボトルネック箇所を正確に見極めるのが難しい場合が多いですね。経験豊かな開発者なら経験に裏付けられたカンでボトルネック箇所をある程度絞れますが、どの箇所でどのくらいの性能劣化が起きているのかを知りたいこともあります。

Javaアプリケーションでボトルネック箇所を特定する市販製品が結構出回っていますが、Java SE 5.0以降なら市販製品を使わずにボトルネック箇所を特定するツールを比較的簡単に自作できます。後日、簡単にご紹介したいと思います。