Прошу помочь восстановить штатную работу кластера postgresql. Началась проблема после выключения и включения серверов. Имеем 2 сервера postgresql+patroni+consul(+1 машина).
[root@serv pg_wal]# patronictl -c /etc/patroni/patroni.yml show-config
loop_wait: 10
maximum_lag_on_failover: 1048576
postgresql:
parameters:
archive_mode: 'off'
archive_timeout: 1800s
checkpoint_completion_target: 0.9
default_statistics_target: 500
effective_cache_size: 96GB
effective_io_concurrency: 200
hot_standby: 'on'
huge_pages: try
maintenance_work_mem: 2GB
max_connections: 300
max_parallel_maintenance_workers: 4
max_parallel_workers: 32
max_parallel_workers_per_gather: 16
max_replication_slots: 5
max_wal_senders: 10
max_wal_size: 16GB
max_worker_processes: 32
min_wal_size: 4GB
random_page_cost: 1.1
shared_buffers: 32GB
wal_buffers: 16MB
wal_keep_segments: 8
wal_level: hot_standby
wal_log_hints: 'on'
work_mem: 3495kB
pg_hba:
- local all postgres peer
- host replication postgres 10.0.0.0/24 trust
- host replication replicator 10.0.0.0/24 md5
- host replication replicator 127.0.0.1/32 trust
- host all all 0.0.0.0/0 md5
use_pg_rewind: true
use_slots: true
ttl: 30
[root@serv pg_wal]# patronictl -c /etc/patroni/patroni.yml list
+ Cluster: pgcluster (7329505506050888804) --+----+-----------+
| Member | Host | Role | State | TL | Lag in MB |
+-------------+----------+---------+---------+----+-----------+
| postgresql1 | 10.0.0.1 | Replica | running | 77 | 40760 |
| postgresql2 | 10.0.0.2 | Leader | running | 79 | |
+-------------+----------+---------+---------+----+-----------+
[root@serv1c-02 pg_wal]#
В логе такое перед тем как выключили второй сервер postgresql2 из кластера(Стал master).
2025-04-30 08:15:48.132 MSK [2726860] СООБЩЕНИЕ: репликация прекращена главным сервером
2025-04-30 08:15:48.132 MSK [2726860] ПОДРОБНОСТИ: На линии времени 77 в 518/4EFFF580 достигнут конец журнала.
2025-04-30 08:15:48.132 MSK [2726860] ВАЖНО: не удалось отправить главному серверу сообщение о конце передачи: сервер неожиданно закрыл соединение
<------><------>Скорее всего сервер прекратил работу из-за сбоя
<------><------>до или в процессе выполнения запроса.
<------>операция COPY не выполняется
2025-04-30 08:15:48.132 MSK [2843645] СООБЩЕНИЕ: неверный ID менеджера ресурсов 61 в позиции 518/4EFFF580
2025-04-30 08:15:50.475 MSK [144553] ВАЖНО: не удалось подключиться к главному серверу: подключиться к серверу "10.0.0.1", порту 5432 не удалось: сервер нео
<------><------>Скорее всего сервер прекратил работу из-за сбоя
<------><------>до или в процессе выполнения запроса.
2025-04-30 08:15:50.476 MSK [2843645] СООБЩЕНИЕ: waiting for WAL to become available at 518/4EFFF598
2025-04-30 08:15:53.136 MSK [144559] ВАЖНО: не удалось подключиться к главному серверу: подключиться к серверу "10.0.0.1", порту 5432 не удалось: В соединен
<------><------>Сервер действительно работает по данному адресу и принимает TCP-соединения?
2025-04-30 08:15:53.136 MSK [2843645] СООБЩЕНИЕ: waiting for WAL to become available at 518/4EFFF598
2025-04-30 08:15:58.137 MSK [144564] ВАЖНО: не удалось подключиться к главному серверу: подключиться к серверу "10.0.0.1", порту 5432 не удалось: В соединен
<------><------>Сервер действительно работает по данному адресу и принимает TCP-соединения?
2025-04-30 08:15:58.137 MSK [2843645] СООБЩЕНИЕ: waiting for WAL to become available at 518/4EFFF598
2025-04-30 08:16:03.142 MSK [144601] ВАЖНО: не удалось подключиться к главному серверу: подключиться к серверу "10.0.0.1", порту 5432 не удалось: В соединен
<------><------>Сервер действительно работает по данному адресу и принимает TCP-соединения?
2025-04-30 08:16:03.142 MSK [2843645] СООБЩЕНИЕ: waiting for WAL to become available at 518/4EFFF598
2025-04-30 08:16:08.144 MSK [144618] ВАЖНО: не удалось подключиться к главному серверу: подключиться к серверу "10.0.0.1", порту 5432 не удалось: В соединен
<------><------>Сервер действительно работает по данному адресу и принимает TCP-соединения?
2025-04-30 08:16:08.144 MSK [2843645] СООБЩЕНИЕ: waiting for WAL to become available at 518/4EFFF598
2025-04-30 08:16:12.638 MSK [2843645] СООБЩЕНИЕ: получен запрос повышения статуса
2025-04-30 08:16:12.638 MSK [2843645] СООБЩЕНИЕ: записи REDO обработаны до смещения 518/4EFFF508, нагрузка системы: CPU: пользов.: 3993.76 с, система: 767.6
2025-04-30 08:16:12.638 MSK [2843645] СООБЩЕНИЕ: последняя завершённая транзакция была выполнена в 2025-04-30 08:15:47.259068+03
2025-04-30 08:16:12.808 MSK [2843645] СООБЩЕНИЕ: выбранный ID новой линии времени: 78
2025-04-30 08:16:12.987 MSK [2843645] СООБЩЕНИЕ: восстановление архива завершено
2025-04-30 08:16:14.495 MSK [2843640] СООБЩЕНИЕ: система БД готова принимать подключения
2025-04-30 08:27:22.879 MSK [144685] LOG: unexpected EOF on client connection with an open transaction
2025-04-30 08:27:23.128 MSK [2843640] СООБЩЕНИЕ: получен запрос на быстрое выключение
2025-04-30 08:27:23.131 MSK [2843640] СООБЩЕНИЕ: прерывание всех активных транзакций
2025-04-30 08:27:23.131 MSK [2843655] ВАЖНО: закрытие подключения по команде администратора
2025-04-30 08:27:23.131 MSK [2843656] ВАЖНО: закрытие подключения по команде администратора
2025-04-30 08:27:23.131 MSK [2843640] СООБЩЕНИЕ: фоновый процесс "logical replication launcher" (PID 144660) завершился с кодом выхода 1
2025-04-30 08:27:23.310 MSK [2843643] СООБЩЕНИЕ: выключение
2025-04-30 08:27:27.443 MSK [2843640] СООБЩЕНИЕ: система БД выключена
А при вкелючении postgresql2 уже получил такое сообщение
2025-04-30 12:53:56.369 MSK [7608] СООБЩЕНИЕ: для приёма подключений открыт Unix-сокет "/tmp/.s.PGSQL.5432"
2025-04-30 12:53:56.737 MSK [7613] СООБЩЕНИЕ: система БД была выключена: 2025-04-30 08:27:23 MSK
2025-04-30 12:53:56.737 MSK [7613] ПРЕДУПРЕЖДЕНИЕ: не указано ни primary_conninfo, ни restore_command
2025-04-30 12:53:56.737 MSK [7613] ПОДСКАЗКА: Сервер БД будет регулярно опрашивать подкаталог pg_wal и проверять содержащиеся в нём файлы.
2025-04-30 12:53:56.737 MSK [7613] СООБЩЕНИЕ: переход в режим резервного сервера
2025-04-30 12:53:56.879 MSK [7613] СООБЩЕНИЕ: согласованное состояние восстановления достигнуто в позиции 518/64BA0A18
2025-04-30 12:53:56.879 MSK [7613] СООБЩЕНИЕ: неверная длина записи в позиции 518/64BA0A18: ожидалось 24, получено 0
2025-04-30 12:53:56.879 MSK [7613] СООБЩЕНИЕ: waiting for WAL to become available at 518/64002000
2025-04-30 12:53:56.879 MSK [7608] СООБЩЕНИЕ: система БД готова принимать подключения в режиме "только чтение"
2025-04-30 12:53:57.114 MSK [7613] СООБЩЕНИЕ: получен запрос повышения статуса
2025-04-30 12:53:57.114 MSK [7613] СООБЩЕНИЕ: данные REDO не требуются
2025-04-30 12:53:57.277 MSK [7613] СООБЩЕНИЕ: выбранный ID новой линии времени: 79
2025-04-30 12:53:57.446 MSK [7613] СООБЩЕНИЕ: восстановление архива завершено
2025-04-30 12:53:57.510 MSK [7608] СООБЩЕНИЕ: система БД готова принимать подключения
2025-04-30 12:54:00.919 MSK [7630] ОШИБКА: запрошенный сегмент WAL 0000004E000005180000004E уже удалён
2025-04-30 12:54:00.919 MSK [7630] ОПЕРАТОР: START_REPLICATION SLOT "postgresql1" 518/4E000000 TIMELINE 77
2025-04-30 12:54:00.925 MSK [7631] ОШИБКА: запрошенный сегмент WAL 0000004E000005180000004E уже удалён
2025-04-30 12:54:00.925 MSK [7631] ОПЕРАТОР: START_REPLICATION SLOT "postgresql1" 518/4E000000 TIMELINE 78
2025-04-30 12:54:05.920 MSK [7676] ОШИБКА: запрошенный сегмент WAL 0000004E000005180000004E уже удалён
И так далее.
Каталог Wal уже распух до 40G.
До момента X postgresql1 был «master». Он выключается «master» стал postgresql2. Включали сервера одновременно. Лидер на данный момент postgresql2.
И лог со старого мастера postgresql1 в момент его выключения.
2025-04-30 08:15:47.134 MSK [3714531] СООБЩЕНИЕ: получен запрос на быстрое выключение
2025-04-30 08:15:47.138 MSK [3714531] СООБЩЕНИЕ: прерывание всех активных транзакций
2025-04-30 08:15:47.138 MSK [2133459] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2133832] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2133121] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2133123] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2133120] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2133118] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2133116] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2133117] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2132760] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2126915] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2126914] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2126899] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2126913] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2133122] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2125988] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2126930] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2133124] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2120560] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2125941] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2122615] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2126908] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2126916] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2131625] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2126898] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2128953] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2132761] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2116272] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2127525] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.138 MSK [2121699] FATAL: terminating connection due to administrator command
2025-04-30 08:15:47.139 MSK [3714551] ВАЖНО: закрытие подключения по команде администратора
2025-04-30 08:15:47.139 MSK [3714550] ВАЖНО: закрытие подключения по команде администратора
2025-04-30 08:15:47.141 MSK [3714531] СООБЩЕНИЕ: фоновый процесс "logical replication launcher" (PID 3714561) завершился с кодом выхода 1
2025-04-30 08:15:47.383 MSK [3714535] СООБЩЕНИЕ: выключение
2025-04-30 08:15:50.479 MSK [3714531] СООБЩЕНИЕ: система БД выключена
И после включения.
2025-04-30 12:53:56.369 MSK [7608] СООБЩЕНИЕ: запускается PostgreSQL 15.5 on x86_64-alt-linux-gnu, compiled by x86_64-alt-linux-gcc (GCC) 10.3.1 20210703 (A
2025-04-30 12:53:56.369 MSK [7608] СООБЩЕНИЕ: для приёма подключений по адресу IPv4 "0.0.0.0" открыт порт 5432
2025-04-30 12:53:56.369 MSK [7608] СООБЩЕНИЕ: для приёма подключений открыт Unix-сокет "/tmp/.s.PGSQL.5432"
2025-04-30 12:53:56.737 MSK [7613] СООБЩЕНИЕ: система БД была выключена: 2025-04-30 08:27:23 MSK
2025-04-30 12:53:56.737 MSK [7613] ПРЕДУПРЕЖДЕНИЕ: не указано ни primary_conninfo, ни restore_command
2025-04-30 12:53:56.737 MSK [7613] ПОДСКАЗКА: Сервер БД будет регулярно опрашивать подкаталог pg_wal и проверять содержащиеся в нём файлы.
2025-04-30 12:53:56.737 MSK [7613] СООБЩЕНИЕ: переход в режим резервного сервера
2025-04-30 12:53:56.879 MSK [7613] СООБЩЕНИЕ: согласованное состояние восстановления достигнуто в позиции 518/64BA0A18
2025-04-30 12:53:56.879 MSK [7613] СООБЩЕНИЕ: неверная длина записи в позиции 518/64BA0A18: ожидалось 24, получено 0
2025-04-30 12:53:56.879 MSK [7613] СООБЩЕНИЕ: waiting for WAL to become available at 518/64002000
2025-04-30 12:53:56.879 MSK [7608] СООБЩЕНИЕ: система БД готова принимать подключения в режиме "только чтение"
2025-04-30 12:53:57.114 MSK [7613] СООБЩЕНИЕ: получен запрос повышения статуса
2025-04-30 12:53:57.114 MSK [7613] СООБЩЕНИЕ: данные REDO не требуются
2025-04-30 12:53:57.277 MSK [7613] СООБЩЕНИЕ: выбранный ID новой линии времени: 79
2025-04-30 12:53:57.446 MSK [7613] СООБЩЕНИЕ: восстановление архива завершено
2025-04-30 12:53:57.510 MSK [7608] СООБЩЕНИЕ: система БД готова принимать подключения
2025-04-30 12:54:00.919 MSK [7630] ОШИБКА: запрошенный сегмент WAL 0000004E000005180000004E уже удалён
2025-04-30 12:54:00.919 MSK [7630] ОПЕРАТОР: START_REPLICATION SLOT "postgresql1" 518/4E000000 TIMELINE 77
2025-04-30 12:54:00.925 MSK [7631] ОШИБКА: запрошенный сегмент WAL 0000004E000005180000004E уже удалён
2025-04-30 12:54:00.925 MSK [7631] ОПЕРАТОР: START_REPLICATION SLOT "postgresql1" 518/4E000000 TIMELINE 78
Как грамотно и без потери данных починить?
