<div dir="ltr"><div dir="ltr"><div dir="ltr"><div>I have added pg_ctl status check to ensure no action is taken when node is down but I'll check 3.7.8 version.</div><div><br></div><div dir="ltr">Here's the Pgpool log from the time node2 is shutdown to time node1(already dead old primary) received follow master command.<div>Sorry for double date logging. I'm also including self-explanatory failover.log that I my failover and follow_master scripts generated.</div><div><br></div><div>Arguments passed to scripts for your reference.</div><div><span style="color:rgb(0,0,0);font-family:Menlo;font-size:9pt">failover.sh %d %h %p %D %M %P %m %H %r %R</span></div><div><span style="color:rgb(0,0,0);font-family:Menlo;font-size:9pt">follow_master.sh %d %h %p %D %M %P %m %H %r %R</span></div><div><div><br></div><div>Pool status before shutdown of node 2:</div><div><div>postgres=> show pool_nodes;</div><div> node_id | hostname | port | status | lb_weight | role | select_cnt | load_balance_node | replication_delay </div><div>---------+----------------------------+------+--------+-----------+---------+------------+-------------------+-------------------</div><div> 0 | pg-hdp-node1.kitchen.local | 5432 | down | 0.333333 | standby | 0 | false | 0</div><div> 1 | pg-hdp-node2.kitchen.local | 5432 | up | 0.333333 | primary | 0 | false | 0</div><div> 2 | pg-hdp-node3.kitchen.local | 5432 | up | 0.333333 | standby | 0 | true | 0</div><div>(3 rows)</div></div><div><br></div><div>Pgpool log</div><div>Feb 22 10:43:27 pg-hdp-node3 pgpool[12437]: [126-1] 2019-02-22 10:43:27: pid 12437: LOG: failed to connect to PostgreSQL server on "pg-hdp-node2.kitchen.local:5432", getsockopt() detected error "Connection refused"</div><div>Feb 22 10:43:27 pg-hdp-node3 pgpool[12437]: [127-1] 2019-02-22 10:43:27: pid 12437: ERROR: failed to make persistent db connection</div><div>Feb 22 10:43:27 pg-hdp-node3 pgpool[12437]: [127-2] 2019-02-22 10:43:27: pid 12437: DETAIL: connection to host:"pg-hdp-node2.kitchen.local:5432" failed</div><div>Feb 22 10:43:37 pg-hdp-node3 pgpool[12437]: [128-1] 2019-02-22 10:43:37: pid 12437: ERROR: Failed to check replication time lag</div><div>Feb 22 10:43:37 pg-hdp-node3 pgpool[12437]: [128-2] 2019-02-22 10:43:37: pid 12437: DETAIL: No persistent db connection for the node 1</div><div>Feb 22 10:43:37 pg-hdp-node3 pgpool[12437]: [128-3] 2019-02-22 10:43:37: pid 12437: HINT: check sr_check_user and sr_check_password</div><div>Feb 22 10:43:37 pg-hdp-node3 pgpool[12437]: [128-4] 2019-02-22 10:43:37: pid 12437: CONTEXT: while checking replication time lag</div><div>Feb 22 10:43:37 pg-hdp-node3 pgpool[12437]: [129-1] 2019-02-22 10:43:37: pid 12437: LOG: failed to connect to PostgreSQL server on "pg-hdp-node2.kitchen.local:5432", getsockopt() detected error "Connection refused"</div><div>Feb 22 10:43:37 pg-hdp-node3 pgpool[12437]: [130-1] 2019-02-22 10:43:37: pid 12437: ERROR: failed to make persistent db connection</div><div>Feb 22 10:43:37 pg-hdp-node3 pgpool[12437]: [130-2] 2019-02-22 10:43:37: pid 12437: DETAIL: connection to host:"pg-hdp-node2.kitchen.local:5432" failed</div><div>Feb 22 10:43:45 pg-hdp-node3 pgpool[7786]: [6-1] 2019-02-22 10:43:45: pid 7786: LOG: failed to connect to PostgreSQL server on "pg-hdp-node2.kitchen.local:5432", getsockopt() detected error "Connection refused"</div><div>Feb 22 10:43:45 pg-hdp-node3 pgpool[7786]: [7-1] 2019-02-22 10:43:45: pid 7786: ERROR: failed to make persistent db connection</div><div>Feb 22 10:43:45 pg-hdp-node3 pgpool[7786]: [7-2] 2019-02-22 10:43:45: pid 7786: DETAIL: connection to host:"pg-hdp-node2.kitchen.local:5432" failed</div><div>Feb 22 10:43:45 pg-hdp-node3 pgpool[7786]: [8-1] 2019-02-22 10:43:45: pid 7786: LOG: health check retrying on DB node: 1 (round:1)</div><div>Feb 22 10:43:47 pg-hdp-node3 pgpool[12437]: [131-1] 2019-02-22 10:43:47: pid 12437: ERROR: Failed to check replication time lag</div><div>Feb 22 10:43:47 pg-hdp-node3 pgpool[12437]: [131-2] 2019-02-22 10:43:47: pid 12437: DETAIL: No persistent db connection for the node 1</div><div>Feb 22 10:43:47 pg-hdp-node3 pgpool[12437]: [131-3] 2019-02-22 10:43:47: pid 12437: HINT: check sr_check_user and sr_check_password</div><div>Feb 22 10:43:47 pg-hdp-node3 pgpool[12437]: [131-4] 2019-02-22 10:43:47: pid 12437: CONTEXT: while checking replication time lag</div><div>Feb 22 10:43:47 pg-hdp-node3 pgpool[12437]: [132-1] 2019-02-22 10:43:47: pid 12437: LOG: failed to connect to PostgreSQL server on "pg-hdp-node2.kitchen.local:5432", getsockopt() detected error "Connection refused"</div><div>Feb 22 10:43:47 pg-hdp-node3 pgpool[12437]: [133-1] 2019-02-22 10:43:47: pid 12437: ERROR: failed to make persistent db connection</div><div>Feb 22 10:43:47 pg-hdp-node3 pgpool[12437]: [133-2] 2019-02-22 10:43:47: pid 12437: DETAIL: connection to host:"pg-hdp-node2.kitchen.local:5432" failed</div><div>Feb 22 10:43:48 pg-hdp-node3 pgpool[7786]: [9-1] 2019-02-22 10:43:48: pid 7786: LOG: failed to connect to PostgreSQL server on "pg-hdp-node2.kitchen.local:5432", getsockopt() detected error "Connection refused"</div><div>Feb 22 10:43:48 pg-hdp-node3 pgpool[7786]: [10-1] 2019-02-22 10:43:48: pid 7786: ERROR: failed to make persistent db connection</div><div>Feb 22 10:43:48 pg-hdp-node3 pgpool[7786]: [10-2] 2019-02-22 10:43:48: pid 7786: DETAIL: connection to host:"pg-hdp-node2.kitchen.local:5432" failed</div><div>Feb 22 10:43:48 pg-hdp-node3 pgpool[7786]: [11-1] 2019-02-22 10:43:48: pid 7786: LOG: health check retrying on DB node: 1 (round:2)</div><div>Feb 22 10:43:51 pg-hdp-node3 pgpool[7786]: [12-1] 2019-02-22 10:43:51: pid 7786: LOG: failed to connect to PostgreSQL server on "pg-hdp-node2.kitchen.local:5432", getsockopt() detected error "Connection refused"</div><div>Feb 22 10:43:51 pg-hdp-node3 pgpool[7786]: [13-1] 2019-02-22 10:43:51: pid 7786: ERROR: failed to make persistent db connection</div><div>Feb 22 10:43:51 pg-hdp-node3 pgpool[7786]: [13-2] 2019-02-22 10:43:51: pid 7786: DETAIL: connection to host:"pg-hdp-node2.kitchen.local:5432" failed</div><div>Feb 22 10:43:51 pg-hdp-node3 pgpool[7786]: [14-1] 2019-02-22 10:43:51: pid 7786: LOG: health check retrying on DB node: 1 (round:3)</div><div>Feb 22 10:43:54 pg-hdp-node3 pgpool[7786]: [15-1] 2019-02-22 10:43:54: pid 7786: LOG: failed to connect to PostgreSQL server on "pg-hdp-node2.kitchen.local:5432", getsockopt() detected error "Connection refused"</div><div>Feb 22 10:43:54 pg-hdp-node3 pgpool[7786]: [16-1] 2019-02-22 10:43:54: pid 7786: ERROR: failed to make persistent db connection</div><div>Feb 22 10:43:54 pg-hdp-node3 pgpool[7786]: [16-2] 2019-02-22 10:43:54: pid 7786: DETAIL: connection to host:"pg-hdp-node2.kitchen.local:5432" failed</div><div>Feb 22 10:43:54 pg-hdp-node3 pgpool[7786]: [17-1] 2019-02-22 10:43:54: pid 7786: LOG: health check failed on node 1 (timeout:0)</div><div>Feb 22 10:43:54 pg-hdp-node3 pgpool[7786]: [18-1] 2019-02-22 10:43:54: pid 7786: LOG: received degenerate backend request for node_id: 1 from pid [7786]</div><div>Feb 22 10:43:54 pg-hdp-node3 pgpool[7746]: [253-1] 2019-02-22 10:43:54: pid 7746: LOG: Pgpool-II parent process has received failover request</div><div>Feb 22 10:43:54 pg-hdp-node3 pgpool[7746]: [254-1] 2019-02-22 10:43:54: pid 7746: LOG: starting degeneration. shutdown host pg-hdp-node2.kitchen.local(5432)</div><div>Feb 22 10:43:54 pg-hdp-node3 pgpool[7746]: [255-1] 2019-02-22 10:43:54: pid 7746: LOG: Restart all children</div><div>Feb 22 10:43:54 pg-hdp-node3 pgpool[7746]: [256-1] 2019-02-22 10:43:54: pid 7746: LOG: execute command: /etc/pgpool-II/failover.sh 1 pg-hdp-node2.kitchen.local 5432 /var/lib/pgsql/10/data 1 1 2 pg-hdp-node3.kitchen.local 5432 /var/lib/pgsql/10/data</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [257-1] 2019-02-22 10:43:55: pid 7746: LOG: find_primary_node_repeatedly: waiting for finding a primary node</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [258-1] 2019-02-22 10:43:55: pid 7746: LOG: find_primary_node: checking backend no 0</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [259-1] 2019-02-22 10:43:55: pid 7746: LOG: find_primary_node: checking backend no 1</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [260-1] 2019-02-22 10:43:55: pid 7746: LOG: find_primary_node: checking backend no 2</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [261-1] 2019-02-22 10:43:55: pid 7746: LOG: find_primary_node: primary node id is 2</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [262-1] 2019-02-22 10:43:55: pid 7746: LOG: starting follow degeneration. shutdown host pg-hdp-node1.kitchen.local(5432)</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [263-1] 2019-02-22 10:43:55: pid 7746: LOG: starting follow degeneration. shutdown host pg-hdp-node2.kitchen.local(5432)</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [264-1] 2019-02-22 10:43:55: pid 7746: LOG: failover: 2 follow backends have been degenerated</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [265-1] 2019-02-22 10:43:55: pid 7746: LOG: failover: set new primary node: 2</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [266-1] 2019-02-22 10:43:55: pid 7746: LOG: failover: set new master node: 2</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[7746]: [267-1] 2019-02-22 10:43:55: pid 7746: LOG: failover done. shutdown host pg-hdp-node2.kitchen.local(5432)</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[12437]: [134-1] 2019-02-22 10:43:55: pid 12437: ERROR: Failed to check replication time lag</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[12437]: [134-2] 2019-02-22 10:43:55: pid 12437: DETAIL: No persistent db connection for the node 1</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[12437]: [134-3] 2019-02-22 10:43:55: pid 12437: HINT: check sr_check_user and sr_check_password</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[12437]: [134-4] 2019-02-22 10:43:55: pid 12437: CONTEXT: while checking replication time lag</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[12437]: [135-1] 2019-02-22 10:43:55: pid 12437: LOG: worker process received restart request</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[12774]: [267-1] 2019-02-22 10:43:55: pid 12774: LOG: failback event detected</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[12774]: [267-2] 2019-02-22 10:43:55: pid 12774: DETAIL: restarting myself</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[12742]: [265-1] 2019-02-22 10:43:55: pid 12742: LOG: start triggering follow command.</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[12742]: [266-1] 2019-02-22 10:43:55: pid 12742: LOG: execute command: /etc/pgpool-II/follow_master.sh 0 pg-hdp-node1.kitchen.local 5432 /var/lib/pgsql/10/data 1 1 2 pg-hdp-node3.kitchen.local 5432 /var/lib/pgsql/10/data</div><div>Feb 22 10:43:55 pg-hdp-node3 pgpool[12742]: [267-1] 2019-02-22 10:43:55: pid 12742: LOG: execute command: /etc/pgpool-II/follow_master.sh 1 pg-hdp-node2.kitchen.local 5432 /var/lib/pgsql/10/data 1 1 2 pg-hdp-node3.kitchen.local 5432 /var/lib/pgsql/10/data</div><div>Feb 22 10:43:56 pg-hdp-node3 pgpool[12436]: [60-1] 2019-02-22 10:43:56: pid 12436: LOG: restart request received in pcp child process</div><div>Feb 22 10:43:56 pg-hdp-node3 pgpool[7746]: [268-1] 2019-02-22 10:43:56: pid 7746: LOG: PCP child 12436 exits with status 0 in failover()</div></div><div><br></div><div>Pgpool self-explanatory failover.log</div><div><br></div><div><div>2019-02-22 10:43:54.893 PST Executing failover script ...</div><div>2019-02-22 10:43:54.895 PST Script arguments:</div><div>failed_node_id 1</div><div>failed_node_host pg-hdp-node2.kitchen.local</div><div>failed_node_port 5432</div><div>failed_node_pgdata /var/lib/pgsql/10/data</div><div>old_primary_node_id 1</div><div>old_master_node_id 1</div><div>new_master_node_id 2</div><div>new_master_node_host pg-hdp-node3.kitchen.local</div><div>new_master_node_port 5432</div><div>new_master_node_pgdata /var/lib/pgsql/10/data</div><div>2019-02-22 10:43:54.897 PST Primary node running on pg-hdp-node2.kitchen.local host is unresponsive or have died</div><div>2019-02-22 10:43:54.898 PST Attempting to stop primary node running on pg-hdp-node2.kitchen.local host before promoting slave as the new primary</div><div>2019-02-22 10:43:54.899 PST ssh -o StrictHostKeyChecking=no -i /var/lib/pgsql/.ssh/id_rsa postgres@pg-hdp-node2.kitchen.local -T /usr/pgsql-10/bin/pg_ctl -D /var/lib/pgsql/10/data stop -m fast</div><div>2019-02-22 10:43:55.151 PST Promoting pg-hdp-node3.kitchen.local host as the new primary</div><div>2019-02-22 10:43:55.153 PST ssh -o StrictHostKeyChecking=no -i /var/lib/pgsql/.ssh/id_rsa postgres@pg-hdp-node3.kitchen.local -T /usr/pgsql-10/bin/pg_ctl -D /var/lib/pgsql/10/data promote</div><div>waiting for server to promote.... done</div><div>server promoted</div><div>2019-02-22 10:43:55.532 PST Completed executing failover </div><div><br></div><div>2019-02-22 10:43:55.564 PST Executing follow master script ...</div><div>2019-02-22 10:43:55.566 PST Script arguments</div><div>detached_node_id 0</div><div>detached_node_host pg-hdp-node1.kitchen.local</div><div>detached_node_port 5432</div><div>detached_node_pgdata /var/lib/pgsql/10/data</div><div>old_primary_node_id 1</div><div>old_master_node_id 1</div><div>new_master_node_id 2</div><div>new_master_node_host pg-hdp-node3.kitchen.local</div><div>new_master_node_port 5432</div><div>new_master_node_pgdata /var/lib/pgsql/10/data</div><div>2019-02-22 10:43:55.567 PST Checking if server is running on pg-hdp-node1.kitchen.local host</div><div>2019-02-22 10:43:55.569 PST ssh -o StrictHostKeyChecking=no -i /var/lib/pgsql/.ssh/id_rsa postgres@pg-hdp-node1.kitchen.local -T /usr/pgsql-10/bin/pg_ctl -D /var/lib/pgsql/10/data status</div><div><br></div><div><br></div><div>pg_ctl: no server running</div><div>2019-02-22 10:43:55.823 PST Node on pg-hdp-node1.kitchen.local host is not running. It could be old slave or primary that needs to be recovered.</div><div>2019-02-22 10:43:55.824 PST Completed executing follow master script</div><div><br></div><div>2019-02-22 10:43:55.829 PST Executing follow master script ...</div><div>2019-02-22 10:43:55.830 PST Script arguments</div><div>detached_node_id 1</div><div>detached_node_host pg-hdp-node2.kitchen.local</div><div>detached_node_port 5432</div><div>detached_node_pgdata /var/lib/pgsql/10/data</div><div>old_primary_node_id 1</div><div>old_master_node_id 1</div><div>new_master_node_id 2</div><div>new_master_node_host pg-hdp-node3.kitchen.local</div><div>new_master_node_port 5432</div><div>new_master_node_pgdata /var/lib/pgsql/10/data</div><div>2019-02-22 10:43:55.831 PST Detached node on pg-hdp-node2.kitchen.local host is the the old primary node</div><div>2019-02-22 10:43:55.833 PST Slave can be created from old primary node by deleting PG_DATA directory under /var/lib/pgsql/10/data on pg-hdp-node2.kitchen.local host and re-running Chef client</div><div>2019-02-22 10:43:55.834 PST Slave can be recovered from old primary node by running /usr/pgsql-10/bin/pg_rewind -D /var/lib/pgsql/10/data --source-server="port=5432 host=pg-hdp-node3.kitchen.local" command on pg-hdp-node2.kitchen.local host as postgres user</div><div>2019-02-22 10:43:55.835 PST After successful pg_rewind run cp /var/lib/pgsql/10/data/recovery.done /var/lib/pgsql/10/data/recovery.conf, ensure host connection string points to pg-hdp-node3.kitchen.local, start PostgreSQL and attach it to pgpool</div><div>2019-02-22 10:43:55.836 PST Completed executing follow master script</div></div></div></div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Thu, Feb 21, 2019 at 4:47 PM Tatsuo Ishii <<a href="mailto:ishii@sraoss.co.jp">ishii@sraoss.co.jp</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">> Is this correct behavior?<br>
> <br>
> In 3-node setup, node1(primary) is shutdown, failover is executed and node2<br>
> becomes new primary and node3 follows new primary on node2.<br>
> Now, node2(new primary) is shutdown, failover is executed and node3 becomes<br>
> new primary but fallow_master_command is executed on node1 even though it<br>
> is reported as down.<br>
<br>
No. follow master command should not be executed on an already-down<br>
node (in this case node1).<br>
<br>
> It happens that my script repoints node1 and restarts it which breaks hell<br>
> because node1 was never recovered after being shutdown.<br>
> <br>
> I'm on PgPool 3.7.4.<br>
<br>
Can you share the log from when node2 was shutdown to when node1 was<br>
recovered by your follow master command?<br>
<br>
In the mean time 3.7.4 is not the latest one. Can you try with the<br>
latest one? (3.7.8).<br>
<br>
Best regards,<br>
--<br>
Tatsuo Ishii<br>
SRA OSS, Inc. Japan<br>
English: <a href="http://www.sraoss.co.jp/index_en.php" rel="noreferrer" target="_blank">http://www.sraoss.co.jp/index_en.php</a><br>
Japanese:<a href="http://www.sraoss.co.jp" rel="noreferrer" target="_blank">http://www.sraoss.co.jp</a><br>
</blockquote></div><br clear="all"><div><br></div>-- <br><div dir="ltr" class="gmail_signature"><div dir="ltr"><p><b><span style="color:rgb(64,64,64)">Andre Piwoni</span></b></p>
<p><span style="color:rgb(64,64,64)">Sr. Software Developer,
BI/Database</span></p>
<p><b><i><span style="color:rgb(31,73,125)">Web</span></i></b><span style="color:black">MD Health Services</span><span style="font-family:"Times New Roman",serif;color:black"></span></p>
<p><span style="color:rgb(64,64,64)">Mobile: 801.541.4722</span></p>
<p><span style="color:rgb(31,73,125)"><a href="http://www.webmdhealthservices.com/" target="_blank"><span style="color:blue">www.webmdhealthservices.com</span></a></span><span style="color:rgb(64,64,64)"></span></p></div></div>