DB操作の“壁”を壊すJPAが起こした「赤壁の戦い」：現場から学ぶWebアプリ開発のトラブルハック（13）（1/2 ページ）

　O/Rマッピングツールは、上手に使えば開発効率を上げることができる、便利なツールです。しかし、データベース（以下、DB）アクセスを隠ぺいしてしまうため、下手に利用するとトラブルの温床になりかねません。本稿では、Java EE 5で採用された標準のDB永続化APIである「JPA（Java Persistence API）」による“悲劇”をお送りします。

「“トラブルハッカー”は神速を尊ぶ」

　プルルル、プルルル、午前2時の深夜、不吉な電話が鳴り響く。電話を取ると、「トラブルが発生した。すぐに来てくれ」とのこと。この時間では電車も走っていない。私はタクシーを呼び、急いで現場に駆け付けた。

　現場にたどり着くと、赤々と明かりのともった赤いビルが目の前に立ちはだかる。つい先日、映画館で観た『レッドクリフ』の炎に包まれる船団を思い出した。私は焼死しないことを祈りながら、ビルに入っていった。

不況下で「驥足を展ぶ」NetBeansプロファイラ

　話を聞くと、「1週間後のリリースを控え、いくつかの業務の処理のレスポンスが極めて遅く業務要件が満たせない」「どうして遅いのか皆目見当が付かない」とのこと。レスポンスが遅い業務は、業務処理のユニットテストでもレスポンスが遅いようだ。

　「少しは見当を付けておけよ」と心の中でつぶやきながら、表面上は「分かりました。任せてください!!」と爽やかに答え、プロファイラを使ってボトルネック解析を始めた。なお、今回プロファイリングで利用したのは、「NetBeansプロファイラ」だ。プロファイラを利用すると、プログラムの実行速度が遅くなりイライラするものだが、NetBeansプロファイラは動作も軽く結果も分かりやすい。昨今の不況の中、無償で利用できるというのがありがたい。

　さて、プロファイラを実行している間に今回のシステムの概要を簡単に紹介しよう。今回のシステムは工場のコスト管理システムで、最新テクノロジーであるJava EE 5の利用による開発コスト削減がシステムの特徴のようだ。プレゼンテーション層にStruts、永続化層に標準のJPA、DIコンテナにはSpringを利用している。

　開発者としては、StrutsとSpringの経験があるプログラマが少々、JPAの経験がある人はいないという状況でシステム開発を始めたらしい。

プロファイラ実行後の「三顧の“検証”」

　さて、事情聴取を行っている間にプロファイラの実行が終わったようだ。

■【壱】ホットスポットの確認

　まずは、ホットスポットを確認し、最も時間がかかっている処理を確認しよう（図1）。

図1　ホットスポット

　ホットスポットがorg.eclipse.persistenceパッケージ以下のDatabaseAccessorクラスのexecuteSelectメソッドであることが確認できた。このことから、JPAの実装には「EclipseLink」を利用しており、クラス名やメソッド名から想像すると、DBアクセスを行っているところがボトルネックになっていると推測できる。

　念のため、EclipseLinkのソースコードをダウンロードし、executeSelectメソッドの概要個所を確認する。

    public ResultSet executeSelect(DatabaseCall call, Statement statement, AbstractSession session) 
    throws SQLException {
 
        ResultSet resultSet;
 
        session.startOperationProfile(SessionProfiler.STATEMENT_EXECUTE,
            call.getQuery(), SessionProfiler.ALL);
 
        try {
            if (call.isDynamicCall(session)) {
                resultSet = statement.executeQuery(call.getSQLString());
            } else {
                resultSet = ((PreparedStatement)statement).executeQuery();
            }
        } finally {
 
.....

　Statement（PreparedStatement）を実行し、ResultSetを取得しているところから、やはりSQL文を実行している部分がボトルネックになっているようだ。

■【弐】呼び出しツリーの確認

　次に、呼び出しツリーを確認する（図2）。

図2　呼び出しツリー（その1）

　アプリケーション内のPattimeWorkerDaoクラスのcalcTotalCostメソッドで97.9％とほとんどの時間を費やしている。calcTotalCostメソッドからの呼び出し先は、「org.eclipse……IndirectSet.iterator()」となっているので、イテレータを取得するところで時間がかかっているようだ。さらに、呼び出しツリーの先を調べていきexecuteSelectがあることを確認した（図3）。

図3　呼び出しツリー（その2）

　executeSelectが数百回にわたって呼ばれていることから、DB周りの処理が原因で全体のレスポンスが低下していると考えられる。

　次ページでは、3回目の検証としていよいよボトルネックとなっている部分のソースコードを確認する。どの部分が原因となったのか、読者には分かるだろうか。