Tomcat8.0.0がやたら遅い件

Tomcat8もそろそろリリースですね。いまRC5です。
後になって泣きを見ないよう、アプリを乗っけて動作試験を始めたところなのですが…

とにかく動作が遅い。とても常用には耐えない感じです。
レスポンスが30秒間返ってこないとか、ザラ。

一体何が起きている…？というわけでプロファイラーで調査してみました。
判明したことは、どうやらJasper内部のXMLパースで時間がかかっているということです。

このスクリーンキャプチャを見れば分かる通り、"org.apache.xerces"や"org.apache.jasper"パッケージだけで全体の処理時間の半分近くを占めています。(org.eclipse.jdtはJSP コンパイルの一部となっているecjです)
Tomaca7の時は、こんなことは起きていなかった。

Jasperの内部へ

Jasperのソースを追っかけて調査したのですが、怪しい箇所を1つ見つけました。

遅いメソッドのコールスタックを追っていくと、いずれも

org.apache.jasper.compiler.TagLibraryInfoImpl.<init>

にぶちあたる。

TagLibraryInfoとは、名前の通りタグライブラリのメタ情報を保持するクラスです。こんなもん常識的に考えて、最初に1回パースしたら終わりだろ？なんで時間を喰うのだ。

なんでキャッシュしないの？

org.apache.jasper.compiler.ParserクラスのparseTaglibDirectiveの中で、タグライブラリのメタ情報を作成(=TagLibraryInfoImplをnewしている)わけですが、どうもその情報をキャッシュしていないっぽい。だから毎回tldファイルのパースが走る。

以下のコードは抜粋ですが、

private void parseTaglibDirective(Node parent) throws JasperException {
    ...

    TagLibraryInfoImpl impl = null;

    if (ctxt.getOptions().isCaching()) { // ←ココ
        impl = (TagLibraryInfoImpl) ctxt.getOptions().getCache().get(uri);
    }

    if (impl == null) {
        TldLocation location = ctxt.getTldLocation(uri);
        impl = new TagLibraryInfoImpl(ctxt, parserController, pageInfo, prefix, uri, location, err, reader.mark());
        if (ctxt.getOptions().isCaching()) { // ←ココ
            ctxt.getOptions().getCache().put(uri, impl);
        }
    } else {
        ...
    }
    pageInfo.addTaglib(uri, impl);

    ...
}

のようになっており、org.apache.jasper.Options#isCachingの戻り値でキャッシュするかどうかの判定がなされています。

しかしながら、Optionsの実装であるorg.apache.jasper.EmbeddedServletOptionsでは、無常にも

@Override
public boolean isCaching() {
    return false;
}

とハードコーディングされており、キャッシュが働いていない状態です。

この仕様、どうやらTomcat7の時からこうなっているようなのですが、
それはさておき奇妙に見えるのでキャッシュをONにしてみました。

ONにする具体的な方法としては、web.xmlに

  <servlet>
    <servlet-name>jsp</servlet-name>
    <servlet-class>org.apache.jasper.servlet.JspServlet</servlet-class>

    <init-param>
      <param-name>engineOptionsClass</param-name>
      <param-value>my.JasperOptions</param-value>
    </init-param>

    <load-on-startup>3</load-on-startup>
  </servlet>

  <servlet-mapping>
    <servlet-name>jsp</servlet-name>
    <url-pattern>*.jsp</url-pattern>
  </servlet-mapping>

のように書き、my.JasperOptionImplクラスを用意して

package my;

import org.apache.jasper.Options;

public class JasperOptions
    implements Options {

    ...

    public boolean isCaching() { return true; }
}

とでもしておけばOK。

結果

以上の作業を行った結果、僕の環境では、Tomcat7同等のパフォーマンスが出るところまで回復した模様です。

ところでJMCはかなり(・∀・)ｲｲ!!

JDK7u40から標準添付になったJava Misson Control (JMC)ですが、上記のキャプチャを見て頂ければ分かる通り、結構使えます。

以前は個人的にVisualVMを使っていましたが、VisualVMのサンプリング機能では「何処が根本原因か」をわかりやすくメソッドレベルへ分解してくれるわけではなかったので、今回のようなニーズでは、確実にJMCが勝ると思います。

皆様に置かれましても、今後のJavaライフを快適に過ごすためにもぜひお試し頂けますと幸いです。
ただし商用環境で使うとライセンス違反ですのでご注意を。

というわけで、本日はここまで。