質問をすることでしか得られない、回答やアドバイスがある。

15分調べてもわからないことは、質問しよう!

ただいまの
回答率

89.13%

GC中の0byteのレスポンス

受付中

回答 1

投稿 編集

  • 評価
  • クリップ 2
  • VIEW 918

chinsukooo

score 13

GCのタイミングでHTTPステータス200、0byteのレスポンスが返却されます。 

 わかっていること 

  • tomcatのEden領域の使用率が100%なって、GCが発生するタイミングにアクセスすると発生する。
  • デプロイされたモジュール内の静的なコンテンツ(例えば404.htmlなど)にアクセスしても発生しない
  • ActionクラスやControllerを実行するようなアクセスの場合に発生する。
  • Struts2で作ったものも、Springで作ったものを発生する(フレームワークのせいではなさそう)
  • tomcatのcatalina.outに、0byteのレスポンスが発生した時に以下のエラーが出る。
    java.lang.IllegalStateException: レスポンスをコミットした後でフォワードできません

GCのタイミングでアクセスするとしょうがないものなのでしょうか?

だれが0byteのレスポンスを返しているのかもわかっていません。

どこかで(勝手に)0byteのレスポンスを返してしまっているから、「レスポンスをコミットした後でフォワードできません」のエラーが出ている気がしています。
なにか確認すべきことや似た事象があれば教えてください。
よろしくお願いします。

java 1.6
tomcat 6.0.33

追記
tcpdumpを取得してみました。
HTTPステータスは200で、レスポンスBODYが存在しません。
Next Sequene number:136 で
841行目で正常に処理できたことが確認できると思います。

tcpdump結果キャプチャ

追記2
コールスタックを貼ります。

