- PR -

Tomcat の CPU 使用率が 99.9% になる

参照元記事 | 同じ記事を参照しているスレッド一覧
1
投稿者投稿内容
ひじき
常連さん
会議室デビュー日: 2006/12/04
投稿数: 22
投稿日時: 2007-05-28 21:56
いつもお世話になっております。

Linux 上で Apache + Tomcat + PostgreSQL を使用した
Web アプリケーションが動作しており、
一ヶ月くらい前より Tomcat の CPU 使用率が 99.9% になる現象が発生しております。

環境は以下の通りです。
OS : Redhat Linux 9
APPServer : Tomcat 5.0.28
HTTPServer : Apache 2.0.48
mod_jk2 2.0.2
DBServer : PostgreSQL8.4
JDK : JDK 1.4.2_13
FrameWork : Struts 1.1
（サーバ自体は日々再起動を実施しております）

なお、これまでの経緯は以下のスレッドを参照ください。
http://www.atmarkit.co.jp/bbs/phpBB/viewtopic.php?mode=viewtopic&topic=35295&forum=12&start=0

今回発生した現象は top コマンドで確認すると
tomcat (java) プロセスが 99.9% になっており、
30分経っても正常値に戻らず、
Tomcat を再起動せざるを得ない状況になります。
（Tomcat の再起動で復旧）

なお、前回のように FULL GC が頻発しているわけでもありません。
（OutOfMemory も発生していない）

http://syo.cocolog-nifty.com/freely/2006/11/apache22tomcat5.html
上記サイトにて tomcat の server.xml の port=8080 部分と同じ記述を
port=8009 部分に記述すると直るということが書いてありましたが
直りませんでした。

スレッドダンプ（x5）を取得しましたが dead lock も検出されません。
スレッドダンプで以下の3つの内容が若干多く出力されておりました。
関係ありますでしょうか。

"TP-Processor58" daemon prio=1 tid=0x084b4628 nid=0xf9d runnable [0x6f721000..0x6f721cd4]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:222)
at java.io.BufferedInputStream.read(BufferedInputStream.java:277)
- locked <0x58fd6018> (a java.io.BufferedInputStream)
at org.apache.jk.common.ChannelSocket.read(ChannelSocket.java:598)
at org.apache.jk.common.ChannelSocket.receive(ChannelSocket.java:535)
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:663)
at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:866)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
at java.lang.Thread.run(Thread.java:534)


"TP-Processor50" daemon prio=1 tid=0x08075018 nid=0xce5 in Object.wait() [0x6ef11000..0x6ef11cd4]
at java.lang.Object.wait(Native Method)
- waiting on <0x569de3b0> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Object.wait(Object.java:429)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:655)
- locked <0x569de3b0> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Thread.run(Thread.java:534)

"TP-Processor49" daemon prio=1 tid=0x08073e98 nid=0xce4 runnable [0x6ee8f000..0x6ee90cd4]
at java.util.HashMap.get(HashMap.java:325)
at org.apache.catalina.session.StandardSession.getAttribute(StandardSession.java:978)
at org.apache.catalina.session.StandardSessionFacade.getAttribute(StandardSessionFacade.java:113)
at org.apache.jasper.runtime.PageContextImpl.doFindAttribute(PageContextImpl.java:469)
at org.apache.jasper.runtime.PageContextImpl.findAttribute(PageContextImpl.java:454)
at org.apache.struts.util.RequestUtils.lookup(RequestUtils.java:874)
at org.apache.struts.taglib.logic.EmptyTag.condition(EmptyTag.java:121)
at org.apache.struts.taglib.logic.NotEmptyTag.condition(NotEmptyTag.java:94)
at org.apache.struts.taglib.logic.ConditionalTagBase.doStartTag(ConditionalTagBase.java:218)
at org.apache.jsp.xxxxx.xxxxx.xxxxxxx.xxxxxxxxxx_jsp._jspService(xxxxxxxxxx_jsp.java:326)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:94)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:324)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:292)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:236)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:704)
at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:474)
at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:409)
at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:312)
at org.apache.struts.action.RequestProcessor.doForward(RequestProcessor.java:1069)
at org.apache.struts.action.RequestProcessor.processForwardConfig(RequestProcessor.java:455)
at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:279)
at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:507)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:689)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:704)
at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:474)
at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:409)
at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:312)
at org.apache.struts.action.RequestProcessor.doForward(RequestProcessor.java:1069)
at org.apache.struts.action.RequestProcessor.processForwardConfig(RequestProcessor.java:455)
at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:279)
at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:507)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:689)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:704)
at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:474)
at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:409)
at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:312)
at org.apache.struts.action.RequestProcessor.doForward(RequestProcessor.java:1069)
at org.apache.struts.action.RequestProcessor.processForwardConfig(RequestProcessor.java:455)
at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:279)
at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:507)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:689)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at xxx.xxx.xxxxx.online.presentation.web.filter.MultipartFilter.doFilter(MultipartFilter.java:49)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at xxx.xxx.xxxxx.online.presentation.web.filter.AuthFilter.doFilter(AuthFilter.java:156)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at xxx.xxx.xxxxx.online.presentation.web.filter.ExceptionHandlingFilter.doFilter(ExceptionHandlingFilter.java:62)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at xxx.xxx.xxxxx.online.presentation.web.filter.CounterManagingFilter.doFilter(CounterManagingFilter.java:49)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at xxx.xxx.xxxxx.online.presentation.web.filter.CharactorEncodingFilter.doFilter(CharactorEncodingFilter.java:57)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:118)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929)
at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160)
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:300)
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:374)
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:743)
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:675)
at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:866)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
at java.lang.Thread.run(Thread.java:534)

