Database inconsistency: liveness probe shall report error if replica is not in sync

[alex1989hu]

Overview

As of now, the Pod is considered healthy despite the fact that query shows that the database is not in sync therefore the Kubernetes Service routes traffic to this Pod as well leading to inconsistency - anything reads from this specific read-only replica will have outdated data.

I think my S3 WAL stream: ERROR is an edge case, but in general notifying Kubernetes that the Pod is not in sync is crucial.

Environment

• Platform: Kubernetes
• Platform Version: v1.21.10
• PGO Image Tag: ubi8-5.1.2-0
• Postgres Version: ubi8-14.3-0
• Storage: longhorn

Steps to Reproduce

I noticed this after unsuccessful pgbackrest backup jobs (see root cause below). One of the PostgreSQL Pod became broken (no space left on device) so I removed the PVC (later the PV as well) and than the Pod to have a fresh new start.

Password has been changed for S3 bucket but the pgbackrest S3 configuration was not updated.

Usually removing PVC, PV and Pod will end up in a fresh new working and synced instance.

REPRO

Probably there are other scenario which leads to replica kicked out from replication. All I have what I experienced.

Provide steps to get to the error condition:

N/A - see note above

EXPECTED

1. The livenessProbe shall report error if the replica is not in sync to avoid data inconsistency.

ACTUAL

1. The livenessProbe does not report error if the replica is not in sync leading to data inconsistency.

Logs

The PostgresCluster is configured to 5 replicas.

Snippet from replica:

2022-08-09 00:00:01.641 P00   INFO: archive-get command begin 2.38: [0000006800000230000000E8, pg_wal/RECOVERYXLOG] --exec-id=5459-7b2998ef --log-level-console=info --log-path=/pgdata/pgbackrest/log --pg1-path=/pgdata/pg14 --repo1-cipher-pass=<redacted> --repo1-cipher-type=aes-256-cbc --repo1-path=/<redacted>/repo1 --repo1-s3-bucket=<redacted> --repo1-s3-endpoint<redacted> --repo1-s3-key=<redacted> --repo1-s3-key-secret=<redacted> --repo1-s3-region=<redacted> --repo1-s3-uri-style=path --repo1-storage-ca-file=/etc/pgbackrest/conf.d/ca.crt --repo1-type=s3 --stanza=db
2022-08-09 00:00:01.712 P00   INFO: unable to find 0000006800000230000000E8 in the archive
2022-08-09 00:00:01.712 P00   INFO: archive-get command end: completed successfully (73ms)
2022-08-09 00:00:01.818 UTC [5460] LOG:  started streaming WAL from primary at 230/E8000000 on timeline 104
2022-08-09 00:00:01.818 UTC [5460] FATAL:  could not receive data from WAL stream: ERROR:  requested WAL segment 0000006800000230000000E8 has already been removed
2022-08-09 00:00:01.879 P00   INFO: archive-get command begin 2.38: [0000006A.history, pg_wal/RECOVERYHISTORY] --exec-id=5461-95877c8e --log-level-console=info --log-path=/pgdata/pgbackrest/log --pg1-path=/pgdata/pg14 --repo1-cipher-pass=<redacted> --repo1-cipher-type=aes-256-cbc --repo1-path=/<redacted>/repo1 --repo1-s3-bucket=<redacted> --repo1-s3-endpoint=<redacted> --repo1-s3-key=<redacted> --repo1-s3-key-secret=<redacted> --repo1-s3-region=<redacted> --repo1-s3-uri-style=path --repo1-storage-ca-file=/etc/pgbackrest/conf.d/ca.crt --repo1-type=s3 --stanza=db
2022-08-09 00:00:02.162 P00   INFO: unable to find 0000006A.history in the archive
2022-08-09 00:00:02.162 P00   INFO: archive-get command end: completed successfully (285ms)

Based on database container log everything is fine:

database 2022-08-09 08:08:39,947 INFO: no action. I am (postgres-pki-ppfg-0), a secondary, and following a leader (postgres-pki-c8nc-0)

However the SQL query on this specific replica says:

 postgres=# select * from pg_stat_wal_receiver;
 pid | status | receive_start_lsn | receive_start_tli | written_lsn | flushed_lsn | received_tli | last_msg_send_time | last_msg_receipt_time | latest_end_lsn | latest_end_time | slot_name | sender_host | sender_port | conninfo
-----+--------+-------------------+-------------------+-------------+-------------+--------------+--------------------+-----------------------+----------------+-----------------+-----------+-------------+-------------+----------
(0 rows)

The leader confirms that one of the replica is not in pg_stat_replication table:

postgres=# select * from pg_stat_replication;
 pid  | usesysid |   usename    |  application_name   |  client_addr  | client_hostname | client_port |         backend_start         | backend_xmin |   state   |   sent_lsn   |  write_lsn   |  flush_lsn   |  replay_lsn  |    write_lag
 |    flush_lag    |   replay_lag    | sync_priority | sync_state |          reply_time
------+----------+--------------+---------------------+---------------+-----------------+-------------+-------------------------------+--------------+-----------+--------------+--------------+--------------+--------------+----------------
-+-----------------+-----------------+---------------+------------+-------------------------------
 2077 |    16384 | _crunchyrepl | postgres-pki-qm5f-0 | 172.24.47.193 |                 |       56604 | 2022-08-07 17:20:18.012562+00 |              | streaming | 245/C51758A8 | 245/C51758A8 | 245/C51758A8 | 245/C51758A8 | 00:00:00.000474
 | 00:00:00.00275  | 00:00:00.002949 |             0 | async      | 2022-08-09 08:10:45.32744+00
 2078 |    16384 | _crunchyrepl | postgres-pki-dpl2-0 | 172.24.46.31  |                 |       49924 | 2022-08-07 17:20:18.016171+00 |              | streaming | 245/C51758A8 | 245/C51758A8 | 245/C51758A8 | 245/C51758A8 | 00:00:00.000691
 | 00:00:00.002947 | 00:00:00.002976 |             0 | async      | 2022-08-09 08:10:45.327771+00
 2080 |    16384 | _crunchyrepl | postgres-pki-2hdb-0 | 172.24.45.114 |                 |       49904 | 2022-08-07 17:20:18.027174+00 |              | streaming | 245/C51758A8 | 245/C51758A8 | 245/C51758A8 | 245/C51758A8 | 00:00:00.000541
 | 00:00:00.002995 | 00:00:00.003018 |             0 | async      | 2022-08-09 08:10:45.327478+00
(3 rows)

Additional Information

N/A

[yasser1chihab]

Any updates about this issues ??

[batazor]

+1