理系学生日記

おまえはいつまで学生気分なのか

スレッドダンプを解析する地獄とFastThreadというWebサービス

スレッドダンプというと、JVM 言語に関する運用でマジで困ったときの頼みの綱みたいなイメージある。マジで困ったとき、じゃなくて、カジュアルに見れば良いんだけど、スレッドダンプのフォーマットが異常すぎてつらくなる。

そもそもなんなんだこのゴミみたいなフォーマットは。 一体誰がどういう思想の元でこのフォーマットを決めたのかさっぱり分からないし、人類を苦しめるために未来から来た AI が勝手に策定したのではないか。

"[ThreadPool Manager] - Idle Thread" #42 daemon prio=5 os_prio=31 tid=0x000000012a3a7800 nid=0x15503 in Object.wait() [0x000070000ab66000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:502)
        at org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor.run(Executor.java:106)
        - locked <0x0000000744b091c0> (a org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor)

   Locked ownable synchronizers:
        - None

"Worker-2" #40 prio=5 os_prio=31 tid=0x000000012a15e800 nid=0x13843 in Object.wait() [0x000070000a8da000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188)
        - locked <0x0000000741f00888> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:51)

運用してたシステムで Full GC が頻発したりする事象があって、スレッドダンプを目で解析するみたいな地獄みたいなことしたけど、結局原因がネットワークの輻輳にあったとかいう意味のなさだった。 で、そういうのつらすぎるとか思って何年も過ぎたんだけど、今はもう解析してくれる Web サービスとかあった。

単純にスレッドダンプをアップロードするだけで、無料で解析してくれるのが良いかんじ。 スレッドの状態とか、使われてるメソッドとか、CPU 消費してるメソッドとかも解析してダッシュボードに表示してくれる。

f:id:kiririmode:20170625205212p:plain

f:id:kiririmode:20170625205233p:plain

時代は進んでいるし、ゴミみたいなスレッドダンプを目で解析する時代は終わったみたい。そろそろスレッドダンプのフォーマットをマシにしても良いのではなかろうか。

2017/06/29 追記

ご指摘頂いているとおり、Full GC の解析はまずヒープのダンプを取って、どのクラスがどれだけヒープに溜まっているのかを解析するのが定石です。 誤解させてしまったようですみません。

上記の障害事例のときもヒープダンプを取りましたが原因が見えず、スレッドダンプを取っても不明、sar の結果を解析しても不明で、 ネットワークトラフィックと LB の状況からようやく結果が分かったという経緯でした。