[postgresql-ha] Multiple Primaries #2610

gnomus · 2020-05-18T13:16:08Z

Which chart:
postgresql-ha 3.2.1

Describe the bug
Somehow both Postgres Instances End up in Primary Mode.
This Results in pgpool redirecting requests to both instances and thus the 2 Databases drift appart with different States.

Output of repmgr cluster show:

DB 0

WARNING: following issues were detected
  - node "redacted-postgresql-ha-postgresql-1" (ID: 1001) is running but the repmgr node record is inactive

 ID   | Name                            | Role    | Status    | Upstream | Location | Priority | Timeline | Connection string                                                                                                                                                                                 
------+---------------------------------+---------+-----------+----------+----------+----------+----------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | redacted-postgresql-ha-postgresql-0 | primary | * running |          | default  | 100      | 9        | user=repmgr password=redacted host=redacted-postgresql-ha-postgresql-0.redacted-postgresql-ha-postgresql-headless.redacted.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | redacted-postgresql-ha-postgresql-1 | primary | ! running |          | default  | 100      | 8        | user=repmgr password=redacted host=redacted-postgresql-ha-postgresql-1.redacted-postgresql-ha-postgresql-headless.redacted.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

command terminated with exit code 25

DB 1

WARNING: following issues were detected
  - node "redacted-postgresql-ha-postgresql-0" (ID: 1000) is registered as standby but running as primary

 ID   | Name                            | Role    | Status               | Upstream | Location | Priority | Timeline | Connection string                                                                                                                                                                                 
------+---------------------------------+---------+----------------------+----------+----------+----------+----------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | redacted-postgresql-ha-postgresql-0 | standby | ! running as primary |          | default  | 100      | 9        | user=repmgr password=redacted host=redacted-postgresql-ha-postgresql-0.redacted-postgresql-ha-postgresql-headless.redacted.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | redacted-postgresql-ha-postgresql-1 | primary | * running            |          | default  | 100      | 8        | user=repmgr password=redacted host=redacted-postgresql-ha-postgresql-1.redacted-postgresql-ha-postgresql-headless.redacted.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

command terminated with exit code 25

To Reproduce
Steps to reproduce the behavior:
This just happens randomly as it seems.

Expected behavior
Only One Node at a Time being the Primary Node

Version of Helm and Kubernetes:

Output of helm version:

version.BuildInfo{Version:"v3.0.2", GitCommit:"19e47ee3283ae98139d98460de796c1be1e3975f", GitTreeState:"clean", GoVersion:"go1.13.5"}

Output of kubectl version:

