[Pgcluster-general] Starting DB in recovery mode fail

Wed Oct 29 11:04:43 UTC 2008

Hi,

Here is my configurttion :

2 server nodes: SUSE SLES 10.2

The first one : replica1, cluster1 and pglb
The second one : replica2 and cluster2

The configuration is base above template given. the replicas have been 
configured in both upper / lower.

First I run pgreplicate in daemon mode on the 2 nodes : OK
Then I run pg_ctl on first node : OK

Now i tried tu run pg_ctl on the second nodes in recovery mode (-R) : KO

Log file pg_ctl on second nodes :

Start in recovery mode!
Please wait until a data synchronization finishes from Master DB...
unknown packet received

Log file pgreplicate on first node :

Wed Oct 29 11:10:36 2008  first_setup_recovery():get master info error , 
master may be down

Now i kill pgreplicate daemon on the first node and i launch it in debug 
mode with the comand:

pgreplicate -D etc -W etc -n -v > /var/log/pgreplicate.log &

And i retry to launch pg_ctl on the second nodes : And now OK. The second 
nodes is started and the recovery is OK

Here is the log :

2008-10-29 11:33:20 [22561] DEBUG:pgrecovery_loop():recovery accept port 
8101
2008-10-29 11:33:20 [22561] DEBUG:read_packet():receive packet
2008-10-29 11:33:20 [22561] DEBUG:no = 1
2008-10-29 11:33:20 [22561] DEBUG:max_connect = 100
2008-10-29 11:33:20 [22561] DEBUG:port = 5432
2008-10-29 11:33:20 [22561] DEBUG:recoveryPort = 7001
2008-10-29 11:33:20 [22561] DEBUG:hostName = svcstxpgsql02
2008-10-29 11:33:20 [22561] DEBUG:pg_data = /opt/dvt/pgsql/data
2008-10-29 11:33:20 [22561] DEBUG:pgrecovery_loop():receive packet no:1
2008-10-29 11:33:20 [22561] DEBUG:pgrecovery_loop():1st master  - 0
2008-10-29 11:33:20 [22561] DEBUG:pgrecovery_loop():1st target  - 0
2008-10-29 11:33:20 [22561] DEBUG:first_setup_recovery():1st setup target 
svcstxpgsql02
2008-10-29 11:33:20 [22561] DEBUG:first_setup_recovery():1st setup port 
5432
2008-10-29 11:33:20 [22561] DEBUG:first_setup_recovery():add recovery 
target to host table
2008-10-29 11:33:20 [22561] DEBUG:PGRsend_load_balance_packet():host[pglb] 
port[6001]
2008-10-29 11:33:20 [22561] DEBUG:first_setup_recovery():set 
RECOVERY_PGDATA_REQ packet data
2008-10-29 11:33:21 [22561] 
DEBUG:PGRsend_replicate_packet_to_server():connect db:template1 port:5432 
user:postgres host:192.168.2.60 query:VACUUM
2008-10-29 11:33:21 [22561] 
DEBUG:send_replicate_packet_to_server():sync_command(SELECT 
PGR_SYSTEM_COMMAND_FUNCTION(3,0,0,0,1,1) )
2008-10-29 11:33:21 [22561] DEBUG:send_replicate_packet_to_server():PQexec 
send :VACUUM
2008-10-29 11:33:21 [22561] DEBUG:send_replicate_packet_to_server():PQexec 
returns :VACUUM
2008-10-29 11:33:21 [22561] DEBUG:first_setup_recovery():send packet to 
master cluster1 recoveryPort 7001
2008-10-29 11:33:21 [22561] DEBUG:first_setup_recovery():wait answer from 
master server
2008-10-29 11:33:21 [22561] DEBUG:read_packet():receive packet
2008-10-29 11:33:21 [22561] DEBUG:no = 3
2008-10-29 11:33:21 [22561] DEBUG:max_connect = 100
2008-10-29 11:33:21 [22561] DEBUG:port = 5432
2008-10-29 11:33:21 [22561] DEBUG:recoveryPort = 7001
2008-10-29 11:33:21 [22561] DEBUG:hostName = svcstxpgsql01
2008-10-29 11:33:21 [22561] DEBUG:pg_data = /opt/dvt/pgsql/data
2008-10-29 11:33:21 [22561] DEBUG:first_setup_recovery():get answer from 
master:no[3]
2008-10-29 11:33:21 [22561] DEBUG:PGRsend_load_balance_packet():host[pglb] 
port[6001]
2008-10-29 11:33:21 [22561] DEBUG:pgrecovery_loop():first_setup_recovery 
end:0
2008-10-29 11:33:24 [22561] DEBUG:read_packet():receive packet
2008-10-29 11:33:24 [22561] DEBUG:no = 5
2008-10-29 11:33:24 [22561] DEBUG:max_connect = 100
2008-10-29 11:33:24 [22561] DEBUG:port = 5432
2008-10-29 11:33:24 [22561] DEBUG:recoveryPort = 7001
2008-10-29 11:33:24 [22561] DEBUG:hostName = cluster1
2008-10-29 11:33:24 [22561] DEBUG:pg_data = /opt/dvt/pgsql/data
2008-10-29 11:33:24 [22561] DEBUG:pgrecovery_loop():receive packet no:5
2008-10-29 11:33:24 [22561] DEBUG:pgrecovery_loop():2nd master cluster1 - 
5432
2008-10-29 11:33:24 [22561] DEBUG:pgrecovery_loop():2nd target 
svcstxpgsql02 - 5432
2008-10-29 11:33:25 [22561] 
DEBUG:PGRsend_replicate_packet_to_server():connect db:template1 port:5432 
user:postgres host:192.168.2.60 query:VACUUM FULL
2008-10-29 11:33:25 [22561] 
DEBUG:send_replicate_packet_to_server():sync_command(SELECT 
PGR_SYSTEM_COMMAND_FUNCTION(3,0,0,0,1,1) )
2008-10-29 11:33:25 [22561] DEBUG:send_replicate_packet_to_server():PQexec 
send :VACUUM FULL
2008-10-29 11:33:25 [22561] DEBUG:send_replicate_packet_to_server():PQexec 
returns :VACUUM
2008-10-29 11:33:25 [22561] DEBUG:read_packet():receive packet
2008-10-29 11:33:25 [22561] DEBUG:no = 7
2008-10-29 11:33:25 [22561] DEBUG:max_connect = 100
2008-10-29 11:33:25 [22561] DEBUG:port = 5432
2008-10-29 11:33:25 [22561] DEBUG:recoveryPort = 7001
2008-10-29 11:33:25 [22561] DEBUG:hostName = svcstxpgsql01
2008-10-29 11:33:25 [22561] DEBUG:pg_data = /opt/dvt/pgsql/data
2008-10-29 11:33:25 [22561] DEBUG:pgrecovery_loop():second_setup_recovery 
end :0
2008-10-29 11:33:26 [22561] DEBUG:pgrecovery_loop():receive packet no:8
2008-10-29 11:33:26 [22561] DEBUG:pgrecovery_loop():recovery accept port 
8101
2008-10-29 11:33:26 [22561] DEBUG:read_packet():receive packet
2008-10-29 11:33:26 [22561] DEBUG:no = 9
2008-10-29 11:33:26 [22561] DEBUG:max_connect = 0
2008-10-29 11:33:26 [22561] DEBUG:port = 0
2008-10-29 11:33:26 [22561] DEBUG:recoveryPort = 0
2008-10-29 11:33:26 [22561] DEBUG:hostName =
2008-10-29 11:33:26 [22561] DEBUG:pg_data =
2008-10-29 11:33:26 [22561] DEBUG:pgrecovery_loop():receive packet no:9
2008-10-29 11:33:26 [22561] DEBUG:pgrecovery_loop():last master cluster1 - 
5432
2008-10-29 11:33:26 [22561] DEBUG:pgrecovery_loop():last target 
svcstxpgsql02 - 5432
2008-10-29 11:33:26 [22561] DEBUG:PGRsend_queue():master cluster1 - 5432
2008-10-29 11:33:26 [22561] DEBUG:PGRsend_queue():target svcstxpgsql02 - 
5432
2008-10-29 11:33:26 [22561] DEBUG:PGRsend_queue():send_queue return status 
0
2008-10-29 11:33:26 [22561] DEBUG:pgrecovery_loop():recovery accept port 
8101
2008-10-29 11:33:26 [22561] DEBUG:read_packet():receive packet
2008-10-29 11:33:26 [22561] DEBUG:no = 11
2008-10-29 11:33:26 [22561] DEBUG:max_connect = 100
2008-10-29 11:33:26 [22561] DEBUG:port = 5432
2008-10-29 11:33:26 [22561] DEBUG:recoveryPort = 7001
2008-10-29 11:33:26 [22561] DEBUG:hostName = svcstxpgsql02
2008-10-29 11:33:26 [22561] DEBUG:pg_data = /opt/dvt/pgsql/data
2008-10-29 11:33:26 [22561] DEBUG:pgrecovery_loop():receive packet no:11
2008-10-29 11:33:26 [22561] DEBUG:PGRsend_load_balance_packet():host[pglb] 
port[6001]
2008-10-29 11:33:26 [22561] DEBUG:PGRsend_load_balance_packet():host[pglb] 
port[6001]

I've got this problem with pgcluster1.7.0rc12 (I have also tested rc09).

Is there a diference between Daemon mode et debug mode of pgreplicate ???
Why does it work in debug mode and not in daemon mode ?

thanck you for help

Best regards
Nicolas Gaston
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://pgfoundry.org/pipermail/pgcluster-general/attachments/20081029/2df921c5/attachment.html 