Running deploy_pgcluster twice

[ahussainrc]

I understand deploy_pgcluster suppose to be performed once to setup the cluster and for config changes of postgres/patroni/system, config_pgcluster needs to be used.

I want to understand why performing deploy_pgcluster twice breaks the cluster, do we have to be very careful not to run deploy_pgcluster twice ?

Here is what I have performed:

1. perform deploy_pgcluster.
   Two postgres nodes (pgnode01, pgnode02) and three etcd nodes (etcd01, etcd02, etcd03) configured successfully. postgres cluster is up and running and accessible on VIP. pgnode01 is master and pgnode02 is replica.

2. Shutdown pgnode01 to test failover.
   automatic failover did happen. pgnode02 became master and pgnode01 became replica. Database connection on VIP was not broken.

3. Run deploy_pgcluster again.
   Without doing any change in any of the configurations, I perform deploy_pgcluster again but it failed and postgres on pgnode01 became down. Cluster is still accessible because pgnode02 became the master.

Console logs

TASK [patroni : Start patroni service on the Master server] ********************************************************************************************
changed: [10.10.20.129]

TASK [patroni : Wait for port 8008 to become open on the host] *****************************************************************************************
ok: [10.10.20.129]
FAILED - RETRYING: [10.10.20.129]: Check PostgreSQL is started and accepting connections on Master (1000 retries left).
FAILED - RETRYING: [10.10.20.129]: Check PostgreSQL is started and accepting connections on Master (999 retries left).
FAILED - RETRYING: [10.10.20.129]: Check PostgreSQL is started and accepting connections on Master (998 retries left).
FAILED - RETRYING: [10.10.20.129]: Check PostgreSQL is started and accepting connections on Master (997 retries left). 

Patroni logs:

