unnamed

Javaとか、http://twitter.com/sugarlife

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 さんの番です！