- - PR -
Tomcatのデッドロックについて
1
| 投稿者 | 投稿内容 | ||||
|---|---|---|---|---|---|
|
投稿日時: 2004-10-05 18:17
初めまして、いつも参考にさせて頂いています。
初めての投稿ですが宜しくお願いします。 現在、Tomcatがデッドロックする現象に頭を悩ませています。 環境は下記の通りです。 ------------------------------------- RedHat 9(2.4.20- 
Apache 1.3.31 Tomcat 4.1.30 ※コネクタには mod_jk2(v2.0.4)を使用 Java j2sdk1.4.2_04 PostgreSQL 7.4.3 ------------------------------------- 検証環境上のシステムですが、以下のような流れで処理が進みます。 ①ログインページ ID/PWを入力してログインボタンをクリックする ②ログイン認証用サーブレット ・認証用サーブレットにPOSTし、DBを参照してID/PWが正しいか判別。 ・間違っていればログインエラーページへ飛ばす。 ・正しければDBへログインログを登録し、ID/PW他ユーザー個別の情報を Sessionにセットし、メインページへ飛ばす。 ③メイン画面 メイン画面ではDBを参照してデータを表示するだけの単純な仕組みです。 状況としては、Tomcat立ち上げ直後は問題なく①～③までスムーズに処理が進むのですが、 ある一定時間経過すると、②の部分で先に進まなくなり、Tomcatの応答が無いような状態 になります。 「ある一定期間」とは曖昧ですが、具体的に何時間、という決まったものはありません。 朝9時にTomcatを立ち上げ、夜23時に正常動作を確認し、翌日朝9時に確認したら 応答が悪い（無い）状態となります。これが、翌々日に応答が無くなる現象が発生する 場合もあります。 スレッドダンプを取得したところ、下記のような状態のスレッドがありました。 "TP-Processor37" daemon prio=1 tid=0x08605eb8 nid=0x2918 waiting for monitor entry [6b4fe000..6b4fed18] at org.apache.catalina.session.ManagerBase.generateSessionId(ManagerBase.java:706) - waiting to lock <0x4708c588> (a org.apache.catalina.session.StandardManager) at org.apache.catalina.session.ManagerBase.createSession(ManagerBase.java:584) at org.apache.catalina.session.StandardManager.createSession(StandardManager.java:364) at org.apache.coyote.tomcat4.CoyoteRequest.doGetSession(CoyoteRequest.java:1915) at org.apache.coyote.tomcat4.CoyoteRequest.getSession(CoyoteRequest.java:1758) at org.apache.coyote.tomcat4.CoyoteRequestFacade.getSession(CoyoteRequestFacade.java:361) at VerifyUser.checkUser(VerifyUser.java:227) at VerifyUser.doPost(VerifyUser.java:407) at javax.servlet.http.HttpServlet.service(HttpServlet.java:760) at javax.servlet.http.HttpServlet.service(HttpServlet.java:853) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:247) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2422) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:163) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:199) at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:324) at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:395) at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:673) at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:615) at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:786) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683) at java.lang.Thread.run(Thread.java:534) VerifyUserクラスの中ではログイン成功と判断した直後、request.getSession(true); によりセッションを生成して、IDやユーザー個別の情報をセッションに格納するように しています。セッションに格納する文字列は、全て１バイト文字です。 ----------------------------------------------------------------- //Sessionにセット session = request.getSession(true); session.setAttribute("uid",user_id); session.setAttribute("model",model_cd); session.setAttribute("comp",comp_cd); session.setAttribute("group_id",group_id); session.setAttribute("group_count",""+group_count); session.setMaxInactiveInterval(setSessionTimeout); ----------------------------------------------------------------- スレッドダンプからは、request.getSession(true); より先に進んでいないことは分かりました。 ただ、どうしてここでデッドロックするかが分かりません。 初めは、setMaxInactiveInterval() に -1 をセットしていたのが原因かと思い、 極端に、setMaxInactiveInterval(20) をセットしてテストしましたが結果は 同じでした。 どなたか、この現象についてお分かりになる方、アドバイスをお願いします。 また、Session使用時に注意しなければならない点があればご教授頂けると幸いです。 宜しくお願い致します。 | ||||
|
投稿日時: 2004-10-05 19:43
generateSessionId() でロックする事は考えられないですが、 それを呼んでいる createSession() ではセッション ID の重複を 避けるループが存在するので、こちらは有り得るかもしれません。 それには、いつまでたってもユニークなセッション ID が 生成出来ない場合が該当しますが、実際にはそれはあまり 考えられないのですけど... ちなみにその時のセッション数はどうなっているのでしょう。 | ||||
|
投稿日時: 2004-10-05 20:03
jinakaです。
まずは、はしもとさんからご指摘のあったセッション数が確認できるよう、 TomcatのWeb Application Managerのサイトが開けるように設定変更しました。 現状では、20秒（程度）でセッションの数が０になるような動作は確認できています (試験的にsetMaxInactiveInterval(20)をセットしている為）。 これが明朝にどのような値になっているか確認してみます。 現在は、JavaプロセスをkillしてTomcatを再立ち上げすることで正常に稼動しています。 プロセスをkillするまでの間、以下の項目を確かめてみました。 ① 5～6回、ID/PWを入力してログインボタンをクリック --＞スレッドダンプを取得すると、waiting for monitor entryのスレッドが 増えていきました。その中でたった一つだけ、以下の様にgenerateSessionIdより 先に進んでいるスレッドがありました。waiting for monitor entryではない のですが残っています。 "TP-Processor2" daemon prio=1 tid=0x08484038 nid=0x2918 waiting on condition [69fca000..69fcaf18] at sun.security.provider.MD5.engineUpdate(MD5.java:252) at sun.security.provider.MD5.finish(MD5.java:290) at sun.security.provider.MD5.engineDigest(MD5.java:303) at java.security.MessageDigest$Delegate.engineDigest(MessageDigest.java:507) at java.security.MessageDigest.digest(MessageDigest.java:289) at java.security.MessageDigest.digest(MessageDigest.java:335) at org.apache.catalina.session.ManagerBase.generateSessionId(ManagerBase.java:709) - locked <0x4708c588> (a org.apache.catalina.session.StandardManager) at org.apache.catalina.session.ManagerBase.createSession(ManagerBase.java:584) at org.apache.catalina.session.StandardManager.createSession(StandardManager.java:364) at org.apache.coyote.tomcat4.CoyoteRequest.doGetSession(CoyoteRequest.java:1915) at org.apache.coyote.tomcat4.CoyoteRequest.getSession(CoyoteRequest.java:1758) at org.apache.coyote.tomcat4.CoyoteRequestFacade.getSession(CoyoteRequestFacade.java:361) at VerifyUser.checkUser(VerifyUser.java:189) at VerifyUser.doPost(VerifyUser.java:407) at javax.servlet.http.HttpServlet.service(HttpServlet.java:760) at javax.servlet.http.HttpServlet.service(HttpServlet.java:853) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:247) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2422) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:163) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:199) at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:324) at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:395) at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:673) at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:615) at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:786) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683) at java.lang.Thread.run(Thread.java:534) ② 新しいJSPファイルを適用し、ブラウザで表示可能かチェック --＞サーバーの応答が返らず、ブラウザは応答待ちの状態となりました。 あと、これはJavaプロセスをkillした直後に気が付いたのですが、 サーバーのロードアベレージが6.0を超え、徐々に0に近い数値に 近づいていったことです。JSPのコンパイル時に異常な負荷が掛かった のかも知れません。 その際のスレッドダンプには、 "TP-Processor39" daemon prio=1 tid=0x08606f20 nid=0x2918 waiting for monitor entry [6b5fe000..6b5fec18] at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:190) - waiting to lock <0x45084e10> (a org.apache.jasper.servlet.JspServletWrapper) at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:295) at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:241) at javax.servlet.http.HttpServlet.service(HttpServlet.java:853) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:247) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2422) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:163) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:199) at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:324) at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:395) at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:673) at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:615) at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:786) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683) at java.lang.Thread.run(Thread.java:534) と、 "TP-Processor38" daemon prio=1 tid=0x08606220 nid=0x2918 waiting on condition [6b57e000..6b57ec98] at org.apache.jasper.compiler.Parser.parse(Parser.java:117) at org.apache.jasper.compiler.ParserController.parse(ParserController.java:199) at org.apache.jasper.compiler.ParserController.parse(ParserController.java:153) at org.apache.jasper.compiler.Compiler.generateJava(Compiler.java:227) at org.apache.jasper.compiler.Compiler.compile(Compiler.java:369) at org.apache.jasper.JspCompilationContext.compile(JspCompilationContext.java:473) at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:190) - locked <0x45084e10> (a org.apache.jasper.servlet.JspServletWrapper) at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:295) at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:241) at javax.servlet.http.HttpServlet.service(HttpServlet.java:853) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:247) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2422) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:163) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174) at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995) at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:199) at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:324) at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:395) at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:673) at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:615) at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:786) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683) at java.lang.Thread.run(Thread.java:534) が出力されていました。 何を疑ってよいか分からない状態ですが、引き続き調べてみたいと思います。 [ メッセージ編集済み 編集者: jinaka 編集日時 2004-10-06 01:09 ] | ||||
|
投稿日時: 2004-10-06 09:44
おはようございます、jinakaです。
今朝はデッドロックが検出されませんでした。 ログインも正常にできました。 TomcatのManagerでセッション数を確認しても、 昨日ログイン分のセッションが残ることは無く、ゼロでした。 スレッドダンプを取りながら何度ログインしなおしても、 デッドロックしてしまうようなスレッドは見当たりませんでした。 明朝の状況も引き続き確認したいと思います。 ただ、デッドロックしてしまうと、TomcatはHTMLもJSPも返さない状態になる為、 果たしてManagerのサイトが開けるのか分かりません。 一日に一度しかアクセスしなくても、気が付けばデッドロックしている ことが時々ある為、何か外的要因がないかどうかチェックしてみたいと思います。 | ||||
1
スキルアップ／キャリアアップ（JOB@IT）
Copyright © ITmedia, Inc. All Rights Reserved.
著作権はアイティメディア株式会社またはその記事の筆者に属します。
当サイトに掲載されている記事や画像などの無断転載を禁止します。
著作権はアイティメディア株式会社またはその記事の筆者に属します。
当サイトに掲載されている記事や画像などの無断転載を禁止します。