postgresql 高可用 etcd + patroni 之四 failover
os: centos 7.4
postgresql: 9.6.9
etcd: 3.2.18
patroni: 1.4.4
patroni + etcd 是在一个postgrsql 开源大会上 亚信的一个哥们讲解的高可用方案。
依然是基于 postgreql stream replication。
ip规划
192.168.56.101 node1 master
192.168.56.102 node2 slave
192.168.56.103 node3 slave
验证failover
node1 的 master 关闭
# systemctl stop postgresql-9.6.service
mode1 的 patroni 马上就有信息输出
2018-07-11 21:43:52,402 INFO: Lock owner: pg96_101; I am pg96_101
2018-07-11 21:43:52,441 INFO: no action. i am the leader with the lock
2018-07-11 21:44:02,405 WARNING: Postgresql is not running.
2018-07-11 21:44:02,406 INFO: Lock owner: pg96_101; I am pg96_101
2018-07-11 21:44:02,444 INFO: Lock owner: pg96_101; I am pg96_101
2018-07-11 21:44:02,455 INFO: starting as readonly because i had the session lock
2018-07-11 21:44:02,456 INFO: closed patroni connection to the postgresql cluster
2018-07-11 21:44:02,491 INFO: postmaster pid=11705
192.168.56.101:5432 - no response
< 2018-07-11 21:44:02.525 CST > LOG: redirecting log output to logging collector process
< 2018-07-11 21:44:02.525 CST > HINT: Future log output will appear in directory "pg_log".
192.168.56.101:5432 - accepting connections
192.168.56.101:5432 - accepting connections
2018-07-11 21:44:03,555 INFO: Lock owner: pg96_101; I am pg96_101
2018-07-11 21:44:03,555 INFO: establishing a new patroni connection to the postgres cluster
2018-07-11 21:44:03,597 INFO: promoted self to leader because i had the session lock
server promoting
2018-07-11 21:44:03,603 INFO: cleared rewind state after becoming the leader
看到日志输出，马上就把 master 拉起来了。
node1 的 os 掉电
节点掉电是一种极端的情况，在各种ha架构中都会模拟。
可以看到其中一个节点的patroni 很快就有信息输出
2018-07-11 21:49:44,632 INFO: Lock owner: pg96_101; I am pg96_103
2018-07-11 21:49:44,632 INFO: does not have lock
2018-07-11 21:49:44,642 INFO: no action. i am a secondary and i am following a leader
2018-07-11 21:49:55,140 INFO: Selected new etcd server http://192.168.56.101:2379
2018-07-11 21:49:57,643 WARNING: Retrying (Retry(total=0, connect=None, read=None, redirect=0, status=None)) after connection broken by 'ConnectTimeoutError(<urllib3.connection.HTTPConnection object at 0x7f2072ca2b50>, u'Connection to 192.168.56.101 timed out. (connect timeout=2.5)')': /v2/keys/pg96/pg96/?recursive=true
2018-07-11 21:50:00,148 ERROR: Request to server http://192.168.56.101:2379 failed: MaxRetryError(u"HTTPConnectionPool(host=u'192.168.56.101', port=2379): Max retries exceeded with url: /v2/keys/pg96/pg96/?recursive=true (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at 0x7f2072ca2c10>, u'Connection to 192.168.56.101 timed out. (connect timeout=2.5)'))",)
2018-07-11 21:50:00,149 INFO: Reconnection allowed, looking for another server.
2018-07-11 21:50:00,149 INFO: Selected new etcd server http://192.168.56.102:2379
2018-07-11 21:50:00,172 INFO: Lock owner: pg96_101; I am pg96_103
2018-07-11 21:50:00,172 INFO: does not have lock
2018-07-11 21:50:00,191 INFO: no action. i am a secondary and i am following a leader
2018-07-11 21:50:05,137 INFO: Selected new etcd server http://192.168.56.103:2379
2018-07-11 21:50:05,141 INFO: Lock owner: pg96_101; I am pg96_103
2018-07-11 21:50:05,141 INFO: does not have lock
2018-07-11 21:50:05,146 INFO: no action. i am a secondary and i am following a leader
2018-07-11 21:50:15,060 INFO: Got response from pg96_102 http://127.0.0.1:8008/patroni: {"database_system_identifier": "6576484813966394513", "postmaster_start_time": "2018-07-11 17:38:41.768 CST", "timeline": 2, "xlog": {"received_location": 50379696, "replayed_timestamp": "2018-07-11 18:03:34.386 CST", "paused": false, "replayed_location": 50379696}, "patroni": {"scope": "pg96", "version": "1.4.4"}, "state": "running", "role": "replica", "server_version": 90609}
2018-07-11 21:50:15,066 INFO: Got response from pg96_101 http://127.0.0.1:8008/patroni: {"database_system_identifier": "6576484813966394513", "postmaster_start_time": "2018-07-11 17:38:41.768 CST", "timeline": 2, "xlog": {"received_location": 50379696, "replayed_timestamp": "2018-07-11 18:03:34.386 CST", "paused": false, "replayed_location": 50379696}, "patroni": {"scope": "pg96", "version": "1.4.4"}, "state": "running", "role": "replica", "server_version": 90609}
2018-07-11 21:50:15,113 WARNING: Could not activate Linux watchdog device: "Can't open watchdog device: [Errno 2] No such file or directory: '/dev/watchdog'"
2018-07-11 21:50:15,119 INFO: promoted self to leader by acquiring session lock
server promoting
2018-07-11 21:50:15,190 INFO: cleared rewind state after becoming the leader
2018-07-11 21:50:16,257 INFO: Lock owner: pg96_103; I am pg96_103
2018-07-11 21:50:16,318 INFO: no action. i am the leader with the lock
2018-07-11 21:50:26,254 INFO: Lock owner: pg96_103; I am pg96_103
2018-07-11 21:50:26,279 INFO: no action. i am the leader with the lock
看到 日志输出有 server promoting。说明该节点的 slave 被提升为新的master
再次查看 patroni 集群状态
$ patronictl -c /usr/patroni/conf/patroni_postgresql.yml list pg96
+---------+----------+----------------+--------+---------+-----------+
| Cluster | Member | Host | Role | State | Lag in MB |
+---------+----------+----------------+--------+---------+-----------+
| pg96 | pg96_102 | 192.168.56.102 | | running | 0.0 |
| pg96 | pg96_103 | 192.168.56.103 | Leader | running | 0.0 |
+---------+----------+----------------+--------+---------+-----------+
果然如预期一样。这个时候再 node3 节点上查看复制情况。
select client_addr,
pg_xlog_location_diff(sent_location, write_location) as write_delay,
pg_xlog_location_diff(sent_location, flush_location) as flush_delay,
pg_xlog_location_diff(sent_location, replay_location) as replay_delay
from pg_stat_replication;
client_addr | write_delay | flush_delay | replay_delay
----------------+-------------+-------------+--------------
192.168.56.102 | 0 | 0 | 0
(1 row)
哈哈。
再启动node1后，查看信息
# ps -ef|grep -i etcd
etcd 996 1 2 21:57 ? 00:00:00 /usr/bin/etcd --name=node1 --data-dir=/var/lib/etcd/node1.etcd --listen-peer-urls=http://192.168.56.101:2380,http://127.0.0.1:2380 --listen-client-urls=http://192.168.56.101:2379,http://127.0.0.1:2379 --initial-advertise-peer-urls=http://192.168.56.101:2380 --advertise-client-urls=http://192.168.56.101:2379 --initial-cluster=node1=http://192.168.56.101:2380,node2=http://192.168.56.102:2380,node3=http://192.168.56.103:2380 --initial-cluster-token=etcd-cluster --initial-cluster-state=new
root 1486 1332 0 21:57 pts/0 00:00:00 grep --color=auto -i etcd
patroni 没有起来，需要后面设置为随OS启动。手动启动postgresql, patroni
$ mv recovery.done recovery.conf
$ cat recovery.conf
primary_slot_name = 'pg96_101'
standby_mode = 'on'
recovery_target_timeline = 'latest'
primary_conninfo = 'user=replicator password=1qaz2wsx host=192.168.56.103 port=5432 sslmode=prefer sslcompression=1 application_name=pg96_101'
# systemctl start postgresql-9.6.service
$ patroni /usr/patroni/conf/patroni_postgresql.yml
查看 patroni 集群状态后，发现node1的postgreql居然没有加进去。
$ patronictl -c /usr/patroni/conf/patroni_postgresql.yml list pg96
+---------+----------+----------------+--------+---------+-----------+
| Cluster | Member | Host | Role | State | Lag in MB |
+---------+----------+----------------+--------+---------+-----------+
| pg96 | pg96_102 | 192.168.56.102 | | running | 0.0 |
| pg96 | pg96_103 | 192.168.56.103 | Leader | running | 0.0 |
+---------+----------+----------------+--------+---------+-----------+
查看日志后提示信息为 "replication slot ““pg96_101"” does not exist”,“pg96_101”
奇怪了，前面明明创建了 pg96_101 的slot，node3的日志居然提示没有。
postgres=# select * from pg_replication_slots;
-[ RECORD 1 ]-------+----------
slot_name | pg96_102
plugin |
slot_type | physical
datoid |
database |
active | t
active_pid | 19347
xmin |
catalog_xmin |
restart_lsn | 0/300C058
confirmed_flush_lsn |
确实没有，汗，那就再尝试创建一个吧。
select * from pg_create_physical_replication_slot('pg96_101');
node3 的日志里提示：
$ tail -n 1000 postgresql-2018-07-11.csv
2018-07-11 22:14:27.247 CST,"replicator","",19982,"192.168.56.101:53204",5b4610c3.4e0e,3,"idle",2018-07-11 22:14:27 CST,5/0,0,ERROR,42704,"replication slot ""pg96_101"" does not exist",,,,,,,,,"pg96_101"
2018-07-11 22:14:27.248 CST,"replicator","",19982,"192.168.56.101:53204",5b4610c3.4e0e,4,"idle",2018-07-11 22:14:27 CST,,0,LOG,00000,"disconnection: session time: 0:00:00.005 user=replicator database= host=192.168.56.101 port=53204",,,,,,,,,"pg96_101"
2018-07-11 22:14:28.367 CST,"postgres","postgres",19929,"[local]",5b461068.4dd9,6,"SELECT",2018-07-11 22:12:56 CST,4/0,0,LOG,00000,"duration: 29.076 ms",,,,,,,,,"psql"
2018-07-11 22:14:30.777 CST,"postgres","postgres",19929,"[local]",5b461068.4dd9,7,"SELECT",2018-07-11 22:12:56 CST,4/0,0,LOG,00000,"duration: 1.060 ms",,,,,,,,,"psql"
2018-07-11 22:14:32.249 CST,,,19984,"192.168.56.101:53206",5b4610c8.4e10,1,"",2018-07-11 22:14:32 CST,,0,LOG,00000,"connection received: host=192.168.56.101 port=53206",,,,,,,,,""
2018-07-11 22:14:32.252 CST,"replicator","",19984,"192.168.56.101:53206",5b4610c8.4e10,2,"authentication",2018-07-11 22:14:32 CST,5/121,0,LOG,00000,"replication connection authorized: user=replicator",,,,,,,,,""
2018-07-11 22:14:32.315 CST,"replicator","",19984,"192.168.56.101:53206",5b4610c8.4e10,3,"streaming 0/300C138",2018-07-11 22:14:32 CST,5/0,0,LOG,00000,"standby ""pg96_101"" is now a synchronous standby with priority 1",,,,,,,,,"pg96_101"
2018-07-11 22:14:36.255 CST,"postgres","postgres",16066,"192.168.56.103:54424",5b45d88a.3ec2,1453,"SELECT",2018-07-11 18:14:34 CST,2/0,0,LOG,00000,"duration: 0.448 ms",,,,,,,,,"Patroni"
2018-07-11 22:14:46.258 CST,"postgres","postgres",16066,"192.168.56.103:54424",5b45d88a.3ec2,1454,"SELECT",2018-07-11 18:14:34 CST,2/0,0,LOG,00000,"duration: 0.568 ms",,,,,,,,,"Patroni"
稍等一会后，已经可以看到node1 已经加到slave里了
postgres=# select client_addr,
pg_xlog_location_diff(sent_location, write_location) as write_delay,
pg_xlog_location_diff(sent_location, flush_location) as flush_delay,
pg_xlog_location_diff(sent_location, replay_location) as replay_delay
from pg_stat_replication;
client_addr | write_delay | flush_delay | replay_delay
----------------+-------------+-------------+--------------
192.168.56.102 | 0 | 0 | 0
192.168.56.101 | 0 | 0 | 0
(2 rows)
但是用 patronictl 还是查看不到 node1的信息。
$ patronictl -c /usr/patroni/conf/patroni_postgresql.yml list pg96
+---------+----------+----------------+--------+---------+-----------+
| Cluster | Member | Host | Role | State | Lag in MB |
+---------+----------+----------------+--------+---------+-----------+
| pg96 | pg96_102 | 192.168.56.102 | | running | 0.0 |
| pg96 | pg96_103 | 192.168.56.103 | Leader | running | 0.0 |
+---------+----------+----------------+--------+---------+-----------+
等了一段时间，又ok了
$ patronictl -c /usr/patroni/conf/patroni_postgresql.yml list pg96
+---------+----------+----------------+--------+---------+-----------+
| Cluster | Member | Host | Role | State | Lag in MB |
+---------+----------+----------------+--------+---------+-----------+
| pg96 | pg96_101 | 192.168.56.101 | | running | 0.0 |
| pg96 | pg96_102 | 192.168.56.102 | | running | 0.0 |
| pg96 | pg96_103 | 192.168.56.103 | Leader | running | 0.0 |
+---------+----------+----------------+--------+---------+-----------+