Client Version: version.Info{Major:"1", Minor:"17", GitVersion:"v1.17.0", GitCommit:"70132b0f130acc0bed193d9ba59dd186f0e634cf", GitTreeState:"clean", BuildDate:"2019-12-07T21:20:10Z", GoVersion:"go1.13.4", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"16", GitVersion:"v1.16.9", GitCommit:"a17149e1a189050796ced469dbd78d380f2ed5ef", GitTreeState:"clean", BuildDate:"2020-04-16T11:36:15Z", GoVersion:"go1.13.9", Compiler:"gc", Platform:"linux/amd64"

The text was updated successfully, but these errors were encountered:

javsalgar · 2020-05-19T16:12:27Z

Hi,

Do you remember any pattern that could lead to the issue? Did it happen after one instance crashing maybe? Or did it happen just right after deploying randomly

Roarain · 2020-05-25T13:28:40Z

also had this bug.

images

bitnami/minideb:buster
bitnami/pgpool:4.1.1-debian-10-r90
bitnami/postgres-exporter:0.8.0-debian-10-r58
bitnami/postgresql-repmgr:12.2.0-debian-10-r48

repmgr info

postgresql-postgresql-ha-postgresql-0

    1000 |                  | t      | postgresql-postgresql-ha-postgresql-0 | primary | default  |      100 | user=repmgr password=TfEkkmxw1x host=postgresql-postgresql-ha-
postgresql-0.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5 | repmgr   | repmgr_slot_1000 | /opt/bitnami
/repmgr/conf/repmgr.conf
    1001 |             1000 | t      | postgresql-postgresql-ha-postgresql-1 | standby | default  |      100 | user=repmgr password=TfEkkmxw1x host=postgresql-postgresql-ha-
postgresql-1.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5 | repmgr   | repmgr_slot_1001 | /opt/bitnami
/repmgr/conf/repmgr.conf
    1002 |             1000 | t      | postgresql-postgresql-ha-postgresql-2 | standby | default  |      100 | user=repmgr password=TfEkkmxw1x host=postgresql-postgresql-ha-
postgresql-2.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5 | repmgr   | repmgr_slot_1002 | /opt/bitnami
/repmgr/conf/repmgr.conf

postgresql-postgresql-ha-postgresql-1

    1002 |             1000 | t      | postgresql-postgresql-ha-postgresql-2 | standby | default  |      100 | user=repmgr password=TfEkkmxw1x host=postgresql-postgresql-ha-
postgresql-2.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5 | repmgr   | repmgr_slot_1002 | /opt/bitnami
/repmgr/conf/repmgr.conf
    1000 |                  | f      | postgresql-postgresql-ha-postgresql-0 | primary | default  |      100 | user=repmgr password=TfEkkmxw1x host=postgresql-postgresql-ha-
postgresql-0.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5 | repmgr   | repmgr_slot_1000 | /opt/bitnami
/repmgr/conf/repmgr.conf
    1001 |                  | t      | postgresql-postgresql-ha-postgresql-1 | primary | default  |      100 | user=repmgr password=TfEkkmxw1x host=postgresql-postgresql-ha-
postgresql-1.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5 | repmgr   | repmgr_slot_1001 | /opt/bitnami
/repmgr/conf/repmgr.conf

postgresql-postgresql-ha-postgresql-2

    1000 |                  | t      | postgresql-postgresql-ha-postgresql-0 | primary | default  |      100 | user=repmgr password=TfEkkmxw1x host=postgresql-postgresql-ha-
postgresql-0.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5 | repmgr   | repmgr_slot_1000 | /opt/bitnami
/repmgr/conf/repmgr.conf
    1001 |             1000 | t      | postgresql-postgresql-ha-postgresql-1 | standby | default  |      100 | user=repmgr password=TfEkkmxw1x host=postgresql-postgresql-ha-
postgresql-1.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5 | repmgr   | repmgr_slot_1001 | /opt/bitnami
/repmgr/conf/repmgr.conf
    1002 |             1000 | t      | postgresql-postgresql-ha-postgresql-2 | standby | default  |      100 | user=repmgr password=TfEkkmxw1x host=postgresql-postgresql-ha-
postgresql-2.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5 | repmgr   | repmgr_slot_1002 | /opt/bitnami
/repmgr/conf/repmgr.conf

correct role
postgresql-postgresql-ha-postgresql-1: primary
postgresql-postgresql-ha-postgresql-0: standby
postgresql-postgresql-ha-postgresql-2: standby
logs
postgresql-postgresql-ha-postgresql-1

DEBUG: connecting to: "user=repmgr password=TfEkkmxw1x connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local port=5432 fallback_application_name=repmgr"
ERROR: connection to database failed
DETAIL:
timeout expired
INFO: standby promoted to primary after 34 second(s)
DETAIL: server "postgresql-postgresql-ha-postgresql-1" (ID: 1001) was successfully promoted to primary
[2020-05-25 08:29:27] [NOTICE] notifying node "postgresql-postgresql-ha-postgresql-2" (ID: 1002) to follow node 1001
INFO:  node 1002 received notification to follow node 1001
[2020-05-25 08:29:27] [NOTICE] monitoring cluster primary "postgresql-postgresql-ha-postgresql-1" (ID: 1001)

postgresql-postgresql-ha-postgresql-2

^[[38;5;6mrepmgr ^[[38;5;5m08:33:50.62 ^[[0m^[[38;5;2mINFO ^[[0m ==> Auto-detected primary node: 'postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local:5432'
^[[38;5;6mrepmgr ^[[38;5;5m08:33:50.63 ^[[0m^[[38;5;2mINFO ^[[0m ==> Preparing PostgreSQL configuration...
^[[38;5;6mrepmgr ^[[38;5;5m08:33:50.63 ^[[0m^[[38;5;2mINFO ^[[0m ==> Preparing repmgr configuration...
^[[38;5;6mrepmgr ^[[38;5;5m08:33:50.64 ^[[0m^[[38;5;2mINFO ^[[0m ==> Initializing Repmgr...
^[[38;5;6mrepmgr ^[[38;5;5m08:33:50.64 ^[[0m^[[38;5;2mINFO ^[[0m ==> Waiting for primary node...
^[[38;5;6mrepmgr ^[[38;5;5m08:33:50.67 ^[[0m^[[38;5;2mINFO ^[[0m ==> Cloning data from primary node...

postgresql-postgresql-ha-postgresql-0

[2020-05-25 08:28:23] [WARNING] unable to ping "user=repmgr password=TfEkkmxw1x host=postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5"
[2020-05-25 08:28:23] [DETAIL] PQping() returned "PQPING_NO_RESPONSE"
[2020-05-25 08:28:23] [WARNING] connection to node "postgresql-postgresql-ha-postgresql-0" (ID: 1000) lost
[2020-05-25 08:28:23] [DETAIL]

[2020-05-25 08:28:28] [ERROR] connection to database failed
[2020-05-25 08:28:28] [DETAIL]
timeout expired

[2020-05-25 08:28:28] [DETAIL] attempted to connect using:
  user=repmgr password=TfEkkmxw1x connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local port=5432 fallback_application_name=repmgr
[2020-05-25 08:28:28] [WARNING] reconnection to node "postgresql-postgresql-ha-postgresql-0" (ID: 1000) failed
[2020-05-25 08:28:28] [WARNING] unable to connect to local node
[2020-05-25 08:30:00] [WARNING] unable to ping "user=repmgr password=TfEkkmxw1x connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local port=5432 fallback_application_name=repmgr"
[2020-05-25 08:30:00] [DETAIL] PQping() returned "PQPING_NO_RESPONSE"
[2020-05-25 08:30:05] [NOTICE] node 1000 has recovered, reconnecting
[2020-05-25 08:30:05] [NOTICE] reconnected to local node after 96 seconds
[2020-05-25 08:30:07] [NOTICE] standby node "postgresql-postgresql-ha-postgresql-2" (ID: 1002) has disconnected
[2020-05-25 08:30:07] [NOTICE] standby node "postgresql-postgresql-ha-postgresql-1" (ID: 1001) has disconnected
[2020-05-25 08:35:14] [NOTICE] standby node "postgresql-postgresql-ha-postgresql-2" (ID: 1002) has reconnected after 307 seconds

postgresql-postgresql-ha-postgresql-1 cannot connect to postgresql-postgresql-ha-postgresql-0 ,so postgresql-postgresql-ha-postgresql-1 become to primary and notify to
postgresql-postgresql-ha-postgresql-2. But when postgresql-postgresql-ha-postgresql-2 start, Auto-detected primary node: 'postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.postgresql.svc.cluster.local:5432' again and again until split-brain.
bug

postgresql-postgresql-ha-postgresql-1 doesnot get (n/2 + 1) votes to be primary.
postgresql-postgresql-ha-postgresql-0 doesnot been killed after new primary is ok.
postgresql-postgresql-ha-postgresql-2 find first node postgresql-postgresql-ha-postgresql-0 as primary (ERROR), but ignore the real primary postgresql-postgresql-ha-postgresql-2.
Shoud connect to all nodes and recognize the real primary postgresql-postgresql-ha-postgresql-1.
pgpool doesnot recurise all nodes to find the real primary(postgresql-postgresql-ha-postgresql-1) and exception node(postgresql-postgresql-ha-postgresql-2 shoud be remove from standby.)

javsalgar · 2020-05-26T08:12:26Z

Hi,

So, if I understand correctly (to reproduce it correctly), did you kill node 0 so node 1 becomes the primary? If so, at which point did you perform this operation?

stale · 2020-06-10T09:12:07Z

This Issue has been automatically marked as "stale" because it has not had recent activity (for 15 days). It will be closed if no further activity occurs. Thanks for the feedback.

stale · 2020-06-15T23:39:58Z

Due to the lack of activity in the last 5 days since it was marked as "stale", we proceed to close this Issue. Do not hesitate to reopen it later if necessary.

vahid-sohrabloo · 2020-12-14T20:20:15Z

I have this problem too.
it's random.

opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh  repmgr -f /opt/bitnami/repmgr/conf/repmgr.conf  cluster show
 1000 | user-db-postgresql-ha-postgresql-0 | primary | ! running |          | default  | 100      | 3        | user=repmgr password=fffffff host=user-db-postgresql-ha-postgresql-0.user-db-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | user-db-postgresql-ha-postgresql-1 | primary | ! running |          | default  | 100      | 2        | user=repmgr password=fffffff host=user-db-postgresql-ha-postgresql-1.user-db-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1002 | user-db-postgresql-ha-postgresql-2 | primary | * running |          | default  | 100      | 4        | user=repmgr password=fffffff host=user-db-postgresql-ha-postgresql-2.user-db-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

WARNING: following issues were detected
  - node "user-db-postgresql-ha-postgresql-0" (ID: 1000) is running but the repmgr node record is inactive
  - node "user-db-postgresql-ha-postgresql-1" (ID: 1001) is running but the repmgr node record is inactive
```

javsalgar · 2020-12-15T09:06:57Z

Hi,

Any pattern that could give us any clue? Did one of the pod crash or several?

vahid-sohrabloo · 2020-12-15T13:54:37Z

I don't know when exactly. I think when two or three of the pods crashed at the same time. Or maybe I lost my connection between nodes at the same time.

javsalgar · 2020-12-16T09:56:31Z

Hi,

I see, not sure if there's an easy way to reproduce this kind of situations. Let's see if other users come across the same issue as well.

greenday9 · 2021-06-14T17:06:16Z

I ran into a similar issue with multiple primaries.

$ kubectl exec postgresql-postgresql-ha-postgresql-0 -- /opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh repmgr -f /opt/bitnami/repmgr/conf/repmgr.conf cluster show
postgresql-repmgr 15:15:11.04
postgresql-repmgr 15:15:11.04 Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 15:15:11.05 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-postgresql-repmgr
postgresql-repmgr 15:15:11.05 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-postgresql-repmgr/issues
postgresql-repmgr 15:15:11.06

 ID   | Name                                  | Role    | Status    | Upstream | Location | Priority | Timeline | Connection string                                                                                                                                     
------+---------------------------------------+---------+-----------+----------+----------+----------+----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | postgresql-postgresql-ha-postgresql-0 | primary | * running |          | default  | 100      | 3        | user=repmgr password=qe266YJJef host=postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | postgresql-postgresql-ha-postgresql-1 | primary | ! running |          | default  | 100      | 2        | user=repmgr password=qe266YJJef host=postgresql-postgresql-ha-postgresql-1.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

WARNING: following issues were detected
  - node "postgresql-postgresql-ha-postgresql-1" (ID: 1001) is running but the repmgr node record is inactive

command terminated with exit code 25

$ kubectl exec postgresql-postgresql-ha-postgresql-1 -- /opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh repmgr -f /opt/bitnami/repmgr/conf/repmgr.conf cluster show
postgresql-repmgr 15:15:20.42
postgresql-repmgr 15:15:20.42 Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 15:15:20.42 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-postgresql-repmgr
postgresql-repmgr 15:15:20.43 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-postgresql-repmgr/issues
postgresql-repmgr 15:15:20.43

 ID   | Name                                  | Role    | Status               | Upstream | Location | Priority | Timeline | Connection string                                                                                                                          
------+---------------------------------------+---------+----------------------+----------+----------+----------+----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | postgresql-postgresql-ha-postgresql-0 | standby | ! running as primary |          | default  | 100      | 3        | user=repmgr password=qe266YJJef host=postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | postgresql-postgresql-ha-postgresql-1 | primary | * running            |          | default  | 100      | 2        | user=repmgr password=qe266YJJef host=postgresql-postgresql-ha-postgresql-1.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

WARNING: following issues were detected
  - node "postgresql-postgresql-ha-postgresql-0" (ID: 1000) is registered as standby but running as primary

command terminated with exit code 25

DB was created with these args:

helm install postgresql --set persistence.enabled=false,replication.enabled=true,postgresql.password=admin,pgpool.childLifeTime=0,pgpool.replicaCount=2,pgpool.numInitChildren=250,postgresql.maxConnections=500 --version 7.5.3 bitnami/postgresql-ha

Not sure of what triggered this. There was a stability run which should have a relatively stable query traffic rate.

kubectl get pods reports that instance 0 restarted a number of times.

postgresql-postgresql-ha-pgpool-57d4b7b559-fv8l9         1/1     Running     33         2d23h
postgresql-postgresql-ha-pgpool-57d4b7b559-psr9h         1/1     Running     43         2d23h
postgresql-postgresql-ha-postgresql-0                    1/1     Running     51         2d23h
postgresql-postgresql-ha-postgresql-1                    1/1     Running     1          2d23h

instance 0 had this log:

[centos@zc428smlc01kma001 ~]$ kubectl logs postgresql-postgresql-ha-postgresql-0
postgresql-repmgr 15:23:43.78
postgresql-repmgr 15:23:43.79 Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 15:23:43.79 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-postgresql-repmgr
postgresql-repmgr 15:23:43.80 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-postgresql-repmgr/issues
postgresql-repmgr 15:23:43.80
postgresql-repmgr 15:23:43.84 INFO  ==> ** Starting PostgreSQL with Replication Manager setup **
postgresql-repmgr 15:23:43.89 INFO  ==> Validating settings in REPMGR_* env vars...
postgresql-repmgr 15:23:43.90 INFO  ==> Validating settings in POSTGRESQL_* env vars..
postgresql-repmgr 15:23:43.91 INFO  ==> Querying all partner nodes for common upstream node...
postgresql-repmgr 15:23:44.04 INFO  ==> Auto-detected primary node: 'postgresql-postgresql-ha-postgresql-1.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local:5432'
postgresql-repmgr 15:23:44.07 INFO  ==> Preparing PostgreSQL configuration...
postgresql-repmgr 15:23:44.08 INFO  ==> postgresql.conf file not detected. Generating it...
postgresql-repmgr 15:23:52.33 INFO  ==> Preparing repmgr configuration...
postgresql-repmgr 15:23:52.36 INFO  ==> Initializing Repmgr...
postgresql-repmgr 15:23:52.37 INFO  ==> Waiting for primary node...
postgresql-repmgr 15:23:52.43 INFO  ==> Cloning data from primary node...
postgresql-repmgr 15:24:47.13 INFO  ==> Initializing PostgreSQL database...
postgresql-repmgr 15:24:47.15 INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/postgresql.conf detected
postgresql-repmgr 15:24:47.15 INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/pg_hba.conf detected
postgresql-repmgr 15:24:47.20 INFO  ==> Deploying PostgreSQL with persisted data...
postgresql-repmgr 15:24:48.55 INFO  ==> Configuring replication parameters
postgresql-repmgr 15:24:51.33 INFO  ==> Configuring fsync
postgresql-repmgr 15:24:51.66 INFO  ==> Setting up streaming replication slave...
postgresql-repmgr 15:24:53.59 INFO  ==> Starting PostgreSQL in background...
postgresql-repmgr 15:25:05.79 INFO  ==> Unregistering standby node...
postgresql-repmgr 15:25:05.97 INFO  ==> Registering Standby node...
postgresql-repmgr 15:25:06.15 INFO  ==> Check if primary running...
postgresql-repmgr 15:25:06.16 INFO  ==> Waiting for primary node...
postgresql-repmgr 15:25:25.39 INFO  ==> Running standby follow...
postgresql-repmgr 15:25:56.69 INFO  ==> Stopping PostgreSQL...
waiting for server to shut down........ done
server stopped
postgresql-repmgr 15:26:00.82 INFO  ==> ** PostgreSQL with Replication Manager setup finished! **

postgresql-repmgr 15:26:00.86 INFO  ==> Starting PostgreSQL in background...
waiting for server to start.....2021-06-13 15:26:02.165 GMT [455] LOG:  pgaudit extension initialized
2021-06-13 15:26:02.167 GMT [455] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2021-06-13 15:26:02.167 GMT [455] LOG:  listening on IPv6 address "::", port 5432
..2021-06-13 15:26:04.512 GMT [455] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
..2021-06-13 15:26:06.202 GMT [455] LOG:  redirecting log output to logging collector process
2021-06-13 15:26:06.202 GMT [455] HINT:  Future log output will appear in directory "/opt/bitnami/postgresql/logs".
.........2021-06-13 15:26:15.683 GMT [476] LOG:  database system was shut down in recovery at 2021-06-13 15:25:57 GMT
2021-06-13 15:26:15.683 GMT [476] LOG:  entering standby mode
2021-06-13 15:26:15.686 GMT [477] FATAL:  the database system is starting up
2021-06-13 15:26:15.687 GMT [479] FATAL:  the database system is starting up
2021-06-13 15:26:15.687 GMT [480] FATAL:  the database system is starting up
2021-06-13 15:26:15.687 GMT [478] FATAL:  the database system is starting up
2021-06-13 15:26:15.688 GMT [481] FATAL:  the database system is starting up
2021-06-13 15:26:15.688 GMT [482] FATAL:  the database system is starting up
2021-06-13 15:26:15.689 GMT [483] FATAL:  the database system is starting up
2021-06-13 15:26:15.689 GMT [486] FATAL:  the database system is starting up
2021-06-13 15:26:15.690 GMT [485] FATAL:  the database system is starting up
2021-06-13 15:26:15.691 GMT [489] FATAL:  the database system is starting up
2021-06-13 15:26:15.691 GMT [488] FATAL:  the database system is starting up
2021-06-13 15:26:15.691 GMT [484] FATAL:  the database system is starting up
2021-06-13 15:26:15.691 GMT [487] FATAL:  the database system is starting up
2021-06-13 15:26:15.693 GMT [490] FATAL:  the database system is starting up
..2021-06-13 15:26:16.947 GMT [476] LOG:  redo starts at 0/43000028
2021-06-13 15:26:16.949 GMT [476] LOG:  consistent recovery state reached at 0/44003260
2021-06-13 15:26:16.949 GMT [476] LOG:  invalid record length at 0/44003338: wanted 24, got 0
2021-06-13 15:26:16.950 GMT [455] LOG:  database system is ready to accept read only connections
 done
server started
postgresql-repmgr 15:26:17.72 INFO  ==> ** Starting repmgrd **
2021-06-13 15:26:17.728 GMT [495] LOG:  started streaming WAL from primary at 0/44000000 on timeline 2
[2021-06-13 15:26:17] [NOTICE] repmgrd (repmgrd 5.2.1) starting up
INFO:  set_repmgrd_pid(): provided pidfile is /opt/bitnami/repmgr/tmp/repmgr.pid
[2021-06-13 15:26:17] [NOTICE] starting monitoring of node "postgresql-postgresql-ha-postgresql-0" (ID: 1000)
[2021-06-14 09:52:31] [WARNING] unable to ping "user=repmgr password=qe266YJJef host=postgresql-postgresql-ha-postgresql-1.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5"
[2021-06-14 09:52:31] [DETAIL] PQping() returned "PQPING_NO_RESPONSE"
[2021-06-14 09:52:31] [WARNING] unable to connect to upstream node "postgresql-postgresql-ha-postgresql-1" (ID: 1001)
[2021-06-14 09:52:36] [WARNING] unable to ping "user=repmgr password=qe266YJJef connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-1.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local port=5432 fallback_application_name=repmgr"
[2021-06-14 09:52:36] [DETAIL] PQping() returned "PQPING_NO_RESPONSE"
[2021-06-14 09:52:46] [WARNING] unable to ping "user=repmgr password=qe266YJJef connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-1.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local port=5432 fallback_application_name=repmgr"
[2021-06-14 09:52:46] [DETAIL] PQping() returned "PQPING_NO_RESPONSE"
2021-06-14 09:52:50.918 GMT [31637] LOG:  could not receive data from client: Connection timed out
2021-06-14 09:52:51.494 GMT [31648] LOG:  could not receive data from client: Connection timed out
2021-06-14 09:52:51.494 GMT [2453] LOG:  could not receive data from client: Connection timed out
2021-06-14 09:52:51.622 GMT [2559] LOG:  could not receive data from client: Connection timed out
2021-06-14 09:52:53.158 GMT [31725] LOG:  could not receive data from client: Connection timed out
[2021-06-14 09:52:56] [WARNING] unable to ping "user=repmgr password=qe266YJJef connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-1.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local port=5432 fallback_application_name=repmgr"
[2021-06-14 09:52:56] [DETAIL] PQping() returned "PQPING_NO_RESPONSE"
[2021-06-14 09:52:56] [WARNING] unable to reconnect to node "postgresql-postgresql-ha-postgresql-1" (ID: 1001) after 3 attempts
[2021-06-14 09:52:56] [NOTICE] this node is the only available candidate and will now promote itself
NOTICE: using provided configuration file "/opt/bitnami/repmgr/conf/repmgr.conf"
DEBUG: connecting to: "user=repmgr password=qe266YJJef connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local port=5432 fallback_application_name=repmgr options=-csearch_path="
DEBUG: set_config():
  SET synchronous_commit TO 'local'
INFO: connected to standby, checking its state
DEBUG: get_recovery_type(): SELECT pg_catalog.pg_is_in_recovery()
DEBUG: get_node_record():
  SELECT n.node_id, n.type, n.upstream_node_id, n.node_name,  n.conninfo, n.repluser, n.slot_name, n.location, n.priority, n.active, n.config_file, '' AS upstream_node_name, NULL AS attached   FROM repmgr.nodes n  WHERE n.node_id = 1000
DEBUG: get_replication_info():
 SELECT ts,         in_recovery,         last_wal_receive_lsn,         last_wal_replay_lsn,         last_xact_replay_timestamp,         CASE WHEN (last_wal_receive_lsn = last_wal_replay_lsn)           THEN 0::INT         ELSE           CASE WHEN last_xact_replay_timestamp IS NULL             THEN 0::INT           ELSE             EXTRACT(epoch FROM (pg_catalog.clock_timestamp() - last_xact_replay_timestamp))::INT           END         END AS replication_lag_time,         last_wal_receive_lsn >= last_wal_replay_lsn AS receiving_streamed_wal,         wal_replay_paused,         upstream_last_seen,         upstream_node_id    FROM (  SELECT CURRENT_TIMESTAMP AS ts,         pg_catalog.pg_is_in_recovery() AS in_recovery,         pg_catalog.pg_last_xact_replay_timestamp() AS last_xact_replay_timestamp,         COALESCE(pg_catalog.pg_last_wal_receive_lsn(), '0/0'::PG_LSN) AS last_wal_receive_lsn,         COALESCE(pg_catalog.pg_last_wal_replay_lsn(),  '0/0'::PG_LSN) AS last_wal_replay_lsn,         CASE WHEN pg_catalog.pg_is_in_recovery() IS FALSE           THEN FALSE           ELSE pg_catalog.pg_is_wal_replay_paused()         END AS wal_replay_paused,         CASE WHEN pg_catalog.pg_is_in_recovery() IS FALSE           THEN -1           ELSE repmgr.get_upstream_last_seen()         END AS upstream_last_seen,         CASE WHEN pg_catalog.pg_is_in_recovery() IS FALSE           THEN -1           ELSE repmgr.get_upstream_node_id()         END AS upstream_node_id           ) q
INFO: searching for primary node
DEBUG: get_primary_connection():
  SELECT node_id, conninfo,          CASE WHEN type = 'primary' THEN 1 ELSE 2 END AS type_priority         FROM repmgr.nodes    WHERE active IS TRUE      AND type != 'witness' ORDER BY active DESC, type_priority, priority, node_id
INFO: checking if node 1001 is primary
DEBUG: connecting to: "user=repmgr password=qe266YJJef connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-1.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local port=5432 fallback_application_name=repmgr options=-csearch_path="
2021-06-14 09:52:58.982 GMT [495] FATAL:  could not receive data from WAL stream: could not receive data from server: Connection timed out
2021-06-14 09:52:58.982 GMT [476] LOG:  invalid record length at 0/44003658: wanted 24, got 0
2021-06-14 09:52:59.306 GMT [2985] LOG:  incomplete startup packet
ERROR: connection to database failed
DETAIL:
timeout expired

DETAIL: attempted to connect using:
  user=repmgr password=qe266YJJef connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-1.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local port=5432 fallback_application_name=repmgr options=-csearch_path=
INFO: checking if node 1000 is primary
DEBUG: connecting to: "user=repmgr password=qe266YJJef connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.default.svc.cluster.local port=5432 fallback_application_name=repmgr options=-csearch_path="
DEBUG: set_config():
  SET synchronous_commit TO 'local'
DEBUG: get_recovery_type(): SELECT pg_catalog.pg_is_in_recovery()
DEBUG: get_node_replication_stats():
 SELECT pg_catalog.current_setting('max_wal_senders')::INT AS max_wal_senders,         (SELECT pg_catalog.count(*) FROM pg_catalog.pg_stat_replication) AS attached_wal_receivers,         current_setting('max_replication_slots')::INT AS max_replication_slots,         (SELECT pg_catalog.count(*) FROM pg_catalog.pg_replication_slots WHERE slot_type='physical') AS total_replication_slots,         (SELECT pg_catalog.count(*) FROM pg_catalog.pg_replication_slots WHERE active IS TRUE AND slot_type='physical')  AS active_replication_slots,         (SELECT pg_catalog.count(*) FROM pg_catalog.pg_replication_slots WHERE active IS FALSE AND slot_type='physical') AS inactive_replication_slots,         pg_catalog.pg_is_in_recovery() AS in_recovery
DEBUG: get_active_sibling_node_records():
  SELECT n.node_id, n.type, n.upstream_node_id, n.node_name,  n.conninfo, n.repluser, n.slot_name, n.location, n.priority, n.active, n.config_file, '' AS upstream_node_name, NULL AS attached     FROM repmgr.nodes n    WHERE n.upstream_node_id = 1001      AND n.node_id != 1000      AND n.active IS TRUE ORDER BY n.node_id
DEBUG: clear_node_info_list() - closing open connections
DEBUG: clear_node_info_list() - unlinking
DEBUG: get_node_record():
  SELECT n.node_id, n.type, n.upstream_node_id, n.node_name,  n.conninfo, n.repluser, n.slot_name, n.location, n.priority, n.active, n.config_file, '' AS upstream_node_name, NULL AS attached   FROM repmgr.nodes n  WHERE n.node_id = 1000
NOTICE: promoting standby to primary
DETAIL: promoting server "postgresql-postgresql-ha-postgresql-0" (ID: 1000) using "/opt/bitnami/postgresql/bin/pg_ctl -o "--config-file="/opt/bitnami/postgresql/conf/postgresql.conf" --external_pid_file="/opt/bitnami/postgresql/tmp/postgresql.pid" --hba_file="/opt/bitnami/postgresql/conf/pg_hba.conf"" -w -D '/bitnami/postgresql/data' promote"
2021-06-14 09:53:01.142 GMT [476] LOG:  received promote request
2021-06-14 09:53:01.142 GMT [2997] FATAL:  terminating walreceiver process due to administrator command
2021-06-14 09:53:01.144 GMT [476] LOG:  redo done at 0/44003620
2021-06-14 09:53:01.144 GMT [476] LOG:  last completed transaction was at log time 2021-06-13 15:26:25.442619+00
2021-06-14 09:53:01.146 GMT [476] LOG:  selected new timeline ID: 3
2021-06-14 09:53:08.291 GMT [3020] LOG:  incomplete startup packet
2021-06-14 09:53:08.292 GMT [2991] LOG:  incomplete startup packet
2021-06-14 09:53:08.294 GMT [2990] LOG:  incomplete startup packet
2021-06-14 09:53:08.298 GMT [3005] LOG:  incomplete startup packet
2021-06-14 09:53:08.303 GMT [2987] LOG:  incomplete startup packet
2021-06-14 09:53:08.306 GMT [2988] LOG:  incomplete startup packet
2021-06-14 09:53:08.307 GMT [3031] LOG:  incomplete startup packet
2021-06-14 09:53:08.313 GMT [2996] LOG:  incomplete startup packet
2021-06-14 09:53:08.443 GMT [476] LOG:  archive recovery complete
NOTICE: waiting up to 60 seconds (parameter "promote_check_timeout") for promotion to complete
DEBUG: get_recovery_type(): SELECT pg_catalog.pg_is_in_recovery()
INFO: standby promoted to primary after 0 second(s)
DEBUG: setting node 1000 as primary and marking existing primary as failed
DEBUG: begin_transaction()
DEBUG: commit_transaction()
2021-06-14 09:53:10.662 GMT [455] LOG:  database system is ready to accept connections
NOTICE: STANDBY PROMOTE successful
DETAIL: server "postgresql-postgresql-ha-postgresql-0" (ID: 1000) was successfully promoted to primary
DEBUG: _create_event(): event is "standby_promote" for node 1000
DEBUG: get_recovery_type(): SELECT pg_catalog.pg_is_in_recovery()
DEBUG: _create_event():
   INSERT INTO repmgr.events (              node_id,              event,              successful,              details             )       VALUES ($1, $2, $3, $4)    RETURNING event_timestamp
DEBUG: _create_event(): Event timestamp is "2021-06-14 09:53:10.710021+00"
DEBUG: _create_event(): command is '/opt/bitnami/repmgr/events/router.sh %n %e %s "%t" "%d"'
INFO: executing notification command for event "standby_promote"
DETAIL: command is:
  /opt/bitnami/repmgr/events/router.sh 1000 standby_promote 1 "2021-06-14 09:53:10.710021+00" "server \"postgresql-postgresql-ha-postgresql-0\" (ID: 1000) was successfully promoted to primary"
DEBUG: clear_node_info_list() - closing open connections
DEBUG: clear_node_info_list() - unlinking
[2021-06-14 09:53:11] [NOTICE] node 1000 has recovered, reconnecting
[2021-06-14 09:53:11] [NOTICE] monitoring cluster primary "postgresql-postgresql-ha-postgresql-0" (ID: 1000)
2021-06-14 10:32:08.676 GMT [2751] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:02:28.659 GMT [822] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:22:03.217 GMT [2649] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:28:53.664 GMT [972] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:34:03.675 GMT [380] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:39:24.724 GMT [32290] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:39:53.229 GMT [2796] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:50:50.886 GMT [2831] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:50:50.886 GMT [2826] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:52:11.270 GMT [2777] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:52:11.270 GMT [2757] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:52:12.807 GMT [32524] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 11:52:12.807 GMT [458] LOG:  could not receive data from client: Connection reset by peer

Around the time of the instance 0 promote, I see this in the instance 1 log:

2021-06-13 16:47:34.230 GMT [9390] LOG:  could not receive data from client: Connection reset by peer
2021-06-13 16:47:34.230 GMT [9354] LOG:  could not receive data from client: Connection reset by peer
2021-06-13 16:47:34.230 GMT [9345] LOG:  could not receive data from client: Connection reset by peer
2021-06-13 16:53:34.678 GMT [10191] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 09:52:58.260 GMT [19283] LOG:  could not receive data from client: Connection timed out
2021-06-14 09:52:58.260 GMT [19283] LOG:  unexpected EOF on client connection with an open transaction
2021-06-14 09:52:58.357 GMT [15451] LOG:  could not send data to client: Connection reset by peer
2021-06-14 09:52:58.357 GMT [15451] FATAL:  connection to client lost
2021-06-14 09:52:58.452 GMT [15212] LOG:  could not receive data from client: Connection timed out
2021-06-14 09:52:58.485 GMT [15419] WARNING:  there is no transaction in progress
2021-06-14 09:53:23.925 GMT [15314] WARNING:  there is no transaction in progress
2021-06-14 09:53:24.180 GMT [19157] WARNING:  there is no transaction in progress
2021-06-14 09:53:24.436 GMT [15228] LOG:  could not receive data from client: Connection timed out
2021-06-14 09:53:24.436 GMT [15228] LOG:  unexpected EOF on standby connection
[2021-06-14 09:53:24] [NOTICE] standby node "postgresql-postgresql-ha-postgresql-0" (ID: 1000) has disconnected
2021-06-14 09:57:26.076 GMT [20557] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 09:57:26.108 GMT [20556] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 09:57:37.494 GMT [20603] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 09:57:40.661 GMT [20653] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 09:57:41.068 GMT [20654] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 09:57:46.033 GMT [20659] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 09:57:51.054 GMT [20682] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 09:57:56.054 GMT [20692] LOG:  could not receive data from client: Connection reset by peer
2021-06-14 09:58:10.656 GMT [20740] LOG:  could not receive data from client: Connection reset by peer

javsalgar · 2021-06-15T08:01:15Z

Hi,

I see some connection issues, but it's not clear to me if it has to do with the instance startup, and then everything gets back to normal. Did you see any more connection issues with other pods?

greenday9 · 2021-06-15T23:19:09Z

@javsalgar , it is possible there was some connectivity issues during the last time of startup for instance 0. I don't have much more data from when this event happened. Regardless, both instances remained as masters after the last instance 0 startup. I eventually deleted instance 0 and it recovered.

aw381246 · 2021-08-27T20:05:20Z

We have also had this issue and I've actually found it pretty easy to reproduce. It does seem random though as another commenter said.

If you start with 2 replicas, -0 being primary and -1 being standby. Then kubectl delete pod -0, then it will automatically come back up in our case because it's in a statefulset. I have seen these 3 different outcomes doing this, seemingly at random.

Outcome 1 (expected and healthy): pod -1 becomes primary and pod -0 becomes standby when it comes back up
Outcome 2 (unexpected but healthy): pod -0 remains primary when it comes up and pod -1 remains standby
Outcome 3 (unexpected and unhealthy): pod -0 stays primary, but pod -1 also becomes primary (shows active = false in repmgr.nodes table). Replication does not happen between the pods, queries fail, etc.

Once you're in the Outcome 3 state, you cannot get out of it unless you scale the replicas down to 1 (leaving only -0 as primary) then scale back up to desired number and you will be back in starting state.

javsalgar · 2021-08-30T10:14:13Z

Let me try this again, and I will let you know if I get to the issue.

mikeoutlaw · 2021-08-30T15:31:27Z

FWIW, to add onto @aw381246's comment, we were able to reproduce the issue via the following steps:

Install the chart

➜  ~ helm install pg-ha-test bitnami/postgresql-ha

Verify the cluster status

➜  ~ kubectl exec pg-ha-test-postgresql-ha-postgresql-0 -- /opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh repmgr -f /opt/bitnami/repmgr/conf/repmgr.conf cluster show
postgresql-repmgr 14:03:35.44
postgresql-repmgr 14:03:35.45 Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 14:03:35.45 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-postgresql-repmgr
postgresql-repmgr 14:03:35.45 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-postgresql-repmgr/issues
postgresql-repmgr 14:03:35.45

 ID   | Name                                  | Role    | Status    | Upstream                              | Location | Priority | Timeline | Connection string
------+---------------------------------------+---------+-----------+---------------------------------------+----------+----------+----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | pg-ha-test-postgresql-ha-postgresql-0 | primary | * running |                                       | default  | 100      | 1        | user=repmgr password=0EPD7026uM host=pg-ha-test-postgresql-ha-postgresql-0.pg-ha-test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | pg-ha-test-postgresql-ha-postgresql-1 | standby |   running | pg-ha-test-postgresql-ha-postgresql-0 | default  | 100      | 1        | user=repmgr password=0EPD7026uM host=pg-ha-test-postgresql-ha-postgresql-1.pg-ha-test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

Delete the primary replica

To simulate a future deployment that would need to terminate a pod, as well as simulate a real pod termination due to unforeseen issues, we delete the primary pod.

➜  ~ kubectl delete pod pg-ha-test-postgresql-ha-postgresql-0
pod "pg-ha-test-postgresql-ha-postgresql-0" deleted

Oddities

In this particular test, we needed to delete the primary pod twice in order to reproduce the eventual error state being reported, but we have experienced this same issue sometimes on the first try and on other attempts it took 3 or more tries. Regardless, we could eventually reproduce the error state.
The expectation is that the standby replica would take over as the primary. However, we often noticed that after the primary was terminated, it would restart as the primary, even if the error wasn't immediately reproduced. Or said another way, the primary always seemed to restart as the primary and only when we got into the error state would the standby report that it was a primary.

Verify cluster status

From the original primary replica:

➜  ~ kubectl exec pg-ha-test-postgresql-ha-postgresql-0 -- /opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh repmgr -f /opt/bitnami/repmgr/conf/repmgr.conf cluster show
postgresql-repmgr 14:09:07.02
postgresql-repmgr 14:09:07.02 Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 14:09:07.03 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-postgresql-repmgr
postgresql-repmgr 14:09:07.03 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-postgresql-repmgr/issues
postgresql-repmgr 14:09:07.03

 ID   | Name                                  | Role    | Status               | Upstream | Location | Priority | Timeline | Connection string
------+---------------------------------------+---------+----------------------+----------+----------+----------+----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | pg-ha-test-postgresql-ha-postgresql-0 | primary | * running            |          | default  | 100      | 1        | user=repmgr password=0EPD7026uM host=pg-ha-test-postgresql-ha-postgresql-0.pg-ha-test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | pg-ha-test-postgresql-ha-postgresql-1 | standby | ! running as primary |          | default  | 100      | 2        | user=repmgr password=0EPD7026uM host=pg-ha-test-postgresql-ha-postgresql-1.pg-ha-test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

WARNING: following issues were detected
  - node "pg-ha-test-postgresql-ha-postgresql-1" (ID: 1001) is registered as standby but running as primary

command terminated with exit code 25

From the original standby replica:

➜  ~ kubectl exec pg-ha-test-postgresql-ha-postgresql-1 -- /opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh repmgr -f /opt/bitnami/repmgr/conf/repmgr.conf cluster show
postgresql-repmgr 14:09:32.42
postgresql-repmgr 14:09:32.42 Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 14:09:32.42 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-postgresql-repmgr
postgresql-repmgr 14:09:32.42 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-postgresql-repmgr/issues
postgresql-repmgr 14:09:32.43

WARNING: following issues were detected
  - node "pg-ha-test-postgresql-ha-postgresql-0" (ID: 1000) is running but the repmgr node record is inactive

 ID   | Name                                  | Role    | Status    | Upstream | Location | Priority | Timeline | Connection string
------+---------------------------------------+---------+-----------+----------+----------+----------+----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | pg-ha-test-postgresql-ha-postgresql-0 | primary | ! running |          | default  | 100      | 1        | user=repmgr password=0EPD7026uM host=pg-ha-test-postgresql-ha-postgresql-0.pg-ha-test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | pg-ha-test-postgresql-ha-postgresql-1 | primary | * running |          | default  | 100      | 2        | user=repmgr password=0EPD7026uM host=pg-ha-test-postgresql-ha-postgresql-1.pg-ha-test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

command terminated with exit code 25

NOTE that each replica reports both as primary, albeit with slight verbiage difference from the original primary replica in the Role and Status columns that it reports for the original standby replica, and that neither replica is communicating with the other per the Upstream column.

javsalgar · 2021-08-31T08:25:58Z

Thank you so much for the detailed report!

javsalgar · 2021-09-03T09:04:41Z

Hi,

Just a note to let you know that I was able to reproduce the issue after shutting down node 0 two times. I will open a task for investigating the issue in more detail. Thank you so much for reporting.

mikeoutlaw · 2021-09-07T14:05:57Z

Thank you @javsalgar!

jpsn123 · 2021-10-16T12:55:09Z

postgresql-repmgr 12:52:46.10 INFO ==> Starting PostgreSQL with Replication Manager setup

Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.14 INFO ==> Validating settings in REPMGR_* env vars...
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.15 INFO ==> Validating settings in POSTGRESQL_* env vars..
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.16 INFO ==> Querying all partner nodes for common upstream node...
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.29 WARN ==> Conflict of pretending primary role nodes (previously: 'postgresql-ha-postgresql-0.postgresql-ha-postgresql-headless.gitlab.svc.cluster.local:5432', now: 'postgresql-ha-postgresql-1.postgresql-ha-postgresql-headless.gitlab.svc.cluster.local:5432')
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.29 INFO ==> This node was acting as a primary before restart!
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.29 INFO ==> Can not find new primary. Starting PostgreSQL normally...
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.30 INFO ==> There are no nodes with primary role. Assuming the primary role...
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.30 INFO ==> Preparing PostgreSQL configuration...
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.31 INFO ==> postgresql.conf file not detected. Generating it...
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.45 INFO ==> Preparing repmgr configuration...
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.46 INFO ==> Initializing Repmgr...
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.47 INFO ==> Initializing PostgreSQL database...
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.48 INFO ==> Custom configuration /opt/bitnami/postgresql/conf/postgresql.conf detected
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.48 INFO ==> Custom configuration /opt/bitnami/postgresql/conf/pg_hba.conf detected
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.51 INFO ==> Deploying PostgreSQL with persisted data...
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.54 INFO ==> Configuring replication parameters
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.58 INFO ==> Configuring fsync
Sat, Oct 16 2021 8:52:46 pm | postgresql-repmgr 12:52:46.59 INFO ==> ** PostgreSQL with Replication Manager setup finished! **

migruiz4 · 2021-10-18T08:45:05Z

Thank you @jpsn123 for sharing your logs.

We have an internal task to investigate Postgresql-HA split-brain scenarios and look for solutions to prevent this behavior: some proposed solutions were adding witness nodes and improve the method used to reintegrate the primary node when recovered.

If you would like to contribute, feel free to send a PR with your suggestions and we will be happy to review it.

vishrantgupta · 2021-11-10T01:10:04Z

@migruiz4 how can we add the witness node given the current HELM chart?

migruiz4 · 2021-11-10T07:28:25Z

Hi @vishrantgupta,

Without getting much into details, the chart bitnami/postgresql-ha would need an additional Statefulset, similar to how MongoDB arbiter is implemented in bitnami/mongodb.

And the bitnami-docker-postgresql-repmgr would also require changes adding the 'register the node as witness' capability as it is described in the repmgr documentation.

pkExec · 2021-11-18T08:50:44Z

How to recover to a proper state when this issue occurs? Is there a workaround?

migruiz4 · 2021-11-22T12:53:25Z

Hi @pkExec,

I'm sorry but I don't know the exact method to recover Postgresql. As a suggestion, maybe performing a DB dump, redeploying the PostgreSQL chart, and restoring the dump would solve the problem. The following link may help you: https://www.postgresguide.com/utilities/backup-restore/

We are aware of this issue, and we are working on a solution to prevent split-brain scenarios. We are also open to any contributions that would help improve the chart.

colega · 2023-05-06T17:41:56Z

I think this issue should be reopened, I've been fighting this for some days. I thought it would be my setup (I'm running a jsonnet version of this helm) but then I tried to run the original helm chart, and this is still reproducible.

Steps to reproduce:

Create an empty cluster kind create cluster
Install helm chart: helm install bitnami/postgresql-ha --generate-name
Wait until all pods are healthy
Restart them: kubectl rollout restart sts postgresql-ha-1683393697-postgresql
Check the state: kubectl exec -it postgresql-ha-1683393697-postgresql-2 -- /opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh repmgr -f /opt/bitnami/repmgr/conf/repmgr.conf cluster show

Get this:

 ID   | Name                                  | Role    | Status               | Upstream                              | Location | Priority | Timeline | Connection string                                                                                                                                                                          
------+---------------------------------------+---------+----------------------+---------------------------------------+----------+----------+----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | postgresql-ha-1683393697-postgresql-0 | standby |   running            | postgresql-ha-1683393697-postgresql-2 | default  | 100      | 2        | user=repmgr password=ougc6E8kaO host=postgresql-ha-1683393697-postgresql-0.postgresql-ha-1683393697-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | postgresql-ha-1683393697-postgresql-1 | standby | ! running as primary |                                       | default  | 100      | 2        | user=repmgr password=ougc6E8kaO host=postgresql-ha-1683393697-postgresql-1.postgresql-ha-1683393697-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1002 | postgresql-ha-1683393697-postgresql-2 | primary | * running            |                                       | default  | 100      | 2        | user=repmgr password=ougc6E8kaO host=postgresql-ha-1683393697-postgresql-2.postgresql-ha-1683393697-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

migruiz4 · 2023-05-08T07:09:06Z

Hi @colega,

Could you please share what version of the chart you are using? Does your chart or values.yaml include any modification?

I tried to reproduce the issue in two different scenarios using the latest version (11.5.2), but none resulted in the error you shared.

Can you reproduce it consistently or does it only happen under certain circumstances? E.g.: several restarts, manually deleting pods, a specific node promotes to primary...

In my first deployment, using default values, the chart was restarted successfully:

$ kubectl exec -it test-postgresql-ha-postgresql-1 -- /opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh repmgr -f /opt/bitnami/repmgr/conf/repmgr.conf cluster show
 ID   | Name                            | Role    | Status    | Upstream                        | Location | Priority | Timeline | Connection string                                                                                                                                                              
------+---------------------------------+---------+-----------+---------------------------------+----------+----------+----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | test-postgresql-ha-postgresql-0 | standby |   running | test-postgresql-ha-postgresql-1 | default  | 100      | 2        | user=repmgr password=9GqJZWaK0J host=test-postgresql-ha-postgresql-0.test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | test-postgresql-ha-postgresql-1 | primary | * running |                                 | default  | 100      | 2        | user=repmgr password=9GqJZWaK0J host=test-postgresql-ha-postgresql-1.test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1002 | test-postgresql-ha-postgresql-2 | standby |   running | test-postgresql-ha-postgresql-1 | default  | 100      | 2        | user=repmgr password=9GqJZWaK0J host=test-postgresql-ha-postgresql-2.test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

In my second deployment, I added some extra settings to delay the restart in case my local environment was restarting faster:

postgresql:
  command:
    - /bin/bash
  args:
    - -ec
    - |
      sleep 60
      /opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh /opt/bitnami/scripts/postgresql-repmgr/run.sh
  livenessProbe:
    initialDelaySeconds: 90

$ kubectl exec -it test-postgresql-ha-postgresql-2 -- /opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh repmgr -f /opt/bitnami/repmgr/conf/repmgr.conf cluster show
 ID   | Name                            | Role    | Status    | Upstream                        | Location | Priority | Timeline | Connection string                                                                                                                                                              
------+---------------------------------+---------+-----------+---------------------------------+----------+----------+----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | test-postgresql-ha-postgresql-0 | standby |   running | test-postgresql-ha-postgresql-1 | default  | 100      | 2        | user=repmgr password=U4y45fPzmX host=test-postgresql-ha-postgresql-0.test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | test-postgresql-ha-postgresql-1 | primary | * running |                                 | default  | 100      | 2        | user=repmgr password=U4y45fPzmX host=test-postgresql-ha-postgresql-1.test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1002 | test-postgresql-ha-postgresql-2 | standby |   running | test-postgresql-ha-postgresql-1 | default  | 100      | 2        | user=repmgr password=U4y45fPzmX host=test-postgresql-ha-postgresql-2.test-postgresql-ha-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

I don't discard a race condition during the failover process. In your case, does Postgresql get stuck in that status or does it resolve after some time?

Please provide all the information you can, it would help us troubleshoot the issue.

xtianus79 · 2023-11-16T05:33:39Z

this is still an issue and should be reopened because the witness doesn't do anything here to help which is just odd. the delta of the primary coming back is 40 seconds after the election happened on the other nodes and it is still setting itself up as the primary and causing a split brain. A. why doesn't the witness help here B. what is the pretending mean in this log? it's saying that 1 is "pretending" do be the primary when in fact it is. this seems to be the error.

carrodher · 2023-11-20T08:33:08Z

Could you please create a separate issue filling the template with the specific information for your use case? Thanks

xtianus79 · 2023-11-28T14:44:41Z

I think this may be related?

bitnami/containers#52213

colega · 2023-11-28T16:41:38Z

@migruiz4 sorry for the delayed response on this (I'm not even using this helm chart).

I just got a new laptop, fresh install on an M3 MBP, and I decided to give this a try. Fresh install of docker, kind, helm, etc.

Current version is:

bitnami/postgresql-ha                       	12.2.0       	16.1.0

I followed exactly the same steps of my previous post (except that I had to add the bitnami repo this time, and the change to the sts name), and I could reproduce it after second restart of the sts:

$ kubectl exec -it postgresql-ha-1701189148-postgresql-2 -- /opt/bitnami/scripts/postgresql-repmgr/entrypoint.sh repmgr -f /opt/bitnami/repmgr/conf/repmgr.conf cluster show
postgresql-repmgr 16:38:37.74 INFO  ==>
postgresql-repmgr 16:38:37.74 INFO  ==> Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 16:38:37.74 INFO  ==> Subscribe to project updates by watching https://github.com/bitnami/containers
postgresql-repmgr 16:38:37.75 INFO  ==> Submit issues and feature requests at https://github.com/bitnami/containers/issues
postgresql-repmgr 16:38:37.75 INFO  ==>

 ID   | Name                                  | Role    | Status               | Upstream                              | Location | Priority | Timeline | Connection string
------+---------------------------------------+---------+----------------------+---------------------------------------+----------+----------+----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1000 | postgresql-ha-1701189148-postgresql-0 | primary | * running            |                                       | default  | 100      | 3        | user=repmgr password=dQdNK8vflJ host=postgresql-ha-1701189148-postgresql-0.postgresql-ha-1701189148-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1001 | postgresql-ha-1701189148-postgresql-1 | standby | ! running as primary |                                       | default  | 100      | 4        | user=repmgr password=dQdNK8vflJ host=postgresql-ha-1701189148-postgresql-1.postgresql-ha-1701189148-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5
 1002 | postgresql-ha-1701189148-postgresql-2 | standby |   running            | postgresql-ha-1701189148-postgresql-0 | default  | 100      | 3        | user=repmgr password=dQdNK8vflJ host=postgresql-ha-1701189148-postgresql-2.postgresql-ha-1701189148-postgresql-headless.default.svc.cluster.local dbname=repmgr port=5432 connect_timeout=5

WARNING: following issues were detected
  - node "postgresql-ha-1701189148-postgresql-1" (ID: 1001) is registered as standby but running as primary

command terminated with exit code 25

isFxh · 2024-07-24T12:12:54Z

@javsalgar Hi, I think this problem is not solved. I reproduced this problem in bitnami/postgresql-ha 16.3.0 version. I hope to reopen this issue for discussion.

stale bot added the stale 15 days without activity label Jun 10, 2020

stale bot closed this as completed Jun 15, 2020

javsalgar reopened this Jun 16, 2021

javsalgar added the on-hold Issues or Pull Requests with this label will never be considered stale label Jun 16, 2021

github-actions bot removed the stale 15 days without activity label Jun 17, 2021

vishrantgupta mentioned this issue Nov 8, 2021

Incorrect timeline and inconsistent data #8062

Closed

github-actions bot added the solved label Jun 28, 2023

github-actions bot added triage Triage is needed and removed solved labels Nov 16, 2023

bitnami-bot assigned carrodher Nov 16, 2023

carrodher added the postgresql-ha label Nov 20, 2023

github-actions bot added the solved label Nov 20, 2023

github-actions bot removed the solved label Nov 28, 2023

bitnami-bot assigned javsalgar Nov 28, 2023

github-actions bot added the solved label Nov 29, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[postgresql-ha] Multiple Primaries #2610

[postgresql-ha] Multiple Primaries #2610

gnomus commented May 18, 2020

javsalgar commented May 19, 2020

Roarain commented May 25, 2020 •

edited

Loading

javsalgar commented May 26, 2020

stale bot commented Jun 10, 2020

stale bot commented Jun 15, 2020

vahid-sohrabloo commented Dec 14, 2020

javsalgar commented Dec 15, 2020

vahid-sohrabloo commented Dec 15, 2020

javsalgar commented Dec 16, 2020

greenday9 commented Jun 14, 2021

javsalgar commented Jun 15, 2021

greenday9 commented Jun 15, 2021

aw381246 commented Aug 27, 2021 •

edited

Loading

javsalgar commented Aug 30, 2021

mikeoutlaw commented Aug 30, 2021

javsalgar commented Aug 31, 2021

javsalgar commented Sep 3, 2021

mikeoutlaw commented Sep 7, 2021

jpsn123 commented Oct 16, 2021

migruiz4 commented Oct 18, 2021

vishrantgupta commented Nov 10, 2021

migruiz4 commented Nov 10, 2021

pkExec commented Nov 18, 2021

migruiz4 commented Nov 22, 2021

colega commented May 6, 2023

migruiz4 commented May 8, 2023

xtianus79 commented Nov 16, 2023

carrodher commented Nov 20, 2023

xtianus79 commented Nov 28, 2023

colega commented Nov 28, 2023

isFxh commented Jul 24, 2024

[postgresql-ha] Multiple Primaries #2610

[postgresql-ha] Multiple Primaries #2610

Comments

gnomus commented May 18, 2020

javsalgar commented May 19, 2020

Roarain commented May 25, 2020 • edited Loading

javsalgar commented May 26, 2020

stale bot commented Jun 10, 2020

stale bot commented Jun 15, 2020

vahid-sohrabloo commented Dec 14, 2020

javsalgar commented Dec 15, 2020

vahid-sohrabloo commented Dec 15, 2020

javsalgar commented Dec 16, 2020

greenday9 commented Jun 14, 2021

javsalgar commented Jun 15, 2021

greenday9 commented Jun 15, 2021

aw381246 commented Aug 27, 2021 • edited Loading

javsalgar commented Aug 30, 2021

mikeoutlaw commented Aug 30, 2021

Install the chart

Verify the cluster status

Delete the primary replica

Oddities

Verify cluster status

javsalgar commented Aug 31, 2021

javsalgar commented Sep 3, 2021

mikeoutlaw commented Sep 7, 2021

jpsn123 commented Oct 16, 2021

postgresql-repmgr 12:52:46.10 INFO ==> ** Starting PostgreSQL with Replication Manager setup **

migruiz4 commented Oct 18, 2021

vishrantgupta commented Nov 10, 2021

migruiz4 commented Nov 10, 2021

pkExec commented Nov 18, 2021

migruiz4 commented Nov 22, 2021

colega commented May 6, 2023

migruiz4 commented May 8, 2023

xtianus79 commented Nov 16, 2023

carrodher commented Nov 20, 2023

xtianus79 commented Nov 28, 2023

colega commented Nov 28, 2023

isFxh commented Jul 24, 2024

Roarain commented May 25, 2020 •

edited

Loading

aw381246 commented Aug 27, 2021 •

edited

Loading

postgresql-repmgr 12:52:46.10 INFO ==> Starting PostgreSQL with Replication Manager setup