何故だ〜！！！
こんにちは、JDBC関連のプログラムばかり作っては捨て、作っては捨ての作業を繰り返しトライ＆エラーのスペシャリストになりつつある高橋です。トライ＆エラーのスペシャリストって、たんなるダメダメプログラマーなんですけどね...(＾＾；)
以前「夢を見たい年頃です。。。」のエントリーにも書いた通り、その実力も資格も無い私ですが、少しだけ世界のシッポがみえてきましたよ。
EzJDBCの開発の中で生まれた「トランザクション管理機能」の「EzTx」のレスポンスが、いつの間にか世界レベルに達していました。
何をもって世界レベルに達しているといっているのか！
実際に世界中のトランザクション機構のベンチマークと比較したのか！そんなの無理ではないか、愚か者め！！！とお思いの方もいると思います。
実際問題として世界中の(Javaの)トランザクション機構のベンチマークを取得することは出来ませんが、オープンソースであれば可能でしょう。
とはいっても、今回はもっと良い方法をみつけましたので、そちらと比較しました。
最適化したJDBCプログラムと比較するのが一番手っ取り早いのです。
世界に幾つトランザクション機構が存在したとしても、Javaである限り、最適化したJDBCプログラムより高速のトランザクション機構は存在しえません。
だって、Javaで開発しているわけだから。。。（注：RDBMS自体にネイティブなJDBCを開発した場合は可能でしょうけど...ベンダー以外ありえない）
そんなわけで、
今回は10,000回のSELECTを発行した時のパフォーマンスを、「最適化したJDBCプログラミング」と「EzTxを利用したプログラム」で比較しました。
処理結果は、それぞれ10回行なった平均です。
1.最適化したJDBCプログラミング
// ドライバーをロードします
Class.forName("com.ibm.db2.jcc.DB2Driver");
// コネクション取得
Connection connection = DriverManager.getConnection("TG3DB","","");
// 処理時間を計測するインスタンス生成(ミリ秒).結果をシステムアウト(true)
EzStopWatch w = new EzStopWatch(2).systemout(true);
// 処理時間計測開始
w.start();
// プリペアステートメントを取得します。プリペアを使い回すためloopの外で取得します。
PreparedStatement ps
= connection.prepareStatement("SELECT * FROM CUSTOMER WHERE ID = ?");
// 10000回処理を繰り返します＝1万回SQLを発行します。
for(int i=0; i<10000; i++) {
ps.setInt(1,i);
Resultset rs = ps.executeQuery();
rs.next();
rs.close();
}
// 処理時間計測終了
w.stop();
// プリペアステートメント・クローズ
ps.close();
// コネクション・クローズ
connection.close();
注意：クラスロードやキャッシュを考慮して、事前に1回処理してから計測しています。
最適化したJDBCプログラムでは、コネクション取得およびクローズは計測時間にいれていません。
また、同一SQLの場合はPreparedStatementを使いまわしたほうが良いため、PreparedStatementの生成はループの外で1回だけ行なっています。
【実行時間】
2,786 ミリ秒
2.EzTxを利用したJDBCプログラミング
// 処理時間を計測するインスタンス生成(ミリ秒).結果をシステムアウト(true)
EzStopWatch w = new EzStopWatch(2).systemout(true);
// 処理時間計測開始
w.start();
// トランザクション開始
EzTx.begin();
// 10000回処理を繰り返します＝1万回SQLを発行します。
for(int i=0; i<10000; i++) {
// コネクション取得
Connection connection = EzTx.getConnection();
PreparedStatement ps
= connection.prepareStatement("SELECT * FROM CUSTOMER WHERE ID = ?");
ps.setInt(1,i);
Resultset rs = ps.executeQuery();
rs.next();
rs.close();
ps.close();
connection.close();
}
// トランザクション終了
EzTx.end();
// 処理時間計測終了
w.stop();注意：クラスロードやキャッシュを考慮して、事前に1回処理してから計測しています。
EzTxを利用したプログラムでは、トランザクションの開始(EzTx.begin)から計測時間に含めています。
また、コネクションの取得(EzTx.getConnection)とPreparedStatementの生成は、あえてループ内で行なっています。明らかに、最適化したJDBCプログラムよりも、不利な状況で計測を行なっていることに注目してください。この理由は、同一トランザクション内で複数のテーブルを参照する場合、クラスをまたがって同じコネクションを利用する必要があります。
その様な時に、EzTx.getConnectionメソッドは、どのクラス(インスタンス)から呼び出しても同一のコネクションを返してくれます。その様な状況を加味して、あえて不利なコードを書いています。
実行時間は、「ログ未出力バージョン」と「ログ出力バージョン(非同期)」の2種類だしています。
【ログ未出力の実行時間】
2,095 ミリ秒
な、何故だ？？？EzTxのほうが最適化したJDBCより早い...(￣口￣|||)
【ログ出力の実行時間】
2,247 ミリ秒
【トランザクションログ】
DEBUG 2010-08-05 12:38:08:296 [main] トランザクションを開始しました
DEBUG 2010-08-05 12:38:08:296 [main] コネクションを取得しました(JDBC接続)
DEBUG 2010-08-05 12:38:08:296 [main] SELECT * FROM CUSTOMER WHERE ID = 0
DEBUG 2010-08-05 12:38:08:296 [main] SQLの実行が完了しました
9998回分のログ...
DEBUG 2010-08-05 12:38:10:546 [main] コネクションを取得しました(JDBC接続)
DEBUG 2010-08-05 12:38:10:546 [main] SELECT * FROM CUSTOMER WHERE ID = 9999
DEBUG 2010-08-05 12:38:10:546 [main] SQLの実行が完了しました
DEBUG 2010-08-05 12:38:10:546 [main] コミットしました
DEBUG 2010-08-05 12:38:10:546 [main] コネクションを返却しました。
DEBUG 2010-08-05 12:38:10:546 [main] トランザクションを終了しました
非同期ログを出力しても、最適化したJDBCより早い...(。。し)
な、何故だ〜！！！！(￣口￣|||)
