Qiitaのために書きました。「GCログ」や「GCViewer」のキーワードからこのサイトに訪れてくれる方が多いので、改めてGCログやヒープダンプの見方についてまとめることにしました。GCログのビューアとして有名なGCViewerとヒープの解析ツールとしてすごく優秀なVisualVM、この2つを紹介しつつJVMのプロファイリングを行う方法を解説したいと思います。GCViewerでGCログを見るまずはGCViewerでGCログを見てみます。GCViewerでGCログを見るためには、GCログをファイルに出力する必要があります。GCログをファイルに出力する方法は以前の記事をご参照いただければと思います。javaを再起動する必要があります。GCViewerのインストールGCViewerは下記のページからダウンロードすることができます。https://github.com/chewiebug/GCViewer/wiki/ChangelogもともとはTagtraumによって開発されたGCViewerですが、2008年で開発をストップしておりjava1.5までにしか対応していません。これをフォークしてchewiebugさんが開発を続けていてくれているので、こちらを使います。↑のGitHub上のリポジトリからソースコードをcloneしてきて、最新版をビルドして使っても構いませんが(Mavenでビルド可能)、macユーザはmacバージョンをダウンロードするとapp形式になっているので使いやすいかと思います。GCViewerの使い方GCViewerを起動します。フォルダのアイコンをタップしてGCログを開きます。このGCログを出力した時のjvmのオプションは下記のとおりです。-Xms14336M※-XX:+UseConcMarkSweepGCを指定していることからわかるようにGCアルゴリズムはコンカレントGCを選択しています。上の図だけでも何となくスパイクしているのはわかりますが、これでは線が多すぎて正直良くわかりません。そこで、見たい情報を絞ります。メニューのViewから表示する線をいろいろカスタマイズすることができます。GCViewerのグラフの説明wikiに書いてある通りですが、それぞれ下記のようになっています。水色の垂直線がmark開始、ピンクの垂直線がコンカレント・リセットまずは倍率を1000倍から5000倍に上げます。Panelも一旦非表示にします。これを見ると、使用済みヒープと使用済みNew領域は比例しつつ一定の間隔で上下しています。ここからは特異点は見えないので、一旦非表示にします。イニシャル・マークレベル(黄色の線)も一定で、分析対象としづらいので非表示にします。して少し見やすくなりました。時間がかかっているのはイニシャル・マークイニシャル・マークは1分間に2回程度発生しているということが読み取れます。イニシャル・マークでは、そもそも、コンカレントGCにおけるイニシャル・マークとは何なのでしょうか。CMSによると、New領域から参照されているオブジェクトをマークするのだと。Worldを伴い、マイナーGC程度のアプリケーション停止を伴うと述べられています。このGCログから、1分間に2回程度、1秒くらいのアプリケーション停止が発生している、ということがわかります。イニシャル・マークが大量に発生しているということはマイナーGCで開放されないメモリ領域が多いということです。GCログからは、どのようなオブジェクトが使用されていて、マイナーGCで開放されないような参照を持たれているかを追うことはできません。そこで次に、VisualVMを使ってスレッドダンプとヒープダンプを見ていきます。VisualVMでリモート接続VisualVMはJDK1.6に同梱されているのですが、単体でアプリケーションをダウンロードして使用することもできます。Mac向けのapp形式もあります。Downloadsダウンロードして解凍すればすぐに使えます。リモート・ホストで実行されているjavaプロセスをモニタリングする(jstatd)VisualVMの素晴らしいところは、ローカルで実行されているjavaプロセスのみならず、リモート・ホスト上で実行されているjavaプロセスのモニタリングも行えるところです。リモート・ホストで実行されているjavaプロセスに接続するためには、ホスト上に少し仕掛けが必要です。リモート接続する方法は2つあり、1つはjstatd(jstatデーモン)を起動しておき、jstatd経由でプロファイリングする方法、2つめはJMXを利用する方法です。jstatd経由で接続してみます。サーバにログインし、jstatd用のポリシーファイルを作成します。java.security.AllPermission;};~作成したファイルをパラメータとして渡し、jstatdを実行します。17937/jstatdサーバ側の設定はこれだけです。VisualVMからつないでみます。左パネルのリモートを右クリックし、ホストの追加を行います。接続が成功するとサーバ上で実行されている全てのjavaプロセスとそのヒープ状況やスレッドの状態を取得することができます。使っていただくとわかるのですが、jstatd経由のプロファイリングでは、ヒープやスレッドの概要は取れてもスレッドの詳しい実行状況やヒープダンプ・スレッドダンプの取得、GCの強制実行などができないのです。jstatd経由でのプロファイリングでは、実行中のjavaプロセスを停止することなくリモートでプロファイリングを行えるのですが、詳しいプロファイリングができないのが弱点です。リモート・ホストで実行されているjavaプロセスをモニタリングする(JMX)さてそれではJMX経由でプロファイリングを行ってみます。JMX経由でのプロファイリングを行うためには、下記のオプションを指定してjavaプロセスを実行する必要があります。-Djava.rmi.server.hostname=a006.hostd.jp上記のオプションを指定してjavaプロセスを再実行したら、VisualVMで接続してみます。ホストを右クリックし「JMX接続を追加」を選択します。接続情報を入力します。「概要」を表示するとjavaの情報や指定されているオプションの情報が表示されます。「監視」にはCPU、ヒープ、クラス、スレッドのグラフがリアルタイムで表示されます。ここからGCダンプを取得することもできます。「スレッド」では実行中のスレッドの状況が表示され、スレッドダンプを取得することができます。スレッド・ダンプを見るVisualVMの「スレッド」タブで「スレッドダンプ」をタップするとスレッドダンプを表示することができます。ここから、WAITINGになっているスレッドがないか、どこかでロックが発生していないか探すことができます。ヒープ・ダンプを見るVisualVMの「監視」タブで「ヒープダンプ」をタップするとヒープダンプを取得することができます。jmapで取得したヒープダンプを読み込んでビジュアライズすることもできます。このサマリーからだけでもGCルートとなるオブジェクトが2,083個あることがわかります。次に、「クラス」タブを開きます。「クラス」には使用されているクラスのインスタンス数とサイズが表示されます。ここから対象のクラスをダブルタップするとインスタンスの詳細を見ることができます。これはjava.lang.StringBuilderの詳細ですが、「値」を見ると明らかに私が作成したテスト用Webアプリケーションのコードです。同じ文字列が何度も何度も生成されていることを示しています。この文字列の生成を1回にすれば多少なりともコストが削減できることは明らかです。JVMのチューニングを行うのにとても便利なGCViewerとVisualVMを紹介させて頂きました。今後も更に良いTipsやツールを見つけたら紹介させていただきたいと思います。こちらの動画でVisualVMの使い方を詳しく解説しています。Trip】いつでも弾丸旅行このブログについてエンジニアとしての考え方が間逆な2人がしょーもないこと書いてます。バツイチIT業界で働くエンジニアです。名前の通りバツイチです。理論や抽象的概念が好きだけど人に説明するのが下手。インケンくんにバカにされてますインケンバツイチちゃんと同じ業界で働いています。バツイチとインケンのエンジニアブログ。