[pgpool-general-jp: 123] Re: pgpool3.2+JDBC環境でのreplication_strictの挙動について
tutui-t @ sys.tosho.co.jp
tutui-t @ sys.tosho.co.jp
2007年 5月 7日 (月) 15:04:03 JST
こんにちは、筒井です。
> 同じような再現プログラムを書いて動かしてみましたが、手元の環境では結果
> が返ってきてからセカンダリに送っていました。もしデバッグログが残ってい
> ましたらいただけないでしょうか?
>
> また、接続する際に以下のように loglevel を 2 にしていただけますでしょ
> うか?JDBC ドライバのデバッグログを取得することができます。
先ほど、テストした結果をお送りします(少し長くなります)。
パケットのやり取り順序は前と変わりありませんでした。
今回は以下のように実行しています。
connection.setAutoCommit(false);
stmt = connection.createStatement();
stmt.executeUpdate("LOCK test_data;");
stmt.executeUpdate("UPDATE 〜");
connection.commit();
pgpoolのデバッグログです。
---------------------------------------------------------------
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737: I
am 9737 accept fd 6
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
Protocol Major: 3 Minor: 0 database: test_db user: postgres
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length: lenghth: 8
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
trying clear text password authentication
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length2: master lenghth: 28
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
name: client_encoding value: UNICODE
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
secondary name: client_encoding value: UNICODE
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length2: master lenghth: 23
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
name: DateStyle value: ISO, YMD
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
secondary name: DateStyle value: ISO, YMD
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length2: master lenghth: 26
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
name: integer_datetimes value: off
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
secondary name: integer_datetimes value: off
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length2: master lenghth: 20
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
name: is_superuser value: on
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
secondary name: is_superuser value: on
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length2: master lenghth: 27
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
name: server_encoding value: EUC_JP
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
secondary name: server_encoding value: EUC_JP
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length2: master lenghth: 25
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
name: server_version value: 8.2.4
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
secondary name: server_version value: 8.2.4
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length2: master lenghth: 35
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
name: session_authorization value: postgres
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
secondary name: session_authorization value: postgres
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length2: master lenghth: 36
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
name: standard_conforming_strings value: off
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
secondary name: standard_conforming_strings value: off
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length2: master lenghth: 19
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
name: TimeZone value: Japan
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
secondary name: TimeZone value: Japan
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length: lenghth: 12
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_send_auth_ok: send pid 304 to frontend
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from backend pending data Z len: 5 po: 270
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_process_query: kind from backend: Z
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length: lenghth: 5
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
ReadyForQuery: message length: 5
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
ReadyForQuery: transaction state: I
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend P(50)
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend B(42)
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
bind message: portal_name stmt_name S_1
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend E(45)
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
Execute: portal name <>
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
waiting for backend completing the query
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
waiting for backend completing the query
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend P(50)
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend B(42)
May 7 14:25:25 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
bind message: portal_name stmt_name
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend D(44)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend E(45)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
Execute: portal name <>
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
waiting for backend completing the query
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
waiting for backend completing the query
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend S(53)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from secondary backend Z
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_process_query: kind from backend: Z
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length: lenghth: 5
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
ReadyForQuery: message length: 5
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
ReadyForQuery: transaction state: T
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend P(50)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend B(42)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
bind message: portal_name stmt_name
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend D(44)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend E(45)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
Execute: portal name <>
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
waiting for backend completing the query
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
waiting for backend completing the query
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend S(53)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from secondary backend Z
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_process_query: kind from backend: Z
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length: lenghth: 5
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
ReadyForQuery: message length: 5
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
ReadyForQuery: transaction state: T
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend P(50)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend B(42)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
bind message: portal_name stmt_name S_2
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend E(45)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
Execute: portal name <>
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
waiting for backend completing the query
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
waiting for backend completing the query
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from frontend S(53)
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
read kind from backend Z
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_process_query: waiting for secondary for data ready
May 7 14:25:26 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_process_query: kind from backend: Z
May 7 14:25:27 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
pool_read_message_length: lenghth: 5
May 7 14:25:27 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
ReadyForQuery: message length: 5
May 7 14:25:27 test_host pgpool: 2007-05-07 14:25:25 DEBUG: pid 9737:
ReadyForQuery: transaction state: I
JDBCのデバッグログです。
---------------------------------------------------------------
14:25:25.032 (2) PostgreSQL 8.2 JDBC3 with SSL (build 505)
14:25:25.033 (2) Trying to establish a protocol version 3 connection to
192.168.0.25:5432
14:25:25.046 (2) FE=> StartupPacket(user=postgres, database=test_db,
client_encoding=UNICODE, DateStyle=ISO)
14:25:25.055 (2) <=BE AuthenticationReqPassword
14:25:25.055 (2) FE=> Password(password=<not shown>)
14:25:25.063 (2) <=BE AuthenticationOk
14:25:25.071 (2) <=BE ParameterStatus(client_encoding = UNICODE)
14:25:25.072 (2) <=BE ParameterStatus(DateStyle = ISO, YMD)
14:25:25.073 (2) <=BE ParameterStatus(integer_datetimes = off)
14:25:25.073 (2) <=BE ParameterStatus(is_superuser = on)
14:25:25.074 (2) <=BE ParameterStatus(server_encoding = EUC_JP)
14:25:25.074 (2) <=BE ParameterStatus(server_version = 8.2.4)
14:25:25.074 (2) <=BE ParameterStatus(session_authorization = postgres)
14:25:25.075 (2) <=BE ParameterStatus(standard_conforming_strings = off)
14:25:25.075 (2) <=BE ParameterStatus(TimeZone = Japan)
14:25:25.075 (2) <=BE BackendKeyData(pid=304,ckey=200397122)
14:25:25.075 (2) <=BE ReadyForQuery(I)
14:25:25.076 (2) compatible = 8.2
14:25:25.076 (2) loglevel = 2
14:25:25.076 (2) prepare threshold = 5
14:25:25.078 (2) simple execute,
handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler @ 2f0d54,
maxRows=0, fetchSize=0, flags=5
14:25:25.079 (2) FE=> Parse(stmt=S_1,query="BEGIN",oids={})
14:25:25.079 (2) FE=> Bind(stmt=S_1,portal=null)
14:25:25.079 (2) FE=> Execute(portal=null,limit=0)
14:25:25.080 (2) FE=> Parse(stmt=null,query="LOCK test_data",oids={})
14:25:25.080 (2) FE=> Bind(stmt=null,portal=null)
14:25:25.080 (2) FE=> Describe(portal=null)
14:25:25.080 (2) FE=> Execute(portal=null,limit=1)
14:25:25.081 (2) FE=> Sync
14:25:25.083 (2) <=BE ParseComplete [S_1]
14:25:25.083 (2) <=BE BindComplete [null]
14:25:25.085 (2) <=BE CommandStatus(BEGIN)
14:25:25.085 (2) <=BE ParseComplete [null]
14:25:25.086 (2) <=BE BindComplete [null]
14:25:25.087 (2) <=BE NoData
14:25:25.089 (2) <=BE CommandStatus(LOCK TABLE)
14:25:25.090 (2) <=BE ReadyForQuery(T)
14:25:25.090 (2) simple execute,
handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler @ a9255c,
maxRows=0, fetchSize=0, flags=5
14:25:25.091 (2) FE=> Parse(stmt=null,query="UPDATE test_data SET
last_logout='2007-05-07 14:25:00' WHERE user_id = '12'",oids={})
14:25:25.091 (2) FE=> Bind(stmt=null,portal=null)
14:25:25.091 (2) FE=> Describe(portal=null)
14:25:25.091 (2) FE=> Execute(portal=null,limit=1)
14:25:25.092 (2) FE=> Sync
14:25:25.095 (2) <=BE ParseComplete [null]
14:25:25.096 (2) <=BE BindComplete [null]
14:25:25.096 (2) <=BE NoData
14:25:25.099 (2) <=BE CommandStatus(UPDATE 1)
14:25:25.146 (2) <=BE ReadyForQuery(T)
14:25:25.147 (2) simple execute,
handler=org.postgresql.jdbc2.AbstractJdbc2Connection$TransactionCommandHandler @ d3c6a3,
maxRows=0, fetchSize=0, flags=22
14:25:25.147 (2) FE=> Parse(stmt=S_2,query="COMMIT",oids={})
14:25:25.147 (2) FE=> Bind(stmt=S_2,portal=null)
14:25:25.148 (2) FE=> Execute(portal=null,limit=1)
14:25:25.148 (2) FE=> Sync
14:25:25.149 (2) <=BE ParseComplete [S_2]
14:25:25.150 (2) <=BE BindComplete [null]
14:25:25.198 (2) <=BE CommandStatus(COMMIT)
14:25:25.199 (2) <=BE ReadyForQuery(I)
以上ですが、これでよろしいでしょうか?
よろしくお願いいたします。
pgpool-general-jp メーリングリストの案内