[pgcluster: 1016] 更新でレプリケーションサーバが固まってしまいます。
Shiroyuki Inooka
inooka ＠ cyphertec.co.jp
2008年 1月 18日 (金) 20:25:45 JST
初めまして。イノオカと申します。
以下の3台構成で、クラスタサーバ1,2上には
同じWebアプリケーションを起動させているのですが、
WebアプリケーションからそれぞれのDBへ、
同時に同じレコードに対しアップデートを行うと、
レプリケーションサーバが固まってしまいます。
PgClusterバージョン：pgcl.1.5.0rc14
・クラスタサーバ1
OS：CentOS4.4
ホスト名：first
IP：192.168.1.53
・クラスタサーバ2
OS：CentOS4.4
ホスト名：second
IP：192.168.1.52
・レプリケーションサーバ
OS：CentOS4.4
ホスト名：replica
IP：192.168.1.51
アップデートは以下のごく単純なSQL文で
クラスタ1,2両方からそれぞれ一回、同時に投入しています。
「UPDATE test set name = 'ddd' where id = 1」
以下が設定ファイルとログになりますが、
何か分かることがありましたらご教授下さい。
〜設定ファイル〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜
■クラスタサーバ1
・cluster.conf
<Replicate_Server_Info>
<Host_Name> replica </Host_Name>
<Port> 8001 </Port>
<Recovery_Port> 8101 </Recovery_Port>
</Replicate_Server_Info>
<Host_Name> first </Host_Name>
<Recovery_Port> 7001 </Recovery_Port>
<Rsync_Path> /usr/bin/rsync </Rsync_Path>
<Rsync_Option> ssh -1 </Rsync_Option>
<Rsync_Compress> yes </Rsync_Compress>
<Pg_Dump_Path> /usr/local/pgsql/bin/pg_dump </Pg_Dump_Path>
<When_Stand_Alone> read_write </When_Stand_Alone>
<Replication_Timeout> 10s </Replication_Timeout>
・pg_hba.conf
host all all 192.168.1.53 255.255.255.255 trust
host all all 192.168.1.52 255.255.255.255 trust
host all all 192.168.1.51 255.255.255.255 trust
■クラスタサーバ2
・cluster.conf
<Replicate_Server_Info>
<Host_Name> replica </Host_Name>
<Port> 8001 </Port>
<Recovery_Port> 8101 </Recovery_Port>
<LifeCheck_Port> 8201 </LifeCheck_Port>
</Replicate_Server_Info>
<Host_Name> second </Host_Name>
<Recovery_Port> 7001 </Recovery_Port>
<LifeCheck_Port> 7201 </LifeCheck_Port>
<Rsync_Path> /usr/bin/rsync </Rsync_Path>
<Rsync_Option> ssh -1 </Rsync_Option>
<Rsync_Compress> yes </Rsync_Compress>
<Pg_Dump_Path> /usr/local/pgsql/bin/pg_dump </Pg_Dump_Path>
<When_Stand_Alone> read_write </When_Stand_Alone>
<Replication_Timeout> 10s </Replication_Timeout>
・pg_hba.conf
host all all 192.168.1.53 255.255.255.255 trust
host all all 192.168.1.52 255.255.255.255 trust
host all all 192.168.1.51 255.255.255.255 trust
■レプリケーションサーバ
・pgreplicate.conf
<Cluster_Server_Info>
<Host_Name> first </Host_Name>
<Port> 5432 </Port>
<Recovery_Port> 7001 </Recovery_Port>
</Cluster_Server_Info>
<Cluster_Server_Info>
<Host_Name> second </Host_Name>
<Port> 5432 </Port>
<Recovery_Port> 7001 </Recovery_Port>
</Cluster_Server_Info>
<Host_Name> replica </Host_Name>
<Replication_Port> 8001 </Replication_Port>
<Recovery_Port> 8101 </Recovery_Port>
<RLOG_Port> 8301 </RLOG_Port>
<Response_Mode> normal </Response_Mode>
<Use_Replication_Log> no </Use_Replication_Log>
<Replication_Timeout> 10s </Replication_Timeout>
<Log_File_Info>
<File_Name> /tmp/pgreplicate.log </File_Name>
<File_Size> 1M </File_Size>
<Rotate> 3 </Rotate>
</Log_File_Info>
・pg_hba.conf
host all all 192.168.1.53 255.255.255.255 trust
host all all 192.168.1.52 255.255.255.255 trust
host all all 192.168.1.51 255.255.255.255 trust
〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜
〜ログ〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜
[立ち上げ時]
2008-01-18 19:11:56 [9067] DEBUG:PGR_Get_Conf_Data ok
2008-01-18 19:11:56 [9067] DEBUG:LoadBalanceTbl allocate ok
2008-01-18 19:11:56 [9067] DEBUG:PGRget_Conf_Data():CascadeTbl shmget ok
2008-01-18 19:11:56 [9067] DEBUG:PGRget_Conf_Data():CascadeTbl shmat ok
2008-01-18 19:11:56 [9067] DEBUG:PGRget_Conf_Data():CascadeInf shmget ok
2008-01-18 19:11:56 [9067] DEBUG:PGRget_Conf_Data():CascadeInf shmat ok
2008-01-18 19:11:56 [9067] DEBUG:PGRget_Conf_Data():CommitLog shmget ok
2008-01-18 19:11:56 [9067] DEBUG:PGRget_Conf_Data():Commit_Log_Tbl shmat ok
2008-01-18 19:11:56 [9067] DEBUG:PGRget_Conf_Data():RLog Memory
Allocation ok
2008-01-18 19:11:56 [9067] DEBUG:registering (key,value)=(Host_Name,first)
2008-01-18 19:11:56 [9067] DEBUG:registering hostname first
2008-01-18 19:11:56 [9067] DEBUG:resolved name is 192.168.1.53
2008-01-18 19:11:56 [9067] DEBUG:registering (key,value)=(Port,5432)
2008-01-18 19:11:56 [9067] DEBUG:registering
(key,value)=(Recovery_Port,7001)
2008-01-18 19:11:56 [9067] DEBUG:registering (key,value)=(Host_Name,second)
2008-01-18 19:11:56 [9067] DEBUG:registering hostname second
2008-01-18 19:11:56 [9067] DEBUG:resolved name is 192.168.1.52
2008-01-18 19:11:56 [9067] DEBUG:registering (key,value)=(Port,5432)
2008-01-18 19:11:56 [9067] DEBUG:registering
(key,value)=(Recovery_Port,7001)
2008-01-18 19:11:56 [9067] DEBUG:registering (key,value)=(Host_Name,replica)
2008-01-18 19:11:56 [9067] DEBUG:registering
(key,value)=(Replication_Port,8001)
2008-01-18 19:11:56 [9067] DEBUG:registering
(key,value)=(Recovery_Port,8101)
2008-01-18 19:11:56 [9067] DEBUG:registering (key,value)=(RLOG_Port,8301)
2008-01-18 19:11:56 [9067] DEBUG:registering
(key,value)=(Response_Mode,normal)
2008-01-18 19:11:56 [9067] DEBUG:registering
(key,value)=(Use_Replication_Log,no)
2008-01-18 19:11:56 [9067] DEBUG:registering
(key,value)=(Replication_Timeout,10s)
2008-01-18 19:11:56 [9067] DEBUG:registering
(key,value)=(File_Name,/tmp/pgreplicate.log)
2008-01-18 19:11:56 [9067] DEBUG:registering (key,value)=(File_Size,1M)
2008-01-18 19:11:56 [9067] DEBUG:registering (key,value)=(Rotate,3)
2008-01-18 19:11:56 [9067] DEBUG:PGRget_Conf_Data():HostTbl shmget ok
2008-01-18 19:11:56 [9067] DEBUG:PGRget_Conf_Data():HostTbl shmat ok
2008-01-18 19:11:56 [9068] DEBUG:PGRrecovery_main():PGRrecovery_main
bind port 8101
2008-01-18 19:11:56 [9067] DEBUG:replicate_main():entering replicate_main
2008-01-18 19:11:56 [9067] DEBUG:replicate_main() 8001 port bind OK
2008-01-18 19:11:56 [9067] DEBUG:cmdSts=N
2008-01-18 19:11:56 [9067] DEBUG:rlog=0
2008-01-18 19:11:56 [9067] DEBUG:port=0
2008-01-18 19:11:56 [9067] DEBUG:pid=0
2008-01-18 19:11:56 [9067] DEBUG:from_host=192.168.1.51
2008-01-18 19:11:56 [9067] DEBUG:dbName=template1
2008-01-18 19:11:56 [9067] DEBUG:userName=postgres
2008-01-18 19:11:56 [9067] DEBUG:recieve sec=0
2008-01-18 19:11:56 [9067] DEBUG:recieve usec=0
2008-01-18 19:11:56 [9067] DEBUG:query_size=64
2008-01-18 19:11:56 [9067] DEBUG:request_id=0
2008-01-18 19:11:56 [9067] DEBUG:replicate_id=0
2008-01-18 19:11:56 [9067] DEBUG:recovery_status=0
2008-01-18 19:11:56 [9067] DEBUG:query=SELECT
PGR_SYSTEM_COMMAND_FUNCTION(1,'192.168.1.51',8001,8101)
2008-01-18 19:11:56 [9067] DEBUG:PGRis_same_host():target host
2008-01-18 19:11:56 [9067] DEBUG:pgr_createConn():PQsetdbLogin
host[192.168.1.53] port[5432] db[template1] user[postgres]
2008-01-18 19:11:56 [9067] DEBUG:pgr_createConn():PQsetdbLogin ok!!
2008-01-18 19:11:56 [9067] DEBUG:PGRis_same_host():target host
2008-01-18 19:11:56 [9067] DEBUG:pgr_createConn():PQsetdbLogin
host[192.168.1.52] port[5432] db[template1] user[postgres]
2008-01-18 19:11:56 [9067] DEBUG:start thread_send_cluster()
2008-01-18 19:11:56 [9067]
DEBUG:send_replicate_packet_to_server():sync_command(SELECT
PGR_SYSTEM_COMMAND_FUNCTION(8,1,0,1) )
2008-01-18 19:11:56 [9067]
DEBUG:send_replicate_packet_to_server():sync_command returns SYSTEM_COMMAND
2008-01-18 19:11:56 [9067]
DEBUG:send_replicate_packet_to_server():PQexec send :SELECT
PGR_SYSTEM_COMMAND_FUNCTION(1,'192.168.1.51',8001,8101)
2008-01-18 19:11:56 [9067]
DEBUG:send_replicate_packet_to_server():PQexec returns :SYSTEM_COMMAND
2008-01-18 19:11:56 [9067] DEBUG:thread_send_cluster():return value from
send_replicate_packet_to_server() is 0
2008-01-18 19:11:56 [9067] DEBUG:thread_send_cluster():pthread_exit[0]
2008-01-18 19:11:56 [9067] DEBUG:pgr_createConn():PQsetdbLogin ok!!
2008-01-18 19:11:56 [9067] DEBUG:start thread_send_cluster()
2008-01-18 19:11:56 [9067]
DEBUG:send_replicate_packet_to_server():sync_command(SELECT
PGR_SYSTEM_COMMAND_FUNCTION(8,1,0,1) )
2008-01-18 19:11:56 [9067]
DEBUG:send_replicate_packet_to_server():sync_command returns SYSTEM_COMMAND
2008-01-18 19:11:56 [9067]
DEBUG:send_replicate_packet_to_server():PQexec send :SELECT
PGR_SYSTEM_COMMAND_FUNCTION(1,'192.168.1.51',8001,8101)
2008-01-18 19:11:56 [9067]
DEBUG:send_replicate_packet_to_server():PQexec returns :SYSTEM_COMMAND
2008-01-18 19:11:56 [9067] DEBUG:thread_send_cluster():return value from
send_replicate_packet_to_server() is 0
2008-01-18 19:11:56 [9067] DEBUG:thread_send_cluster():pthread_exit[1]
[SQL発行時]
2008-01-18 19:12:09 [9071] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():PGRreturn_result[1]
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9071] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9071] DEBUG:PGRdo_replicate():query ::
2008-01-18 19:12:09 [9071] DEBUG:cmdSts=P
2008-01-18 19:12:09 [9071] DEBUG:cmdType=P
2008-01-18 19:12:09 [9071] DEBUG:rlog=0
2008-01-18 19:12:09 [9071] DEBUG:port=5432
2008-01-18 19:12:09 [9071] DEBUG:pid=13344
2008-01-18 19:12:09 [9071] DEBUG:from_host=192.168.1.52
2008-01-18 19:12:09 [9071] DEBUG:dbName=test_replica
2008-01-18 19:12:09 [9071] DEBUG:userName=postgres
2008-01-18 19:12:09 [9071] DEBUG:recieve sec=1200651129
2008-01-18 19:12:09 [9071] DEBUG:recieve usec=646207
2008-01-18 19:12:09 [9071] DEBUG:query_size=46
2008-01-18 19:12:09 [9071] DEBUG:request_id=1
2008-01-18 19:12:09 [9071] DEBUG:replicate_id=0
2008-01-18 19:12:09 [9071] DEBUG:recovery_status=0
2008-01-18 19:12:09 [9071] DEBUG:sem_lock [1] req
2008-01-18 19:12:09 [9071] DEBUG:sem_lock [1] got it
2008-01-18 19:12:09 [9071] DEBUG:pgr_createConn():PQsetdbLogin
host[192.168.1.53] port[5432] db[test_replica] user[postgres]
2008-01-18 19:12:09 [9072] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():PGRreturn_result[1]
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9072] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9072] DEBUG:PGRdo_replicate():query ::
2008-01-18 19:12:09 [9072] DEBUG:cmdSts=P
2008-01-18 19:12:09 [9072] DEBUG:cmdType=P
2008-01-18 19:12:09 [9072] DEBUG:rlog=0
2008-01-18 19:12:09 [9072] DEBUG:port=5432
2008-01-18 19:12:09 [9072] DEBUG:pid=9636
2008-01-18 19:12:09 [9072] DEBUG:from_host=192.168.1.53
2008-01-18 19:12:09 [9072] DEBUG:dbName=test_replica
2008-01-18 19:12:09 [9072] DEBUG:userName=postgres
2008-01-18 19:12:09 [9072] DEBUG:recieve sec=1200651129
2008-01-18 19:12:09 [9072] DEBUG:recieve usec=684129
2008-01-18 19:12:09 [9072] DEBUG:query_size=46
2008-01-18 19:12:09 [9072] DEBUG:request_id=1
2008-01-18 19:12:09 [9072] DEBUG:replicate_id=0
2008-01-18 19:12:09 [9072] DEBUG:recovery_status=0
2008-01-18 19:12:09 [9072] DEBUG:sem_lock [1] req
2008-01-18 19:12:09 [9071] DEBUG:pgr_createConn():PQsetdbLogin ok!!
2008-01-18 19:12:09 [9071] DEBUG:source host
2008-01-18 19:12:09 [9067] DEBUG:start thread_send_cluster()
2008-01-18 19:12:09 [9067]
DEBUG:send_replicate_packet_to_server():sync_command [SELECT
PGR_SYSTEM_COMMAND_FUNCTION(3,1200651129,646207,0,1,2) ]
2008-01-18 19:12:09 [9067]
DEBUG:send_replicate_packet_to_server():sync_command returns SYSTEM_COMMAND
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():return value from
send_replicate_packet_to_server() is 0
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():pthread_exit[0]
2008-01-18 19:12:09 [9071]
DEBUG:PGRreturn_result():PGRreturn_result[8,2,0,1]
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9071] DEBUG:end thread_send_source()
2008-01-18 19:12:09 [9071] DEBUG:sem_unlock[1]
2008-01-18 19:12:09 [9072] DEBUG:sem_lock [1] got it
2008-01-18 19:12:09 [9072] DEBUG:source host
2008-01-18 19:12:09 [9072] DEBUG:pgr_createConn():PQsetdbLogin
host[192.168.1.52] port[5432] db[test_replica] user[postgres]
2008-01-18 19:12:09 [9071] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():PGRreturn_result[1]
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9071] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9071] DEBUG:PGRdo_replicate():query ::
2008-01-18 19:12:09 [9071] DEBUG:cmdSts=P
2008-01-18 19:12:09 [9071] DEBUG:cmdType=B
2008-01-18 19:12:09 [9071] DEBUG:rlog=0
2008-01-18 19:12:09 [9071] DEBUG:port=5432
2008-01-18 19:12:09 [9071] DEBUG:pid=13344
2008-01-18 19:12:09 [9071] DEBUG:from_host=192.168.1.52
2008-01-18 19:12:09 [9071] DEBUG:dbName=test_replica
2008-01-18 19:12:09 [9071] DEBUG:userName=postgres
2008-01-18 19:12:09 [9071] DEBUG:recieve sec=1200651129
2008-01-18 19:12:09 [9071] DEBUG:recieve usec=760237
2008-01-18 19:12:09 [9071] DEBUG:query_size=9
2008-01-18 19:12:09 [9071] DEBUG:request_id=2
2008-01-18 19:12:09 [9071] DEBUG:replicate_id=0
2008-01-18 19:12:09 [9071] DEBUG:recovery_status=0
2008-01-18 19:12:09 [9071] DEBUG:sem_lock [1] req
2008-01-18 19:12:09 [9072] DEBUG:pgr_createConn():PQsetdbLogin ok!!
2008-01-18 19:12:09 [9067] DEBUG:start thread_send_cluster()
2008-01-18 19:12:09 [9067]
DEBUG:send_replicate_packet_to_server():sync_command [SELECT
PGR_SYSTEM_COMMAND_FUNCTION(3,1200651129,684129,0,1,3) ]
2008-01-18 19:12:09 [9067]
DEBUG:send_replicate_packet_to_server():sync_command returns SYSTEM_COMMAND
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():return value from
send_replicate_packet_to_server() is 0
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():pthread_exit[1]
2008-01-18 19:12:09 [9072]
DEBUG:PGRreturn_result():PGRreturn_result[8,3,0,1]
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9072] DEBUG:end thread_send_source()
2008-01-18 19:12:09 [9072] DEBUG:sem_unlock[1]
2008-01-18 19:12:09 [9071] DEBUG:sem_lock [1] got it
2008-01-18 19:12:09 [9071] DEBUG:source host
2008-01-18 19:12:09 [9067] DEBUG:start thread_send_cluster()
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():return value from
send_replicate_packet_to_server() is 0
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():pthread_exit[0]
2008-01-18 19:12:09 [9071]
DEBUG:PGRreturn_result():PGRreturn_result[3,1200651129,760237,52708,1,4]
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9071] DEBUG:end thread_send_source()
2008-01-18 19:12:09 [9071] DEBUG:sem_unlock[1]
2008-01-18 19:12:09 [9071] DEBUG:PGRread_packet():PG_read_query returns P.
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():PGRreturn_result[1]
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9071] DEBUG:PGRread_packet():PG_read_query returns P.
2008-01-18 19:12:09 [9071] DEBUG:PGRdo_replicate():query :: P
2008-01-18 19:12:09 [9071] DEBUG:cmdSts=P
2008-01-18 19:12:09 [9071] DEBUG:cmdType=D
2008-01-18 19:12:09 [9071] DEBUG:rlog=0
2008-01-18 19:12:09 [9071] DEBUG:port=5432
2008-01-18 19:12:09 [9071] DEBUG:pid=13344
2008-01-18 19:12:09 [9071] DEBUG:from_host=192.168.1.52
2008-01-18 19:12:09 [9071] DEBUG:dbName=test_replica
2008-01-18 19:12:09 [9071] DEBUG:userName=postgres
2008-01-18 19:12:09 [9071] DEBUG:recieve sec=1200651129
2008-01-18 19:12:09 [9071] DEBUG:recieve usec=804292
2008-01-18 19:12:09 [9071] DEBUG:query_size=3
2008-01-18 19:12:09 [9071] DEBUG:request_id=3
2008-01-18 19:12:09 [9071] DEBUG:replicate_id=0
2008-01-18 19:12:09 [9071] DEBUG:recovery_status=0
2008-01-18 19:12:09 [9071] DEBUG:sem_lock [1] req
2008-01-18 19:12:09 [9071] DEBUG:sem_lock [1] got it
2008-01-18 19:12:09 [9071] DEBUG:source host
2008-01-18 19:12:09 [9072] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():PGRreturn_result[1]
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9067] DEBUG:start thread_send_cluster()
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():return value from
send_replicate_packet_to_server() is 0
2008-01-18 19:12:09 [9072] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9072] DEBUG:PGRdo_replicate():query ::
2008-01-18 19:12:09 [9072] DEBUG:cmdSts=P
2008-01-18 19:12:09 [9072] DEBUG:cmdType=B
2008-01-18 19:12:09 [9072] DEBUG:rlog=0
2008-01-18 19:12:09 [9072] DEBUG:port=5432
2008-01-18 19:12:09 [9072] DEBUG:pid=9636
2008-01-18 19:12:09 [9072] DEBUG:from_host=192.168.1.53
2008-01-18 19:12:09 [9072] DEBUG:dbName=test_replica
2008-01-18 19:12:09 [9072] DEBUG:userName=postgres
2008-01-18 19:12:09 [9072] DEBUG:recieve sec=1200651129
2008-01-18 19:12:09 [9072] DEBUG:recieve usec=822115
2008-01-18 19:12:09 [9072] DEBUG:query_size=9
2008-01-18 19:12:09 [9072] DEBUG:request_id=2
2008-01-18 19:12:09 [9072] DEBUG:replicate_id=0
2008-01-18 19:12:09 [9072] DEBUG:recovery_status=0
2008-01-18 19:12:09 [9072] DEBUG:sem_lock [1] req
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():pthread_exit[0]
2008-01-18 19:12:09 [9071]
DEBUG:PGRreturn_result():PGRreturn_result[8,5,0,1]
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9071] DEBUG:end thread_send_source()
2008-01-18 19:12:09 [9071] DEBUG:sem_unlock[1]
2008-01-18 19:12:09 [9072] DEBUG:sem_lock [1] got it
2008-01-18 19:12:09 [9072] DEBUG:source host
2008-01-18 19:12:09 [9067] DEBUG:start thread_send_cluster()
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():return value from
send_replicate_packet_to_server() is 0
2008-01-18 19:12:09 [9071] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():PGRreturn_result[1]
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():pthread_exit[1]
2008-01-18 19:12:09 [9072]
DEBUG:PGRreturn_result():PGRreturn_result[3,1200651129,822115,52709,1,6]
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9072] DEBUG:end thread_send_source()
2008-01-18 19:12:09 [9072] DEBUG:sem_unlock[1]
2008-01-18 19:12:09 [9071] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9071] DEBUG:PGRdo_replicate():query ::
2008-01-18 19:12:09 [9071] DEBUG:cmdSts=P
2008-01-18 19:12:09 [9071] DEBUG:cmdType=E
2008-01-18 19:12:09 [9071] DEBUG:rlog=0
2008-01-18 19:12:09 [9071] DEBUG:port=5432
2008-01-18 19:12:09 [9071] DEBUG:pid=13344
2008-01-18 19:12:09 [9071] DEBUG:from_host=192.168.1.52
2008-01-18 19:12:09 [9071] DEBUG:dbName=test_replica
2008-01-18 19:12:09 [9071] DEBUG:userName=postgres
2008-01-18 19:12:09 [9071] DEBUG:recieve sec=1200651129
2008-01-18 19:12:09 [9071] DEBUG:recieve usec=844383
2008-01-18 19:12:09 [9071] DEBUG:query_size=6
2008-01-18 19:12:09 [9071] DEBUG:request_id=4
2008-01-18 19:12:09 [9071] DEBUG:replicate_id=0
2008-01-18 19:12:09 [9071] DEBUG:recovery_status=0
2008-01-18 19:12:09 [9072] DEBUG:PGRread_packet():PG_read_query returns P.
2008-01-18 19:12:09 [9071] DEBUG:sem_lock [1] req
2008-01-18 19:12:09 [9071] DEBUG:sem_lock [1] got it
2008-01-18 19:12:09 [9071] DEBUG:source host
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():PGRreturn_result[1]
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9067] DEBUG:start thread_send_cluster()
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():return value from
send_replicate_packet_to_server() is 0
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():pthread_exit[0]
2008-01-18 19:12:09 [9071]
DEBUG:PGRreturn_result():PGRreturn_result[8,7,0,1]
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9071] DEBUG:end thread_send_source()
2008-01-18 19:12:09 [9071] DEBUG:sem_unlock[1]
2008-01-18 19:12:09 [9072] DEBUG:PGRread_packet():PG_read_query returns P.
2008-01-18 19:12:09 [9072] DEBUG:PGRdo_replicate():query :: P
2008-01-18 19:12:09 [9072] DEBUG:cmdSts=P
2008-01-18 19:12:09 [9072] DEBUG:cmdType=D
2008-01-18 19:12:09 [9072] DEBUG:rlog=0
2008-01-18 19:12:09 [9072] DEBUG:port=5432
2008-01-18 19:12:09 [9072] DEBUG:pid=9636
2008-01-18 19:12:09 [9072] DEBUG:from_host=192.168.1.53
2008-01-18 19:12:09 [9072] DEBUG:dbName=test_replica
2008-01-18 19:12:09 [9072] DEBUG:userName=postgres
2008-01-18 19:12:09 [9072] DEBUG:recieve sec=1200651129
2008-01-18 19:12:09 [9072] DEBUG:recieve usec=861199
2008-01-18 19:12:09 [9072] DEBUG:query_size=3
2008-01-18 19:12:09 [9072] DEBUG:request_id=3
2008-01-18 19:12:09 [9072] DEBUG:replicate_id=0
2008-01-18 19:12:09 [9072] DEBUG:recovery_status=0
2008-01-18 19:12:09 [9072] DEBUG:sem_lock [1] req
2008-01-18 19:12:09 [9072] DEBUG:sem_lock [1] got it
2008-01-18 19:12:09 [9072] DEBUG:source host
2008-01-18 19:12:09 [9071] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():PGRreturn_result[1]
2008-01-18 19:12:09 [9071] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9067] DEBUG:start thread_send_cluster()
2008-01-18 19:12:09 [9071] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9071] DEBUG:PGRdo_replicate():query ::
2008-01-18 19:12:09 [9071] DEBUG:cmdSts=P
2008-01-18 19:12:09 [9071] DEBUG:cmdType=S
2008-01-18 19:12:09 [9071] DEBUG:rlog=0
2008-01-18 19:12:09 [9071] DEBUG:port=5432
2008-01-18 19:12:09 [9071] DEBUG:pid=13344
2008-01-18 19:12:09 [9071] DEBUG:from_host=192.168.1.52
2008-01-18 19:12:09 [9071] DEBUG:dbName=test_replica
2008-01-18 19:12:09 [9071] DEBUG:userName=postgres
2008-01-18 19:12:09 [9071] DEBUG:recieve sec=1200651129
2008-01-18 19:12:09 [9071] DEBUG:recieve usec=880275
2008-01-18 19:12:09 [9071] DEBUG:query_size=1
2008-01-18 19:12:09 [9071] DEBUG:request_id=5
2008-01-18 19:12:09 [9071] DEBUG:replicate_id=0
2008-01-18 19:12:09 [9071] DEBUG:recovery_status=0
2008-01-18 19:12:09 [9071] DEBUG:sem_lock [1] req
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():return value from
send_replicate_packet_to_server() is 0
2008-01-18 19:12:09 [9067] DEBUG:thread_send_cluster():pthread_exit[1]
2008-01-18 19:12:09 [9072]
DEBUG:PGRreturn_result():PGRreturn_result[8,8,0,1]
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9072] DEBUG:end thread_send_source()
2008-01-18 19:12:09 [9072] DEBUG:sem_unlock[1]
2008-01-18 19:12:09 [9072] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():PGRreturn_result[1]
2008-01-18 19:12:09 [9072] DEBUG:PGRreturn_result():128 send
2008-01-18 19:12:09 [9071] DEBUG:sem_lock [1] got it
2008-01-18 19:12:09 [9071] DEBUG:source host
2008-01-18 19:12:09 [9072] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:09 [9072] DEBUG:PGRdo_replicate():query ::
2008-01-18 19:12:09 [9072] DEBUG:cmdSts=P
2008-01-18 19:12:09 [9072] DEBUG:cmdType=E
2008-01-18 19:12:09 [9072] DEBUG:rlog=0
2008-01-18 19:12:09 [9072] DEBUG:port=5432
2008-01-18 19:12:09 [9072] DEBUG:pid=9636
2008-01-18 19:12:09 [9072] DEBUG:from_host=192.168.1.53
2008-01-18 19:12:09 [9072] DEBUG:dbName=test_replica
2008-01-18 19:12:09 [9072] DEBUG:userName=postgres
2008-01-18 19:12:09 [9072] DEBUG:recieve sec=1200651129
2008-01-18 19:12:09 [9072] DEBUG:recieve usec=899380
2008-01-18 19:12:09 [9072] DEBUG:query_size=6
2008-01-18 19:12:09 [9072] DEBUG:request_id=4
2008-01-18 19:12:09 [9072] DEBUG:replicate_id=0
2008-01-18 19:12:09 [9072] DEBUG:recovery_status=0
2008-01-18 19:12:09 [9072] DEBUG:sem_lock [1] req
2008-01-18 19:12:09 [9067] DEBUG:start thread_send_cluster()
・・・ここで固まります。
この後10秒おきに以下の繰り返しとなります。
2008-01-18 19:12:18 [9081] DEBUG:PGRread_packet():PG_read_query returns
SELECT PGR_SYSTEM_COMMAND_FUNCTION(2,replica,8001,8101).
2008-01-18 19:12:18 [9081] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:18 [9081] DEBUG:PGRdo_replicate():query ::
2008-01-18 19:12:18 [9081] DEBUG:cmdSts=P
2008-01-18 19:12:18 [9081] DEBUG:cmdType=E
2008-01-18 19:12:18 [9081] DEBUG:rlog=3
2008-01-18 19:12:18 [9081] DEBUG:port=5432
2008-01-18 19:12:18 [9081] DEBUG:pid=9636
2008-01-18 19:12:18 [9081] DEBUG:from_host=192.168.1.53
2008-01-18 19:12:18 [9081] DEBUG:dbName=test_replica
2008-01-18 19:12:18 [9081] DEBUG:userName=postgres
2008-01-18 19:12:18 [9081] DEBUG:recieve sec=1200651138
2008-01-18 19:12:18 [9081] DEBUG:recieve usec=937903
2008-01-18 19:12:18 [9081] DEBUG:query_size=6
2008-01-18 19:12:18 [9081] DEBUG:request_id=4
2008-01-18 19:12:18 [9081] DEBUG:replicate_id=0
2008-01-18 19:12:18 [9081] DEBUG:recovery_status=0
2008-01-18 19:12:18 [9081] DEBUG:sem_lock [1] req
2008-01-18 19:12:19 [9082] DEBUG:PGRread_packet():PG_read_query returns
SELECT PGR_SYSTEM_COMMAND_FUNCTION(2,replica,8001,8101).
2008-01-18 19:12:19 [9082] DEBUG:PGRread_packet():PG_read_query returns .
2008-01-18 19:12:19 [9082] DEBUG:PGRdo_replicate():query ::
2008-01-18 19:12:19 [9082] DEBUG:cmdSts=P
2008-01-18 19:12:19 [9082] DEBUG:cmdType=S
2008-01-18 19:12:19 [9082] DEBUG:rlog=3
2008-01-18 19:12:19 [9082] DEBUG:port=5432
2008-01-18 19:12:19 [9082] DEBUG:pid=13344
2008-01-18 19:12:19 [9082] DEBUG:from_host=192.168.1.52
2008-01-18 19:12:19 [9082] DEBUG:dbName=test_replica
2008-01-18 19:12:19 [9082] DEBUG:userName=postgres
2008-01-18 19:12:19 [9082] DEBUG:recieve sec=1200651139
2008-01-18 19:12:19 [9082] DEBUG:recieve usec=146098
2008-01-18 19:12:19 [9082] DEBUG:query_size=1
2008-01-18 19:12:19 [9082] DEBUG:request_id=5
2008-01-18 19:12:19 [9082] DEBUG:replicate_id=0
2008-01-18 19:12:19 [9082] DEBUG:recovery_status=0
2008-01-18 19:12:19 [9082] DEBUG:sem_lock [1] req
〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜〜
pgcluster メーリングリストの案内