使わにゃ損! 3つのトラブル事例で知る「Java Flight Recorder」の威力--Oracle WebLogic Serverとの組み合わせは特に強力

Oracle Java & Developers編集部
2015-04-27 12:20:00
  • このエントリーをはてなブックマークに追加

ケース(2) エラー・ログに残らない動作情報も記録。プログラマーのミスに起因するトラブルも簡単に究明

 次に紹介するのは、Javaプログラムの側に問題のあったケースだ。

 このJavaプログラムはバッチ処理を行うもので、バッチ処理自体は正しく完了するものの、処理内容を記録するログが出力されないというトラブルが発生した。エラー・ログにも原因を示すようなログが記録されていなかったため、Java Flight Recorderの出番となった。

 Java Flight RecorderでレコーディングしたログをJava Mission Controlに読み込んでイベントグラフを確認すると、当該プログラムのスレッドで例外処理(下記画面の赤枠個所)が多発している。

 そこで、例外の内容を調べてみると、例外のタイプは「FileNotFoundException」であり、ログ・ディレクトリに対する書き込み権限が割り当てられていないことが原因だとわかった。Java Flight Recorderによるレコーディング期間中、同じ例外が60万回も記録されていたという。

 Java Mission Controlでは、どのコンポーネントが例外を投げているのかもスタックトレースで容易に確認することができる。このプログラムでは、上の画面にあるようにサードパーティ製のロガーを呼び出してログを書き込むようにしていた。

 「プログラマーが犯しがちなミスに、catch~throwの骨組みだけを先に書き、例外処理を実装し忘れるというものがありますが、このケースはまさにその典型例でした。書き込み権限のないロガーは例外をthrowしたものの、それがフレームワーク内のcatch句の中で握りつぶされていたのです」(新井氏)

 最終的には、例外を正しくハンドリングするようにコードを追加し、書き込み権限を与えることによって問題が解決したが、同時にパフォーマンスも向上したという。

 「例外処理はオーバーヘッドが大きく、それがなくなったことでパフォーマンスが向上したのです。性能面の問題は、急にパフォーマンスが悪くなったといった変化があると気づきやすいのですが、このケースでは定常的に問題が生じていたため、"遅い"ということに気づきませんでした。Java Flight RecorderとJava Mission Controlを使うと、処理の内容ごとに所要時間を細かく確認できるので、どの部分がボトルネックなのかを簡単に突き止められるのです」(新井氏)

 実際、期待した性能が出ないシステムをJava Flight Recorderで調べてみたところ、1回の処理の中で同一のEJBコンポーネントのメソッドを50回も呼び出していたり、結果を返すまでの間にデータベース・サーバとのやり取りを何度も行っていたりといったプログラミング上のミスが判明したケースもあるという。こうしたプログラム側の不備に起因する性能問題も、Java Flight RecorderとJava Mission Controlで処理内容を可視化することによって容易に突き止められるのである。

ケース(3) Oracle WebLogic Serverとの組み合わせでJava EEアプリケーションの動作状況を詳細に分析

 先述のように、Java Flight RecorderではOS、JVM、アプリケーション・サーバのレベルに加えて、Oracle WebLogic Serverとともに使用した場合はJava EEアプリケーションの稼働情報もレコーディングすることができる。

 「Oracle WebLogic Serverと組み合わせて使った場合、サーブレットやEJBコンポーネント、JDBC接続といったJava EEの各コンポーネントの単位で稼働情報を記録し、Java Mission Controlで可視化することができます。また、Oracle WebLogic Serverとともに使用した場合、Java Flight RecorderはJava EEの各レイヤを横断する処理に対して、それらを串刺しでトレースするための『ECID(Execution Context ID)』という識別番号を割り当てます。Java Mission Controlは、このECIDを使った分析にも対応しており、Java EEアプリケーション全体の動作状況を容易かつ確実に把握することができるのです」(新井氏)

 ボトルネックの調査では、CPU使用率やメモリ使用状況、イベントグラフには兆候が現れにくい事象も、Java EEレベルの情報を加えることで見つけやすくなるという。例えば、次に示すのはJava Mission Controlの表示フィルタで対象をEJBコンポーネントに絞った際の表示だ。この画面から、クラスOrderHistoryEJBがEJBコンポーネント全体の所要時間の90%以上を消費しており、さらに同クラスのメソッドgetOrderHistoryがEJB層で実行される主要なメソッドであることがわかる。

フィルタでEJBコンポーネントの情報だけを表示させた画面フィルタでEJBコンポーネントの情報だけを表示させた画面
※クリックすると拡大画像が見られます

 ここでメソッド名を選んで右クリックすると、コンテキスト・メニューからECIDを調べることができる。そして、当該ECIDを指定してフィルタをかけると、該当するメソッドの前後でどのような処理にどれくらいの時間がかかっているのかを、Java EEのレイヤを横断して確認することが可能だ。

ECIDによってJava EEレベルで横断的にトレースECIDによってJava EEレベルで横断的にトレース
※クリックすると拡大画像が見られます

 この例の場合、EJBコンポーネントのメソッドinvokeの処理は2ミリ秒で終わっているが、その前段にあるサーブレットのメソッドinvokeの処理に25秒もかかっており、ここがボトルネックであると判明した。

 「こうした一連の処理で各レイヤにおける処理時間を調べるには、通常、ログ出力用のコードをレイヤごとに埋め込むなど手の込んだ仕掛けが必要になります。Java Flight RecorderとOracle WebLogic Serverの組み合わせなら、そうした仕掛けの準備が一切不要となり、分析も短時間で行えるのです」(新井氏)

 以上、ここでは実例に基づく3つのケースを例にとり、Java Flight Recorderがシステム障害への対応でどう役立つのかを紹介した。トラブルシューティングや最適化では、修正作業そのものよりも、問題の原因究明に多くの時間がかかることが多い。Java Flight Recorderを使えば、手間と時間のかかる下準備の作業を省き、より簡単かつスピーディに原因を究明することができる。Oracle WebLogic ServerやJava SE Advancedをお使いの方は、ぜひ併せてJava Flight Recorderもご活用いただきたい。

 なお、「Oracle WebLogic Serverを利用していないが、自社システムのサーバ・サイドやクライアント・サイドにおける障害対応でJava Flight Recorderを使ってみたい」という企業は、単体ライセンスであるJava SE Advancedの導入をお勧めする。Java SE Advancedでは、Java Flight Recorderのほか、Oracle Java SEに対する日本語サポート、公開アップデート終了後のアップデート・リリースの提供を受けることができる。大規模なJava環境を長期にわたって安心して利用したいという企業には特に最適なライセンスだ。

このサイトでは、利用状況の把握や広告配信などのために、Cookieなどを使用してアクセスデータを取得・利用しています。 これ以降ページを遷移した場合、Cookieなどの設定や使用に同意したことになります。
Cookieなどの設定や使用の詳細、オプトアウトについては詳細をご覧ください。
[ 閉じる ]