2024-05-24 12:07:40 CEST [11209-3]  LOG:  starting PostgreSQL 14.2 (Debian 14.2-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-05-24 12:07:40 CEST [11209-4]  LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-05-24 12:07:40 CEST [11209-5]  LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-05-24 12:07:40 CEST [11212-1]  LOG:  database system was shut down in recovery at 2024-05-24 10:13:44 CEST
2024-05-24 12:07:40 CEST [11212-2]  LOG:  entering standby mode
2024-05-24 12:07:40 CEST [11212-3]  FATAL:  requested timeline 4 does not contain minimum recovery point B8/D40000D8 on timeline 3
2024-05-24 12:07:40 CEST [11209-6]  LOG:  startup process (PID 11212) exited with exit code 1
2024-05-24 12:07:40 CEST [11209-7]  LOG:  aborting startup due to startup process failure
2024-05-24 12:07:40 CEST [11209-8]  LOG:  database system is shut down

Postgres logs:

May 24 12:10:39 test-postgres-1 patroni[4402]: 2024-05-24 12:10:39,778 WARNING: Postgresql is not running.
May 24 12:10:39 test-postgres-1 patroni[4402]: 2024-05-24 12:10:39,778 INFO: Lock owner: test-postgres-2; I am test-postgres-1
May 24 12:10:39 test-postgres-1 patroni[4402]: 2024-05-24 12:10:39,789 INFO: pg_controldata:
May 24 12:10:39 test-postgres-1 patroni[4402]:   pg_control version number: 1300
May 24 12:10:39 test-postgres-1 patroni[4402]:   Catalog version number: 202107181
May 24 12:10:39 test-postgres-1 patroni[4402]:   Database system identifier: 7077914876252285536
May 24 12:10:39 test-postgres-1 patroni[4402]:   Database cluster state: shut down in recovery
May 24 12:10:39 test-postgres-1 patroni[4402]:   pg_control last modified: Fri May 24 10:13:44 2024
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint location: B8/D4000028
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's REDO location: B8/D4000028
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's REDO WAL file: 00000003000000B8000000D4
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's TimeLineID: 3
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's PrevTimeLineID: 3
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's full_page_writes: on
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's NextXID: 0:41300534
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's NextOID: 6345178
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's NextMultiXactId: 1135
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's NextMultiOffset: 2712
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's oldestXID: 726
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's oldestXID's DB: 13757
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's oldestActiveXID: 0
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's oldestMultiXid: 1
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's oldestMulti's DB: 13757
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's oldestCommitTsXid: 0
May 24 12:10:39 test-postgres-1 patroni[4402]:   Latest checkpoint's newestCommitTsXid: 0
May 24 12:10:39 test-postgres-1 patroni[4402]:   Time of latest checkpoint: Fri May 24 09:56:54 2024
May 24 12:10:39 test-postgres-1 patroni[4402]:   Fake LSN counter for unlogged rels: 0/3E8
May 24 12:10:39 test-postgres-1 patroni[4402]:   Minimum recovery ending location: B8/D40000D8
May 24 12:10:39 test-postgres-1 patroni[4402]:   Min recovery ending loc's timeline: 3
May 24 12:10:39 test-postgres-1 patroni[4402]:   Backup start location: 0/0
May 24 12:10:39 test-postgres-1 patroni[4402]:   Backup end location: 0/0
May 24 12:10:39 test-postgres-1 patroni[4402]:   End-of-backup record required: no
May 24 12:10:39 test-postgres-1 patroni[4402]:   wal_level setting: replica
May 24 12:10:39 test-postgres-1 patroni[4402]:   wal_log_hints setting: off
May 24 12:10:39 test-postgres-1 patroni[4402]:   max_connections setting: 150
May 24 12:10:39 test-postgres-1 patroni[4402]:   max_worker_processes setting: 8
May 24 12:10:39 test-postgres-1 patroni[4402]:   max_wal_senders setting: 10
May 24 12:10:39 test-postgres-1 patroni[4402]:   max_prepared_xacts setting: 0
May 24 12:10:39 test-postgres-1 patroni[4402]:   max_locks_per_xact setting: 64
May 24 12:10:39 test-postgres-1 patroni[4402]:   track_commit_timestamp setting: off
May 24 12:10:39 test-postgres-1 patroni[4402]:   Maximum data alignment: 8
May 24 12:10:39 test-postgres-1 patroni[4402]:   Database block size: 8192
May 24 12:10:39 test-postgres-1 patroni[4402]:   Blocks per segment of large relation: 131072
May 24 12:10:39 test-postgres-1 patroni[4402]:   WAL block size: 8192
May 24 12:10:39 test-postgres-1 patroni[4402]:   Bytes per WAL segment: 16777216
May 24 12:10:39 test-postgres-1 patroni[4402]:   Maximum length of identifiers: 64
May 24 12:10:39 test-postgres-1 patroni[4402]:   Maximum columns in an index: 32
May 24 12:10:39 test-postgres-1 patroni[4402]:   Maximum size of a TOAST chunk: 1996
May 24 12:10:39 test-postgres-1 patroni[4402]:   Size of a large-object chunk: 2048
May 24 12:10:39 test-postgres-1 patroni[4402]:   Date/time type storage: 64-bit integers
May 24 12:10:39 test-postgres-1 patroni[4402]:   Float8 argument passing: by value
May 24 12:10:39 test-postgres-1 patroni[4402]:   Data page checksum version: 0
May 24 12:10:39 test-postgres-1 patroni[4402]:   Mock authentication nonce: 3a67c93eb79ce76419da9fd94ab8b6016ad137b5926266450248d9d6048cc50b
May 24 12:10:39 test-postgres-1 patroni[4402]: 2024-05-24 12:10:39,805 INFO: Lock owner: test-postgres-2; I am test-postgres-1
May 24 12:10:39 test-postgres-1 patroni[4402]: 2024-05-24 12:10:39,860 INFO: starting as a secondary
May 24 12:10:40 test-postgres-1 patroni[4402]: 2024-05-24 12:10:40,303 INFO: postmaster pid=11407
May 24 12:10:40 test-postgres-1 patroni[11408]: /var/run/postgresql:5432 - no response
May 24 12:10:40 test-postgres-1 patroni[11407]: 2024-05-24 12:10:40 CEST [11407-1]  LOG:  redirecting log output to logging collector process
May 24 12:10:40 test-postgres-1 patroni[11407]: 2024-05-24 12:10:40 CEST [11407-2]  HINT:  Future log output will appear in directory "/var/log/postgresql".
May 24 12:10:41 test-postgres-1 patroni[4402]: 2024-05-24 12:10:41,242 INFO: establishing a new patroni heartbeat connection to postgres
May 24 12:10:41 test-postgres-1 patroni[4402]: 2024-05-24 12:10:41,316 ERROR: postmaster is not running
May 24 12:10:42 test-postgres-1 patroni[4402]: 2024-05-24 12:10:42,426 INFO: establishing a new patroni heartbeat connection to postgres
May 24 12:10:42 test-postgres-1 patroni[4402]: 2024-05-24 12:10:42,429 WARNING: Retry got exception: connection problems
May 24 12:10:49 test-postgres-1 patroni[4402]: 2024-05-24 12:10:49,278 INFO: Lock owner: test-postgres-2; I am test-postgres-1
May 24 12:10:49 test-postgres-1 patroni[4402]: 2024-05-24 12:10:49,278 INFO: failed to start postgres

[vitabaks]

@ahussainrc Why did you launch the deployment on top of an already deployed cluster?

The playbook is protected from such a launch by checking for the presence of a data directory and if postgres is already there, then the playbook should have stopped with an error: "Whoops! data directory {{ postgresql_data_dir }} is already initialized".

Recreate the problematic replica patronictl reinit <cluster_name> <replica_name> and use the playbook config_pgcluster in the future, for an already deployed cluster.