下記アプリケーション側のソースコードを確認してみよう。
/** * 組織における集計開始日から集計終了日の間の * パートタイム労働者の労務費を計算 * @param org 組織 * @param begin 集計開始日 * @param end 集計終了日 * @return 労務費 */ public double calcTotalCost(String org, Date begin, Date end) { // クエリ作成 Query q = em.createQuery( "SELECT p FROM ParttimeWorker p WHERE p.org=:org"); //……【1】 q.setParameter("org", org); // 労務費の合計 double cost = 0; // パートタイム労働者リスト取得 List workerList = q.getResultList(); //……【2】 for (ParttimeWorker pw: workerList) { //……【3】 // 労働者の時間単価(円)を取得 int rank_cost = pw.getRank().getCost(); // 勤務日のリストを取得 Set worktimeSet = pw.getDailyWorktimeCollection(); //……【4】 for (DailyWorktime dw : worktimeSet) { //……【5】 // 勤務日の日付を取得 Date d = dw.getPk().getWorkday(); // 開始日(begin)と終了日(end)の間の場合、 // その日の賃金を計算を追加 if (d.after(begin) && d.before(end)) { double dt = dw.getWorkEnd() - dw.getWorkBegin() - 1.0; cost += (dt * rank_cost); } } } return cost; }
リスト2を確認すると、どうやらある組織(org)における集計開始日(begin)と集計終了日(end)の間の契約社員の賃金の合計(cost)を計算しているらしい。一見すると、【1】で組織における労働者のリストを取得し、労働者ごとの勤務日の一覧から、計算対象となる日のコストを計算して、足し込んでいるようだ。
労働者のリストを取得する部分以外は、どう考えても普通のJavaプログラムだ。1回しかSQLを実行していないはずなのに、大量にSQLが実行されている。まるで、「偽兵の計」に掛かっているかのようだ……。
「普通のJavaプログラムに見える」、ここに思わぬ伏兵が潜んでいる。コールツリーのグラフを再度確認すると、IndirectSet.iterator()とSetのイテレータを取得している部分で処理時間のほとんどを費やしていた。しかし、コード中にはイテレータを取得している部分などない。コード中で唯一Setを扱っている下記の部分が怪しい。
Set worktimeSet = pw.getDailyWorktimeCollection(); //……【4】 for (DailyWorktime dw : worktimeSet) { //……【5】
デバッガを利用して、【4】【5】の動作を確認してみる。ついでに、EclipseLink内部でSQL文を実行するときにログメッセージにSQL文を表示するように設定しておく。
デバッガで解析した結果(図4)、for文の中でIndirectSet.iterator()を呼び出していることが判明した。また、iterator()を呼び出したタイミングで、SQLが実行されている。デバッガで確認することにより、プロファイラで発見したボトルネックとなる部分を発見できた。しかし、なぜfor文の中でイテレータが呼ばれているのだろうか?
【5】のfor文はJava 5から実装された「拡張for文」で、実は下記のコードと等価だ。
Iterator i = worktimeSet.iterator(); while(i.hasNext()){ DailyWorktime dw = (DailyWorktime)i.next(); ……
また、ただのイテレータの取得ではなく、図4のログから分かるとおり、このイテレータを取得する際にSQLが実行されている。
SELECT WORK_BEGIN, WORK_END, WORKDAY, ID FROM DAILY_WORKTIME WHERE (ID = ?)
DIALY_WORKTIMEテーブルには労働者の毎日の稼働記録が入っているので、このSQLにより、その労働者のすべての稼働記録が取得される。業務ロジック中では、すべての稼働記録から集計開始日と終了日の間の稼働記録に対して賃金を計算している。
明らかに、DBからデータを取得する時点で、集計開始日と終了日の間のデータだけ取得すればいいだろう。また、労働者ごとに稼働記録をSQL文により抽出しているが、表の結合を使えばSQL一回で済むはずだ。
一生懸命Javaで実装して計算している部分は、1つのSQL文で実行できる。JPAには、「Native Query」という仕組みがあり、生のSQL文を実行できる。この仕組みを利用し、次のようにコードを書き換えた。
public double calcTotalCostByNativeQuery( String org, Date begin, Date end) { Query nq = em.createNativeQuery( "SELECT SUM((d.work_end - d.work_begin - 1) * r.cost) " +"FROM parttime_worker AS w " +"JOIN rank_cost r ON w.rank = r.rank " +"JOIN daily_worktime d ON w.id = d.id " +"WHERE w.org = ? and d.workday > ? AND d.workday < ?"); nq.setParameter(1,org); nq.setParameter(2,begin); nq.setParameter(3,end); return (Double)nq.getSingleResult(); }
コードは極めて簡潔となり、しかも1つのSQL文で高速に結果を取得できるようになり、レスポンスタイムは100倍以上高速になった。
その後、処理速度が遅い業務を次々とプロファイリングした結果、業務の8割がテーブルを意識せずにJPAのエンティティを利用したために生じた過度なSQLの実行であった。同様にNative Queryを利用したチューニングを行い続け、「赤壁の戦い」は終わった。
確かに、O/RマッピングツールはDBに詳しくないプログラマがDBを操作する“壁”を乗り越えやすくした。表の結合やSQL関数などを覚えなくても、Javaのオブジェクトだけで表にアクセスできる。しかし結局のところ、DBの知識がないプログラマはエンティティ(永続化オブジェクト)を通常のJavaのオブジェクトと同じように扱ってしまい、今回のようなトラブルが起こってしまった。
O/Rマッピングツールなどのフレームワークを利用すると、開発が楽になる局面もあるが、内部の動作や特性を把握せずに利用すると、思わぬ落とし穴に落ちることがある。そのような場合でも、JavaやDBの基本的な動作を把握していればすぐに問題解決につながることも多い。
フレームワークによりコーディングが楽になるのは確かだが、一流のエンジニアを目指すなら、それを支える基礎技術や動作の仕組みはぜひともおさえておきたいものだ。
Copyright © ITmedia, Inc. All Rights Reserved.