Patroni 集羣如何恢復一個異常的數據庫節點

前言

今天我們來探討一下,Patroni 集羣下,一個 PostgreSQL 節點需要的日誌已經被刪了,無法啓動該如何恢復?

修改參數

在研究這個問題之前,我們需要設置一下日誌參數,方便我們觀察錯誤。在 Patroni 集羣中,如果我們直接在 postgresql.conf 中設置參數,則該參數可能無法正常工作,並且甚至在 Postgresql 實例重新啓動後會回滾設置。因此,我們要使用 patronictl edit-config 命令進行設置。

patronictl -c /etc/patroni.yaml show-config,通過命令查看 postgresql 相關參數,並未設置 log_directorylogging_collector

[postgres@133e0e204e206 pgdata]$ patronictl -c /etc/patroni.yml show-config
loop_wait: 10
master_start_timeout: 300
maximum_lag_on_failover: 1048576
postgresql:
  parameters:
    hot_standby: 'on'
    listen_addresses: 0.0.0.0
    max_replication_slots: 10
    max_wal_senders: 10
    port: 5432
    wal_keep_segments: 100
    wal_level: logical
    wal_log_hints: 'on'
  use_pg_rewind: true
  use_slots: true
retry_timeout: 10
synchronous_mode: false
ttl: 30

我們來設置一下。patronictl -c /etc/patroni.yml edit-config,通過該命令編輯參數,進入文字編輯界面。

修改完成後保存。然後 reload 集羣配置。

patronictl -c /etc/patroni.yaml reload patnori-test

這裏會同時在三個 postgres 節點上生效。

[postgres@133e0e204e206 pgdata]$ patronictl -c /etc/patroni.yml reload patnori-test       
+ Cluster: patnori-test (6962171552537974697) --+----+-----------+
| Member    | Host          | Role    | State   | TL | Lag in MB |
+-----------+---------------+---------+---------+----+-----------+
| postgres1 | 133.0.204.206 | Leader  | running |  7 |           |
| postgres2 | 133.0.204.207 | Replica | running |  7 |         0 |
| postgres3 | 133.0.204.208 | Replica | running |  7 |         0 |
+-----------+---------------+---------+---------+----+-----------+
Are you sure you want to reload members postgres2, postgres1, postgres3? [y/N]: y
Reload request received for member postgres2 and will be processed within 10 seconds
Reload request received for member postgres1 and will be processed within 10 seconds
Reload request received for member postgres3 and will be processed within 10 seconds

然後把三個節點實例重啓一下,讓參數生效(修改 logging_collector 需要重啓實例)。

pg_ctl stop
pg_ctl start

Patroni 會自動帶起來 PostgreSQL 實例,然後查看三個節點的日誌目錄,已經創建成功了。

模擬節點故障

接下來我們來模擬節點故障,我們把三個節點的集羣都停掉,單獨把節點 1 重啓兩次。

[postgres@133e0e204e206 ~]$ patronictl -c /etc/patroni.yml list
+ Cluster: patnori-test (6962171552537974697) --+----+-----------+-----------------+
| Member    | Host          | Role    | State   | TL | Lag in MB | Pending restart |
+-----------+---------------+---------+---------+----+-----------+-----------------+
| postgres1 | 133.0.204.206 | Leader  | running |  9 |           |                 |
| postgres2 | 133.0.204.207 | Replica | running |  9 |         0 | *               |
| postgres3 | 133.0.204.208 | Replica | running |  9 |         0 | *               |
+-----------+---------------+---------+---------+----+-----------+-----------------+

此時節點 1 的時間線就來到了 11。

[postgres@133e0e204e206 ~]$  patronictl -c /etc/patroni.yml list
+ Cluster: patnori-test (6962171552537974697) -+----+-----------+
| Member    | Host          | Role   | State   | TL | Lag in MB |
+-----------+---------------+--------+---------+----+-----------+
| postgres1 | 133.0.204.206 | Leader | running | 11 |           |
+-----------+---------------+--------+---------+----+-----------+

接下來重啓節點 2。

[postgres@133e0e204e206 ~]$  patronictl -c /etc/patroni.yml list
+ Cluster: patnori-test (6962171552537974697) --+----+-----------+
| Member    | Host          | Role    | State   | TL | Lag in MB |
+-----------+---------------+---------+---------+----+-----------+
| postgres1 | 133.0.204.206 | Leader  | running | 11 |           |
| postgres2 | 133.0.204.207 | Replica | running | 11 |         0 |
+-----------+---------------+---------+---------+----+-----------+

