Recovering failing after all nodes are powered off

[hshmilo]

Please, answer some short questions which should help us to understand your problem / question better?

• Which image of the operator are you using? registry.opensource.zalan.do/acid/postgres-operator:v1.9.0
• Where do you run it - cloud or metal? Kubernetes or OpenShift? AWS K8s
• Are you running Postgres Operator in production? no
• Type of issue? Bug report

Hello,
I am observing that after reboot of all K8S nodes (VMs), some of the nodes (pods) of PG cluster have an empty string State, Host fields:

postgres@postgres-db-pg-cluster-2:~$ patronictl list
+ Cluster: postgres-db-pg-cluster (7195856528308064328) -----+----+-----------+
| Member                   | Host        | Role    | State   | TL | Lag in MB |
+--------------------------+-------------+---------+---------+----+-----------+
| postgres-db-pg-cluster-0 | x.x.x.149 | Replica | running |  6 |       128 |
| postgres-db-pg-cluster-1 | x.x.x.247 | Replica | running |  6 |       112 |
| postgres-db-pg-cluster-2 |             | Leader  |         |    |           |
+--------------------------+-------------+---------+---------+----+-----------+

The pods are in the Running state.
I can run SELECT from DB, but any ALTER TABLE queries are stuck:

postgres@postgres-db-pg-cluster-2:~$ psql -U postgres -d mydb -h postgres-db-pg-cluster
Password for user postgres:
psql (15.1 (Ubuntu 15.1-1.pgdg22.04+1), server 14.6 (Ubuntu 14.6-1.pgdg22.04+1))
SSL connection (protocol: TLSv1.3, cipher: TLS_AES_256_GCM_SHA384, compression: off)
Type "help" for help.

mydb=#  ALTER TABLE mytable alter column name type ltree using name::ltree;

When I deleted the postgres-db-pg-cluster-2 pod and the pod recreated, the Host, State fealds were assigned:

postgres@postgres-db-pg-cluster-2:~$ patronictl list
+ Cluster: postgres-db-pg-cluster (7195856528308064328) +---------+----+-----------+
| Member                   | Host        | Role         | State   | TL | Lag in MB |
+--------------------------+-------------+--------------+---------+----+-----------+
| postgres-db-pg-cluster-0 |             | Sync Standby |         |    |   unknown |
| postgres-db-pg-cluster-1 | 10.42.2.41  | Replica      | running | 10 |         0 |
| postgres-db-pg-cluster-2 | 10.42.0.114 | Leader       | running | 10 |           |
+--------------------------+-------------+--------------+---------+----+-----------+

Then I can perform any ALTER TABLE queries.

I have the following manifest:

apiVersion: acid.zalan.do/v1
kind: postgresql
metadata:
  name: postgres-db-pg-cluster
spec:
  databases: {}
  dockerImage: ghcr.io/zalando/spilo-15:2.1-p9
  enableConnectionPooler: false
  enableLogicalBackup: false
  enableMasterLoadBalancer: false
  enableReplicaLoadBalancer: false
  numberOfInstances: 3
  patroni:
    synchronous_mode: true
    synchronous_mode_strict: true
  postgresql:
    parameters:
      log_min_error_statement: debug1
      log_min_messages: debug1
      max_connections: "250"
      password_encryption: scram-sha-256
    version: "15"

[jicki]

I have the same problem, the master node prompts that the data is behind, but it will never recover

[Jan-M]

Using sync mode you cannot commit unless all replicas are in sync. So until you fix all replicas it will be blocking writes.

Find out where and why replicas are not recovering. Timelines. WAL positions. Lost segment. Rewind.

Which Spilo image?

Last resort is reinig of replicas.

[vincentchong1]

@hshmilo, sorry to piggyback on your ticket.

@Jan-M ,
may I know the procedure to reinig the replicas?
Can I recover the replicas even it is expect to be LAG?

My initial plan is to find way to resolve the LAG, I submitted #2275,
Without any option, I tried sv restart patroni
Below is the sequence of my procedure.

env is

postgres-operator:v1.7.1
spilo-14:2.1-p3

kubectl exec [POD] [COMMAND] is DEPRECATED and will be removed in a future version. Use kubectl exec [POD] -- [COMMAND] instead.
Defaulted container "postgres" out of: postgres, sdmgr, sdmgr-init (init)

 ____        _ _
/ ___| _ __ (_) | ___
\___ \| '_ \| | |/ _ \
 ___) | |_) | | | (_) |
|____/| .__/|_|_|\___/
      |_|

This container is managed by runit, when stopping/starting services use sv

Examples:

sv stop cron
sv restart patroni

