[pgsql-jp: 38639] pgpool でマスタ側が落ちる

[森山 和宏]

森山と申します

既存アプリをpgpool経由に切り替え動作確認中ですが、なぜか
頻繁にDBレプリケーションが停止ししてしまい原因を探ってます。

pgpoolを3.3から3.4へバージョンアップし試し始めたところ、
いままでレプリケーション停止時セカンダリがダウンしていましたが、
3.4に入れ替えてからマスタが切り離される様になりました。

DBを切り離す条件が変わったのでしょうか。
また、DBが切り離される要因がログを見ても良くわからないため、
なにか調査する上で推奨される方法がありましたらご教授願います。

試験環境
 DB1 postgres8.0.8 PORT:5531（セカンダリ）
 DB2 postgres8.0.8 PORT:5532（マスタ）
 pgpool 3.4 PORT:5530
 全て同一サーバ上で稼動させています

pgpool設定
 replication_mode = true
 replication_strict = true
 replication_timeout = 5000
 weight_master = 1
 weight_secondary = 0
 replication_stop_on_mismatch = true
 replicate_select = false
 connection_cache = true
 insert_lock = true

レプリケーションダウン時のpgpoolログ
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from backend T
2007-08-10 00:00:24 DEBUG: pid 30698: pool_process_query: kind from backend:
T
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from backend pending data C
len: 17 po: 537
2007-08-10 00:00:24 DEBUG: pid 30698: pool_process_query: kind from backend:
C
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from backend pending data Z
len: 5 po: 549
2007-08-10 00:00:24 DEBUG: pid 30698: pool_process_query: kind from backend:
Z
2007-08-10 00:00:24 DEBUG: pid 30698: pool_read_message_length: lenghth: 5
2007-08-10 00:00:24 DEBUG: pid 30698: ReadyForQuery: message length: 5
2007-08-10 00:00:24 DEBUG: pid 30698: ReadyForQuery: transaction state: I
2007-08-10 00:00:24 DEBUG: pid 30698: end_load_balance: end load balance
mode
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from frontend X(58)
2007-08-10 00:00:24 LOG:   pid 30698: statement:  RESET ALL
2007-08-10 00:00:24 DEBUG: pid 30698: waiting for master completing the
query
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from backend pending data S
len: 44 po: 1
2007-08-10 00:00:24 DEBUG: pid 30698: pool_process_query: kind from backend:
S
2007-08-10 00:00:24 DEBUG: pid 30698: pool_read_message_length2: master
lenghth: 27
2007-08-10 00:00:24 DEBUG: pid 30698: name: client_encoding value: EUC_JP
2007-08-10 00:00:24 DEBUG: pid 30698: secondary name: client_encoding value:
EUC_JP
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from backend pending data C
len: 16 po: 29
2007-08-10 00:00:24 DEBUG: pid 30698: pool_process_query: kind from backend:
C
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from backend pending data Z
len: 5 po: 40
2007-08-10 00:00:24 DEBUG: pid 30698: pool_process_query: kind from backend:
Z
2007-08-10 00:00:24 DEBUG: pid 30698: pool_read_message_length: lenghth: 5
2007-08-10 00:00:24 DEBUG: pid 30698: ReadyForQuery: message length: 5
2007-08-10 00:00:24 DEBUG: pid 30698: ReadyForQuery: transaction state: I
2007-08-10 00:00:24 LOG:   pid 30698: statement:  SET SESSION AUTHORIZATION
DEFAULT
2007-08-10 00:00:24 DEBUG: pid 30698: waiting for master completing the
query
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from backend pending data S
len: 70 po: 1
2007-08-10 00:00:24 DEBUG: pid 30698: pool_process_query: kind from backend:
S
2007-08-10 00:00:24 DEBUG: pid 30698: pool_read_message_length2: master
lenghth: 21
2007-08-10 00:00:24 DEBUG: pid 30698: name: is_superuser value: off
2007-08-10 00:00:24 DEBUG: pid 30698: secondary name: is_superuser value:
off
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from backend pending data S
len: 48 po: 23
2007-08-10 00:00:24 DEBUG: pid 30698: pool_process_query: kind from backend:
S
2007-08-10 00:00:24 DEBUG: pid 30698: pool_read_message_length2: master
lenghth: 33
2007-08-10 00:00:24 DEBUG: pid 30698: name: session_authorization value:
nobody
2007-08-10 00:00:24 DEBUG: pid 30698: secondary name: session_authorization
value: nobody
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from backend pending data C
len: 14 po: 57
2007-08-10 00:00:24 DEBUG: pid 30698: pool_process_query: kind from backend:
C
2007-08-10 00:00:24 DEBUG: pid 30698: read kind from backend pending data Z
len: 5 po: 66
2007-08-10 00:00:24 DEBUG: pid 30698: pool_process_query: kind from backend:
Z
2007-08-10 00:00:24 DEBUG: pid 30698: pool_read_message_length: lenghth: 5
2007-08-10 00:00:24 DEBUG: pid 30698: ReadyForQuery: message length: 5
2007-08-10 00:00:24 DEBUG: pid 30698: ReadyForQuery: transaction state: I
2007-08-10 00:00:24 DEBUG: pid 30698: pool_connection_pool_timer: set close
time 1186671624
2007-08-10 00:00:28 ERROR: pid 30685: pool_process_query: kind does not
match between backends master(E) secondary(C)
2007-08-10 00:00:28 DEBUG: pid 30685: connecting postmaster Unix domain
socket: /tmp/.s.PGSQL.5532
2007-08-10 00:00:28 DEBUG: pid 30685: connected to postmaster Unix domain
socket: /tmp/.s.PGSQL.5532 fd: 21
2007-08-10 00:00:28 DEBUG: pid 30685: connecting postmaster Unix domain
socket: /tmp/.s.PGSQL.5531
2007-08-10 00:00:28 DEBUG: pid 30685: connected to postmaster Unix domain
socket: /tmp/.s.PGSQL.5531 fd: 21
2007-08-10 00:00:28 LOG:   pid 30685: notice_backend_error: master: 0 fail
over request from pid 30685
2007-08-10 00:00:28 DEBUG: pid 24705: failover_handler called
2007-08-10 00:00:28 LOG:   pid 24705: starting degeneration. shutdown master
host (5532)
2007-08-10 00:00:28 DEBUG: pid 24705: kill 24896
2007-08-10 00:00:28 DEBUG: pid 24705: kill 30273
2007-08-10 00:00:28 DEBUG: pid 24705: kill 30685
2007-08-10 00:00:28 DEBUG: pid 24705: kill 25226
2007-08-10 00:00:28 DEBUG: pid 24705: kill 24897
2007-08-10 00:00:28 DEBUG: pid 24705: kill 24898
2007-08-10 00:00:28 DEBUG: pid 24705: kill 24918
2007-08-10 00:00:28 DEBUG: pid 24705: kill 30696
2007-08-10 00:00:28 DEBUG: pid 24705: kill 30699
2007-08-10 00:00:28 DEBUG: pid 24705: kill 26803