[pgsql-jp: 41475] Re: AutoCommitをfalseにするとレスポンスが遅くなる

[pascalpascal ＠ snow.plala.or.jp]

笠原さん、MauMauさん

宮本です。

情報ありがとうございます。

> そのため、9.2にアップグレードすることが解決方法の１つだと考えます。

何となくですが、これのような気がしますね。
少し時間がかかりますが、テストしてみます。

> サーバ側にバインド変数を含むSQL文が送られているかどうか、つまり、
> SQL文中に$1などが含まれるかどうかを見ます。

ログを確認しましたが、
バインド変数は早い方も遅い方もSQL文の中に出力されていました。
（SQL文が長いので、ここでは省略していますが、実際のログには
出力されていました。）
気になるのは、遅い方（AutoCommit=false）は、"execute S_2/C_3"
のように、prepare文に名前がついていることです。

早い方(AutoCommit=true)は、execute <unnamed>　になっています。

■遅い方

2013-07-24 16:18:22 JST 11503 LOG:  execute S_1: BEGIN
2013-07-24 16:18:22 JST 11503 LOG:  execute S_2/C_3: SELECT COUNT(*) FROM ( SELECT　・・・
2013-07-24 16:18:22 JST 11503 DETAIL:  parameters: $1 = '00060000', $2 = '00060000', $3 = '', $4 = '', $5 = '', $6 = '', $7 = '', $8 = '', $9 = '', $10 = '', $11 = '', $12 = '', $13 = '3', $14 = '3'

■早い方

2013-07-24 16:25:09 JST 14734 LOG:  execute <unnamed>: SELECT COUNT(*) FROM ( SELECT ・・・
2013-07-24 16:25:09 JST 14734 DETAIL:  parameters: $1 = '00060000', $2 = '00060000', $3 = '', $4 = '', $5 = '', $6 = '', $7 = '', $8 = '', $9 = '', $10 = '', $11 = '', $12 = '', $13 = '3', $14 = '3'
	
	
プログラムソースは以下の通りです。setPrepareThresholdはテストで入れたものです。

----------------------------------------------------------------------import java.io.File;
import java.sql.*;
import java.util.Properties;
import java.util.List;
import org.postgresql.PGStatement.*;


public class Test2online3ac {

	public static void main(String[] args) {
		try {
			Class.forName("org.postgresql.Driver");
			Connection conn = DriverManager.getConnection("jdbc:postgresql://localhost:xxxxx/xxxxx", "xxxxx", "xxxxx");

			conn.setAutoCommit(false);

			String sql = "SELECT COUNT(*) FROM ( SELECT ・・・省略

			PreparedStatement st = conn.prepareStatement(sql);
			st.setFetchSize(1000);
			st.setObject(1, "00060000");
			st.setObject(2, "00060000");
			st.setObject(3, "");
			st.setObject(4, "");
			st.setObject(5, "");
			st.setObject(6, "");
			st.setObject(7, "");
			st.setObject(8, "");
			st.setObject(9, "");
			st.setObject(10, "");
			st.setObject(11, "");
			st.setObject(12, "");
			st.setObject(13, "3");
			st.setObject(14, "3");

			System.out.println("AutoCommit is "+conn.getAutoCommit());

			org.postgresql.PGStatement pgstmt = (org.postgresql.PGStatement)st;
			pgstmt.setPrepareThreshold(0);

			long stime = System.currentTimeMillis();
			st.executeQuery();
			conn.commit();
			long etime = System.currentTimeMillis();
			System.out.println("経過時間：" + (etime - stime));

			st.close();

			conn.close();

		} catch (Throwable t) {
			t.printStackTrace();
		}
	}

}


以上

---- MauMau <maumau307 ＠ gmail.com> さんは書きました: 
> MauMauです。
> 
> > 遅い方の実行計画はプラン中に$1や$2などが見えますので、値がバインドされる前の 
> > 
> > 汎用的な実行計画に見えます。
> > 早い方の実行計画は、実際にバインドされた値でもって作成された実行計画に見えます。
> 
> PostgreSQL 9.1までは、問い合わせ計画の作成時にはバインド変数の値は使われません。 
> 
> 汎用的な問い合わせ計画が作成されます。
> 今回の場合、それがnested loopだったのでしょう。
> 
> PostgreSQL 9.2からは、次のように、バインド変数の値が使われるようになりました。 
> 
> そのため、9.2にアップグレードすることが解決方法の１つだと考えます。
> 可能であれば、おためしいただいた結果を共有いただけると幸いです。
> 
> http://www.postgresql.org/docs/current/static/release-9-2.html
> Allow the planner to generate custom plans for specific parameter values 
> even when using prepared statements (Tom Lane)
> In the past, a prepared statement always had a single "generic" plan that 
> was used for all parameter values, which was frequently much inferior to the 
> plans used for non-prepared statements containing explicit constant values. 
> Now, the planner attempts to generate custom plans for specific parameter 
> values. A generic plan will only be used after custom plans have repeatedly 
> proven to provide no benefit. This change should eliminate the performance 
> penalties formerly seen from use of prepared statements (including 
> non-dynamic statements in PL/pgSQL).
> 
> 
> > なので、SQLの早い遅いは、実際のBIND値を考慮された実行計画かどうかの違いで、 
> > 
> > あとはそれがどこから来ているのか？ということか思います。
> 
> たしかに、速かったときは、バインド変数が使われなかったものと思います。
> バインド変数が使われなかった理由はわかりません。
> アプリなのか、JDBCドライバなのか、それともサーバ側なのか。
> もしこれを追求する場合は、次の情報を共有してください。
> 
> ・サーバ側が原因かどうか
> サーバ側にバインド変数を含むSQL文が送られているかどうか、つまり、
> SQL文中に$1などが含まれるかどうかを見ます。
> auto_explainの出力か、log_min_duraton_statement=0で出力される
> サーバログ中のSQL文でよいと思います。
> 
> ・アプリかJDBCドライバか
> テストアプリのソースを見せてください。
> 
> 
> 以上です。
>