GCログが無かったときに通常のログからGCを類推する

「昨日JBossの応答が非常に悪くなったので再起動しました、GCログは取ってませんでした、原因調査お願いします」というような相談を受けたとき、まあ大体GCが犯人なんだけど、GCログないのでGCログ有効化して再現待ちましょうね、というのが普通の着地点。でも通常のログからGCを類推できることがある。

そこそこアクセスを受けつづけるようなシステムで、ログを極端に絞るなどのことをしていない限り、通常のログも1秒で十数行だとか、それくらいのレベルで出力されていることが多い。もしそうであれば、各ログの間に大きな時間のギャップが存在しているかどうかを調べることによって、Full GCによるStop the worldが発生しているかどうか、発生時間などを間接的に類推できることになる。

というわけでログを以下のようなスクリプトにログを流し込む。このスクリプトでは10秒以上差があるようなログ上のタイムスタンプを報告する。日時フォーマットは汎用化しておらず、JBossのもので書いたけどちょこちょこ変えるだけで他のフォーマットにも対応できるはず。

https://github.com/nekop/sandbox/blob/master/junk/printtimegap.rb