バツイチとインケンのエンジニアブログ
プログラムやプログラムじゃないこと

最強のJVMチューニング・ツール: GCログを可視化するGCViewerとリモート接続でプロファイリング可能なVisualVM

2014-12-23
書いた人 : バツイチ
カテゴリ : jvm | タグ : GCViewer, VisualVM

この記事はJVM Advent Calendar 2014 – 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を起動します。

GCViewer1

フォルダのアイコンをタップしてGCログを開きます。

GCViewer2

このGCログを出力した時のjvmのオプションは下記のとおりです。

/usr/lib/jvm/java/bin/java
 -XX:NewRatio=2
 -XX:SurvivorRatio=2
 -XX:TargetSurvivorRatio=90
 -XX:MaxTenuringThreshold=32
 -Xloggc:gc.log.jdk1.6.0
 -XX:+PrintGCDetails
 -XX:+PrintGCDateStamps
 -XX:+UseConcMarkSweepGC
 -XX:+UseParNewGC
 -XX:+CMSClassUnloadingEnabled
 -XX:+CMSPermGenSweepingEnabled
 -XX:+CMSIncrementalMode
 -XX:+CMSIncrementalPacing
 -XX:CMSIncrementalDutyCycleMin=0
 -XX:+CMSParallelRemarkEnabled
 -XX:PermSize=128M
 -XX:MaxPermSize=128M
 -Xmx14336M
 -Xms14336M

※-XX:+UseConcMarkSweepGCを指定していることからわかるようにGCアルゴリズムはコンカレントGCを選択しています。

上の図だけでも何となくスパイクしているのはわかりますが、これでは線が多すぎて正直良くわかりません。

そこで、見たい情報を絞ります。
メニューのViewから表示する線をいろいろカスタマイズすることができます。

GCViewer3

GCViewerのグラフの説明

wikiに書いてある通りですが、それぞれ下記のようになっています。

# item 説明
1 Full GC Lines フルGC 黒い垂直線
2 Inc GC Lines インクリメンタルGC 水色の垂直線
3 GC Times Line GCに掛かった時間 緑の折れ線
4 GC Times Rectangles o 黒の四角: フルGC
o 青の四角: CMSにおけるinital mark
o オレンジの四角: CMSにおけるremark
o 赤の四角: VM操作によるイベント (“application stopped…”)
o グレーの四角: ノーマルGC
o ライト・グレーの四角: インクリメンタルGC
5 Total Heap 全ヒープサイズ 赤い折れ線
6 Tenured Generation Old領域のサイズ マゼンタ・エリア
7 Young Generation New領域のサイズ オレンジ・エリア
8 Used Heap 使用済みのヒープサイズ 青の折れ線
9 Initial mark level Initial markレベル 黄色の折れ線(CMS or G1GCのみ)
10 Concurrent collections 水色の垂直線がmark開始、ピンクの垂直線がコンカレント・リセット

まずは倍率を1000倍から5000倍に上げます。
Data Panelも一旦非表示にします。

GCViewer (2)

さて、これを見ると、使用済みヒープと使用済みNew領域は比例しつつ一定の間隔で上下しています。
ここからは特異点は見えないので、一旦非表示にします。
イニシャル・マークレベル(黄色の線)も一定で、分析対象としづらいので非表示にします。

すっきりして少し見やすくなりました。

GCViewer2

ここから、

  • 最も時間がかかっているのはイニシャル・マーク
  • イニシャル・マークは1分間に2回程度発生している

ということが読み取れます。

イニシャル・マーク

では、そもそも、コンカレントGCにおけるイニシャル・マークとは何なのでしょうか。

OracleのドキュメントのReviewing GC with the CMSによると、New領域から参照されているオブジェクトをマークするのだと。
Stop the Worldを伴い、マイナーGC程度のアプリケーション停止を伴うと述べられています。

つまりこのGCログから、1分間に2回程度、1秒くらいのアプリケーション停止が発生している、ということがわかります。
イニシャル・マークが大量に発生しているということはマイナーGCで開放されないメモリ領域が多いということです。
しかしGCログからは、どのようなオブジェクトが使用されていて、マイナーGCで開放されないような参照を持たれているかを追うことはできません。

