[Pgcluster-general] Issues with PGCluster 1.7 - Recovery fails with few gigs database

[Tommi Berg]

Hi list,

I have been playing some more with the PGCluster and I ran into another
issue. The recovery isn't working with even few G databases. postgres -R
recovery works fine with small databases, but when I tried to recover
with my test database size 3.2G it always fails. It fails at end of 1st
recovery stage or begin of 2nd. The recovering postgres gets following
message at it's log:

Start in recovery mode!
Please wait until a data synchronization finishes from Master DB...
1st recovery step of [global] directory...OK
1st recovery step of [base] directory...OK
1st recovery step of [pg_clog] directory...OK
1st recovery step of [pg_xlog] directory...OK
1st sync_table_space OK
<and hang at this stage>

Strace from this postgres process:
write(2, "1st sync_table_space ", 21)   = 21
write(2, "OK\n", 3)                     = 3
select(5, NULL, [4], NULL, {600, 0})    = 1 (out [4], left {600, 0})
send(4, "\0\5\0d\0258\33Yclusterdb1\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
520, 0) = 520
select(5, [4], NULL, NULL, {600, 0})    = 0 (Timeout)
select(5, [4], NULL, NULL, {600, 0})    = 0 (Timeout)
select(5, [4], NULL, NULL, {600, 0}


And finaly debug from pgreplicate:
2008-01-30 12:43:03 [16207] DEBUG:pgrecovery_loop():recovery accept port
8101
2008-01-30 12:43:03 [16207] DEBUG:read_packet():receive packet
2008-01-30 12:43:03 [16207] DEBUG:no = 1
2008-01-30 12:43:03 [16207] DEBUG:max_connect = 100
2008-01-30 12:43:03 [16207] DEBUG:port = 5432
2008-01-30 12:43:03 [16207] DEBUG:recoveryPort = 7001
2008-01-30 12:43:03 [16207] DEBUG:hostName = clusterdb2
2008-01-30 12:43:03 [16207] DEBUG:pg_data = /var/lib/postgres/data
2008-01-30 12:43:03 [16207] DEBUG:pgrecovery_loop():receive packet no:1
2008-01-30 12:43:03 [16207] DEBUG:pgrecovery_loop():1st master  - 0
2008-01-30 12:43:03 [16207] DEBUG:pgrecovery_loop():1st target  - 0
2008-01-30 12:43:03 [16207] DEBUG:first_setup_recovery():1st setup
target clusterdb2
2008-01-30 12:43:03 [16207] DEBUG:first_setup_recovery():1st setup port 5432
2008-01-30 12:43:03 [16207] DEBUG:first_setup_recovery():add recovery
target to host table
2008-01-30 12:43:03 [16207]
DEBUG:PGRsend_load_balance_packet():host[loadbalancer] port[6001]
2008-01-30 12:43:03 [16207] DEBUG:first_setup_recovery():set
RECOVERY_PGDATA_REQ packet data
2008-01-30 12:43:04 [16207]
DEBUG:PGRsend_replicate_packet_to_server():connect db:template1
port:5432 user:postgres host:10.20.5.141 query:VACUUM
2008-01-30 12:43:04 [16207]
DEBUG:send_replicate_packet_to_server():sync_command(SELECT
PGR_SYSTEM_COMMAND_FUNCTION(3,0,0,0,1,3) )
2008-01-30 12:43:05 [16207]
DEBUG:send_replicate_packet_to_server():PQexec send :VACUUM
2008-01-30 12:43:05 [16207]
DEBUG:send_replicate_packet_to_server():PQexec returns :VACUUM
2008-01-30 12:43:05 [16207] DEBUG:first_setup_recovery():send packet to
master clusterdb1 recoveryPort 7001
2008-01-30 12:43:05 [16207] DEBUG:first_setup_recovery():wait answer
from master server
2008-01-30 12:43:05 [16207] DEBUG:read_packet():receive packet
2008-01-30 12:43:05 [16207] DEBUG:no = 3
2008-01-30 12:43:05 [16207] DEBUG:max_connect = 100
2008-01-30 12:43:05 [16207] DEBUG:port = 5432
2008-01-30 12:43:05 [16207] DEBUG:recoveryPort = 7001
2008-01-30 12:43:05 [16207] DEBUG:hostName = clusterdb1
2008-01-30 12:43:05 [16207] DEBUG:pg_data = /var/lib/postgres/data
2008-01-30 12:43:05 [16207] DEBUG:first_setup_recovery():get answer from
master:no[3]
2008-01-30 12:43:05 [16207]
DEBUG:PGRsend_load_balance_packet():host[loadbalancer] port[6001]
2008-01-30 12:43:05 [16207] DEBUG:pgrecovery_loop():first_setup_recovery
end:0