java.lang.Thread#run
org.apache.tomcat.util.net.JIoEndpoint$Worker#run
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler#process
org.apache.coyote.http11.Http11Processor#process
org.apache.catalina.connector.CoyoteAdapter#service
org.apache.catalina.core.StandardEngineValve#invoke
org.apache.catalina.valves.AccessLogValve#invoke
org.apache.catalina.valves.ErrorReportValve#invoke
org.apache.catalina.core.StandardHostValve#invoke
org.apache.catalina.core.StandardContextValve#invoke
org.apache.catalina.core.StandardWrapperValve#invoke
org.apache.catalina.core.ApplicationFilterChain#doFilter
org.apache.catalina.core.ApplicationFilterChain#internalDoFilter
org.seasar.extension.filter.EncodingFilter#doFilter
org.apache.catalina.core.ApplicationFilterChain#doFilter
org.apache.catalina.core.ApplicationFilterChain#internalDoFilter
XXXXXXXXXXXXXXXXXXXXXX.filter.XXXXXXXXXX.XXXXXXX#doFilter // フィルタA
org.apache.catalina.core.ApplicationFilterChain#doFilter
org.apache.catalina.core.ApplicationFilterChain#internalDoFilter
XXXXXXXXXXXXXXXXXXXXXX.filter.XXXXXXXXXX.XXXXXXX#doFilter // フィルタB
org.apache.catalina.core.ApplicationFilterChain#doFilter
org.apache.catalina.core.ApplicationFilterChain#internalDoFilter
org.seasar.framework.container.filter.S2ContainerFilter#doFilter
org.apache.catalina.core.ApplicationFilterChain$#doFilter
org.apache.catalina.core.ApplicationFilterChain#internalDoFilter
org.seasar.framework.container.hotdeploy.HotdeployFilter#doFilter
org.apache.catalina.core.ApplicationFilterChain#doFilter
org.apache.catalina.core.ApplicationFilterChain#internalDoFilter
org.seasar.struts.filter.RoutingFilter#doFilter
org.seasar.struts.filter.RoutingFilter#forward
org.apache.catalina.core.ApplicationDispatcher#forward
org.apache.catalina.core.ApplicationDispatcher#doForward    // 0bytの時はここでIllegalStateExceptionが発生
org.apache.catalina.core.ApplicationDispatcher#processRequest
org.apache.catalina.core.ApplicationDispatcher#invoke
org.apache.catalina.core.ApplicationFilterChain#doFilter
org.apache.catalina.core.ApplicationFilterChain#internalDoFilter
org.seasar.framework.container.filter.S2ContainerFilter#doFilter
org.apache.catalina.core.ApplicationFilterChain#doFilter
org.apache.catalina.core.ApplicationFilterChain#internalDoFilter
org.seasar.framework.container.hotdeploy.HotdeployFilter#doFilter
org.apache.catalina.core.ApplicationFilterChain#doFilter
org.apache.catalina.core.ApplicationFilterChain#internalDoFilter
javax.servlet.http.HttpServlet#service
javax.servlet.http.HttpServlet#service
org.apache.struts.action.ActionServlet#doGet
org.apache.struts.action.ActionServlet#process
org.apache.struts.util.ModuleUtils#selectModule
org.apache.struts.util.ModuleUtils#getModuleName
org.apache.struts.util.ModuleUtils#getModuleName
  • 気になる質問をクリップする

    クリップした質問は、後からいつでもマイページで確認できます。

    またクリップした質問に回答があった際、通知やメールを受け取ることができます。

    クリップを取り消します

  • 良い質問の評価を上げる

    以下のような質問は評価を上げましょう

    • 質問内容が明確
    • 自分も答えを知りたい
    • 質問者以外のユーザにも役立つ

    評価が高い質問は、TOPページの「注目」タブのフィードに表示されやすくなります。

    質問の評価を上げたことを取り消します

  • 評価を下げられる数の上限に達しました

    評価を下げることができません

    • 1日5回まで評価を下げられます
    • 1日に1ユーザに対して2回まで評価を下げられます

    質問の評価を下げる

    teratailでは下記のような質問を「具体的に困っていることがない質問」、「サイトポリシーに違反する質問」と定義し、推奨していません。

    • プログラミングに関係のない質問
    • やってほしいことだけを記載した丸投げの質問
    • 問題・課題が含まれていない質問
    • 意図的に内容が抹消された質問
    • 過去に投稿した質問と同じ内容の質問
    • 広告と受け取られるような投稿

    評価が下がると、TOPページの「アクティブ」「注目」タブのフィードに表示されにくくなります。

    質問の評価を下げたことを取り消します

    この機能は開放されていません

    評価を下げる条件を満たしてません

    評価を下げる理由を選択してください

    詳細な説明はこちら

    上記に当てはまらず、質問内容が明確になっていない質問には「情報の追加・修正依頼」機能からコメントをしてください。

    質問の評価を下げる機能の利用条件

    この機能を利用するためには、以下の事項を行う必要があります。

質問への追記・修正、ベストアンサー選択の依頼

  • wwbQzhMkhhgEmhU

    2019/02/12 17:16

    了解です。あと分かるなら
    Tomcatの正確なバージョン
    seasarはよく知らないので、これもバージョン
    もお願いします。
    他には可能であればTomcatのバッファサイズ確か変更できたと思ったので、広げて試したりもしてみてほしいです。それでは。

    キャンセル

  • chinsukooo

    2019/02/13 10:55

    こんにちは。遅くなってしまいましたが確認しました。
    GCが発生したタイミングで、1秒ほど中身のないチャンク転送の200が続きます。
    正常に返す時もチャンク転送です。(HTTP chunked response と出ているのでそう判断しています。)
    tomcatは6.0.33です。
    ヒープ領域やバッファサイズも増やしたりしましたが、GCが発生する間隔が広がっただけで、GCのタイミングで0byteレスポンスが発生するのは変わりませんでした。

    キャンセル

  • wwbQzhMkhhgEmhU

    2019/02/13 11:27

    了解です。amdahlslawさんの情報までは確認できて、現象も不一致がない状態ですね。
    200の部分で起きている現象を確認しないとですね。ヒープサイズは変えてもしょうがないかと思いますが、バッファが効かなかったのはちょっと困りましたね。変更したパラメータと前後の値を教えてください。
    長くなったので、以降はamdahlslawさんの回答の方に移りますね。

    キャンセル

回答 1

0

情報提供

スタックトレースから読めるのは、次のようなエラーの発生状況です。

HTTPリクエスト受付 -> サーブレットフィルター処理 -> ... -> defaultサーブレットのservice処理へ転送