そこで次に、VisualVMを使ってスレッドダンプとヒープダンプを見ていきます。


VisualVMでリモート接続

VisualVMはJDK1.6に同梱されているのですが、単体でアプリケーションをダウンロードして使用することもできます。
Mac向けのapp形式もあります。

VisualVM | Downloads

ダウンロードして解凍すればすぐに使えます。まずは起動してみます。

VisualVM1

リモート・ホストで実行されているjavaプロセスをモニタリングする(jstatd)

VisualVMの素晴らしいところは、ローカルで実行されているjavaプロセスのみならず、リモート・ホスト上で実行されているjavaプロセスのモニタリングも行えるところです。

リモート・ホストで実行されているjavaプロセスに接続するためには、ホスト上に少し仕掛けが必要です。
リモート接続する方法は2つあり、
1つはjstatd(jstatデーモン)を起動しておき、jstatd経由でプロファイリングする方法、
2つめはJMXを利用する方法です。

まずはjstatd経由で接続してみます。

サーバにログインし、jstatd用のポリシーファイルを作成します。

vi jstatd.all.policy
~
grant codebase "file:${java.home}/../lib/tools.jar" {

   permission java.security.AllPermission;

};
~

作成したファイルをパラメータとして渡し、jstatdを実行します。

nohup jstatd -J-Djava.security.policy=/root/jstatd.1.7.all.policy &
# ポートを確認します。
netstat -nap | grep jstat
tcp        0      0 :::1099                     :::*                        LISTEN      17937/jstatd
tcp        0      0 :::52232                    :::*                        LISTEN      17937/jstatd

サーバ側の設定はこれだけです。
さて、VisualVMからつないでみます。

左パネルのリモートを右クリックし、

VisualVM2

ホストの追加を行います。

VisualVM3

接続が成功するとサーバ上で実行されている全てのjavaプロセスとそのヒープ状況やスレッドの状態を取得することができます。
しかし、使っていただくとわかるのですが、jstatd経由のプロファイリングでは、ヒープやスレッドの概要は取れてもスレッドの詳しい実行状況やヒープダンプ・スレッドダンプの取得、GCの強制実行などができないのです。

jstatd経由でのプロファイリングでは、実行中のjavaプロセスを停止することなくリモートでプロファイリングを行えるのですが、詳しいプロファイリングができないのが弱点です。

リモート・ホストで実行されているjavaプロセスをモニタリングする(JMX)

さてそれではJMX経由でプロファイリングを行ってみます。
JMX経由でのプロファイリングを行うためには、下記のオプションを指定してjavaプロセスを実行する必要があります。

 -Dcom.sun.management.jmxremote
 -Dcom.sun.management.jmxremote.port=7900
 -Dcom.sun.management.jmxremote.authenticate=false # 認証を行うならtrue
 -Dcom.sun.management.jmxremote.ssl=false # sslを使用するならtrue
 -Djava.rmi.server.hostname=a006.hostd.jp

上記のオプションを指定してjavaプロセスを再実行したら、VisualVMで接続してみます。

ホストを右クリックし「JMX接続を追加」を選択します。

VisualVM4

接続情報を入力します。

VisualVM5

「概要」を表示するとjavaの情報や指定されているオプションの情報が表示されます。

VisualVM7

「監視」にはCPU、ヒープ、クラス、スレッドのグラフがリアルタイムで表示されます。
ここからGCダンプを取得することもできます。

VisualVM8

「スレッド」では実行中のスレッドの状況が表示され、スレッドダンプを取得することができます。

スレッド・ダンプを見る

VisualVMの「スレッド」タブで「スレッドダンプ」をタップするとスレッドダンプを表示することができます。

VisualVM10

ここから、WAITINGになっているスレッドがないか、どこかでロックが発生していないか探すことができます。

ヒープ・ダンプを見る

VisualVMの「監視」タブで「ヒープダンプ」をタップするとヒープダンプを取得することができます。
また、jmapで取得したヒープダンプを読み込んでビジュアライズすることもできます。

VisualVM11

このサマリーからだけでもGCルートとなるオブジェクトが2,083個あることがわかります。
次に、「クラス」タブを開きます。

VisualVM12

