Javaプロセスの中でCPUを浪費しているスレッドを特定する

## 概要

Javaプロセスの中でCPUを浪費しているスレッドを特定する方法を紹介します。Linuxだけでなく、Windowsでの方法も載せています。

## 前提条件

JDKがインストールされていること

## Linuxの場合

まずは、Linuxでの方法です。これと同じことがWindowsでも、できればいいわけです(後述します)。

(1) jpsコマンドで対象のJavaプロセスのIDを特定する

```bash
$ jps
25830 Jps
25800 EmbeddedJettyServer
25769 Launcher
```

(2) topコマンドで対象のJavaプロセスのスレッド単位のCPU使用状況を把握する

```
$ top -n 1 -H -p 25800

top - 21:29:39 up 23:36,  3 users,  load average: 1.66, 0.97, 0.52
Tasks:  31 total,   1 running,  30 sleeping,   0 stopped,   0 zombie
Cpu(s):  2.9%us,  0.8%sy,  0.0%ni, 96.2%id,  0.1%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   3909512k total,  3778736k used,   130776k free,     9520k buffers
Swap:  2031612k total,    52248k used,  1979364k free,   366352k cached

   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                               
 25826 root      20   0 3912m 332m  16m R 95.9  8.7   1:34.14 java                                                                  
 25800 root      20   0 3912m 332m  16m S  0.0  8.7   0:00.00 java                                                                  
 25804 root      20   0 3912m 332m  16m S  0.0  8.7   0:04.61 java                                                                  
 25805 root      20   0 3912m 332m  16m S  0.0  8.7   0:00.59 java                                                                  
 25806 root      20   0 3912m 332m  16m S  0.0  8.7   0:00.01 java                                                                  
 25807 root      20   0 3912m 332m  16m S  0.0  8.7   0:00.02 java                                                                  
 25808 root      20   0 3912m 332m  16m S  0.0  8.7   0:00.00 java                                                                  
 25809 root      20   0 3912m 332m  16m S  0.0  8.7   0:00.00 java                                                                  
 25810 root      20   0 3912m 332m  16m S  0.0  8.7   0:00.00 java          
```

上の場合、PIDが「25826」のスレッドがCPUが95.9%を消費していることが分かります。

(3) 「25826」を以下のコマンドで16進数に変換します。

```bash
$ printf %x\\n 25826
64e2
```

(4) jstackコマンドで対象のJavaプロセスのスレッドダンプを取得する

```bash
$ jstack 25800 > thread_dump.txt
```

(5) thread_dump.txtをテキストエディタで開いて、nid=0x64e2で検索すれば、スレッドが特定できます。

```bash
"qtp2122049087-23" #23 prio=5 os_prio=0 tid=0x00007f5368f2b000 nid=0x64e2 runnable [0x00007f53a06b7000]
   java.lang.Thread.State: RUNNABLE
        at org.apache.log4j.Category.getEffectiveLevel(Category.java:442)
        at org.apache.log4j.Category.isDebugEnabled(Category.java:736)
        at org.slf4j.impl.Log4jLoggerAdapter.debug(Log4jLoggerAdapter.java:250)
        at org.t246osslab.easybuggy.troubles.InfiniteLoopServlet.doGet(InfiniteLoopServlet.java:24)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:668)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:770)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:684)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1507)
        at org.t246osslab.easybuggy.core.filters.AuthenticationFilter.doFilter(AuthenticationFilter.java:72)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1495)
        at org.t246osslab.easybuggy.core.filters.SecurityFilter.doFilter(SecurityFilter.java:51)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1495)
        at org.t246osslab.easybuggy.core.filters.EncodingFilter.doFilter(EncodingFilter.java:42)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1487)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:499)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
```

## Windowsの場合

(1) jpsコマンドで対象のJavaプロセスのIDを特定する

```bat
> jps
9488 Jps
5256 Launcher
3948 EmbeddedJettyServer
```

(2) Process Explorerで対象のJavaプロセスのスレッド単位のCPU使用状況を把握する

topコマンドの無いWindowsでは、[Process Explorer](https://technet.microsoft.com/en-us/sysinternals/bb896653.aspx)というツールを使用します。ダウンロードして、exeファイルをクリックするだけで起動します。


![pe64.png](https://qiita-image-store.s3.amazonaws.com/0/43869/24b254e6-bb7a-9437-32ed-f21495a509d5.png)

対象のプロセスを見つけたら、右クリックして「Properties」をクリックします。

![WS000001.JPG](https://qiita-image-store.s3.amazonaws.com/0/43869/0d7f73ac-0762-39b8-8b43-e19b46c99404.jpeg)

次のようなウインドウが表示されるので、CPUを消費しているスレッドのTIDを確認します。

![pe_sub.png](https://qiita-image-store.s3.amazonaws.com/0/43869/4f0203d7-b476-52fa-c253-73a9555b4b96.png)

上の場合、PIDが「9292」のスレッドがCPUが26.47%を消費していることが分かります。

(3) 「9292」を関数電卓(Windowsなので)で16進数に変換します。

![WS000002.JPG](https://qiita-image-store.s3.amazonaws.com/0/43869/6c0e0945-fc69-2bab-5758-0f5fdc60dbdc.jpeg)

「9292」の16進数は、244cです。

(4) jstackコマンドで対象のJavaプロセスのスレッドダンプを取得する

```bat
> jstack 3948 > thread_dmup.txt
```

(5) 出力したファイル(thread_dmup.txt)を開いて、nid=0x244cで検索すれば、スレッドが特定できます。

![tdh1.png](https://qiita-image-store.s3.amazonaws.com/0/43869/063eb46a-0057-e71b-b565-734490527d75.png)