概要
Javaプロセスの中でCPUを浪費しているスレッドを特定する方法を紹介します。Linuxだけでなく、Windowsでの方法も載せています。
前提条件
JDKがインストールされていること
Linuxの場合
まずは、Linuxでの方法です。これと同じことがWindowsでも、できればいいわけです(後述します)。
(1) jpsコマンドで対象のJavaプロセスのIDを特定する
$ 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進数に変換します。
$ printf %x\\n 25826
64e2
(4) jstackコマンドで対象のJavaプロセスのスレッドダンプを取得する
$ jstack 25800 > thread_dump.txt
(5) thread_dump.txtをテキストエディタで開いて、nid=0x64e2で検索すれば、スレッドが特定できます。
"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を特定する
> jps
9488 Jps
5256 Launcher
3948 EmbeddedJettyServer
(2) Process Explorerで対象のJavaプロセスのスレッド単位のCPU使用状況を把握する
topコマンドの無いWindowsでは、Process Explorerというツールを使用します。ダウンロードして、exeファイルをクリックするだけで起動します。
対象のプロセスを見つけたら、右クリックして「Properties」をクリックします。
次のようなウインドウが表示されるので、CPUを消費しているスレッドのTIDを確認します。
上の場合、PIDが「9292」のスレッドがCPUが26.47%を消費していることが分かります。
(3) 「9292」を関数電卓(Windowsなので)で16進数に変換します。
「9292」の16進数は、244cです。
(4) jstackコマンドで対象のJavaプロセスのスレッドダンプを取得する
> jstack 3948 > thread_dmup.txt
(5) 出力したファイル(thread_dmup.txt)を開いて、nid=0x244cで検索すれば、スレッドが特定できます。
