kagamihogeの日記

kagamihogeの日記です。

JDBCのsetFetchSize変更時の動きをstatspackで見てみる

昔書いたJDBC経由で100万件取得・追加してみた - kagamihogeのblogでは、JDBCjava.sql.Statement#setFetchSize(int rows)を変更するとSELECT文の実行速度が改善できる可能性があることを調べた。ここでは、なぜ速度が改善されるかを考える。やることとしては、変更前と後とで、それぞれstatspackのレポートを取得し、それらにどのような差が出るかを見てみる。

準備

下記のような、ごく単純なテーブルを作成し、そこへ100万行追加する。また、fetchSize変更前と後とのそれぞれのプログラムを実行するとき、バッファキャッシュをクリアしておく。

DROP TABLE MILLION_ROWS_TABLE PURGE;
CREATE TABLE MILLION_ROWS_TABLE 
(
  COLUMN1 VARCHAR2(20) 
);

INSERT INTO MILLION_ROWS_TABLE(COLUMN1)
  SELECT dbms_random.string('X', 20)
    FROM 
      (SELECT ROWNUM FROM ALL_CATALOG WHERE ROWNUM <= 1000),
      (SELECT ROWNUM FROM all_catalog WHERE ROWNUM <= 1000);
COMMIT;

ALTER SYSTEM FLUSH BUFFER_CACHE;

計測対象のプログラム

計測は、sql.setFetchSize();のところを10もしくは100に変更したあと実行する。

package oraclestudy.fetchsize;

import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.PreparedStatement;
import java.sql.ResultSet;

public class SelectWithChangeFetchSize {

    public static void main(String[] args) throws Exception {
        long start = System.currentTimeMillis();

        final String sqlStr = "SELECT column1 FROM million_rows_table";
        try (Connection connection = DriverManager.getConnection(
            "jdbc:oracle:thin:@192.168.0.20:1521:XE", "kagamihoge", "xxxx");
            PreparedStatement sql = connection.prepareStatement(sqlStr);) {
            sql.setFetchSize(100);
            
            try (ResultSet r = sql.executeQuery();) {
                int i=0;
                while (r.next()) {
                    String s1 = r.getString("column1");
                    i++;
                }
                System.out.println(i);
            }
        }

        long end = System.currentTimeMillis();
        System.out.println(end - start);
    }
}

実行時間

fetchSize/時間 1 2 3
10 29984 29203 29516
100 4828 5172 4797

前書いたJDBC経由で100万件取得・追加してみた - kagamihogeのblogと比べると実行時間がかなり遅くなっているが、以前はOraclelocalhostにあったのが、現在はネットワーク越しの別マシンに移動しているため。

感想とか

下記の表は、statspackレポートから比較的差が見られるものを中心にピックアップした。

Statistic 10 100
db file sequential read 457 270
SQL*Net message from client 100,025 10,025
SQL*Net message to client 100,023 10,023
SQL*Net roundtrips to/from client 100,017 10,017
consistent gets 109,970 14,175
consistent gets from cache 6,715 597
db block gets 1,878 1,641
execute count 2,277 114
file io wait time 1,124,680 367,071
user calls 100,028 10,030
Latch 10 100
cache buffers chains 16,494 7,553
shared pool 11,315 252

まず目に付くのはSQL*Net roundtrips to/from clientなどの項目が約10倍の差がついている。これは、setFetchSizeが10と100で10倍差の現れと見られる。roundtripsやfrom/to clientに差が見られるのは予想通りだが、user callsも約10倍差となる。したがって、execute count等も差が出る。プログラムのコードだけを見ていると、SELECT文をただ1度実行するように見える。しかし、実際にはJDBCクライアントがfetchSizeの間隔ごとに何らかの通信をOracleと行い、Oracleはそれを受けて何らかの処理を実行している、ことが伺える。

したがって、ブロックアクセスの回数も約10差がつくことになり、consistent getsにそれが現れている。db block getsはほとんど変わらないので、実ディスクからの読み出しに関しては実行時間に余り影響を与えていないことが分かる。先に書いたように、通信回数ないしOracleへのユーザー・コールの数が10倍になれば、ブロックアクセスの回数も10倍必要になる。ここも実行時間の差に影響していると思われるが、より正確を期すにはラウンドトリップの影響を排した状態でテストしなければならないので、証拠としてはやや薄い。

もう一つ興味深いのはLatchの項目のcache buffers chainsについて。共有プール領域に関する検証 その3 | Insight Technology, Inc.を読むまで知らなかったのだが、Oracleでは下記のようなラッチが存在する。

“CACHE BUFFER CHAIN” ラッチは、SQL文が取得しようとするデータがデータベースバッファ上に存在しているかどうかを、サーチする際に取得される一種の”ロック”であり、このラッチ(ロック)の回数が上昇するほど、データベースバッファから大量のデータが取得されていることが予想される。
共有プール領域に関する検証 その3 | Insight Technology, Inc. より抜粋

fetchSizeを大きくするとcache buffers chainsが減っているのが分かる。ユーザーコールの数が減れば、キャッシュを見に行く回数も減ることになる。consistent getsが良い例。なので、そのときに必要なラッチであるcache buffers chainsが減るのは当然と言える。

shared poolに関してもほぼ同様のことが言える。とはいえ、一般的にはラッチが実行時間に影響を与えてくるのは複数セッションでのことである。このエントリのプログラムは単一セッションでのことなので、数値に差が出ても、実際には大した影響は与えていないと考えられる。