觀察節點 2 日誌情況。

2021-05-23 22:59:15.410 CST [10540] FATAL:  the database system is starting up
2021-05-23 22:59:15.414 CST [10539] LOG:  redo starts at 0/70004E0
2021-05-23 22:59:15.414 CST [10539] LOG:  consistent recovery state reached at 0/70005C8
2021-05-23 22:59:15.414 CST [10539] LOG:  invalid record length at 0/70005C8: wanted 24, got 0
2021-05-23 22:59:15.415 CST [10536] LOG:  database system is ready to accept read only connections
2021-05-23 22:59:15.422 CST [10545] LOG:  fetching timeline history file for timeline 10 from primary server
2021-05-23 22:59:15.430 CST [10545] LOG:  fetching timeline history file for timeline 11 from primary server
2021-05-23 22:59:15.434 CST [10539] LOG:  new target timeline is 11
2021-05-23 22:59:25.455 CST [10575] LOG:  started streaming WAL from primary at 0/7000000 on timeline 9
2021-05-23 22:59:25.455 CST [10575] LOG:  replication terminated by primary server
2021-05-23 22:59:25.455 CST [10575] DETAIL:  End of WAL reached on timeline 9 at 0/7000640.
2021-05-23 22:59:30.453 CST [10539] LOG:  invalid record length at 0/7000640: wanted 24, got 0
2021-05-23 22:59:30.454 CST [10575] LOG:  restarted WAL streaming at 0/7000000 on timeline 10
2021-05-23 22:59:30.516 CST [10575] LOG:  replication terminated by primary server
2021-05-23 22:59:30.516 CST [10575] DETAIL:  End of WAL reached on timeline 10 at 0/7000848.
2021-05-23 22:59:35.458 CST [10539] LOG:  invalid record length at 0/7000848: wanted 24, got 0
2021-05-23 22:59:35.459 CST [10575] LOG:  restarted WAL streaming at 0/7000000 on timeline 11

這裏有兩個重要的信息。

fetching timeline history file for timeline 10 from primary server
fetching timeline history file for timeline 11 from primary server

如果我們重啓節點 3 的時候,把節點 1 和節點 2 上的 timeline history file 刪掉,節點 3 就無法啓動了。

我們來測試一下這個情況。

[root@133e0e204e206 pg_wal]# rm -rf 0000000A.history
[root@133e0e204e206 pg_wal]# rm -rf 0000000B.history

啓動節點 3,此時節點 3 就會因爲缺少 timeline history file 無法啓動。

2021-05-23 23:04:46.820 CST [6254] LOG:  consistent recovery state reached at 0/7000880
2021-05-23 23:04:46.820 CST [6254] LOG:  invalid record length at 0/7000880: wanted 24, got 0
2021-05-23 23:04:46.821 CST [6251] LOG:  database system is ready to accept read only connections
2021-05-23 23:04:46.827 CST [6260] LOG:  fetching timeline history file for timeline 11 from primary server
2021-05-23 23:04:46.828 CST [6260] FATAL:  could not receive timeline history file from the primary server: ERROR:  could not open file "pg_wal/0000000B.history": No such file or directory
2021-05-23 23:04:46.835 CST [6262] LOG:  fetching timeline history file for timeline 11 from primary server
2021-05-23 23:04:46.835 CST [6262] FATAL:  could not receive timeline history file from the primary server: ERROR:  could not open file "pg_wal/0000000B.history": No such file or directory
2021-05-23 23:04:51.838 CST [6295] LOG:  fetching timeline history file for timeline 11 from primary server
2021-05-23 23:04:51.838 CST [6295] FATAL:  could not receive timeline history file from the primary server: ERROR:  could not open file "pg_wal/0000000B.history": No such file or directory

這個時候如何恢復,我們可以使用 patronictl reinit 恢復失敗的實例,該命令將刪除目錄,重新使用 pg_basebackup 進行恢復。

[postgres@133e0e204e208 ~]$ patronictl -c  /etc/patroni.yml reinit patnori-test postgres3
+ Cluster: patnori-test (6962171552537974697) --+----+-----------+
| Member    | Host          | Role    | State   | TL | Lag in MB |
+-----------+---------------+---------+---------+----+-----------+
| postgres1 | 133.0.204.206 | Leader  | running | 11 |           |
| postgres2 | 133.0.204.207 | Replica | running | 11 |         0 |
| postgres3 | 133.0.204.208 | Replica | running | 10 |        16 |
+-----------+---------------+---------+---------+----+-----------+
Are you sure you want to reinitialize members postgres3? [y/N]:

