<div dir="ltr">I know that failover.py did not execute because it did not print anything to the failover.log. If it is executed, i see that the activities is logged to the file, below is the sample:<br><br>Thu Feb 28 16:04:04 2013 failover DEBUG: --><br>
Thu Feb 28 16:04:04 2013 failover DEBUG: FAILED NODEID: 0<br>Thu Feb 28 16:04:04 2013 failover DEBUG: <--<br>Thu Feb 28 16:04:04 2013 failover DEBUG: --><br>Thu Feb 28 16:04:04 2013 failover DEBUG: FAILED HOSTNAME: server0<br>
Thu Feb 28 16:04:04 2013 failover DEBUG: <--<br>Thu Feb 28 16:04:04 2013 failover DEBUG: --><br>Thu Feb 28 16:04:04 2013 failover DEBUG: FAILED PORTNUMBER: 5432<br>Thu Feb 28 16:04:04 2013 failover DEBUG: <--<br>
Thu Feb 28 16:04:04 2013 failover DEBUG: --><br>Thu Feb 28 16:04:04 2013 failover DEBUG: FAILED DBPath: /opt/postgres/9.2/data<br>Thu Feb 28 16:04:04 2013 failover DEBUG: <--<br>Thu Feb 28 16:04:04 2013 failover DEBUG: --><br>
Thu Feb 28 16:04:04 2013 failover DEBUG: NEW_MASTER_NODEID: 1<br>Thu Feb 28 16:04:04 2013 failover DEBUG: <--<br>Thu Feb 28 16:04:04 2013 failover DEBUG: --><br>Thu Feb 28 16:04:04 2013 failover DEBUG: NEW_MASTER_HOSTNAME: server1<br>
Thu Feb 28 16:04:04 2013 failover DEBUG: <--<br>Thu Feb 28 16:04:04 2013 failover DEBUG: --><br>Thu Feb 28 16:04:04 2013 failover DEBUG: OLD_MASTER_NODEID: 0<br>Thu Feb 28 16:04:04 2013 failover DEBUG: <--<br>
Thu Feb 28 16:04:04 2013 failover DEBUG: --><br>Thu Feb 28 16:04:04 2013 failover DEBUG: OLD_PRIMARY_NODEID: 0<br>Thu Feb 28 16:04:04 2013 failover DEBUG: <--<br>Thu Feb 28 16:04:04 2013 failover DEBUG: --><br>
Thu Feb 28 16:04:04 2013 failover DEBUG: NEW_MASTER_PORT: 5432<br>Thu Feb 28 16:04:04 2013 failover DEBUG: <--<br>Thu Feb 28 16:04:04 2013 failover DEBUG: --><br>Thu Feb 28 16:04:04 2013 failover DEBUG: NEW_MASTER_DBPATH: /opt/postgres/9.2/data<br>
Thu Feb 28 16:04:04 2013 failover DEBUG: <--<br>Thu Feb 28 16:04:04 2013 failover.run ERROR: Failed server server0 is an old Primary, and localhost is the new primary, let's failover.<br>Thu Feb 28 16:04:04 2013 failover.run DEBUG: Executing /bin/touch /opt/postgres/9.2/data/trigger_file0<br>
Thu Feb 28 16:04:04 2013 failover.run DEBUG: Failover has been triggered successfully<br>Thu Feb 28 16:04:04 2013 failover.run DEBUG: <--<br></div><div class="gmail_extra"><br><br><div class="gmail_quote">On Thu, Feb 28, 2013 at 11:38 PM, Tatsuo Ishii <span dir="ltr"><<a href="mailto:ishii@postgresql.org" target="_blank">ishii@postgresql.org</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div class="im">> Hi Tatsuo,<br>
> I reproduce the problem on pgpool 3.2.3.<br>
> Basically server1 is the originally primary, and server0 is standby. When<br>
> server1 kernel panic, server0 failover which become the primary, which is<br>
> expected.<br>
> When failed server1 comes back online, execute pcp_recovery on server0 to<br>
> recover and connect it to primary as a standby, which is expected also.<br>
> Now, if server0 kernel panic, pgpool on server1 trigger the failover<br>
> script, however, the script did not really get executed although it is<br>
> logged in the pgpool log.<br>
<br>
</div>How do you determine failover scrit did not get executed?<br>
I see this line:<br>
<div class="im HOEnZb"><br>
Feb 28 21:47:41 server1 pgpool[2054]: execute command:<br>
/home/pgpool/failover.py -d 0 -h server0 -p 5432 -D /opt/postgres/9.2/data<br>
-m 1 -H server1 -M 0 -P 0 -r 5432 -R /opt/postgres/9.2/data<br>
</div><div class="HOEnZb"><div class="h5">--<br>
Tatsuo Ishii<br>
SRA OSS, Inc. Japan<br>
English: <a href="http://www.sraoss.co.jp/index_en.php" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
Japanese: <a href="http://www.sraoss.co.jp" target="_blank">http://www.sraoss.co.jp</a><br>
<br>
> See below for the trace:<br>
><br>
> Feb 28 21:47:40 server1 pgpool[3593]: connect_inet_domain_socket: select()<br>
> timedout. retrying...<br>
> Feb 28 21:47:40 server1 pgpool[3679]: connect_inet_domain_socket: select()<br>
> timedout. retrying...<br>
> Feb 28 21:47:41 server1 pgpool[3594]: wd_create_send_socket: connect()<br>
> reports failure (No route to host). You can safely ignore this while<br>
> starting up.<br>
> Feb 28 21:47:41 server1 pgpool[2054]: pool_flush_it: write failed to<br>
> backend (0). reason: No route to host offset: 0 wlen: 42<br>
> Feb 28 21:47:41 server1 pgpool[2054]: notice_backend_error: called from<br>
> pgpool main. ignored.<br>
> Feb 28 21:47:41 server1 pgpool[2054]: child_exit: called from pgpool main.<br>
> ignored.<br>
> Feb 28 21:47:41 server1 pgpool[2054]: pool_read: EOF encountered with<br>
> backend<br>
> Feb 28 21:47:41 server1 pgpool[2054]: s_do_auth: error while reading<br>
> message kind<br>
> Feb 28 21:47:41 server1 pgpool[2054]: make_persistent_db_connection:<br>
> s_do_auth failed<br>
> Feb 28 21:47:41 server1 pgpool[2054]: health check failed. 0 th host<br>
> server0 at port 5432 is down<br>
> Feb 28 21:47:41 server1 pgpool[2054]: health check retry sleep time: 5<br>
> second(s)<br>
> Feb 28 21:47:41 server1 pgpool[2054]: starting degeneration. shutdown host<br>
> server0(5432)<br>
> Feb 28 21:47:41 server1 pgpool[2054]: Restart all children<br>
> Feb 28 21:47:41 server1 pgpool[2054]: execute command:<br>
> /home/pgpool/failover.py -d 0 -h server0 -p 5432 -D /opt/postgres/9.2/data<br>
> -m 1 -H server1 -M 0 -P 0 -r 5432 -R /opt/postgres/9.2/data<br>
> Feb 28 21:47:41 server1 pgpool[2054]: find_primary_node_repeatedly: waiting<br>
> for finding a primary node<br>
> Feb 28 21:47:41 server1 pgpool[2054]: connect_inet_domain_socket_by_port:<br>
> health check timer expired<br>
> Feb 28 21:47:41 server1 pgpool[2054]: make_persistent_db_connection:<br>
> connection to server1(5432) failed<br>
> Feb 28 21:47:41 server1 pgpool[2054]: find_primary_node:<br>
> make_persistent_connection failed<br>
> Feb 28 21:47:41 server1 pgpool[3679]: connect_inet_domain_socket: select()<br>
> timedout. retrying...<br>
> Feb 28 21:47:42 server1 pgpool[2054]: connect_inet_domain_socket_by_port:<br>
> health check timer expired<br>
><br>
> above logs repeat few times, and after few seconds, i see this:<br>
> Feb 28 21:47:47 server1 pgpool[3679]: check_replication_time_lag: could not<br>
> connect to DB node 0, check sr_check_user and sr_check_password<br>
><br>
> Feb 28 21:48:24 server1 pgpool[2054]: find_primary_node:<br>
> make_persistent_connection failed<br>
> Feb 28 21:48:25 server1 pgpool[3679]: connect_inet_domain_socket: select()<br>
> timedout. retrying...<br>
> Feb 28 21:48:25 server1 pgpool[2057]: wd_lifecheck: lifecheck failed 3<br>
> times. pgpool 0 (server1:9999) seems not to be working<br>
> Feb 28 21:48:25 server1 pgpool[3679]: connect_inet_domain_socket:<br>
> getsockopt() detected error: No route to host<br>
> Feb 28 21:48:25 server1 pgpool[3679]: make_persistent_db_connection:<br>
> connection to server0(5432) failed<br>
> Feb 28 21:48:25 server1 pgpool[2057]: wd_lifecheck: lifecheck failed 3<br>
> times. pgpool 1 (server0:9999) seems not to be working<br>
> Feb 28 21:48:25 server1 pgpool[2057]: wd_lifecheck: watchdog status is<br>
> DOWN. You need to restart this for recovery.<br>
> Feb 28 21:48:25 server1 pgpool[3679]: check_replication_time_lag: could not<br>
> connect to DB node 0, check sr_check_user and sr_check_password<br>
><br>
> Feb 28 21:48:44 server1 pgpool[2057]: wd_lifecheck: lifecheck failed 3<br>
> times. pgpool 0 (server1:9999) seems not to be working<br>
> Feb 28 21:48:44 server1 pgpool[2057]: wd_lifecheck: lifecheck failed 3<br>
> times. pgpool 1 (server0:9999) seems not to be working<br>
><br>
> Feb 28 21:49:10 server1 pgpool[2054]: connect_inet_domain_socket_by_port:<br>
> health check timer expired<br>
> Feb 28 21:49:10 server1 pgpool[2054]: make_persistent_db_connection:<br>
> connection to server1(5432) failed<br>
> Feb 28 21:49:10 server1 pgpool[2054]: find_primary_node:<br>
> make_persistent_connection failed<br>
> Feb 28 21:49:11 server1 pgpool[2054]: failover: no follow backends are<br>
> degenerated<br>
> Feb 28 21:49:11 server1 pgpool[2054]: failover: set new primary node: -1<br>
> Feb 28 21:49:11 server1 pgpool[2054]: failover: set new master node: 1<br>
> Feb 28 21:49:11 server1 pgpool[4012]: do_child: failback event found.<br>
> restart myself.<br>
> Feb 28 21:49:11 server1 pgpool[4013]: do_child: failback event found.<br>
> restart myself.<br>
> Feb 28 21:49:11 server1 pgpool[4014]: do_child: failback event found.<br>
> restart myself.<br>
> Feb 28 21:49:11 server1 pgpool[4015]: do_child: failback event found.<br>
> restart myself.<br>
><br>
> Feb 28 21:49:11 server1 pgpool[4030]: do_child: failback event found.<br>
> restart myself.<br>
> Feb 28 21:49:11 server1 pgpool[4039]: do_child: failback event found.<br>
> restart myself.<br>
> Feb 28 21:49:11 server1 pgpool[4040]: connection received:<br>
> host=server1.local port=41474<br>
> Feb 28 21:49:11 server1 pgpool[4040]: read_startup_packet: incorrect packet<br>
> length (0)<br>
> Feb 28 21:49:11 server1 pgpool[4040]: connection received:<br>
> host=server1.local port=41481<br>
> Feb 28 21:49:11 server1 pgpool[4040]: read_startup_packet: incorrect packet<br>
> length (0)<br>
> Feb 28 21:49:11 server1 pgpool[4040]: connection received:<br>
> host=server1.local port=41485<br>
> Feb 28 21:49:11 server1 pgpool[4040]: read_startup_packet: incorrect packet<br>
> length (0)<br>
> Feb 28 21:49:11 server1 pgpool[4040]: connection received:<br>
> host=server1.local port=41491<br>
> Feb 28 21:49:11 server1 pgpool[4040]: read_startup_packet: incorrect packet<br>
> length (0)<br>
> Feb 28 21:49:11 server1 pgpool[2054]: failover done. shutdown host<br>
> server0(5432)<br>
> Feb 28 21:49:11 server1 pgpool[4029]: do_child: failback event found.<br>
> restart myself.<br>
> Feb 28 21:49:12 server1 pgpool[3678]: pcp child process received restart<br>
> request<br>
> Feb 28 21:49:12 server1 pgpool[2054]: PCP child 3678 exits with status 256<br>
> in failover()<br>
> Feb 28 21:49:12 server1 pgpool[2054]: fork a new PCP child pid 4042 in<br>
> failover()<br>
> Feb 28 21:49:12 server1 pgpool[2054]: worker child 3679 exits with status<br>
> 256<br>
> Feb 28 21:49:12 server1 pgpool[2054]: fork a new worker child pid 4043<br>
> Feb 28 21:49:12 server1 pgpool[4043]: connect_inet_domain_socket_by_port:<br>
> health check timer expired<br>
> Feb 28 21:49:12 server1 pgpool[4043]: make_persistent_db_connection:<br>
> connection to server1(5432) failed<br>
> Feb 28 21:49:12 server1 pgpool[2054]: after some retrying backend returned<br>
> to healthy state<br>
> Feb 28 21:49:13 server1 pgpool[4073]: connection received:<br>
> host=server1.local port=41496<br>
> Feb 28 21:49:13 server1 pgpool[4073]: connect_inet_domain_socket_by_port:<br>
> health check timer expired<br>
> Feb 28 21:49:13 server1 pgpool[4073]: connection to server1(5432) failed<br>
> Feb 28 21:49:13 server1 pgpool[4073]: new_connection: create_cp() failed<br>
> Feb 28 21:49:13 server1 pgpool[4073]: degenerate_backend_set: 1 fail over<br>
> request from pid 4073<br>
> Feb 28 21:49:13 server1 pgpool[2054]: starting degeneration. shutdown host<br>
> server1(5432)<br>
> Feb 28 21:49:13 server1 pgpool[2054]: failover_handler: no valid DB node<br>
> found<br>
> Feb 28 21:49:13 server1 pgpool[2054]: Restart all children<br>
> Feb 28 21:49:13 server1 pgpool[2054]: execute command:<br>
> /home/pgpool/failover.py -d 1 -h server1 -p 5432 -D /opt/postgres/9.2/data<br>
> -m -1 -H -M 1 -P 1 -r -R<br>
> Feb 28 21:49:13 server1 pgpool[2054]: find_primary_node_repeatedly: waiting<br>
> for finding a primary node<br>
> Feb 28 21:49:16 server1 pgpool[2057]: wd_lifecheck: lifecheck failed 3<br>
> times. pgpool 0 (server1:9999) seems not to be working<br>
> Feb 28 21:49:16 server1 pgpool[2057]: wd_lifecheck: lifecheck failed 3<br>
> times. pgpool 1 (server0:9999) seems not to be working<br>
> Feb 28 21:49:16 server1 pgpool[2057]: wd_lifecheck: watchdog status is<br>
> DOWN. You need to restart this for recovery.<br>
> Feb 28 21:49:22 server1 pgpool[4043]: connect_inet_domain_socket_by_port:<br>
> health check timer expired<br>
> Feb 28 21:49:22 server1 pgpool[4043]: make_persistent_db_connection:<br>
> connection to server1(5432) failed<br>
> Feb 28 21:49:32 server1 pgpool[4043]: connect_inet_domain_socket_by_port:<br>
> health check timer expired<br>
> Feb 28 21:49:32 server1 pgpool[4043]: make_persistent_db_connection:<br>
> connection to server1(5432) failed<br>
> Feb 28 21:49:35 server1 pgpool[2057]: wd_lifecheck: lifecheck failed 3<br>
> times. pgpool 0 (server1:9999) seems not to be working<br>
> Feb 28 21:49:35 server1 pgpool[2057]: wd_lifecheck: lifecheck failed 3<br>
> times. pgpool 1 (server0:9999) seems not to be working<br>
> Feb 28 21:49:35 server1 pgpool[2057]: wd_lifecheck: watchdog status is<br>
> DOWN. You need to restart this for recovery.<br>
> Feb 28 21:49:42 server1 pgpool[4043]: connect_inet_domain_socket_by_port:<br>
> health check timer expired<br>
><br>
><br>
> Question 1: why the failover script did not executed? is it becuase primary<br>
> is -1?<br>
> Question 2: why failover script trigger again?<br>
> Question 3: why pgpool on server1 failed? why watchdog on server1 is down?<br>
><br>
> Thanks~<br>
> Ning<br>
><br>
><br>
><br>
><br>
><br>
> On Wed, Feb 27, 2013 at 10:44 PM, ning chan <<a href="mailto:ninchan8328@gmail.com">ninchan8328@gmail.com</a>> wrote:<br>
><br>
>> Hi Tatsuo,<br>
>> I am on 3.2.1. I will try 3.2.3 and report back to you.<br>
>><br>
>> Meanwhile, I have question about the backend server setting in the<br>
>> pgpool.conf<br>
>> I have two pgpools and each of them pointing to the same backend servers,<br>
>> should both pgpool.conf have the same backend_hostname configuration?<br>
>><br>
>> *****pgpool-A****<br>
>> backend_hostname0 = 'se032c-94-30'<br>
>> backend_port0 = 5432<br>
>> backend_weight0 = 1<br>
>> backend_data_directory0 = '/opt/postgres/9.2/data'<br>
>> backend_flag0 = 'ALLOW_TO_FAILOVER'<br>
>><br>
>> backend_hostname1 = 'se032c-94-31'<br>
>> backend_port1 = 5432<br>
>> backend_weight1 = 1<br>
>> backend_data_directory1 = '/opt/postgres/9.2/data'<br>
>> backend_flag1 = 'ALLOW_TO_FAILOVER'<br>
>><br>
>><br>
>> ****pgpool-B****<br>
>> backend_hostname0 = 'se032c-94-30'<br>
>> backend_port0 = 5432<br>
>> backend_weight0 = 1<br>
>> backend_data_directory0 = '/opt/postgres/9.2/data'<br>
>> backend_flag0 = 'ALLOW_TO_FAILOVER'<br>
>><br>
>> backend_hostname1 = 'se032c-94-31'<br>
>> backend_port1 = 5432<br>
>> backend_weight1 = 1<br>
>> backend_data_directory1 = '/opt/postgres/9.2/data'<br>
>> backend_flag1 = 'ALLOW_TO_FAILOVER'<br>
>><br>
>> Thanks~<br>
>> Ning<br>
>><br>
>><br>
>> On Wed, Feb 27, 2013 at 6:12 PM, Tatsuo Ishii <<a href="mailto:ishii@postgresql.org">ishii@postgresql.org</a>>wrote:<br>
>><br>
>>> What version of pgpool-II are you using? We have found a failover<br>
>>> handling problem with 3.2.2 and released 3.2.3 afterwards.<br>
>>> --<br>
>>> Tatsuo Ishii<br>
>>> SRA OSS, Inc. Japan<br>
>>> English: <a href="http://www.sraoss.co.jp/index_en.php" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
>>> Japanese: <a href="http://www.sraoss.co.jp" target="_blank">http://www.sraoss.co.jp</a><br>
>>><br>
>>> > Hi Tatsuo,<br>
>>> > Do you have any chance to look at this problem yet?<br>
>>> ><br>
>>> > Thanks~<br>
>>> > Ning<br>
>>> ><br>
>>> ><br>
>>> > On Tue, Feb 19, 2013 at 3:02 PM, ning chan <<a href="mailto:ninchan8328@gmail.com">ninchan8328@gmail.com</a>><br>
>>> wrote:<br>
>>> ><br>
>>> >> Hi Tatsuo,<br>
>>> >> I figured out the problem to the some scripting error in the<br>
>>> >> pgpool_remote_start to have the incorrect path to pg_ctl.<br>
>>> >> As soon as I corrected it i can recover the failed server and bring it<br>
>>> >> online.<br>
>>> >> I now however facing another problem.<br>
>>> >> After I bring the failed master back in to the pgpool as a standby<br>
>>> server,<br>
>>> >> i then shutdown the currect Primary server and expecting Standby server<br>
>>> >> will be promoted to become the new Primary; however it did not happen.<br>
>>> >> I check the pgpool log, i see failover command is called but it did not<br>
>>> >> execute. I check and confirm my failover script works just fine.<br>
>>> >><br>
>>> >> Here is the log:<br>
>>> >> Feb 19 14:51:40 server0 pgpool[3519]: set 1 th backend down status<br>
>>> >> Feb 19 14:51:43 server0 pgpool[3554]: wd_create_send_socket: connect()<br>
>>> >> reports failure (No route to host). You can safely ignore this while<br>
>>> >> starting up.<br>
>>> >> Feb 19 14:51:43 server0 pgpool[3522]: wd_lifecheck: lifecheck failed 3<br>
>>> >> times. pgpool seems not to be working<br>
>>> >> Feb 19 14:51:43 server0 pgpool[3522]: wd_IP_down: ifconfig down<br>
>>> succeeded<br>
>>> >> Feb 19 14:51:43 server0 pgpool[3519]: starting degeneration. shutdown<br>
>>> host<br>
>>> >> server1(5432)<br>
>>> >> Feb 19 14:51:43 server0 pgpool[3519]: Restart all children<br>
>>> >> Feb 19 14:51:43 server0 pgpool[3519]: execute command:<br>
>>> >> /home/pgpool/failover.py -d 1 -h server1 -p 5432 -D<br>
>>> /opt/postgres/9.2/data<br>
>>> >> -m 0 -H server0 -M 0 -P 1 -r 5432 -R /opt/postgres/9.2/data<br>
>>> >> Feb 19 14:51:43 server0 postgres[3939]: [2-1] LOG: incomplete startup<br>
>>> >> packet<br>
>>> >> Feb 19 14:51:43 server0 postgres[3931]: [2-1] LOG: incomplete startup<br>
>>> >> packet<br>
>>> >> Feb 19 14:51:43 server0 postgres[3935]: [2-1] LOG: incomplete startup<br>
>>> >> packet<br>
>>> >> Feb 19 14:51:43 server0 pgpool[3519]: find_primary_node_repeatedly:<br>
>>> >> waiting for finding a primary node<br>
>>> >> Feb 19 14:51:46 server0 pgpool[3522]: wd_create_send_socket: connect()<br>
>>> >> reports failure (No route to host). You can safely ignore this while<br>
>>> >> starting up.<br>
>>> >> Feb 19 14:51:46 server0 pgpool[3522]: wd_lifecheck: lifecheck failed 3<br>
>>> >> times. pgpool seems not to be working<br>
>>> >> Feb 19 14:51:54 server0 pgpool[3556]: connect_inet_domain_socket:<br>
>>> >> connect() failed: Connection timed out<br>
>>> >> Feb 19 14:51:54 server0 pgpool[3556]: make_persistent_db_connection:<br>
>>> >> connection to server1(5432) failed<br>
>>> >> Feb 19 14:51:54 server0 pgpool[3556]: check_replication_time_lag: could<br>
>>> >> not connect to DB node 1, check sr_check_user and sr_check_password<br>
>>> >> Feb 19 14:52:05 server0 pgpool[3522]: wd_lifecheck: lifecheck failed 3<br>
>>> >> times. pgpool seems not to be working<br>
>>> >> Feb 19 14:52:05 server0 pgpool[3556]: connect_inet_domain_socket:<br>
>>> >> connect() failed: No route to host<br>
>>> >> Feb 19 14:52:05 server0 pgpool[3556]: make_persistent_db_connection:<br>
>>> >> connection to server1(5432) failed<br>
>>> >> Feb 19 14:52:05 server0 pgpool[3556]: check_replication_time_lag: could<br>
>>> >> not connect to DB node 1, check sr_check_user and sr_check_password<br>
>>> >> Feb 19 14:52:05 server0 pgpool[3522]: wd_lifecheck: lifecheck failed 3<br>
>>> >> times. pgpool seems not to be working<br>
>>> >> Feb 19 14:52:14 server0 pgpool[3519]: failover: no follow backends are<br>
>>> >> degenerated<br>
>>> >> Feb 19 14:52:14 server0 pgpool[3519]: failover: set new primary node:<br>
>>> -1<br>
>>> >> Feb 19 14:52:14 server0 pgpool[3519]: failover: set new master node: 0<br>
>>> >> Feb 19 14:52:14 server0 pgpool[3980]: connection received:<br>
>>> >> host=server0.local port=45361<br>
>>> >> Feb 19 14:52:14 server0 pgpool[3556]: worker process received restart<br>
>>> >> request<br>
>>> >> Feb 19 14:52:14 server0 pgpool[3519]: failover done. shutdown host<br>
>>> >> server1(5432)<br>
>>> >><br>
>>> >> As you can see, postgreSQL did not restarted.<br>
>>> >><br>
>>> >> From a successful failover, the log should looks like this:<br>
>>> >> Feb 19 13:47:01 server0 pgpool[4391]: execute command:<br>
>>> >> /home/pgpool/failover.py -d 1 -h server1 -p 5432 -D<br>
>>> /opt/postgres/9.2/data<br>
>>> >> -m 0 -H server0 -M 0 -P 1 -r 5432 -R /opt/postgres/9.2/data<br>
>>> >> Feb 19 13:47:01 server0 postgres[4786]: [2-1] LOG: incomplete startup<br>
>>> >> packet<br>
>>> >> Feb 19 13:47:02 server0 pgpool[4391]: find_primary_node_repeatedly:<br>
>>> >> waiting for finding a primary node<br>
>>> >> Feb 19 13:47:06 server0 postgres[3083]: [6-1] LOG: trigger file found:<br>
>>> >> /opt/postgres/9.2/data/trigger_file0<br>
>>> >> Feb 19 13:47:06 server0 postgres[3083]: [7-1] LOG: redo done at<br>
>>> 0/91000020<br>
>>> >> Feb 19 13:47:06 server0 postgres[3083]: [8-1] LOG: selected new<br>
>>> timeline<br>
>>> >> ID: 18<br>
>>> >> Feb 19 13:47:06 server0 postgres[3083]: [9-1] LOG: archive recovery<br>
>>> >> complete<br>
>>> >> Feb 19 13:47:06 server0 postgres[3081]: [2-1] LOG: database system is<br>
>>> >> ready to accept connections<br>
>>> >> Feb 19 13:47:06 server0 postgres[4804]: [2-1] LOG: autovacuum launcher<br>
>>> >> started<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4391]: find_primary_node: primary node<br>
>>> id<br>
>>> >> is 0<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4391]: starting follow degeneration.<br>
>>> >> shutdown host server1(5432)<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4391]: failover: 1 follow backends have<br>
>>> >> been degenerated<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4391]: failover: set new primary node: 0<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4391]: failover: set new master node: 0<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4817]: connection received:<br>
>>> >> host=server1.local port=54619<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4816]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4818]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4819]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4815]: start triggering follow command.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4815]: execute command: echo 1 server1<br>
>>> 5432<br>
>>> >> /opt/postgres/9.2/data 0 server0 0 1 5432 /opt/postgres/9.2/data %<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4821]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4822]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4823]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4820]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4827]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4828]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4826]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4829]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4830]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4831]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4832]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4833]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4834]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4833]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4834]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4835]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4836]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4837]: do_child: failback event found.<br>
>>> >> restart myself.<br>
>>> >> Feb 19 13:47:07 server0 pgpool[4391]: failover done. shutdown host<br>
>>> >> server1(5432)<br>
>>> >><br>
>>> >> Any idea why failover did not work after the recovery? Do i need to<br>
>>> >> restart remote pgpool after recovery?<br>
>>> >><br>
>>> >><br>
>>> >> On Mon, Feb 18, 2013 at 4:24 PM, ning chan <<a href="mailto:ninchan8328@gmail.com">ninchan8328@gmail.com</a>><br>
>>> wrote:<br>
>>> >><br>
>>> >>><br>
>>> >>> Hi Tatsuo,<br>
>>> >>> Sorry for the late reply as I was traveling.<br>
>>> >>> I am able to reproduce the problem and here is what I did:<br>
>>> >>><br>
>>> >>> *1) Make sure primary (server0) and standby (server1) connections are<br>
>>> >>> good.*<br>
>>> >>> [root@server0 tmp]# psql -c "show pool_nodes" -p 9999<br>
>>> >>> node_id | hostname | port | status | lb_weight | role<br>
>>> >>> ---------+----------+------+--------+-----------+---------<br>
>>> >>> 0 | server0 | 5432 | 2 | 0.500000 | primary<br>
>>> >>> 1 | server1 | 5432 | 2 | 0.500000 | standby<br>
>>> >>> (2 rows)<br>
>>> >>><br>
>>> >>> [root@server1 tmp]# psql -c "show pool_nodes" -p 9999<br>
>>> >>> node_id | hostname | port | status | lb_weight | role<br>
>>> >>> ---------+----------+------+--------+-----------+---------<br>
>>> >>> 0 | server0 | 5432 | 2 | 0.500000 | primary<br>
>>> >>> 1 | server1 | 5432 | 2 | 0.500000 | standby<br>
>>> >>> (2 rows)<br>
>>> >>><br>
>>> >>> *2) force shutdown primary (server0), and standby (server1) server was<br>
>>> >>> promoted, below is the pgpool log from server1 during the failover:*<br>
>>> >>> Feb 18 15:31:45 server1 pgpool[2691]: connect_inet_domain_socket:<br>
>>> >>> connect() failed: No route to host<br>
>>> >>> Feb 18 15:31:45 server1 pgpool[2691]: make_persistent_db_connection:<br>
>>> >>> connection to server0(5432) failed<br>
>>> >>> Feb 18 15:31:45 server1 pgpool[2691]: check_replication_time_lag:<br>
>>> could<br>
>>> >>> not connect to DB node 0, check sr_check_user and sr_check_password<br>
>>> >>> Feb 18 15:31:45 server1 pgpool[2689]: connect_inet_domain_socket:<br>
>>> >>> connect() failed: No route to host<br>
>>> >>> Feb 18 15:31:45 server1 pgpool[2689]: connection to server0(5432)<br>
>>> failed<br>
>>> >>> Feb 18 15:31:45 server1 pgpool[2689]: new_connection: create_cp()<br>
>>> failed<br>
>>> >>> Feb 18 15:31:45 server1 pgpool[2689]: degenerate_backend_set: 0 fail<br>
>>> over<br>
>>> >>> request from pid 2689<br>
>>> >>> Feb 18 15:31:48 server1 pgpool[2689]: wd_create_send_socket: connect()<br>
>>> >>> reports failure (No route to host). You can safely ignore this while<br>
>>> >>> starting up.<br>
>>> >>> Feb 18 15:31:48 server1 pgpool[2653]: connect_inet_domain_socket:<br>
>>> >>> connect() failed: No route to host<br>
>>> >>> Feb 18 15:31:48 server1 pgpool[2653]: make_persistent_db_connection:<br>
>>> >>> connection to server0(5432) failed<br>
>>> >>> Feb 18 15:31:48 server1 pgpool[2653]: health check failed. 0 th host<br>
>>> >>> server0 at port 5432 is down<br>
>>> >>> Feb 18 15:31:48 server1 pgpool[2653]: health check retry sleep time: 5<br>
>>> >>> second(s)<br>
>>> >>> Feb 18 15:31:48 server1 pgpool[2653]: starting degeneration. shutdown<br>
>>> >>> host server0(5432)<br>
>>> >>> Feb 18 15:31:48 server1 pgpool[2653]: Restart all children<br>
>>> >>> Feb 18 15:31:48 server1 pgpool[2653]: execute command:<br>
>>> >>> /home/pgpool/failover.py -d 0 -h server0 -p 5432 -D<br>
>>> /opt/postgres/9.2/data<br>
>>> >>> -m 1 -H server1 -M 0 -P 0 -r 5432 -R /opt/postgres/9.2/data<br>
>>> >>> Feb 18 15:31:49 server1 pgpool[2653]: find_primary_node_repeatedly:<br>
>>> >>> waiting for finding a primary node<br>
>>> >>> Feb 18 15:31:53 server1 postgres[1970]: [7-1] LOG: trigger file<br>
>>> found:<br>
>>> >>> /tmp/trigger_file0<br>
>>> >>> Feb 18 15:31:53 server1 postgres[2597]: [3-1] FATAL: terminating<br>
>>> >>> walreceiver process due to administrator command<br>
>>> >>> Feb 18 15:31:53 server1 postgres[1970]: [8-1] LOG: record with zero<br>
>>> >>> length at 0/64000418<br>
>>> >>> Feb 18 15:31:53 server1 postgres[1970]: [9-1] LOG: redo done at<br>
>>> >>> 0/640003B8<br>
>>> >>> Feb 18 15:31:53 server1 postgres[1970]: [10-1] LOG: selected new<br>
>>> >>> timeline ID: 15<br>
>>> >>> Feb 18 15:31:53 server1 postgres[1970]: [11-1] LOG: archive recovery<br>
>>> >>> complete<br>
>>> >>> Feb 18 15:31:53 server1 postgres[1968]: [2-1] LOG: database system is<br>
>>> >>> ready to accept connections<br>
>>> >>> Feb 18 15:31:53 server1 postgres[3168]: [2-1] LOG: autovacuum<br>
>>> launcher<br>
>>> >>> started<br>
>>> >>> Feb 18 15:31:54 server1 pgpool[2653]: find_primary_node: primary node<br>
>>> id<br>
>>> >>> is 1<br>
>>> >>> Feb 18 15:31:54 server1 pgpool[2653]: starting follow degeneration.<br>
>>> >>> shutdown host server0(5432)<br>
>>> >>> Feb 18 15:31:54 server1 pgpool[2653]: failover: 1 follow backends have<br>
>>> >>> been degenerated<br>
>>> >>> Feb 18 15:31:54 server1 pgpool[2653]: failover: set new primary node:<br>
>>> 1<br>
>>> >>> Feb 18 15:31:54 server1 pgpool[2653]: failover: set new master node: 1<br>
>>> >>> Feb 18 15:31:54 server1 pgpool[3171]: connection received:<br>
>>> >>> host=server1.local port=58346<br>
>>> >>> Feb 18 15:31:54 server1 pgpool[3170]: start triggering follow command.<br>
>>> >>> Feb 18 15:31:54 server1 pgpool[3170]: execute command: echo 0 server0<br>
>>> >>> 5432 /opt/postgres/9.2/data 1 server1 0 0 5432 /opt/postgres/9.2/data<br>
>>> %<br>
>>> >>> Feb 18 15:31:54 server1 pgpool[2691]: worker process received restart<br>
>>> >>> request<br>
>>> >>> Feb 18 15:31:54 server1 pgpool[2653]: failover done. shutdown host<br>
>>> >>> server0(5432)<br>
>>> >>><br>
>>> >>> *3) boot up the failed server (server0) as usual, pgpool and database<br>
>>> >>> started up as usual.<br>
>>> >>> *<br>
>>> >>> *after server0 boot up, i check the pool_nodes info, server0 pgpool<br>
>>> >>> still think server0 is the primary:*<br>
>>> >>> [root@server0 ~]# psql -c "show pool_nodes" -p 9999<br>
>>> >>> node_id | hostname | port | status | lb_weight | role<br>
>>> >>> ---------+----------+------+--------+-----------+---------<br>
>>> >>> 0 | server0 | 5432 | 2 | 0.500000 | primary<br>
>>> >>> 1 | server1 | 5432 | 2 | 0.500000 | standby<br>
>>> >>> (2 rows)<br>
>>> >>><br>
>>> >>> server1 pgpool still think server1 is the primary:<br>
>>> >>> [root@server1 tmp]# psql -c "show pool_nodes" -p 9999<br>
>>> >>> node_id | hostname | port | status | lb_weight | role<br>
>>> >>> ---------+----------+------+--------+-----------+---------<br>
>>> >>> 0 | server0 | 5432 | 3 | 0.500000 | standby<br>
>>> >>> 1 | server1 | 5432 | 2 | 0.500000 | primary<br>
>>> >>> (2 rows)<br>
>>> >>><br>
>>> >>> *4) kill the database on server0 to prepare of the recovery*<br>
>>> >>> *as soon as i kill the server0 database, pgpool log shows following:*<br>
>>> >>> Feb 18 15:33:56 server0 pgpool[2153]: execute command:<br>
>>> >>> /home/pgpool/failover.py -d 0 -h server0 -p 5432 -D<br>
>>> /opt/postgres/9.2/data<br>
>>> >>> -m 1 -H server1 -M 0 -P 0 -r 5432 -R /opt/postgres/9.2/data<br>
>>> >>> Feb 18 15:33:57 server0 pgpool[2153]: find_primary_node_repeatedly:<br>
>>> >>> waiting for finding a primary node<br>
>>> >>> Feb 18 15:33:57 server0 pgpool[2153]: find_primary_node: primary node<br>
>>> id<br>
>>> >>> is 1<br>
>>> >>> Feb 18 15:33:57 server0 pgpool[2153]: starting follow degeneration.<br>
>>> >>> shutdown host server0(5432)<br>
>>> >>> Feb 18 15:33:57 server0 pgpool[2153]: failover: 1 follow backends have<br>
>>> >>> been degenerated<br>
>>> >>> Feb 18 15:33:57 server0 pgpool[2153]: failover: set new primary node:<br>
>>> 1<br>
>>> >>> Feb 18 15:33:57 server0 pgpool[2153]: failover: set new master node: 1<br>
>>> >>> Feb 18 15:33:57 server0 pgpool[2534]: start triggering follow command.<br>
>>> >>> Feb 18 15:33:57 server0 pgpool[2534]: execute command: echo 0 server0<br>
>>> >>> 5432 /opt/postgres/9.2/data 1 server1 0 0 5432 /opt/postgres/9.2/data<br>
>>> %<br>
>>> >>> Feb 18 15:33:57 server0 pgpool[2190]: worker process received restart<br>
>>> >>> request<br>
>>> >>> Feb 18 15:33:57 server0 pgpool[2153]: failover done. shutdown host<br>
>>> >>> server0(5432)<br>
>>> >>><br>
>>> >>> pool_nodes shows:<br>
>>> >>> [root@server0 ~]# psql -c "show pool_nodes" -p 9999<br>
>>> >>> node_id | hostname | port | status | lb_weight | role<br>
>>> >>> ---------+----------+------+--------+-----------+---------<br>
>>> >>> 0 | server0 | 5432 | 3 | 0.500000 | standby<br>
>>> >>> 1 | server1 | 5432 | 2 | 0.500000 | primary<br>
>>> >>> (2 rows)<br>
>>> >>><br>
>>> >>><br>
>>> >>> *5) on server1, execute /usr/local/bin/pcp_recovery_node 10 localhost<br>
>>> >>> 9898 pgpool password 0*<br>
>>> >>> server 1 pgpool log shows following:<br>
>>> >>> Feb 18 15:34:52 server1 pgpool[3209]: starting recovery command:<br>
>>> "SELECT<br>
>>> >>> pgpool_recovery('basebackup.sh', 'server0', '/opt/postgres/9.2/data')"<br>
>>> >>> Feb 18 15:34:53 server1 pgpool[3209]: 1st stage is done<br>
>>> >>> Feb 18 15:34:53 server1 pgpool[3209]: check_postmaster_started: try to<br>
>>> >>> connect to postmaster on hostname:server0 database:postgres<br>
>>> user:postgres<br>
>>> >>> (retry 0 times)<br>
>>> >>> Feb 18 15:34:53 server1 pgpool[3209]: check_postmaster_started:<br>
>>> failed to<br>
>>> >>> connect to postmaster on hostname:server0 database:postgres<br>
>>> user:postgres<br>
>>> >>><br>
>>> >>> *The message "fail to connect to postmaster on hostname server0"<br>
>>> >>> continue until the command timeout.<br>
>>> >>> *<br>
>>> >>> *it looks like the 1st stage command is done but pgpool on server1 did<br>
>>> >>> not call the pgpool_remote_start to start the server0 database engine<br>
>>> >>> although the script is there under postgresql data folder<br>
>>> >>> *<br>
>>> >>> [root@server1 data]# ls<br>
>>> >>> backup_label.old data pg_hba.conf pg_notify<br>
>>> >>> pg_stat_tmp PG_VERSION postmaster.pid<br>
>>> >>> base global pg_ident.conf pgpool_remote_start<br>
>>> >>> pg_subtrans pg_xlog recovery.done<br>
>>> >>> basebackup.sh ning.test pg_log pg_serial<br>
>>> >>> pg_tblspc postgresql.conf recovery.standby1<br>
>>> >>> copy-base-backup.sh pg_clog pg_multixact pg_snapshots<br>
>>> >>> pg_twophase postmaster.opts<br>
>>> >>><br>
>>> >>> *during this period, pgpool log on server0 shows the following:*<br>
>>> >>> Feb 18 15:34:42 server0 pgpool[2567]: connection received:<br>
>>> >>> host=server0.local port=45366<br>
>>> >>> Feb 18 15:34:46 server0 pgpool[2567]: connection received:<br>
>>> >>> host=server1.local port=39535<br>
>>> >>> Feb 18 15:34:52 server0 pgpool[2567]: connection received:<br>
>>> >>> host=server0.local port=45381<br>
>>> >>> Feb 18 15:34:56 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server1.local port=39557<br>
>>> >>> Feb 18 15:35:02 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server0.local port=45396<br>
>>> >>> Feb 18 15:35:06 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server1.local port=39576<br>
>>> >>> Feb 18 15:35:12 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server0.local port=45410<br>
>>> >>> Feb 18 15:35:16 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server1.local port=39593<br>
>>> >>> Feb 18 15:35:22 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server0.local port=45425<br>
>>> >>> Feb 18 15:35:26 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server1.local port=39612<br>
>>> >>> Feb 18 15:35:32 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server0.local port=45440<br>
>>> >>> Feb 18 15:35:36 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server1.local port=39630<br>
>>> >>> Feb 18 15:35:42 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server0.local port=45455<br>
>>> >>> Feb 18 15:35:46 server0 pgpool[2565]: connection received:<br>
>>> >>> host=server1.local port=39648<br>
>>> >>><br>
>>> >>> *Below is the script of recovery_1st_stage_command = 'basebackup.sh'*<br>
>>> >>> [root@server1 ~]# more /opt/postgres/9.2/data/basebackup.sh<br>
>>> >>> #! /bin/sh<br>
>>> >>> # Recovery script for streaming replication.<br>
>>> >>> # This script assumes that DB node 0 is primary, and 1 is standby.<br>
>>> >>> #<br>
>>> >>> datadir=$1<br>
>>> >>> desthost=$2<br>
>>> >>> destdir=$3<br>
>>> >>><br>
>>> >>> echo "datadir=$datadir"<br>
>>> >>> echo "desthost=$desthost"<br>
>>> >>> echo "destdir=$destdir"<br>
>>> >>><br>
>>> >>> echo "Executing basebackup.sh" >> /var/log/replication.log<br>
>>> >>><br>
>>> >>> echo "Executing start backup" >> /var/log/replication.log<br>
>>> >>> psql -c "SELECT pg_start_backup('Streaming Replication', true)"<br>
>>> postgres<br>
>>> >>><br>
>>> >>> echo "Executing rsync" >> /var/log/replication.log<br>
>>> >>> echo "rsync -C -a --progress --delete -e ssh --exclude postgresql.conf<br>
>>> >>> --exclude postmaster.pid --exclude postmaster.<br>
>>> >>> opts --exclude pg_log --exclude pg_xlog --exclude recovery.conf<br>
>>> $datadir/<br>
>>> >>> $desthost:$destdir/"<br>
>>> >>><br>
>>> >>> echo "Renaming recovery conf file" >>/var/log/replication.log<br>
>>> >>> echo "ssh -T $desthost mv $destdir/recovery.done<br>
>>> $destdir/recovery.conf"<br>
>>> >>> ssh -T $desthost mv $destdir/recovery.done $destdir/recovery.conf<br>
>>> >>><br>
>>> >>> echo "Removing trigger file"<br>
>>> >>> ssh -T $desthost rm -f /tmp/trigger_file0<br>
>>> >>><br>
>>> >>> echo "Executing stop backup" >> /var/log/replication.log<br>
>>> >>> psql -c "SELECT pg_stop_backup()" postgres<br>
>>> >>><br>
>>> >>> echo "existing basebackup.sh" >> /var/log/replication.log<br>
>>> >>><br>
>>> >>> *Manually execute the command on server1 return the following result:*<br>
>>> >>><br>
>>> >>> [root@server1 data]# ./basebackup.sh /opt/postgres/9.2/data/ server0<br>
>>> >>> /opt/postgres/9.2/data/<br>
>>> >>> datadir=/opt/postgres/9.2/data/<br>
>>> >>> desthost=server0<br>
>>> >>> destdir=/opt/postgres/9.2/data/<br>
>>> >>> pg_start_backup<br>
>>> >>> -----------------<br>
>>> >>> 0/76000020<br>
>>> >>> (1 row)<br>
>>> >>><br>
>>> >>> rsync -C -a --progress --delete -e ssh --exclude postgresql.conf<br>
>>> >>> --exclude postmaster.pid --exclude postmaster.opts --exclude pg_log<br>
>>> >>> --exclude pg_xlog --exclude recovery.conf /opt/postgres/9.2/data//<br>
>>> >>> server0:/opt/postgres/9.2/data//<br>
>>> >>> ssh -T server0 mv /opt/postgres/9.2/data//recovery.done<br>
>>> >>> /opt/postgres/9.2/data//recovery.conf<br>
>>> >>> Removing trigger file<br>
>>> >>> NOTICE: WAL archiving is not enabled; you must ensure that all<br>
>>> required<br>
>>> >>> WAL segments are copied through other means to complete the backup<br>
>>> >>> pg_stop_backup<br>
>>> >>> ----------------<br>
>>> >>> 0/760000E0<br>
>>> >>> (1 row)<br>
>>> >>><br>
>>> >>> Thanks and please advise.<br>
>>> >>><br>
>>> >>> Ning<br>
>>> >>><br>
>>> >>><br>
>>> >>> On Sun, Feb 17, 2013 at 7:05 AM, Tatsuo Ishii <<a href="mailto:ishii@postgresql.org">ishii@postgresql.org</a><br>
>>> >wrote:<br>
>>> >>><br>
>>> >>>> Hi,<br>
>>> >>>><br>
>>> >>>> It seems the standby was unable to start up. Can you show standby<br>
>>> >>>> PostgreSQL's log? Maybe we could find the cause of the problem.<br>
>>> >>>> --<br>
>>> >>>> Tatsuo Ishii<br>
>>> >>>> SRA OSS, Inc. Japan<br>
>>> >>>> English: <a href="http://www.sraoss.co.jp/index_en.php" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
>>> >>>> Japanese: <a href="http://www.sraoss.co.jp" target="_blank">http://www.sraoss.co.jp</a><br>
>>> >>>><br>
>>> >>>> > Hi Tatsuo,<br>
>>> >>>> > Thank you so much for your reply.<br>
>>> >>>> > Actually in my case, i was using the pcp_recovery command and<br>
>>> execute<br>
>>> >>>> it on<br>
>>> >>>> > the current primary server.<br>
>>> >>>> > However, if the remote node (recover node) database is off, i got<br>
>>> the<br>
>>> >>>> > following message on the primary server pgpool log:<br>
>>> >>>> ><br>
>>> >>>> > Jan 31 16:58:10 server0 pgpool[2723]: starting recovery command:<br>
>>> >>>> "SELECT<br>
>>> >>>> > pgpool_recovery('basebackup.sh', 'server1',<br>
>>> '/opt/postgres/9.2/data')"<br>
>>> >>>> > Jan 31 16:58:11 server0 pgpool[2723]: 1st stage is done<br>
>>> >>>> > Jan 31 16:58:11 server0 pgpool[2723]: check_postmaster_started:<br>
>>> try to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:postgres<br>
>>> >>>> user:postgres<br>
>>> >>>> > (retry 0 times)<br>
>>> >>>> > Jan 31 16:58:11 server0 pgpool[2723]: check_postmaster_started:<br>
>>> failed<br>
>>> >>>> to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:postgres<br>
>>> >>>> user:postgres<br>
>>> >>>> > Jan 31 16:58:13 server0 pgpool[2719]: connection received:<br>
>>> >>>> > host=server0.local port=58446<br>
>>> >>>> > Jan 31 16:58:14 server0 pgpool[2723]: check_postmaster_started:<br>
>>> try to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:postgres<br>
>>> >>>> user:postgres<br>
>>> >>>> > (retry 1 times)<br>
>>> >>>> > Jan 31 16:58:14 server0 pgpool[2723]: check_postmaster_started:<br>
>>> failed<br>
>>> >>>> to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:postgres<br>
>>> >>>> user:postgres<br>
>>> >>>> > Jan 31 16:58:14 server0 pgpool[2719]: connection received:<br>
>>> >>>> > host=server1.local port=39928<br>
>>> >>>> > Jan 31 16:58:17 server0 pgpool[2723]: check_postmaster_started:<br>
>>> try to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:postgres<br>
>>> >>>> user:postgres<br>
>>> >>>> > (retry 2 times)<br>
>>> >>>> > Jan 31 16:58:17 server0 pgpool[2723]: check_postmaster_started:<br>
>>> failed<br>
>>> >>>> to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:postgres<br>
>>> >>>> user:postgres<br>
>>> >>>> > Jan 31 16:58:20 server0 pgpool[2723]: check_postmaster_started:<br>
>>> try to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:postgres<br>
>>> >>>> user:postgres<br>
>>> >>>> > (retry 3 times)<br>
>>> >>>> > Jan 31 16:58:20 server0 pgpool[2723]: check_postmaster_started:<br>
>>> failed<br>
>>> >>>> to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:postgres<br>
>>> >>>> user:postgres<br>
>>> >>>> > Jan 31 16:58:23 server0 pgpool[2719]: connection received:<br>
>>> >>>> > host=server0.local port=58464<br>
>>> >>>> > Jan 31 16:58:23 server0 pgpool[2723]: check_postmaster_started:<br>
>>> try to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > (retry 0 times)<br>
>>> >>>> > Jan 31 16:58:23 server0 pgpool[2723]: check_postmaster_started:<br>
>>> failed<br>
>>> >>>> to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > Jan 31 16:58:26 server0 pgpool[2723]: check_postmaster_started:<br>
>>> try to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > (retry 1 times)<br>
>>> >>>> > Jan 31 16:58:26 server0 pgpool[2723]: check_postmaster_started:<br>
>>> failed<br>
>>> >>>> to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > Jan 31 16:58:26 server0 pgpool[2719]: connection received:<br>
>>> >>>> > host=server1.local port=39946<br>
>>> >>>> > Jan 31 16:58:29 server0 pgpool[2723]: check_postmaster_started:<br>
>>> try to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > (retry 2 times)<br>
>>> >>>> > Jan 31 16:58:29 server0 pgpool[2723]: check_postmaster_started:<br>
>>> failed<br>
>>> >>>> to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > Jan 31 16:58:32 server0 pgpool[2723]: check_postmaster_started:<br>
>>> try to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > (retry 3 times)<br>
>>> >>>> > Jan 31 16:58:32 server0 pgpool[2723]: check_postmaster_started:<br>
>>> failed<br>
>>> >>>> to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > Jan 31 16:58:33 server0 pgpool[2719]: connection received:<br>
>>> >>>> > host=server0.local port=58483<br>
>>> >>>> > Jan 31 16:58:35 server0 pgpool[2723]: check_postmaster_started:<br>
>>> try to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > (retry 4 times)<br>
>>> >>>> > Jan 31 16:58:35 server0 pgpool[2723]: check_postmaster_started:<br>
>>> failed<br>
>>> >>>> to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > Jan 31 16:58:38 server0 pgpool[2723]: check_postmaster_started:<br>
>>> try to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> > (retry 5 times)<br>
>>> >>>> > Jan 31 16:58:38 server0 pgpool[2723]: check_postmaster_started:<br>
>>> failed<br>
>>> >>>> to<br>
>>> >>>> > connect to postmaster on hostname:server1 database:template1<br>
>>> >>>> user:postgres<br>
>>> >>>> ><br>
>>> >>>> > here is the exact command i execute on server0 to recover server1,<br>
>>> >>>> > /usr/local/bin/pcp_recovery_node 10 localhost 9898 pgpool password<br>
>>> 1<br>
>>> >>>> ><br>
>>> >>>> > Do you have any idea why?<br>
>>> >>>> ><br>
>>> >>>> > Just FYI, we cannot pgpoolAdmin in our environment.<br>
>>> >>>> ><br>
>>> >>>> ><br>
>>> >>>> > On Sun, Feb 17, 2013 at 12:13 AM, Tatsuo Ishii <<br>
>>> <a href="mailto:ishii@postgresql.org">ishii@postgresql.org</a>><br>
>>> >>>> wrote:<br>
>>> >>>> ><br>
>>> >>>> >> > Hi all,<br>
>>> >>>> >> > I have the following question regarding the recovery of a filed<br>
>>> >>>> Primary<br>
>>> >>>> >> > Database Server.<br>
>>> >>>> >> ><br>
>>> >>>> >> > Question 1: in the documentation, under Streaming Replication<br>
>>> Online<br>
>>> >>>> >> > Recovery section.<br>
>>> >>>> >> ><br>
>>> >>>> >> > <a href="http://www.pgpool.net/docs/latest/pgpool-en.html#stream" target="_blank">http://www.pgpool.net/docs/latest/pgpool-en.html#stream</a><br>
>>> >>>> >> ><br>
>>> >>>> >> > in steps 6:<br>
>>> >>>> >> ><br>
>>> >>>> >> > 1. After completing online recovery, pgpool-II will start<br>
>>> >>>> PostgreSQL<br>
>>> >>>> >> on<br>
>>> >>>> >> > the standby node. Install the script for this purpose on<br>
>>> each DB<br>
>>> >>>> >> > nodes. Sample<br>
>>> >>>> >> > script <<br>
>>> <a href="http://www.pgpool.net/docs/latest/pgpool_remote_start" target="_blank">http://www.pgpool.net/docs/latest/pgpool_remote_start</a>><br>
>>> >>>> is<br>
>>> >>>> >> > included in "sample" directory of the source code. This<br>
>>> script<br>
>>> >>>> uses<br>
>>> >>>> >> ssh.<br>
>>> >>>> >> > You need to allow recovery_user to login from the primary<br>
>>> node<br>
>>> >>>> to the<br>
>>> >>>> >> > standby node without being asked password.<br>
>>> >>>> >> ><br>
>>> >>>> >> > To my understanding, i think the postgreSQL doesn't not need to<br>
>>> be<br>
>>> >>>> online<br>
>>> >>>> >> > for the recovery process right? Since later on it mentions that<br>
>>> >>>> >> > pgpool_remote_start will start up the DB on the failed node.<br>
>>> >>>> >><br>
>>> >>>> >> Acually standby PostgreSQL node should not be started.<br>
>>> >>>> >><br>
>>> >>>> >> > Question 2: in my configuration, i have 2 pgpool server with two<br>
>>> >>>> >> backends.<br>
>>> >>>> >> > Will it work for oneline recovery?<br>
>>> >>>> >><br>
>>> >>>> >> Yes, but online recovery process should be initiated by one of<br>
>>> pgpool,<br>
>>> >>>> >> not both. If you enable pgpool-II 3.2's watchdog, it will take<br>
>>> care of<br>
>>> >>>> >> neccessary interlocking.<br>
>>> >>>> >><br>
>>> >>>> >> > Question 3: when the failed node comes back online, should i use<br>
>>> >>>> >> > pcp_recovery from DB primary or should i use pcp_attach on the<br>
>>> >>>> failed<br>
>>> >>>> >> node<br>
>>> >>>> >> > to recover the failed system? Actually in my case, both methods<br>
>>> do<br>
>>> >>>> not<br>
>>> >>>> >> > recover my system every time.<br>
>>> >>>> >><br>
>>> >>>> >> I'm confused. Didn't you start the online recovery process by<br>
>>> using<br>
>>> >>>> >> pcp_recovery_node?(of course you could do it via pgpoolAdmin).<br>
>>> >>>> >><br>
>>> >>>> >> Anyway pcp_recovery_node automatically attach recovered node, and<br>
>>> you<br>
>>> >>>> >> don't need to execute pcp_attach_node.<br>
>>> >>>> >><br>
>>> >>>> >> I suggest you read tutorial:<br>
>>> >>>> >><br>
>>> >>>><br>
>>> <a href="http://www.pgpool.net/pgpool-web/contrib_docs/simple_sr_setting2/index.html" target="_blank">http://www.pgpool.net/pgpool-web/contrib_docs/simple_sr_setting2/index.html</a><br>
>>> >>>> >> --<br>
>>> >>>> >> Tatsuo Ishii<br>
>>> >>>> >> SRA OSS, Inc. Japan<br>
>>> >>>> >> English: <a href="http://www.sraoss.co.jp/index_en.php" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
>>> >>>> >> Japanese: <a href="http://www.sraoss.co.jp" target="_blank">http://www.sraoss.co.jp</a><br>
>>> >>>> >><br>
>>> >>>><br>
>>> >>><br>
>>> >>><br>
>>> >><br>
>>><br>
>><br>
>><br>
</div></div></blockquote></div><br></div>