Groovy で JVM ログ解析 (ClassHistogram編) #gadvent #java
Groovy で 面倒な JVM ログを解析する (ClassHistogram)
前置き
この記事はG*(Groovy, Grails ..) Advent Calendar 2013 - Qiita [キータ]の10日目です。
前日は研究室の先輩 @tetsurokitaharaさんのGracenote with Groovy でした。
JVM(hotspot) は好きですが Java は余り書かず、作りこむなら Scala、速度が欲しいなら C、ログの解析なら awk/sed、Ruby 等で済ます日々ですが、Java のログなので Groovy でさっと処理してしまおうと考え取り組んでみました。どうせなので groovysh で扱える仮想配列として出力し、後々好きな様に加工できるようにしました。
この題目は7日目の@nobusueさんのGroovyでGCログ解析と多少被ってますが、別のログが対象ということで許してください＞＜
JVM ログで出力される ClassHistogram とは
一般的には OutOfMemoryError が発生した場合などで利用するクラス統計情報で、現在実行中の Java プロセスに存在する各クラスのインスタンス数、バイト数が含まれています。
JVM 起動オプションに -XX:+PrintClassHistogram を指定し、SIGQUIT (kill -3
num #instances #bytes class name -------------------------------------- 1: 24868 3398080 <no name> 2: 24868 2598976 <methodKlass> 3: 2813 2432352 [I 4: 1970 2415680 <constantPoolKlass> 5: 1970 1873040 <instanceKlassKlass> 6: 1873 1661760 <constantPoolCacheKlass> (中略) 1105: 1 16 sun.reflect.GeneratedMethodAccessor3 1106: 1 16 sun.awt.X11.XProtocol$1 Total 172945 22390368
これを間隔を置いて複数回出力させれば、各クラスが時系列にそってどのように増減しているかが調べることが可能です。解りやすい例だと、あるクラスのバイト数が常に増大していれば、明らかにそのオブジェクト(を生成している部分)でメモリリークを起こしてることが判明します。
このログで面倒なのは、複数クラスローダが存在する場合です。クラスローダAとクラスローダBで同じクラスがロードされていると、それは別物扱いなので同じクラス名の情報が重複して出力されます。その上このログからはクラスローダ情報はばっさり捨てられてるので、今回は同じものとして加算しています。
ログから各クラスの時系列ごとの統計情報を解析する
というわけで仮想配列を出力するコードです。実は何気に殆ど初 Groovy だったりするので所々酷いところがあると思います。。
一枚目の gist のコードを保存し、二枚目の gist の通り groovysh で呼び出して仮想配列として出力できます。その後は、例えば以下のようにすればクラス一覧を出力しつつ、各自系列ごとのランク、インスタンス、バイト数情報が引き出せます。
import static ClassHistrogram.* ch = calc("*log") ch.each{ klass, timeline -> println "{${klass}:" timeline.each{ time, value -> println " {${time}:{rank:${value[0]},instance:${value[1]},byte:${value[2]}}}" } println "}" } ---出力例--- {sun.java2d.pipe.LoopPipe: {0:{rank:1040,instance:1,byte:16}} {1:{rank:1057,instance:1,byte:16}} {2:{rank:1071,instance:1,byte:16}} {3:{rank:1079,instance:1,byte:16}} {4:{rank:1079,instance:1,byte:16}} {5:{rank:1081,instance:1,byte:16}} {6:{rank:1082,instance:1,byte:16}} {7:{rank:1079,instance:1,byte:16}} {8:{rank:1078,instance:1,byte:16}} {9:{rank:1078,instance:1,byte:16}} {10:{rank:1078,instance:1,byte:16}} } ---
このように LTSV 形式に出力するのもよし、CSV ファイル形式に出力や特定クラスの情報だけ引っこ抜くのも良しで、加工しやすいのではないかと思います。
以上です、次は https://twitter.com/setoazusa:title@setoazusa さんの番です！
「Java解析ツールバトル」に登壇しました ＆ HeapStats の動かし方について #jjug
JJUG ナイト・セミナー 「Java解析ツールバトル」に HeapStats 陣営でコミッターとして参加してきました！
今回のJJUGでは、自分達の JVM に深く密着してパフォーマンスに心血を注いでいる HeapStats、最近 OSS 化された Java だけでなく SQL 実行計画まで総合的に診断する EndoSnipe、昨日の OracleJDK 7u40のリリースで公式に JDK に付属された Java Flight Recorder と twitter4j の開発者であるモデレータが過去に開発された 侍 の四三つ巴でディスカッションを行いました。
数々のプロジェクトやサービスで利用されている Java だからこそ、障害や性能問題に悩まされる人の数も多いと思われます。障害解析の手助けになるツール、それも今回参加した３つの内２つは日本人によって開発されていることもあり、かなりの盛況ぶりだったと思います:)
自分達のHeapStatsの発表資料はSlideshareで公開しています。興味のある方はぜひご覧ください。
ディスカッションでは時間の関係上、駆け足での説明だったため、「HeapStats はどうやって動かすの？」という最初の一歩をもう少し詳しく補足していきたいと思います。
HeapStatsのインストール
HeapStats インストール条件
性能に心血を注いだ結果として、JVMに手を突っ込み、一部のコードをアセンブラ化している等が原因で、HeapStatsを動かすためには以下の環境である必要があります
HeapStats インストール＆動作方法
HeapStats をインストールするためにはバイナリからインストールする方法と、ソースからビルドする方法があります。今回はバイナリからインストールする方法を紹介します。
- バイナリをここから取得してインストールする。
- $ rpm -ivh heapstats-agent-[version].[CPU命令セット].[Linux dist].[アーキテクチャ].rpm
- CPU命令セットの部分は解らない場合は何も記載されていない物を利用して下さい。
- 利用している環境がサポートしているCPU命令セットを確認したい場合、"/proc/cpuinfo" の "flags" を見ることで確認ができます。
- avxが書かれている場合はavxを、avxはないがsse4が書かれている場合はsse4を、それ以外は無印を利用するのがお勧めです。
- Linux dist の fc は Fedora, el は RedHat Enterprise Linux を指します。
- 監視させたい Java プログラムの起動オプションに以下を追加して実行する。
- 実行ディレクトリに heapstats.csv, heapstats.dat が出力される。
- analyzer を利用して可視化が行えます。
- 出力フォルダは設定ファイル /etc/heapstats/heapstats.conf (デフォルト) を編集することで変更できます。
以上で HeapStats は実行している Java プロセスを常時監視しつつ各種情報を取得し、故障発生時には解析に必要な情報を根こそぎ取得するようになります！
公式配布のソフトウェアだけでWindowsでMOVファイルをWMVファイルに変換する方法
不慣れな人が動画変換をする場合、無料でやるためによく解らないフリーウェアを入れて変換することが多い。しかしMOVからWMVに変換するだけなら、公式で配布しているソフトウェア(無料)で変換することができた。検索してもやり方が見つかり辛いので備忘録として残す。
MP4(H.264)に変換したい場合は、餅は餅屋ということでここらへんを参考にすると良い。
前準備
- Microsoft Expression Encoder 4 を入手して、インストールする。
- 環境によっては.NET Framework 4.0や、Silverlightのインストールが求められる。それぞれのダウンロード先は表示されるので手順に従ってインストールする。
- Quick Time を入手して、インストールする。
- Expression EncoderだけではMOVファイルを認識できないが、Quick Timeをインストールすれば認識できる。
これらのソフトウェアは有料(Pro)版も販売されているが、無料版も用意されているのでそれを使う。上記リンク先は全部無料版なので、ここでは気にせず導入すると良い。
JavaでFull GCを実行する方法
Full GCを任意のタイミングで実行させ、負荷の高い処理に備えておくという戦略を取りたい時がたまにあります。基本的にはチューニングで解決すべきですが、緊急or暫定策の備忘録として。
jmap -histo:live <pid>
LinuxはJDK5から、WindowsはJDK6から利用可能。生存中のオブジェクトのみ抽出したメモリーマップを作成するために、直前にFull GCを実行するのでこれを利用する。
対象のJavaプロセスを実行しているユーザで実行する必要があるので注意。
jcmd <pid> GC.heap_dump <output_filename>
Linux、WindowsともにJDK7から。これも上のjmap -histo:live と同じく、生存中のオブジェクトのみ抽出するためにFull GCを実行する。これもJavaプロセス実行ユーザと同じユーザで実行する。
Full GCを実行する機能について
JDKでは、恐らく上記の生存オブジェクトのヒープ情報を取得する(HeapInspection)場合でしか、明示的にFull GCを実行する方法は準備されていないと思われる。
実際に呼び出されるコードは以下。
./hotspot/src/share/vm/gc_implementation/shared/vmGCOperations.cpp VM_GC_HeapInspection(outputStream* out, bool request_full_gc, bool need_prologue)から以下を呼ぶ VM_GC_Operation(0 /* total collections, dummy, ignored */, GCCause::_heap_inspection /* GC Cause */, 0 /* total full collections, dummy, ignored */, request_full_gc /* live=true, all=false */)
GCを起動させる方法(追記)
以下はGCが実行され、条件によってはFull GCが呼ばれる。これは上のVM_GC_Operationとは別ルートで、この記事のコメントにあるルートで呼ばれる。条件については未確認なので注意。条件についてはとは書いているが、基本的に Full GC になることを期待できる…はず。
- Runtime.getRuntime().gc() / System.gc()
- jcmd <pid> GC.run
- jconsole の 「Perform GC」ボタン
以下は上のJVM_GC_OperationでFullGCがリクエストされない形で呼ばれるため、普通のGCが起動される。GCなのでヒープ状況次第ではFullGCも呼ばれる。
- jmap -histo <pid>
Java SE 7 JavaDoc 日本語版 公開
前回の記事でJava SE 7 の日本語版 JavaDoc は公開されていないと書きましたが、先日の Java Day Tokyo 2013 で公開されました！
なんてタイミングだ＼(^o^)／
ともあれ大変喜ばしい事です。一部英語の部分もありますが、順次アップデートされるそうです。日本オラクル社と寺田さんの尽力に感謝します！#てらだよしおあいしてる
Java SE 7 JavaDoc公開先：http://www.oracle.com/technetwork/jp/java/javase/documentation/
最新のOpenJDK8のJavaDoc (Java API) #yutori_history
こちらはゆとり Advent Calendar の 12 日目です。おすしたべたいので参加しました！
昨日は @mike_neck さんの mike、mikeなるままに…: ゆとりさんが鮨を奢ってくれるそうなので、感謝の気持を込めて、たくさんのプロセスに「sushi」と言わせてみた でした。
ゆとり Advent Calendar : ATND
ゆとりさん転職おめでとうございます！出会ったのは #glassfishjp で発表した日だったような気がします。GlassFish寿司おごって下さい！
そんなゆとりさんですがこんな事を呼びかけていました。
だれかJDK8が固まる前後あたりで有志でJavaDocの日本語化する人いませんか？
— ゆとり (@megascus) April 9, 2013
残念なことに現在の最新版である JDK7 は
当初、JDK8は夏にGAリリースだったので、しばらくしたらすぐ動き始めるかなと思いきや、JDK8はhttp://mail.openjdk.java.net/pipermail/jdk8-dev/2013-April/002336.html:title:MLでの周知にもある通り、GAが来年の3月14日にズレることになりました。なので、実際にやり始めるのはもうしばらく後になると思いますが、折角なので最新のOpenJDK8のAPIを作って用意しておきましょう。
と、思ったら普通に最新(2013/05/12現在 b89)のAPIが公開されてました。
Overview (Java Platform SE 8 b89)
今日の気付き：さきにしらべとけゆとり
明日は @eiryu さんの番です！
OpenJDK 8 をFedora18でビルドする
OpenJDK と戯れるため、OpenJDK ビルド用サンドボックスとして、まっさらな Fedora 18 (x86_64) 環境を用意してビルドしてみました。
以下、再構築時のための覚え書き。
Fedora 18
Fedoraはこちらのページから好きな形式で落として、KVMなりXenなりVMwareなりにインストールする。
VMWareにインストールする場合は、仮想マシン設定のディスプレイから3Dグラフィックスのアクセラレーションをオフにしないとフリーズするので注意。
インストールが終わったら前準備として環境設定を一通り実施する。
# sudoの設定 su - visudo # 以下を追記する。hogeは適当なユーザ名に変更する。 # hoge ALL=(ALL) ALL # %wheel ALL=(ALL) NOPASSWD: ALL exit # 必要に応じてキーボードを日本語入力に sudo setxkbmap jp -model jp106 # 必要に応じてプロクシを設定 vi ~/.bashrc # 以下を追記する。 # export proxy=xxx.xxx.xxx.xxx:xxxx # export http_proxy=xxx.xxx.xxx.xxx:xxxx # export ftp_proxy=xxx.xxx.xxx.xxx:xxxx source ~/.bashrc sudo vi /etc/yum.conf # 以下を追記する。 # proxy=http://xxx.xxx.xxx.xxx:xxxx
これでFedora18の最低限の設定が完了。
OpenJDK8
続いてビルドに必要なパッケージを導入しつつ、OpenJDK8の最新版を入手してビルドする。これは時間がかかるのでシェルスクリプトとして実行するのが良い。一度実行してしまえばあとはビルド部分のみで済む。
#!/bin/baash # ソースコード取得するための hg(mercurial)導入 sudo yum install -y hg # 最新のOpenJDK8のソースコード取得 hg clone http://hg.openjdk.java.net/jdk8/jdk8 openjdk8 # ビルドに必要な関連プロジェクトのソースコード取得 cd openjdk8 ./get_source.sh # ビルドに必要なパッケージ等のインストール # Fedora標準はJREのみのため、Boot JDK用に jdk7u7 以降のJDKを導入する。 sudo yum install -y java-1.7.0-openjdk-devel # ビルドに必要な諸々のパッケージインストール (ないとconfigure/make時にエラー) sudo yum install -y libXtst-devel libXrender-devel cups-devel freetype-devel alsa-lib-devel libXt-devel # configuration chmod +x configure ./configure # ビルド make all # 動作確認(バージョン表示) build/linux-x86_64-normal-server-release/jdk/bin/java -version
今回は特にオプションを追記せず、 make all でビルドしたが、色々なオプションがあるので Makefile 等を参照すると良い。