但是問題是 pg_basebackup 恢復的時候也報找不到 0000000B.history。

May 23 23:17:16 133e0e204e208 patroni[7889]: 2021-05-23 23:17:16,508 INFO: Selected new etcd server http://133.0.204.205:2379
May 23 23:17:16 133e0e204e208 patroni[7889]: 2021-05-23 23:17:16,515 INFO: No PostgreSQL configuration items changed, nothing to reload.
May 23 23:17:16 133e0e204e208 patroni[7889]: 2021-05-23 23:17:16,522 INFO: Lock owner: postgres1; I am postgres3
May 23 23:17:16 133e0e204e208 patroni[7889]: 2021-05-23 23:17:16,527 INFO: trying to bootstrap from leader 'postgres1'
May 23 23:17:16 133e0e204e208 patroni[7889]: pg_basebackup: error: could not send replication command "TIMELINE_HISTORY": ERROR:  could not open file "pg_wal/0000000B.history": No such file or directory
May 23 23:17:16 133e0e204e208 patroni[7889]: pg_basebackup: error: child process exited with exit code 1
May 23 23:17:16 133e0e204e208 patroni[7889]: pg_basebackup: removing data directory "/app/pgdata"
May 23 23:17:16 133e0e204e208 patroni[7889]: 2021-05-23 23:17:16,892 ERROR: Error when fetching backup: pg_basebackup exited with code=1
May 23 23:17:16 133e0e204e208 patroni[7889]: 2021-05-23 23:17:16,892 WARNING: Trying again in 5 seconds

這個問題不復雜,只要把 Patroni 節點 1 在重啓一下,再改變一下時間線,它就不會在需要這個 timeline history file 文件,就能恢復了。

此時節點 2 也會因爲這個時間線文件,仍然處於 11,處理方法也一樣。

[postgres@133e0e204e206 log]$  patronictl -c /etc/patroni.yml list
+ Cluster: patnori-test (6962171552537974697) --+----+-----------+
| Member    | Host          | Role    | State   | TL | Lag in MB |
+-----------+---------------+---------+---------+----+-----------+
| postgres1 | 133.0.204.206 | Leader  | running | 12 |           |
| postgres2 | 133.0.204.207 | Replica | running | 11 |        96 |
| postgres3 | 133.0.204.208 | Replica | running | 12 |         0 |
+-----------+---------------+---------+---------+----+-----------+

對節點 2 執行 reinit。

從系統日誌中可以看出,reinit 先是移除了整個 data 目錄。然後選擇正確的節點進行備份恢復。

May 23 23:45:17 133e0e204e207 patroni: 2021-05-23 23:45:17,306 INFO: Removing data directory: /app/pgdata
May 23 23:45:17 133e0e204e207 shell_cmd: {postgres,/home/postgres,  122  ,2021-05-23 23:45:15,133.0.206.107,patronictl -c  /etc/patroni.yml reinit patnori-test postgres2}
May 23 23:45:18 133e0e204e207 patroni: 2021-05-23 23:45:18,146 INFO: replica has been created using basebackup
May 23 23:45:18 133e0e204e207 patroni: 2021-05-23 23:45:18,147 INFO: bootstrapped from leader 'postgres1'
May 23 23:45:18 133e0e204e207 patroni: 2021-05-23 23:45:18,149 INFO: closed patroni connection to the postgresql cluster
May 23 23:45:18 133e0e204e207 patroni: 2021-05-23 23:45:18.321 CST [14280] LOG:  redirecting log output to logging collector process
May 23 23:45:18 133e0e204e207 patroni: 2021-05-23 23:45:18.321 CST [14280] HINT:  Future log output will appear in directory "log".
May 23 23:45:18 133e0e204e207 patroni: 2021-05-23 23:45:18,326 INFO: postmaster pid=14280
May 23 23:45:18 133e0e204e207 patroni: localhost:5432 - rejecting connections
May 23 23:45:18 133e0e204e207 patroni: localhost:5432 - rejecting connections
May 23 23:45:19 133e0e204e207 patroni: localhost:5432 - accepting connections
May 23 23:45:22 133e0e204e207 patroni: 2021-05-23 23:45:22,180 INFO: Lock owner: postgres1; I am postgres2
本文由 Readfog 進行 AMP 轉碼,版權歸原作者所有。
來源https://mp.weixin.qq.com/s/-kiPXIFx46_yOUjYQ7-PbA