「クラス」には使用されているクラスのインスタンス数とサイズが表示されます。
ここから対象のクラスをダブルタップするとインスタンスの詳細を見ることができます。

VisualVM13

これはjava.lang.StringBuilderの詳細ですが、「値」を見ると明らかに私が作成したテスト用Webアプリケーションのコードです。
同じ文字列が何度も何度も生成されていることを示しています。
この文字列の生成を1回にすれば多少なりともコストが削減できることは明らかです。

JVMのチューニングを行うのにとても便利なGCViewerとVisualVMを紹介させて頂きました。
今後も更に良いTipsやツールを見つけたら紹介させていただきたいと思います。


こちらの動画でVisualVMの使い方を詳しく解説しています。

スクリーンショット 2015-08-24 10.01.11

VisualVMでjavaプロセスを可視化してみよう part1

このエントリーをはてなブックマークに追加
Tweet

← Apache Spark+IPython notebook(&Mesos)インストール〜動作確認
Apache SparkからGoogle Cloud Strageを使う →

 

最近書いた記事

  • Ryzen7 3800XT でmini ITXオープンフレームPCを作る
  • Pythonで機械学習入門 競馬予測
  • HP ENVY 15 クリエイターモデルレビューとRAID0解除
  • JRA-VAN データラボを使って、競馬データを収集する
  • Surface Pro 3 にubuntu18.04を入れる

カテゴリー

  • Android
  • Apache Flink
  • API
  • AWS
  • bazel
  • BigQuery
  • Cassandra
  • Docker
  • Druid
  • Elasticsearch
  • Git
  • Golang
  • gradle
  • HDFS
  • JavaScript
  • jvm
  • Linux
  • MongoDB
  • MySQL
  • Nginx
  • Nodejs
  • PaaS
  • PHP
  • Python
  • RabbitMQ
  • Raspberry Pi
  • React Native
  • Redis
  • Riak
  • rust
  • scala
  • Scheme
  • SEO
  • solr
  • Spark
  • spray
  • Sublime Text
  • Swift
  • Tableau
  • Unity
  • WebIDE
  • Wordpress
  • Youtube
  • ひとこと
  • カンファレンス
  • スケジューラ
  • マイクロマウス
  • 広告
  • 技術じゃないやつ
  • 株
  • 機械学習
  • 競馬
  • 自作キーボード
  • 自然言語処理

アーカイブ

  • 2021年4月
  • 2021年2月
  • 2021年1月
  • 2020年3月
  • 2020年2月
  • 2020年1月
  • 2019年10月
  • 2019年9月
  • 2019年8月
  • 2019年7月
  • 2019年6月
  • 2019年5月
  • 2019年4月
  • 2019年2月
  • 2019年1月
  • 2018年12月
  • 2018年11月
  • 2018年9月
  • 2018年5月
  • 2018年3月
  • 2018年2月
  • 2017年9月
  • 2017年8月
  • 2017年6月
  • 2017年4月
  • 2017年3月
  • 2017年1月
  • 2016年10月
  • 2016年9月
  • 2016年8月
  • 2016年6月
  • 2016年5月
  • 2016年4月
  • 2016年3月
  • 2016年2月
  • 2016年1月
  • 2015年12月
  • 2015年11月
  • 2015年10月
  • 2015年9月
  • 2015年8月
  • 2015年6月
  • 2015年5月
  • 2015年2月
  • 2015年1月
  • 2014年12月
  • 2014年11月
  • 2014年9月
  • 2014年6月
  • 2014年5月
  • 2014年3月
  • 2014年2月
  • 2014年1月
  • 2013年12月
  • 2013年11月
  • 2013年10月
  • 2013年9月
  • 2013年8月

書いた人

  • バツイチちゃん
  • インケンくん

このブログについて

エンジニアとしての考え方が間逆な2人がしょーもないこと書いてます。

バツイチ

アイコン

IT業界で働くエンジニアです。名前の通りバツイチです。
理論や抽象的概念が好きだけど人に説明するのが下手。

インケン

アイコン

バツイチちゃんと同じ業界で働いています。
理論とか開発手法とかは正直どうでもよくて、
生活する上で役に立つことに使いたい

Copyright 2025 バツイチとインケンのエンジニアブログ