[pgcluster: 951] Re: ロードバランサが固まります
shinozaki ＠ cobalt.co.jp
shinozaki ＠ cobalt.co.jp
2007年 1月 11日 (木) 18:13:35 JST
三谷さん。
返信メールありがとうございます。
返事が遅くなってしまってすいません。
その後、三谷さんの指摘を受けて、
PGClusterのバージョンを1.5.0.rc13に変更
ライブラリパスの設定、設定ファイルを最新の物に変更
等を行ってみたのですが、
どうしても、ロードバランサのロック状態がかわりませんでした。
ロードバランサのロック現象は、毎回確実に２０〜３０分で起こせますので、
実際に動作を行いnetstatでパラメータの取得を行いました。
内部的な情報も含まれますので、別途結果を添付いたしました。
度々お世話になり申し訳ないのですが、
よろしくお願いいたします。
a.mitani ＠ sra-europe.com さんは書きました:
>篠崎さん，こんにちは．
>
>ロードバランサがロックしたときのnetstatの状態が分かりましたら教えてください．
>あと，ロードバランサのホスト名にlocalhostを指定されているようですが，ここを
>ホスト名にしてみてください．
>それから，設定ファイルの内容がPGClusterのバージョンと合っていないようですの
>で，念のため，他のバージョンのライブラリなどが混在していないか確認してみてく
>ださい．
>なお，1.5.0の最新版はrc12ですので，こちらもお試しください．
>
>三谷＠オランダ
>
>>
>> 今回は、また別の件でメールさせていただきます。
>>
>> システムの安定度を確認するために、
>> PHPからselectとinsertをトランザクションを張らずに１回呼ぶプログラムを
>> 外部から（http経由で）毎秒４０回程度回すベンチを流してみたのですが、
>> だいたい２０分から３０分程度でロードバランサが固まってしまいます。
>>
>> ロードバランサをリスタートすると復活するのですが、
>> 書き込みが間に合ってない感じでしょうか？
>>
>> なにか対策等ありましたら、ご教授ください。
>> よろしくお願いいたします。
>>
>> PGCluster-1.5.0rc10
>>
>> pglb.conf
>>
>> <Cluster_Server_Info>
>> <Host_Name> db01 </Host_Name>
>> <Port> 5432 </Port>
>> <Max_Connect> 128 </Max_Connect>
>> </Cluster_Server_Info>
>> <Cluster_Server_Info>
>> <Host_Name> db02 </Host_Name>
>> <Port> 5432 </Port>
>> <Max_Connect> 128 </Max_Connect>
>> </Cluster_Server_Info>
>> <Cluster_Server_Info>
>> <Host_Name> db03 </Host_Name>
>> <Port> 5432 </Port>
>> <Max_Connect> 128 </Max_Connect>
>> </Cluster_Server_Info>
>>
>> <Backend_Socket_Dir> /tmp </Backend_Socket_Dir>
>> <Receive_Port> 5432 </Receive_Port>
>> <Recovery_Port> 6001 </Recovery_Port>
>> <Max_Cluster_Num> 4 </Max_Cluster_Num>
>> <Use_Connection_Pooling> yes </Use_Connection_Pooling>
>>
>> pgreplicate.conf
>>
>> <Cluster_Server_Info>
>> <Host_Name> db01 </Host_Name>
>> <Port> 5432 </Port>
>> <Recovery_Port> 7001 </Recovery_Port>
>> </Cluster_Server_Info>
>> <Cluster_Server_Info>
>> <Host_Name> db02 </Host_Name>
>> <Port> 5432 </Port>
>> <Recovery_Port> 7001 </Recovery_Port>
>> </Cluster_Server_Info>
>> <Cluster_Server_Info>
>> <Host_Name> db03 </Host_Name>
>> <Port> 5432 </Port>
>> <Recovery_Port> 7001 </Recovery_Port>
>> </Cluster_Server_Info>
>>
>> <LoadBalance_Server_Info>
>> <Host_Name> localhost </Host_Name>
>> <Recovery_Port> 6001 </Recovery_Port>
>> </LoadBalance_Server_Info>
>>
>> <LoadBalance_Server_Info>
>> <Host_Name> lb02 </Host_Name>
>> <Recovery_Port> 6001 </Recovery_Port>
>> </LoadBalance_Server_Info>
>>
>> <Replication_Port> 8001 </Replication_Port>
>> <Recovery_Port> 8101 </Recovery_Port>
>> <Response_Mode> normal </Response_Mode>
>> <Status_Log_File> /dbdata/pgreplicate.sts </Status_Log_File>
>> <Error_Log_File> /dbdata/pgreplicate.log </Error_Log_File>
>> <Use_Replication_Log> yes </Use_Replication_Log>
>> <RLOG_Port> 8301 </RLOG_Port>
>>
>> 止まった時あたりの
>> ロードバランサログ以下のログが繰り返されます。
>>
>> 2006-12-26 11:52:51 [29260] DEBUG:pool_process_query():read kind from
>> backend C
>> 2006-12-26 11:52:51 [29260] DEBUG:pool_process_query():read kind from
>> backend pending data Z len: 5 po: 11
>> 2006-12-26 11:52:51 [29260] DEBUG:ReadyForQuery(): message length: 5
>> 2006-12-26 11:52:51 [29260] DEBUG:ReadyForQuery(): transaction state: I
>> 2006-12-26 11:52:51 [29260]
>> DEBUG:pool_connection_pool_timer():pool_connection_pool_timer: called
>> 2006-12-26 11:52:51 [29222] DEBUG:pool_process_query():read kind from
>> backend C
>> 2006-12-26 11:52:51 [29222] DEBUG:pool_process_query():read kind from
>> backend pending data Z len: 5 po: 11
>> 2006-12-26 11:52:51 [29222] DEBUG:ReadyForQuery(): message length: 5
>> 2006-12-26 11:52:51 [29222] DEBUG:ReadyForQuery(): transaction state: I
>> 2006-12-26 11:52:51 [29222]
>> DEBUG:pool_connection_pool_timer():pool_connection_pool_timer: called
>> 2006-12-26 11:52:51 [29343] DEBUG:pool_process_query():read kind from
>> backend C
>> 2006-12-26 11:52:51 [29343] DEBUG:pool_process_query():read kind from
>> backend pending data Z len: 5 po: 11
>> 2006-12-26 11:52:51 [29343] DEBUG:ReadyForQuery(): message length: 5
>> 2006-12-26 11:52:51 [29343] DEBUG:ReadyForQuery(): transaction state: I
>> 2006-12-26 11:52:51 [29343]
>> DEBUG:pool_connection_pool_timer():pool_connection_pool_timer: called
>> 2006-12-26 11:52:51 [29391] DEBUG:pool_process_query():read kind from
>> backend C
>> 2006-12-26 11:52:51 [29391] DEBUG:pool_process_query():read kind from
>> backend pending data Z len: 5 po: 11
>> 2006-12-26 11:52:51 [29391] DEBUG:ReadyForQuery(): message length: 5
>> 2006-12-26 11:52:51 [29391] DEBUG:ReadyForQuery(): transaction state: I
>> 2006-12-26 11:52:51 [29391]
>> DEBUG:pool_connection_pool_timer():pool_connection_pool_timer: called
>> 2006-12-26 11:52:51 [29470] DEBUG:pool_process_query():read kind from
>> backend C
>> 2006-12-26 11:52:51 [29470] DEBUG:pool_process_query():read kind from
>> backend pending data Z len: 5 po: 11
>> 2006-12-26 11:52:51 [29470] DEBUG:ReadyForQuery(): message length: 5
>> 2006-12-26 11:52:51 [29470] DEBUG:ReadyForQuery(): transaction state: I
>> 2006-12-26 11:52:51 [29470]
>> DEBUG:pool_connection_pool_timer():pool_connection_pool_timer: called
>> 2006-12-26 11:52:51 [29471] DEBUG:pool_process_query():read kind from
>> backend C
>> 2006-12-26 11:52:51 [29471] DEBUG:pool_process_query():read kind from
>> backend pending data Z len: 5 po: 11
>> 2006-12-26 11:52:51 [29471] DEBUG:ReadyForQuery(): message length: 5
>> 2006-12-26 11:52:51 [29471] DEBUG:ReadyForQuery(): transaction state: I
>> 2006-12-26 11:52:51 [29471]
>> DEBUG:pool_connection_pool_timer():pool_connection_pool_timer: called
>>
>>
>>
>> レプリログ以下のログ５１分台が止まった時、ロードバランサを停止した時に５３分
>> のログが一気に出力されました。
>>
>> 2006-12-26 11:52:51 [29746] DEBUG:same host
>> 2006-12-26 11:52:51 [30169] DEBUG:PGRread_packet():PG_read_query returns
>> PGR_QUERY_DONE_NOTICE_CMD.
>> 2006-12-26 11:52:51 [29184] DEBUG:start thread_send_cluster()
>> 2006-12-26 11:52:51 [29184]
>> DEBUG:send_replicate_packet_to_server():sync_command(SELECT
>> PGR_SYSTEM_COMMAND_FUNCTION(8,9574,0,1) )
>> 2006-12-26 11:52:51 [29184] DEBUG:start thread_send_cluster()
>> 2006-12-26 11:52:51 [29184]
>> DEBUG:send_replicate_packet_to_server():sync_command(SELECT
>> PGR_SYSTEM_COMMAND_FUNCTION(8,9574,0,1) )
>> 2006-12-26 11:52:51 [29184]
>> DEBUG:send_replicate_packet_to_server():sync_command returns
>> SYSTEM_COMMAND
>> 2006-12-26 11:52:51 [29184]
>> DEBUG:send_replicate_packet_to_server():sync_command returns
>> SYSTEM_COMMAND
>> 2006-12-26 11:52:51 [29184] DEBUG:send_replicate_packet_to_server():PQexec
>> send :RESET ALL
>> 2006-12-26 11:52:51 [29184] DEBUG:send_replicate_packet_to_server():PQexec
>> returns :RESET
>> 2006-12-26 11:52:51 [29184] DEBUG:thread_send_cluster():return value from
>> send_replicate_packet_to_server() is 0
>> 2006-12-26 11:52:51 [29184] DEBUG:thread_send_cluster():pthread_exit[0]
>> 2006-12-26 11:52:51 [29184] DEBUG:send_replicate_packet_to_server():PQexec
>> send :RESET ALL
>> 2006-12-26 11:52:51 [29184] DEBUG:send_replicate_packet_to_server():PQexec
>> returns :RESET
>> 2006-12-26 11:52:51 [29184] DEBUG:thread_send_cluster():return value from
>> send_replicate_packet_to_server() is 0
>> 2006-12-26 11:52:51 [29184] DEBUG:thread_send_cluster():pthread_exit[1]
>> 2006-12-26 11:52:51 [29746]
>> DEBUG:PGRreturn_result():PGRreturn_result[8,9574,0,1]
>> 2006-12-26 11:52:51 [29746] DEBUG:PGRreturn_result():128 send
>> 2006-12-26 11:52:51 [29746] DEBUG:end thread_send_source()
>> 2006-12-26 11:52:51 [29746] DEBUG:sem_unlock[1]
>> 2006-12-26 11:52:51 [29738] DEBUG:sem_lock [1] got it
>> 2006-12-26 11:52:51 [29738] DEBUG:same host
>> 2006-12-26 11:52:51 [29184] DEBUG:start thread_send_cluster()
>> 2006-12-26 11:52:51 [29184]
>> DEBUG:send_replicate_packet_to_server():sync_command(SELECT
>> PGR_SYSTEM_COMMAND_FUNCTION(8,9575,0,1) )
>> 2006-12-26 11:52:51 [29184] DEBUG:start thread_send_cluster()
>> 2006-12-26 11:52:51 [29184]
>> DEBUG:send_replicate_packet_to_server():sync_command(SELECT
>> PGR_SYSTEM_COMMAND_FUNCTION(8,9575,0,1) )
>> 2006-12-26 11:52:51 [29184]
>> DEBUG:send_replicate_packet_to_server():sync_command returns
>> SYSTEM_COMMAND
>> 2006-12-26 11:52:51 [29184]
>> DEBUG:send_replicate_packet_to_server():sync_command returns
>> SYSTEM_COMMAND
>> 2006-12-26 11:52:51 [29184] DEBUG:send_replicate_packet_to_server():PQexec
>> send :RESET ALL
>> 2006-12-26 11:52:51 [29184] DEBUG:send_replicate_packet_to_server():PQexec
>> returns :RESET
>> 2006-12-26 11:52:51 [29184] DEBUG:thread_send_cluster():return value from
>> send_replicate_packet_to_server() is 0
>> 2006-12-26 11:52:51 [29184] DEBUG:thread_send_cluster():pthread_exit[0]
>> 2006-12-26 11:52:51 [29184] DEBUG:send_replicate_packet_to_server():PQexec
>> send :RESET ALL
>> 2006-12-26 11:52:51 [29184] DEBUG:send_replicate_packet_to_server():PQexec
>> returns :RESET
>> 2006-12-26 11:52:51 [29184] DEBUG:thread_send_cluster():return value from
>> send_replicate_packet_to_server() is 0
>> 2006-12-26 11:52:51 [29184] DEBUG:thread_send_cluster():pthread_exit[1]
>> 2006-12-26 11:52:51 [29738]
>> DEBUG:PGRreturn_result():PGRreturn_result[8,9575,0,1]
>> 2006-12-26 11:52:51 [29738] DEBUG:PGRreturn_result():128 send
>> 2006-12-26 11:52:51 [29738] DEBUG:end thread_send_source()
>> 2006-12-26 11:52:51 [29738] DEBUG:sem_unlock[1]
>> 2006-12-26 11:52:51 [29738] DEBUG:PGRread_packet():PG_read_query returns
>> PGR_QUERY_DONE_NOTICE_CMD.
>> 2006-12-26 11:52:51 [29746] DEBUG:PGRread_packet():PG_read_query returns
>> PGR_QUERY_DONE_NOTICE_CMD.
>> 2006-12-26 11:58:53 [29673] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29717] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [30007] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29697] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [30010] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29704] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [30021] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29720] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [30032] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29185] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():got result:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): CMD_STS_TRANSACTION_ABORT
>> 2006-12-26 11:58:53 [29185] DEBUG:reconfirm_commit():PGR_NOT_YET_COMMIT
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): SYS_CALL process done
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():process result done:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():got result:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): CMD_STS_TRANSACTION_ABORT
>> 2006-12-26 11:58:53 [29185] DEBUG:reconfirm_commit():PGR_NOT_YET_COMMIT
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): SYS_CALL process done
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():process result done:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():got result:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): CMD_STS_TRANSACTION_ABORT
>> 2006-12-26 11:58:53 [29185] DEBUG:reconfirm_commit():PGR_NOT_YET_COMMIT
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): SYS_CALL process done
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():process result done:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():got result:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): CMD_STS_TRANSACTION_ABORT
>> 2006-12-26 11:58:53 [29185] DEBUG:reconfirm_commit():PGR_NOT_YET_COMMIT
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): SYS_CALL process done
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():process result done:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():got result:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): CMD_STS_TRANSACTION_ABORT
>> 2006-12-26 11:58:53 [29185] DEBUG:reconfirm_commit():PGR_NOT_YET_COMMIT
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): SYS_CALL process done
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():process result done:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():got result:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): CMD_STS_TRANSACTION_ABORT
>> 2006-12-26 11:58:53 [29185] DEBUG:reconfirm_commit():PGR_NOT_YET_COMMIT
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): SYS_CALL process done
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():process result done:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():got result:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): CMD_STS_TRANSACTION_ABORT
>> 2006-12-26 11:58:53 [29185] DEBUG:reconfirm_commit():PGR_NOT_YET_COMMIT
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): SYS_CALL process done
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():process result done:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():got result:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): CMD_STS_TRANSACTION_ABORT
>> 2006-12-26 11:58:53 [29185] DEBUG:reconfirm_commit():PGR_NOT_YET_COMMIT
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): SYS_CALL process done
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():process result done:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:PGRread_packet():PG_read_query returns .
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():got result:cmdSys='S'
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): CMD_STS_TRANSACTION_ABORT
>> 2006-12-26 11:58:53 [29185] DEBUG:reconfirm_commit():PGR_NOT_YET_COMMIT
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog(): SYS_CALL process done
>> 2006-12-26 11:58:53 [29185] DEBUG:do_rlog():process result done:cmdSys='S'
>> 2006-12-26 11:58:53 [29673] DEBUG:PGRreturn_result():PGRreturn_result[5,0]
>> 2006-12-26 11:58:53 [29717] DEBUG:PGRreturn_result():PGRreturn_result[5,0]
>> 2006-12-26 11:58:53 [29717] DEBUG:PGRreturn_result():128 send
>> 2006-12-26 11:58:53 [29717] DEBUG:replicate_loop():session closed
>> 2006-12-26 11:58:53 [29717] DEBUG:PGRdo_replicate():query ::
>> PGR_CLOSE_CONNECTION
>>
>
pgcluster メーリングリストの案内