Current status: (sv status /etc/service/*)

run: /etc/service/patroni: (pid 27) 21079s
run: /etc/service/pgqd: (pid 26) 21079s
root@dlp-postgresql-2:/home/postgres# sv
usage: sv [-v] [-w sec] command service ...

root@dlp-postgresql-2:/home/postgres# patronictl list
+ Cluster: dlp-postgresql (7215972589039407173) --------+----+-----------+
| Member           | Host           | Role    | State   | TL | Lag in MB |
+------------------+----------------+---------+---------+----+-----------+
| dlp-postgresql-0 | 172.16.181.178 | Leader  | running |  9 |           |
| dlp-postgresql-1 | 172.16.243.112 | Replica | running |  9 |         0 |
| dlp-postgresql-2 | 172.16.181.163 | Replica | running |  5 |       143 |
+------------------+----------------+---------+---------+----+-----------+

root@dlp-postgresql-2:/home/postgres# sv restart patroni
timeout: finish: patroni: (pid 25812) 21142s, want down

root@dlp-postgresql-2:/home/postgres# ps -eaf
UID          PID    PPID  C STIME TTY          TIME CMD
root           1       0  0 14:15 ?        00:00:00 /usr/bin/dumb-init -c --rewrite 1:0 -- /bin/sh /launch.sh
root           7       1  0 14:15 ?        00:00:00 /bin/sh /launch.sh
root          23       7  0 14:15 ?        00:00:00 /usr/bin/runsvdir -P /etc/service
root          24      23  0 14:15 ?        00:00:00 runsv pgqd
root          25      23  0 14:15 ?        00:00:00 runsv patroni
postgres      26      24  0 14:15 ?        00:00:00 /bin/bash /scripts/patroni_wait.sh --role master -- /usr/bin/pgqd /home/postgres/pgq_ticker.ini
root       25724       0  0 20:07 pts/0    00:00:00 /bin/bash
postgres   25811      26  0 20:08 ?        00:00:00 sleep 60


root@dlp-postgresql-2:/home/postgres# patronictl list
+ Cluster: dlp-postgresql (7215972589039407173) --------+----+-----------+
| Member           | Host           | Role    | State   | TL | Lag in MB |
+------------------+----------------+---------+---------+----+-----------+
| dlp-postgresql-0 | 172.16.181.178 | Leader  | running |  9 |           |
| dlp-postgresql-1 | 172.16.243.112 | Replica | running |  9 |         0 |
| dlp-postgresql-2 | 172.16.181.163 | Replica | stopped |    |   unknown |
+------------------+----------------+---------+---------+----+-----------+


postgres@dlp-postgresql-2:/usr/lib/postgresql/14/bin$ ./pg_controldata -D /home/postgres/pgdata/pgroot/data
WARNING: Calculated CRC checksum does not match value stored in file.
Either the file is corrupt, or it has a different layout than this program
is expecting.  The results below are untrustworthy.

WARNING: invalid WAL segment size
The WAL segment size stored in the file, 32 bytes, is not a power of two
between 1 MB and 1 GB.  The file is corrupt and the results below are
untrustworthy.

pg_control version number:            1100
Catalog version number:               201809051
Database system identifier:           7215972589039407173
Database cluster state:               shut down in recovery
pg_control last modified:             Thu Mar 30 20:08:12 2023
Latest checkpoint location:           0/917DEA0
Latest checkpoint's REDO location:    0/917DE68
Latest checkpoint's REDO WAL file:    00000005000000000048BEF3
Latest checkpoint's TimeLineID:       5
Latest checkpoint's PrevTimeLineID:   5
Latest checkpoint's full_page_writes: on
Latest checkpoint's NextXID:          57344:2278
Latest checkpoint's NextOID:          1
Latest checkpoint's NextMultiXactId:  0
Latest checkpoint's NextMultiOffset:  562
Latest checkpoint's oldestXID:        1
Latest checkpoint's oldestXID's DB:   1
Latest checkpoint's oldestActiveXID:  1
Latest checkpoint's oldestMultiXid:   1
Latest checkpoint's oldestMulti's DB: 1680166517
Latest checkpoint's oldestCommitTsXid:2278
Latest checkpoint's newestCommitTsXid:0
Time of latest checkpoint:            Thu Jan  1 00:00:00 1970
Fake LSN counter for unlogged rels:   0/917DF48
Minimum recovery ending location:     0/5
Min recovery ending loc's timeline:   0
Backup start location:                0/0
Backup end location:                  1/0
End-of-backup record required:        yes
wal_level setting:                    unrecognized wal_level
wal_log_hints setting:                on
max_connections setting:              0
max_worker_processes setting:         64
max_wal_senders setting:              0
max_prepared_xacts setting:           8
max_locks_per_xact setting:           0
track_commit_timestamp setting:       off
Maximum data alignment:               1093850759
Database block size:                  8192
Blocks per segment of large relation: 16777216
WAL block size:                       64
Bytes per WAL segment:                32
Maximum length of identifiers:        1996
Maximum columns in an index:          2048
Maximum size of a TOAST chunk:        257
Size of a large-object chunk:         1
Date/time type storage:               64-bit integers
Float8 argument passing:              by value
Data page checksum version:           3723407806
Mock authentication nonce:            7c4d1e95bf53c1268279a288684aaf559a155456ae44e51ac89af2f200000000

[vincentchong1]

I started patroni successfully.

down: /etc/service/patroni: 4609s, normally up
run: /etc/service/pgqd: (pid 26) 25752s

root@dlp-postgresql-2:/home/postgres# patronictl list
+ Cluster: dlp-postgresql (7215972589039407173) --------+----+-----------+
| Member           | Host           | Role    | State   | TL | Lag in MB |
+------------------+----------------+---------+---------+----+-----------+
| dlp-postgresql-0 | 172.16.181.178 | Leader  | running |  9 |           |
| dlp-postgresql-1 | 172.16.243.112 | Replica | running |  9 |         0 |
| dlp-postgresql-2 | 172.16.181.163 | Replica | stopped |    |   unknown |
+------------------+----------------+---------+---------+----+-----------+


root@dlp-postgresql-2:/home/postgres# sv status /etc/service/*
down: /etc/service/patroni: 4648s, normally up
run: /etc/service/pgqd: (pid 26) 25791s


root@dlp-postgresql-2:/home/postgres# sv start patroni
ok: run: patroni: (pid 26201) 0s

root@dlp-postgresql-2:/home/postgres# ps -eaf
UID          PID    PPID  C STIME TTY          TIME CMD
root           1       0  0 14:15 ?        00:00:00 /usr/bin/dumb-init -c --rewrite 1:0 -- /bin/sh /launch.sh
root           7       1  0 14:15 ?        00:00:00 /bin/sh /launch.sh
root          23       7  0 14:15 ?        00:00:00 /usr/bin/runsvdir -P /etc/service
root          24      23  0 14:15 ?        00:00:00 runsv pgqd
root          25      23  0 14:15 ?        00:00:00 runsv patroni
postgres      26      24  0 14:15 ?        00:00:00 /bin/bash /scripts/patroni_wait.sh --role master -- /usr/bin/pgqd /home/postgres/pgq_ticker.ini
root       26172       0  0 21:25 pts/0    00:00:00 /bin/bash
postgres   26201      25  4 21:26 ?        00:00:00 /usr/bin/python3 /usr/local/bin/patroni /home/postgres/postgres.yml
postgres   26230       1  1 21:26 ?        00:00:00 /usr/lib/postgresql/11/bin/postgres -D /home/postgres/pgdata/pgroot/data --config-file=/home/postgres/pgdata/pgroot/data/postgresql.conf --listen_addresses=* --port=5432 --cluster_name=
postgres   26232   26230  0 21:26 ?        00:00:00 postgres: dlp-postgresql: logger
postgres   26233   26230  0 21:26 ?        00:00:00 postgres: dlp-postgresql: startup   waiting for 000000060000000000000009
postgres   26234   26230  0 21:26 ?        00:00:00 postgres: dlp-postgresql: bg_mon
postgres   26237   26230  0 21:26 ?        00:00:00 postgres: dlp-postgresql: checkpointer
postgres   26238   26230  0 21:26 ?        00:00:00 postgres: dlp-postgresql: background writer
postgres   26240   26230  0 21:26 ?        00:00:00 postgres: dlp-postgresql: stats collector
postgres   26245   26230  0 21:26 ?        00:00:00 postgres: dlp-postgresql: postgres postgres [local] idle
postgres   26255      26  0 21:26 ?        00:00:00 sleep 60
root       26257   26172  0 21:26 pts/0    00:00:00 ps -eaf

root@dlp-postgresql-2:/home/postgres# patronictl list
+ Cluster: dlp-postgresql (7215972589039407173) --------+----+-----------+
| Member           | Host           | Role    | State   | TL | Lag in MB |
+------------------+----------------+---------+---------+----+-----------+
| dlp-postgresql-0 | 172.16.181.178 | Leader  | running |  9 |           |
| dlp-postgresql-1 | 172.16.243.112 | Replica | running |  9 |         0 |
| dlp-postgresql-2 | 172.16.181.163 | Replica | running |  5 |       143 |
+------------------+----------------+---------+---------+----+-----------+

[FxKu]

@vincentchong1 you should have a look at the Postgres logs on the replica why it does not catch up with the primary. Maybe it requests WAL files which are already gone. You can reinit replicas with patronictl reinit, but I would suggest you first learn and understand how you end up in this situation.

I would also recommend updating Spilo and Postgres Operator version.