defaultサーブレットはStrutsのフロントコンポーネント(すべてのリクエストを受け付けるサーブレット)ではないかと思います。

転送は、ApplicationDispatcher(RequestDispatcher)の doForward で実行。

org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:312)

例外メッセージは「レスポンスをコミットした後でフォワードできません」なので以下のプロパティが使われたと想定。

applicationDispatcher.forward.ise=レスポンスをコミットした後でフォワードできません

ApplicationDispatcherのソースコードを見ます。(正確なバージョンがわからないので行番号(312)が一致したもの)

    private void doForward(ServletRequest request, ServletResponse response)
        throws ServletException, IOException
    {

        // Reset any output that has been buffered, but keep headers/cookies
        if (response.isCommitted()) {  // <------- (1) isCommited
            throw new IllegalStateException
                (sm.getString("applicationDispatcher.forward.ise"));  // <------- (2) property
        }
        try {
            response.resetBuffer();
        } catch (IllegalStateException e) {
            throw e;
        }

最初の IllegalStateException を投げているところ、(1)の response.isCommitted() に該当するようです。つまり、レスポンスはすでにコミットされた。では、誰がコミットしたのか?それは、リクエスト処理を実行しているスレッドのはず、手前にあるサーブレットフィルターのどれかではないでしょうか。(困るんだけど...)

ついでにいうと、ServletResponseは本物でない可能性があります。Servletの仕様では ServletResponseWrapper を許すので、ラッパーの内部で、実際の出力内容をメモリにキャッシュすることもできます。GCの状況から、手前のサーブレットフィルターのどれかが、キャッシュ用のメモリが確保できないのでギブアップした、などが想像できます。

以上、情報提供だけです。

参考
https://www.google.com/url?sa=t&rct=j&q=&esrc=s&source=web&cd=1&cad=rja&uact=8&ved=2ahUKEwiuyOXOy7XgAhUP8LwKHSzlB7kQFjAAegQICRAB&url=https%3A%2F%2Fsvn.apache.org%2Frepos%2Fasf%2Ftomcat%2Ftrunk%2Fjava%2Forg%2Fapache%2Fcatalina%2Fcore%2FApplicationDispatcher.java&usg=AOvVaw04faUFOh_JgqIvFQpDqTZx

https://svn.apache.org/repos/asf/tomcat/trunk/java/org/apache/catalina/core/LocalStrings_ja.properties

フレームワークではない
Tomcatのコンポーネントを疑うべきでしょうか。

投稿

編集

  • 回答の評価を上げる

    以下のような回答は評価を上げましょう

    • 正しい回答
    • わかりやすい回答
    • ためになる回答

    評価が高い回答ほどページの上位に表示されます。

  • 回答の評価を下げる

    下記のような回答は推奨されていません。

    • 間違っている回答
    • 質問の回答になっていない投稿
    • スパムや攻撃的な表現を用いた投稿

    評価を下げる際はその理由を明確に伝え、適切な回答に修正してもらいましょう。

  • 2019/02/14 15:53

    ログ2とログ3の間です。
    全部貼るとすごいことになってしまいますが
    大体の流れでいうと、
    フィルタA:ログ1⇒フィルタB:ログ2⇒Exception発生箇所⇒Actionクラスとか・・・⇒フィルタB⇒フィルタA:ログ3 という流れです。

    キャンセル

  • 2019/02/14 16:15

    なるほど。。。それは大変な。。。
    最初にExceptionが発生したときのリクエストとその直前のリクエスト辺りが気になりますね
    ただ出せる情報ではない/出す作業自体が大変だと思うので、こちらでも引き続き暇なときに独自調査していくつもりですが、こちらからの成果は諦めた方がいいと思います
    頑張ってください

    キャンセル

  • 2019/02/14 16:19

    自分では思い浮かばないたくさんの調査切り口を提供してくださり、感謝します。
    だれがどこで0byte返却しているのか、引き続き調査します。とりあえずはフレームワーク周り、、
    ありがとうございます。

    キャンセル

15分調べてもわからないことは、teratailで質問しよう!

  • ただいまの回答率 89.13%
  • 質問をまとめることで、思考を整理して素早く解決
  • テンプレート機能で、簡単に質問をまとめられる