1.事の発端

Tomcat上で動いているjavaアプリケーションで、CPUがずっと80%とかにくっついている現象が発生。
「うぇーまじか」となった。
ともあれ調査せねば。となった時にやったこと。

2.手順

2.1 topコマンドで状況確認（当時のものとは違っています）

コマンド

$ top
top - 18:27:24 up 285 days,  3:05,  3 users,  load average: 5.33, 5.36, 4.93
Tasks:  70 total,   1 running,  69 sleeping,   0 stopped,   0 zombie        
Cpu(s): 10.1%us,  0.9%sy,  0.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  0.0%si, 89.0%st
Mem:    617044k total,   522324k used,    94720k free,     4812k buffers
Swap:        0k total,        0k used,        0k free,    79684k cached 
                                                                                                                                    
  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND    
 1722 root      20   0 1422m 394m 6004 S 96.5 65.5  53:50.89 jsvc       
    6 root      20   0     0    0    0 S  3.4  0.0  11:35.37 events/0   
 1929 hoge      20   0  2592 1000  784 R  0.3  0.2   0:24.33 top        
    1 root      20   0  2892  868  664 S  0.0  0.1   0:01.76 init       
    2 root      20   0     0    0    0 S  0.0  0.0   0:00.00 kthreadd   
--- (以下略) ---

2.2 プロセスでヤバそうな奴を見つける

$ ps -L aux
そうすると、tomcat上で動くプログラムのうちいくつかにおける（TIME）が永遠と増え続けていることに気付く。

コマンド

     USER       PID   LWP %CPU NLWP %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
    tomcat    3487  1111  25.1   39 14.1 10233084 2222644 ?    Sl   09:03   25:10 jsvc.exec -user tomcat -home /usr/lib/jvm/java

こんな感じ（イメージです）。

PIDとLWPを控える。

2.3スレッドダンプを取得

rootユーザで
su - tomcat -s /bin/bash
jstack PID（先ほど控えた奴）

そうすると以下みたいな情報が出てくるので、控えるなり、目を背けるなりする

スタックトレース(例)

"RMI TCP Accept-0" #10 daemon prio=5 os_prio=0 tid=0x0000000000c29800 nid=xxxx runnable [0x00007f2f36728000]
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAccept(Native Method)
--- (以下略) ---

16進数にしたLWPのIDがスレッドダンプ内の"nid=xxxxx" と対応する
なのでスレッドダンプしたファイルをそのIDで検索してやれば、対象のスタックトレースが見つかる

LWP: Linux上のプロセスよりも小さい実行単位、スレッドのようなもの

2.4 終わってみて

調査してみたところ、再帰処理で死亡していたことが判明。修正し一段落