[pgcluster: 502] リカバリー中に更新系クエリを発行すると整合性が取れない
kazunari takahashi
kazunari.takahashi ＠ ctc-g.co.jp
2004年 8月 13日 (金) 17:48:02 JST
お世話になっております．
高橋です．
av14にてリカバリー時に更新系クエリをロードバランサ経由で発行し、
リカバリー終了時にデータを確認したところ、データの整合性が取れておりませんでした．
ロードバランサは、serverB(セカンダリークラスタDB)のみにつなぐように設定されてます．
取り急ぎ、報告させていただきます．
####################################
#環境
####################################
pgcluster-1.0.7av14
pglb × 1 (solaris8 sparc)
clusterDB ×3 (solaris8 sparc) host名:serverA , serverB , serverC
rgrp × 2 (solaris8 sparc)
####################################
#手順
####################################
-------------------------
1.テーブル作成
-------------------------
test=> create TABLE test(id serial , name varchar(10));
NOTICE: CREATE TABLE will create implicit sequence 'test_id_seq' for SERIAL column 'test.id'
CREATE TABLE
-------------------------
2.データをloadbalancer経由でインサート
-------------------------
test=> insert into test(name) values('a');
INSERT 33366 1
3clusterDBとも正常にインサートされる．
----------------------------
3.serverCのpostmasterを落とす
-----------------------------
$ pg_ctl stop -D /usr/local/pgsql/data -m i
----------------------------
4.serverCのpostmasterを起動
----------------------------
$ pg_ctl start -D /usr/local/pgsql/data -o "-i -R"
Start in recovery mode!
Please wait until a data synchronization finishes from Master DB...
postmaster successfully started
----------------------------
5.loadbalancer経由でインサートを50件
----------------------------
レプリケーションサーバのdebugログで、
「2nd master 〜」のメッセージが出てからインサート開始．
1セッション中で、50件インサートしています．
----------------------------
6.結果
----------------------------
serverB:
test=> select count(*) from test;
count
-------
51
(1 row)
serverA,serverC:
test=> select count(*) from test;
count
-------
10
(1 row)
-----------------------------
debugログ
-----------------------------
DEBUG(replicate_loop): replicate main: selected
DEBUG(pgrecovery_loop): recovery accept port 7778
DEBUG(read_packet): receive packet no:1
DEBUG(first_setup_recovery): 1st setup target serverC
DEBUG(first_setup_recovery): 1st setup port 5432
DEBUG(first_setup_recovery): check another recovery process
DEBUG(PGRsem_unlock): add recovery target to host table
DEBUG(replicate_loop): wait replicate
DEBUG(send_recovery_packet): set RECOVERY_PGDATA_REQ packet data
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): not found in transaction tbl host db:template1 pid:27722
DEBUG(getTransactionTbl): not found in getTransactionTbl
DEBUG(getTransactionTbl): not found in transaction tbl host db:template1 pid:27722
DEBUG(pgr_createConn): PQsetdbLogin host[serverA] port[5432] db[template1] user[postgres]
DEBUG(pgr_createConn): PQsetdbLogin ok!!
DEBUG(insertTransactionTbl): db:template1 port:5432 user:postgres host:serverA query:VACUUM
DEBUG(insertTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,0,0,2) )
DEBUG(insertTransactionTbl): PQexec send :VACUUM
DEBUG(insertTransactionTbl): PQexec end
DEBUG(getTransactionTbl): hit !! transaction tbl host serverA db:template1 pid:27722
DEBUG(getTransactionTbl): send packet to master serverA recoveryPort 7779
DEBUG(PGRsem_unlock): wait answer from master server
DEBUG(read_packet_from_master): wait
DEBUG(read_packet): get answer from master
DEBUG(send_recovery_packet): 1st master serverA - 5432
DEBUG(send_recovery_packet): 1st target serverC - 5432
DEBUG(replicate_loop): wait replicate
DEBUG(replicate_loop): wait replicate
DEBUG(read_packet): receive packet no:5
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): not found in transaction tbl host db:template1 pid:27722
DEBUG(getTransactionTbl): not found in getTransactionTbl
DEBUG(getTransactionTbl): not found in transaction tbl host db:template1 pid:27722
DEBUG(pgr_createConn): PQsetdbLogin host[serverA] port[5432] db[template1] user[postgres]
DEBUG(pgr_createConn): PQsetdbLogin ok!!
DEBUG(insertTransactionTbl): db:template1 port:5432 user:postgres host:serverA query:VACUUM FULL
DEBUG(insertTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,0,0,2) )
DEBUG(replicate_loop): wait replicate
DEBUG(insertTransactionTbl): PQexec send :VACUUM FULL
DEBUG(insertTransactionTbl): PQexec end
DEBUG(getTransactionTbl): hit !! transaction tbl host serverA db:template1 pid:27722
DEBUG(read_packet_from_master): wait
DEBUG(send_recovery_packet): 2nd master serverA - 5432
DEBUG(send_recovery_packet): 2nd target serverC - 5432
DEBUG(send_recovery_packet): second_setup_recovery end :1
DEBUG(replicate_loop): replicate main: selected
DEBUG(replicate_loop): replicate_loop selected
DEBUG(PGRread_packet): query :: insert into test (name) values ('a')
DEBUG(PGRset_queue): msgsnd header rtn:0
DEBUG(PGRset_queue): msgsnd query[insert into test (name) values ('a')] rtn:0
DEBUG(PGRreplicate_packet_send): cmdSts=Q
DEBUG(PGRreplicate_packet_send): cmdType=I
DEBUG(PGRreplicate_packet_send): port=5432
DEBUG(PGRreplicate_packet_send): pid=16439
DEBUG(PGRreplicate_packet_send): from_host=serverB
DEBUG(PGRreplicate_packet_send): dbName=test
DEBUG(PGRreplicate_packet_send): userName=test
DEBUG(PGRreplicate_packet_send): recieve sec=1092377369
DEBUG(PGRreplicate_packet_send): recieve usec=706554
DEBUG(PGRreplicate_packet_send): query_size=36
DEBUG(PGRreplicate_packet_send): query=insert into test (name) values ('a')
DEBUG(PGRreplicate_packet_send): useFlag[2]
DEBUG(PGRget_master): serverA skipped
DEBUG(PGRis_same_host): 5432 @ serverB return trigger
DEBUG(is_need_sync_time): sem_lock[1]
DEBUG(PGRreturn_result): PGRreturn_result[3,1092377369,706554,2]
DEBUG(PGRreturn_result): [128 / 128] send
DEBUG(PGRreturn_result): 128 send
DEBUG(PGRreturn_result): wait for answer
DEBUG(replicate_loop): wait replicate
DEBUG(PGRread_packet): answer[PGR_QUERY_DONE_NOTICE_CMD]
DEBUG(PGRread_packet): QUERY DONE
DEBUG(PGRread_packet): status of PGRreturn_result[0]
DEBUG(PGRread_packet): sem_lock[2]
DEBUG(PGRsem_lock): sem_unlock[1]
DEBUG(PGRsem_unlock): PGRreplicate_packet_send end
DEBUG(PGRreturn_result): PGRreturn_result[6]
DEBUG(PGRreturn_result): [128 / 128] send
DEBUG(PGRreturn_result): 128 send
DEBUG(PGRreturn_result): status of PGRreturn_result[0]
DEBUG(delete_template): sem_unlock[2]
DEBUG(PGRsem_unlock): replicate_loop selected
(snip)
DEBUG(PGRread_packet): query :: insert into test (name) values ('a')
DEBUG(PGRset_queue): msgsnd header rtn:-1
DEBUG(PGRset_queue): msgsnd query[insert into test (name) values ('a')] rtn:-1
DEBUG(PGRreplicate_packet_send): cmdSts=Q
DEBUG(PGRreplicate_packet_send): cmdType=I
DEBUG(PGRreplicate_packet_send): port=5432
DEBUG(PGRreplicate_packet_send): pid=16439
DEBUG(PGRreplicate_packet_send): from_host=serverB
DEBUG(PGRreplicate_packet_send): dbName=test
DEBUG(PGRreplicate_packet_send): userName=test
DEBUG(PGRreplicate_packet_send): recieve sec=1092377369
DEBUG(PGRreplicate_packet_send): recieve usec=874251
DEBUG(PGRreplicate_packet_send): query_size=36
DEBUG(PGRreplicate_packet_send): query=insert into test (name) values ('a')
DEBUG(PGRreplicate_packet_send): useFlag[2]
DEBUG(PGRget_master): serverA skipped
DEBUG(PGRis_same_host): 5432 @ serverB return trigger
DEBUG(is_need_sync_time): sem_lock[1]
DEBUG(PGRreturn_result): PGRreturn_result[3,1092377369,874251,2]
DEBUG(PGRreturn_result): [128 / 128] send
DEBUG(PGRreturn_result): 128 send
DEBUG(PGRreturn_result): wait for answer
DEBUG(PGRread_packet): answer[PGR_QUERY_DONE_NOTICE_CMD]
DEBUG(PGRread_packet): QUERY DONE
DEBUG(PGRread_packet): status of PGRreturn_result[0]
DEBUG(PGRread_packet): sem_lock[2]
DEBUG(PGRsem_lock): sem_unlock[1]
DEBUG(PGRsem_unlock): PGRreplicate_packet_send end
DEBUG(PGRreturn_result): PGRreturn_result[6]
DEBUG(PGRreturn_result): [128 / 128] send
DEBUG(PGRreturn_result): 128 send
DEBUG(PGRreturn_result): status of PGRreturn_result[0]
DEBUG(delete_template): sem_unlock[2]
DEBUG(PGRsem_unlock): replicate_loop selected
(snip)
DEBUG(pgrecovery_loop): recovery accept port 7778
DEBUG(read_packet): receive packet no:9
DEBUG(read_packet): last master serverA - 5432
DEBUG(read_packet): last target serverC - 5432
DEBUG(PGRsend_queue): master serverA - 5432
DEBUG(PGRget_HostTbl): target serverC - 5432
DEBUG(PGRget_HostTbl): msgrcv[insert into test (name) values ('a')]
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): not found in transaction tbl host serverB db:test pid:16439
DEBUG(getTransactionTbl): not found in getTransactionTbl
DEBUG(getTransactionTbl): not found in transaction tbl host serverB db:test pid:16439
DEBUG(pgr_createConn): PQsetdbLogin host[serverA] port[5432] db[test] user[test]
DEBUG(pgr_createConn): PQsetdbLogin ok!!
DEBUG(insertTransactionTbl): db:test port:5432 user:test host:serverA query:insert into test (name) values ('a')
DEBUG(insertTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,706554,2) )
WARNING: This query is not permitted while recovery db
DEBUG(insertTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(insertTransactionTbl): PQexec end
DEBUG(PGRsend_replicate_packet_to_server): host(serverC) : port(5432)
DEBUG(getTransactionTbl): not found in transaction tbl host serverB db:test pid:16439
DEBUG(getTransactionTbl): not found in getTransactionTbl
DEBUG(getTransactionTbl): not found in transaction tbl host serverB db:test pid:16439
DEBUG(pgr_createConn): PQsetdbLogin host[serverC] port[5432] db[test] user[test]
DEBUG(pgr_createConn): PQsetdbLogin ok!!
DEBUG(insertTransactionTbl): db:test port:5432 user:test host:serverC query:insert into test (name) values ('a')
DEBUG(insertTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,706554,2) )
DEBUG(insertTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(insertTransactionTbl): PQexec end
DEBUG(delete_template): msgrcv[insert into test (name) values ('a')]
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverA db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverA query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,774663,2) )
WARNING: This query is not permitted while recovery db
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(PGRsend_replicate_packet_to_server): host(serverC) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverC db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverC query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,774663,2) )
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(delete_template): msgrcv[insert into test (name) values ('a')]
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverA db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverA query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,790345,2) )
WARNING: This query is not permitted while recovery db
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(PGRsend_replicate_packet_to_server): host(serverC) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverC db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverC query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,790345,2) )
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(delete_template): msgrcv[insert into test (name) values ('a')]
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverA db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverA query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,802475,2) )
WARNING: This query is not permitted while recovery db
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(PGRsend_replicate_packet_to_server): host(serverC) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverC db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverC query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,802475,2) )
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(delete_template): msgrcv[insert into test (name) values ('a')]
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverA db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverA query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,814683,2) )
WARNING: This query is not permitted while recovery db
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(PGRsend_replicate_packet_to_server): host(serverC) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverC db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverC query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,814683,2) )
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(delete_template): msgrcv[insert into test (name) values ('a')]
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverA db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverA query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,826600,2) )
WARNING: This query is not permitted while recovery db
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(PGRsend_replicate_packet_to_server): host(serverC) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverC db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverC query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,826600,2) )
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(delete_template): msgrcv[insert into test (name) values ('a')]
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverA db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverA query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,838562,2) )
WARNING: This query is not permitted while recovery db
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(PGRsend_replicate_packet_to_server): host(serverC) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverC db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverC query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,838562,2) )
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(delete_template): msgrcv[insert into test (name) values ('a')]
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverA db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverA query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,850314,2) )
WARNING: This query is not permitted while recovery db
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(PGRsend_replicate_packet_to_server): host(serverC) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverC db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverC query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,850314,2) )
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(delete_template): msgrcv[insert into test (name) values ('a')]
DEBUG(PGRsend_replicate_packet_to_server): host(serverA) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverA db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverA query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,862622,2) )
WARNING: This query is not permitted while recovery db
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(PGRsend_replicate_packet_to_server): host(serverC) : port(5432)
DEBUG(getTransactionTbl): hit !! transaction tbl host serverC db:test pid:16439
DEBUG(getTransactionTbl): db:test port:5432 user:test host:serverC query:insert into test (name) values ('a')
DEBUG(getTransactionTbl): sync_command(SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1092377369,862622,2) )
DEBUG(getTransactionTbl): PQexec send :insert into test (name) values ('a')
DEBUG(getTransactionTbl): PQexec end
DEBUG(delete_template): send_queue return status 0
DEBUG(delete_template): PGRsend_queue ok
DEBUG(replicate_loop): wait replicate
高橋 一成 <kazunari.takahashi ＠ ctc-g.co.jp>
pgcluster メーリングリストの案内