不定期に発生するため、非常に困っております。
ご教授ください。
山本 裕介
ぬし
会議室デビュー日: 2003/05/22
投稿数: 2415
お住まい・勤務地: 恵比寿
投稿日時: 2007-05-28 22:11
>"TP-Processor58" daemon prio=1 tid=0x084b4628 nid=0xf9d runnable [0x6f721000..0x6f721cd4]
>at java.net.SocketInputStream.socketRead0(Native Method)
クライアントからのリクエストを読み込んでいる状態です。

>"TP-Processor50" daemon prio=1 tid=0x08075018 nid=0xce5 in Object.wait() [0x6ef11000..0x6ef11cd4]
> at java.lang.Object.wait(Native Method)
>- waiting on <0x569de3b0> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
スレッドプール内でヒマをもてあましているスレッドです。

>"TP-Processor49" daemon prio=1 tid=0x08073e98 nid=0xce4 runnable [0x6ee8f000..0x6ee90cd4]
>at java.util.HashMap.get(HashMap.java:325)
>at org.apache.catalina.session.StandardSession.getAttribute(StandardSession.java:978)
HttpSession から値を取得しているところです。


どのスレッドが特に CPU を消費しているのか確認しましょう。
以下のサポートパターンが参考になると思います。
・BEA トラブルシューティング ガイド > サポート診断パターン > WLS での予期しない高い CPU 使用率
http://www.beasys.co.jp/cs/support_news/product_troubleshooting/High_CPU_Usage_Pattern.html#Linux

RedHat9なら恐らくスレッド一つ一つに対応するプロセスがあるはずですのでどのスレッドが問題になっているのか top で確認できると思います。
ひじき
常連さん
会議室デビュー日: 2006/12/04
投稿数: 22
投稿日時: 2007-06-08 15:53
ご回答ありがとうございます。
引用:

インギさんの書き込み (2007-05-28 22:11) より:
どのスレッドが特に CPU を消費しているのか確認しましょう。
以下のサポートパターンが参考になると思います。
・BEA トラブルシューティング ガイド > サポート診断パターン > WLS での予期しない高い CPU 使用率
http://www.beasys.co.jp/cs/support_news/product_troubleshooting/High_CPU_Usage_Pattern.html#Linux

RedHat9なら恐らくスレッド一つ一つに対応するプロセスがあるはずですのでどのスレッドが問題になっているのか top で確認できると思います。


以下、top、pstree の実行結果です。

[root@server root]# top
PID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME CPU COMMAND
675 webadmin 25 0 469M 441M 2824 S 99.9 11.6 44:38 2 java
17535 postgres 15 0 84984 82M 83272 S 4.7 2.1 0:06 0 postmaster
17515 postgres 15 0 84752 82M 83276 S 4.3 2.1 0:06 3 postmaster
17534 postgres 15 0 84960 82M 83368 S 3.9 2.1 0:09 3 postmaster
17691 postgres 19 0 10104 9.8M 8792 S 2.5 0.2 0:00 2 postmaster
17687 webadmin 15 0 1384 1384 900 R 0.3 0.0 0:00 0 top

[root@server root]# pstree -p
init(1)-+-aacraid(23)
|-atd(946)
|-bdflush(15)
|-cannaserver(825)
|-crond(836)
|-cupsd(847)
|-gpm(783)
|-java(675)---java(716)-+-java(717)
| |-java(718)
| |-java(719)
| |-java(720)
| |-java(721)
| |-java(722)
| |-java(723)
| |-java(724)
| |-java(725)

本現象発生時は java プロセス（上記で言うと pid=675）の CPU 使用率が
99.9% になっておりました。

pid=675 は java の親プロセスのような気がします。（pstree 実行結果参照）
こういった場合、top で java プロセスのどのスレッドが特にCPUを消費しているかを
確認する方法はございますでしょうか。

ご教授ください。

ちなみに pid=675 を原因のスレッドだと仮定した場合、
教えていただきました URL を参考にスレッドダンプを確認しましたところ、
次のように出力されておりました。
"main" prio=1 tid=0x08058578 nid=0x29f runnable [0xbfffb000..0xbfffc0c8]
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
- locked <0x561a0d38> (a java.net.PlainSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:448)
at java.net.ServerSocket.accept(ServerSocket.java:419)
at org.apache.catalina.core.StandardServer.await(StandardServer.java:513)
at org.apache.catalina.startup.Catalina.await(Catalina.java:619)
at org.apache.catalina.startup.Catalina.start(Catalina.java:579)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:287)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:425)


[ メッセージ編集済み 編集者: ひじき 編集日時 2007-06-08 16:49 ]
1

スキルアップ／キャリアアップ（JOB@IT）