Charts: postgresql-ha repmgr extension not found on this node

Created on 4 Feb 2020 · 36Comments · Source: bitnami/charts

Which chart:

bitnami/postgresql-ha 1.3.0

Description

StatefulSet fails to start using persistence.enabled=true.
It works fine if persistence is turned off.

Steps to reproduce the issue:

Set persistence.enabled=true
Watch the pod fail

Describe the results you received:

First time the pod starts:

postgresql-repmgr 09:20:36.33                                                                                                                                                                                                                                                                                                  
postgresql-repmgr 09:20:36.33 Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 09:20:36.33 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-postgresql-repmgr                                                                                                                                                                                             
postgresql-repmgr 09:20:36.34 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-postgresql-repmgr/issues
postgresql-repmgr 09:20:36.34 Send us your feedback at [email protected]                                                                                  
postgresql-repmgr 09:20:36.34                                                                                                                                                                                                                                                                                                  
postgresql-repmgr 09:20:36.37 INFO  ==> ** Starting PostgreSQL with Replication Manager setup **        
repmgr 09:20:36.44 INFO  ==> Validating settings in REPMGR_* env vars...                                                                                                                                                                                                                                                       
postgresql 09:20:36.44 INFO  ==> Validating settings in POSTGRESQL_* env vars..                                                                                
repmgr 09:20:36.45 INFO  ==> Querying all partner nodes for common upstream node...                                                                            
repmgr 09:20:36.50 INFO  ==> There are no nodes with primary role. Assuming the primary role...
repmgr 09:20:36.51 INFO  ==> Preparing PostgreSQL configuration...
postgresql 09:20:36.52 INFO  ==> postgresql.conf file not detected. Generating it...
repmgr 09:20:36.58 INFO  ==> Preparing repmgr configuration...                                                                                                                                                                                                                                                                 
repmgr 09:20:36.59 INFO  ==> Initializing Repmgr...                                                                                                            
postgresql 09:20:36.59 INFO  ==> Initializing PostgreSQL database... 
postgresql 09:20:36.60 INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/postgresql.conf detected
postgresql 09:20:36.60 INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/pg_hba.conf detected                                                                                                                                                                                                                        
postgresql 09:20:38.72 INFO  ==> Starting PostgreSQL in background...                                                                                          
postgresql 09:20:39.39 INFO  ==> Creating user clair                           
postgresql 09:20:39.42 INFO  ==> Grating access to "clair" to the database "clair"
postgresql 09:20:39.46 INFO  ==> Starting PostgreSQL in background...                                                                                          
repmgr 09:20:39.47 INFO  ==> Creating repmgr user: repmgr                                                                                                                                                                                                                                                                      
repmgr 09:20:39.54 INFO  ==> Creating repmgr database: repmgr                  
postgresql 09:20:40.03 INFO  ==> Stopping PostgreSQL...

Subsequent starts:

postgresql-repmgr 09:23:57.02 
postgresql-repmgr 09:23:57.02 Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 09:23:57.03 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-postgresql-repmgr
postgresql-repmgr 09:23:57.03 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-postgresql-repmgr/issues
postgresql-repmgr 09:23:57.03 Send us your feedback at [email protected]
postgresql-repmgr 09:23:57.04 
postgresql-repmgr 09:23:57.06 INFO  ==> ** Starting PostgreSQL with Replication Manager setup **
repmgr 09:23:57.16 INFO  ==> Validating settings in REPMGR_* env vars...
postgresql 09:23:57.17 INFO  ==> Validating settings in POSTGRESQL_* env vars..
repmgr 09:23:57.18 INFO  ==> Querying all partner nodes for common upstream node...
repmgr 09:23:57.22 INFO  ==> There are no nodes with primary role. Assuming the primary role...
repmgr 09:23:57.23 INFO  ==> Preparing PostgreSQL configuration...
postgresql 09:23:57.24 INFO  ==> postgresql.conf file not detected. Generating it...
repmgr 09:23:57.31 INFO  ==> Preparing repmgr configuration...
repmgr 09:23:57.32 INFO  ==> Initializing Repmgr...
postgresql 09:23:57.32 INFO  ==> Initializing PostgreSQL database...
postgresql 09:23:57.33 INFO  ==> Cleaning stale /bitnami/postgresql/data/postmaster.pid file
postgresql 09:23:57.34 INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/postgresql.conf detected
postgresql 09:23:57.35 INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/pg_hba.conf detected
postgresql 09:23:57.37 INFO  ==> Deploying PostgreSQL with persisted data...
postgresql 09:23:57.39 INFO  ==> Stopping PostgreSQL...
postgresql-repmgr 09:23:57.40 INFO  ==> ** PostgreSQL with Replication Manager setup finished! **

postgresql 09:23:57.50 INFO  ==> Starting PostgreSQL in background...
postgresql-repmgr 09:23:57.74 INFO  ==> ** Starting repmgrd **
[2020-01-29 09:23:57] [NOTICE] repmgrd (repmgrd 5.0.0) starting up
[2020-01-29 09:23:57] [ERROR] repmgr extension not found on this node
[2020-01-29 09:23:57] [DETAIL] repmgr extension is available but not installed in database "repmgr"
[2020-01-29 09:23:57] [HINT] check that this node is part of a repmgr cluster

Describe the results you expected:

It actually work ;)

Additional information you deem important (e.g. issue happens only occasionally):

Only happens if persistence.enabled=true
Using CephRBD as Storage Provider with XFS as filesystem.

Version of Helm and Kubernetes:

Output of helm version:

version.BuildInfo{Version:"v3.0", GitCommit:"", GitTreeState:"", GoVersion:"go1.12.13"}

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:"17", GitVersion:"v1.17.2", GitCommit:"59603c6e503c87169aea6106f57b9f242f64df89", GitTreeState:"clean", BuildDate:"2020-01-18T23:22:30Z", GoVersion:"go1.13.5", Compiler:"gc", Platform:"linux/amd64"}

on-hold

Source

f0o

Most helpful comment

Thank you guys for reporting this issue.
I will create an internal task so we can debug this properly.

miguelaeh on 23 Jun 2020

👍4

All 36 comments

Hi @f0o ,
We tried to reproduce the issue with the following steps:

helm install bitnami/postgresql-ha --set persistence.enabled=true

wait until it is deployed.

kubectl delete pod righteous-pike-postgresql-ha-postgresql-0

Then the pod is restarted one time before the correct initialization.
Could you describe the steps you are following to replicate the issue?
Also, could you share the full log of the first initialization?

miguelaeh on 4 Feb 2020

@miguelaeh that is the full log.

postgresql:
  pdb:
    create: true
    minAvailable: 1
  username: clair
  password: clair
  database: clair
metrics:
  enabled: true
  serviceMonitor:
    enabled: true
    namespace: monitoring
persistence:
  enabled: true

helm -n bitname-tests install miguelaeh bitnami/postgresql-ha -f clair/pg.yaml

$ kubectl -n bitname-tests logs miguelaeh-postgresql-ha-postgresql-0 postgresql -f
postgresql-repmgr 10:38:05.20 
postgresql-repmgr 10:38:05.20 Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 10:38:05.20 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-postgresql-repmgr
postgresql-repmgr 10:38:05.21 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-postgresql-repmgr/issues
postgresql-repmgr 10:38:05.21 Send us your feedback at [email protected]
postgresql-repmgr 10:38:05.21 
postgresql-repmgr 10:38:05.24 INFO  ==> ** Starting PostgreSQL with Replication Manager setup **
repmgr 10:38:05.33 INFO  ==> Validating settings in REPMGR_* env vars...
postgresql 10:38:05.33 INFO  ==> Validating settings in POSTGRESQL_* env vars..
repmgr 10:38:05.34 INFO  ==> Querying all partner nodes for common upstream node...
repmgr 10:38:05.39 INFO  ==> There are no nodes with primary role. Assuming the primary role...
repmgr 10:38:05.40 INFO  ==> Preparing PostgreSQL configuration...
postgresql 10:38:05.40 INFO  ==> postgresql.conf file not detected. Generating it...
repmgr 10:38:05.47 INFO  ==> Preparing repmgr configuration...
repmgr 10:38:05.48 INFO  ==> Initializing Repmgr...
postgresql 10:38:05.48 INFO  ==> Initializing PostgreSQL database...
postgresql 10:38:05.50 INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/postgresql.conf detected
postgresql 10:38:05.50 INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/pg_hba.conf detected
postgresql 10:38:07.60 INFO  ==> Starting PostgreSQL in background...
postgresql 10:38:08.45 INFO  ==> Creating user clair
postgresql 10:38:08.48 INFO  ==> Grating access to "clair" to the database "clair"
postgresql 10:38:08.52 INFO  ==> Starting PostgreSQL in background...
repmgr 10:38:08.52 INFO  ==> Creating repmgr user: repmgr
repmgr 10:38:08.60 INFO  ==> Creating repmgr database: repmgr
postgresql 10:38:09.12 INFO  ==> Stopping PostgreSQL...
postgresql 10:38:19.17 INFO  ==> Starting PostgreSQL in background...
repmgr 10:38:19.18 INFO  ==> Registering Primary...
postgresql 10:38:19.19 INFO  ==> Stopping PostgreSQL...

$ kubectl -n bitname-tests logs miguelaeh-postgresql-ha-postgresql-0 postgresql -f
postgresql-repmgr 10:38:30.88 
postgresql-repmgr 10:38:30.88 Welcome to the Bitnami postgresql-repmgr container
postgresql-repmgr 10:38:30.88 Subscribe to project updates by watching https://github.com/bitnami/bitnami-docker-postgresql-repmgr
postgresql-repmgr 10:38:30.89 Submit issues and feature requests at https://github.com/bitnami/bitnami-docker-postgresql-repmgr/issues
postgresql-repmgr 10:38:30.89 Send us your feedback at [email protected]
postgresql-repmgr 10:38:30.89 
postgresql-repmgr 10:38:30.92 INFO  ==> ** Starting PostgreSQL with Replication Manager setup **
repmgr 10:38:31.02 INFO  ==> Validating settings in REPMGR_* env vars...
postgresql 10:38:31.02 INFO  ==> Validating settings in POSTGRESQL_* env vars..
repmgr 10:38:31.03 INFO  ==> Querying all partner nodes for common upstream node...
repmgr 10:38:31.07 INFO  ==> There are no nodes with primary role. Assuming the primary role...
repmgr 10:38:31.09 INFO  ==> Preparing PostgreSQL configuration...
postgresql 10:38:31.09 INFO  ==> postgresql.conf file not detected. Generating it...
repmgr 10:38:31.16 INFO  ==> Preparing repmgr configuration...
repmgr 10:38:31.17 INFO  ==> Initializing Repmgr...
postgresql 10:38:31.17 INFO  ==> Initializing PostgreSQL database...
postgresql 10:38:31.17 INFO  ==> Cleaning stale /bitnami/postgresql/data/postmaster.pid file
postgresql 10:38:31.19 INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/postgresql.conf detected
postgresql 10:38:31.19 INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/pg_hba.conf detected
postgresql 10:38:31.21 INFO  ==> Deploying PostgreSQL with persisted data...
postgresql 10:38:31.23 INFO  ==> Stopping PostgreSQL...
postgresql-repmgr 10:38:31.24 INFO  ==> ** PostgreSQL with Replication Manager setup finished! **

postgresql 10:38:31.34 INFO  ==> Starting PostgreSQL in background...
postgresql-repmgr 10:38:31.57 INFO  ==> ** Starting repmgrd **
[2020-02-04 10:38:31] [NOTICE] repmgrd (repmgrd 5.0.0) starting up
[2020-02-04 10:38:31] [ERROR] repmgr extension not found on this node
[2020-02-04 10:38:31] [DETAIL] repmgr extension is available but not installed in database "repmgr"
[2020-02-04 10:38:31] [HINT] check that this node is part of a repmgr cluster

$ kubectl -n bitname-tests get po                                                 
NAME                                              READY   STATUS             RESTARTS   AGE
miguelaeh-postgresql-ha-pgpool-69dc5494d5-nhr6t   0/1     Init:0/1           0          74s
miguelaeh-postgresql-ha-postgresql-0              1/2     CrashLoopBackOff   2          74s
$ kubectl -n bitname-tests get pvc   
NAME                                        STATUS   VOLUME                                     CAPACITY   ACCESS MODES   STORAGECLASS   AGE
data-miguelaeh-postgresql-ha-postgresql-0   Bound    pvc-34099b5a-6714-4195-81d4-605f120a6be1   8Gi        RWO            ceph           89s

At this point the pod is crashlooping forever with the same output [2020-02-04 10:38:31] [ERROR] repmgr extension not found on this node

Exact same config without persistence.enabled=true will work just fine.

f0o on 4 Feb 2020

Hi @f0o ,
It is weird that your first log does not continue, after this

 postgresql 10:38:19.19 INFO  ==> Stopping PostgreSQL...

After that, it should be started again correctly. My logs after that are the following:

postgresql 10:58:08.60 INFO  ==> Stopping PostgreSQL...
postgresql-repmgr 10:58:09.63 INFO  ==> ** PostgreSQL with Replication Manager setup finished! **

postgresql 10:58:09.73 INFO  ==> Starting PostgreSQL in background...
postgresql-repmgr 10:58:09.99 INFO  ==> ** Starting repmgrd **
[2020-02-05 10:58:10] [NOTICE] repmgrd (repmgrd 5.0.0) starting up
INFO:  set_repmgrd_pid(): provided pidfile is /opt/bitnami/repmgr/tmp/repmgr.pid
[2020-02-05 10:58:10] [NOTICE] starting monitoring of node "looping-buffoon-postgresql-ha-postgresql-0" (ID: 1000)
[2020-02-05 10:58:10] [NOTICE] monitoring cluster primary "looping-buffoon-postgresql-ha-postgresql-0" (ID: 1000)
[2020-02-05 10:58:46] [NOTICE] new standby "looping-buffoon-postgresql-ha-postgresql-1" (ID: 1001) has connected

As you can see the container finish to start.
Also, be sure you delete the PVC to ensure it is not taking old ones, as your second logs are showing that data is already initialized but it seems your first run was not correct.

miguelaeh on 5 Feb 2020

As you can see in the PVC output the age of the PVC is about the same as the Deployment/Pod.

I can assert you that the PVC is manually removed on every try in any case.

f0o on 5 Feb 2020

Hi @f0o ,
Could you try to test using a different storage class? To be sure it is not an issue with that storage class type.

miguelaeh on 6 Feb 2020

We don't have any other storage available so that's a negative.

I tried with leaving storageclass out but same result.

f0o on 6 Feb 2020

Solved it.

The culprit was PDB. Without PDB it all works fine.

So if you need PDB and Persistence you need to first deploy it without PDB and then update the release with PDB enabled.

f0o on 6 Feb 2020

❤1

Hi @f0o ,
I am glad you solved the issue, thanks for sharing the solution!!

miguelaeh on 7 Feb 2020

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[bot] on 22 Feb 2020

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.

stale[bot] on 27 Feb 2020

I have encountered a similar issue, but the PDB setting makes no difference -- only disabling of persistence will work or some carefully placed sleep statements in the docker image. I believe there's some race conditions during the initial-boot-sequence, which can prevent the Primary Registration from completing.

In my testing, the primary node isn't registered, but several other operations complete. This means the next time it starts, it will skip the initial-boot-sequence with an incomplete configuration:

repmgr 15:19:23.69 INFO  ==> Registering Primary...
ERROR: connection to database failed
DETAIL: 
could not connect to server: Connection refused
    Is the server running on host "postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.<namespcae>.svc.cluster.local" (1.2.3.4) and accepting
    TCP/IP connections on port 5432?
DETAIL: attempted to connect using:
  user=repmgr password=repmgr connect_timeout=5 dbname=repmgr host=postgresql-postgresql-ha-postgresql-0.postgresql-postgresql-ha-postgresql-headless.<namespace>.svc.cluster.local port=5432 fallback_application_name=repmgr
postgresql 15:19:28.70 INFO  ==> Stopping PostgreSQL...

if you look at a snippet of the initial-boot-squence:

            postgresql_stop
            postgresql_start_bg
            repmgr_register_primary

The script stops & starts the db, and then tries to register the primary. What I noticed is that postgresql_stop, which invokes a separate stop_service_using_pid, issues a kill on the process but only waits 10 seconds for the process to terminate. If the process hasn't terminated, the script continues and postgresql_start_bg will incorrectly verify that the process is running (since it hasn't stopped yet), and will allow the script to continue. At this point repmgr_register_primary may or may not succeed.

Placing a few sleep statements to try and keep the DB up when registration takes place seems to help, but properly waiting for the db to come down takes longer than the readiness/liveness probes will allow. I'm toying with this to see if i can get the db to start consistently each time :)

elordahl on 19 Jun 2020

Hi @elordahl ,
Could you try if adding those sleep you commented plus increasing readiness and liveness probes makes the application to start always, so we can confirm it is a race condition?

miguelaeh on 22 Jun 2020

For the record, it also happens to me from time to time. I also believe that @elordahl is right regarding the root cause. My workaround is to manually scale down the StatefulSet to 0, delete the PVCs and then scale back up to 3 replicas.

mboutet on 22 Jun 2020

The sleeps improved the probability of it starting, but still not to 100%. I pushed up the changes to the image that helped start the primary node (there's some debug stuff in there). Basically, I added an iteration (each stop of PG seems to restart the pod) to the boot sequence:

First boot: Initial Boot - create repmgr db & user, and run init scripts
Next boot: [NEW] - Check for created repmgr resources from first step and then run repmgr registration
Remaining boots/restarts: normal operation

The secondary nodes dont start 😃 but I have not looked into that yet -- will look shortly.

References:

https://github.com/elordahl/bitnami-docker-postgresql-repmgr/commit/f575b84e01d4616c38386552b0991c02b6b5cb6a

elordahl on 22 Jun 2020

👍1

What I am noticing is:

The entrypoint invokes setup.sh which appears to complete.
Then, the database shuts down and the entrypoint doesn't proceed, since the subsequent "setup finished!" logs are never printed.

~This has me suspicious of the trap in setup.sh since the database DOES shut down after the script completes~ update: see my next comment:

postgresql 21:48:53.00 INFO ==> Stopping PostgreSQL...
2020-06-22 21:48:53.010 GMT [235] LOG: received smart shutdown request
2020-06-22 21:48:53.012 GMT [241] FATAL: terminating walreceiver process due to administrator command
2020-06-22 21:48:53.013 GMT [238] LOG: shutting down
2020-06-22 21:48:53.019 GMT [235] LOG: database system is shut down

After this, the pod restarts (and continues this loop).

elordahl on 23 Jun 2020

👍1

@miguelaeh, can we reopen the issue since this is still occasionally happening?

mboutet on 23 Jun 2020

Just realized the standby node wasn't starting because of a debug cmd I added to verify when PIDs are killed. The TRAP is likely OK. Will update and retest

https://github.com/elordahl/bitnami-docker-postgresql-repmgr/commit/f575b84e01d4616c38386552b0991c02b6b5cb6a#diff-d1a60fd4a64a59a6016e7376f14173e0R74

elordahl on 23 Jun 2020

Thank you guys for reporting this issue.
I will create an internal task so we can debug this properly.

miguelaeh on 23 Jun 2020

👍4

If this is of any help, it just happened again two times in a row. It always happens during a fresh install of the postgresql-ha chart (I'm using 3.2.10). I'm using the following values:

  postgresql:
    replicaCount: 3
    resources:
      requests:
        cpu: 1800m
        memory: 6144Mi
      limits:
        cpu: 1800m
        memory: 6144Mi
  pgpool:
    replicaCount: 1
    resources:
      requests:
        cpu: 500m
        memory: 1536Mi
      limits:
        cpu: 500m
        memory: 1536Mi
  persistence:
    storageClass: azure-disk-premium-retain-and-wait-for-first-consumer
    size: 32Gi
  volumePermissions:
    enabled: true

I'm using AKS and here are my helm and kubectl versions:

helm:

version.BuildInfo{Version:"v3.2.4", GitCommit:"0ad800ef43d3b826f31a5ad8dfbb4fe05d143688", GitTreeState:"dirty", GoVersion:"go1.14.3"}

kubectl:

Client Version: version.Info{Major:"1", Minor:"18", GitVersion:"v1.18.4", GitCommit:"c96aede7b5205121079932896c4ad89bb93260af", GitTreeState:"clean", BuildDate:"2020-06-18T02:59:13Z", GoVersion:"go1.14.3", Compiler:"gc", Platform:"darwin/amd64"}
Server Version: version.Info{Major:"1", Minor:"18", GitVersion:"v1.18.2", GitCommit:"52c56ce7a8272c798dbc29846288d7cd9fbae032", GitTreeState:"clean", BuildDate:"2020-04-16T23:18:00Z", GoVersion:"go1.13.6", Compiler:"gc", Platform:"linux/amd64"}

mboutet on 25 Jun 2020

Thank you for sharing that information @mboutet , it will be useful for us to debug the issue.

miguelaeh on 26 Jun 2020

if it helps with diagnosing this issue further, i found that i was able to consistently reproduce this error by overriding values for the postgresql.securityContext. for example, running with this:

securityContext:
    enabled: true
    fsGroup: 0
    runAsUser: 0

would fail every time, no matter what i tried (e.g. scaling the statefulset down and deleting the pvc as mboutet suggested).

EDIT
upon further testing/scrutiny, it seems as if this problem may stem from issues arising from the pvc. first thing to note is that i was experimenting using a custom storageclass (ebs's mayastor storage class, specifically) for postgresql, which has known issues with finalizers / removing volume claims. as such, when an install of the chart goes poorly, i end up having to patch the pv to remove the finalizer to fully delete the install. that said, i discovered that if i do a full stop/start of the cluster (im using microk8s so this is easy to do) upon a fresh start i am able to get the install to go through without issue using the same settings as before.

in lieu of discovering this, i decided to see if i use the default storage class (for microk8s this is just a hostpath abstraction) if i have this issue anymore and what was surprising to find is that _i did_. meaning that, even though i was able to remove the pvc without having to patch the pv to remove the finalizer, if i had a bad install, reinstalling the chart would continue to have problems until i did a full stop/start of the cluster again.

heres hoping that this might help others diagnose / bypass this problem if it occurs for them.

cbrendanprice on 17 Jul 2020

👍1

Thanks so much for sharing your valuable insights @cbrendanprice !! We really appreciate it!

juan131 on 20 Jul 2020

same issue here with a fresh install.
it's due to liveness check and hostname issue. need to register until the service pod is live.

postgresql-repmgr 10:17:13.14 INFO  ==> Registering Primary...
ERROR: connection to database failed
DETAIL: 
could not translate host name "postgres-postgresql-ha-postgresql-0.postgres-postgresql-ha-postgresql-headless.postgres.svc.cluster.local" to address: Name or service not known

DETAIL: attempted to connect using:

ruruiye on 29 Jul 2020

Maybe one more piece of anecdata. I feel like I tried 10 different things trying to get past this bug. I finally got it to work when I turned off another busy process in the cluster that was making a lot of requests to the DB, so maybe those production-scale requests were skewing the installation process? Sorry I can't provide more data, it's late on Sunday, and I just wanna get things working :/

tombh on 9 Aug 2020

Hi @tombh

Thanks for your info, we really appreciate any feedback as it helps us to debug and tackle the issue 👍

joancafom on 11 Aug 2020

👍1

Same problem here with a fresh install and using local volume provisioner (https://github.com/kubernetes-sigs/sig-storage-local-static-provisioner):

```
[2020-08-12 19:21:27] [NOTICE] repmgrd (repmgrd 5.0.0) starting up
[2020-08-12 19:21:27] [ERROR] repmgr extension not found on this node
[2020-08-12 19:21:27] [DETAIL] repmgr extension is available but not installed in database "repmgr"
[2020-08-12 19:21:27] [HINT] check that this node is part of a repmgr cluster

danielmorlock on 12 Aug 2020

Thanks for reporting back additional information @danielmorlock !

joancafom on 14 Aug 2020

same issue here.
when I set --set pgpool.replicaCount=2.it ran wrong way.but it workes when I use the default vaule (pgpool.replicaCount=1)

zffocussss on 2 Sep 2020

paste the error messages

postgresql-repmgr 04:13:47.65 INFO  ==> ** Starting repmgrd **
[2020-09-02 04:13:47] [NOTICE] repmgrd (repmgrd 5.1.0) starting up
[2020-09-02 04:13:47] [ERROR] repmgr extension not found on this node
[2020-09-02 04:13:47] [DETAIL] repmgr extension is available but not installed in database "repmgr"
[2020-09-02 04:13:47] [HINT] check that this node is part of a repmgr cluster

zffocussss on 2 Sep 2020

Thanks for the information @zffocussss ,
We didn't have the time to work on this but we will update this thread once we have news.

miguelaeh on 2 Sep 2020

postgresql:

  replicaCount: 1

  pdb:
    create: false

  upgradeRepmgrExtension: false (true doesn't help either)

  syncReplication: true

pgpool:
  pdb:
    create: false

  replicaCount: 1

INFO  ==> ** Starting PostgreSQL with Replication Manager setup **
INFO  ==> Validating settings in REPMGR_* env vars...
INFO  ==> Validating settings in POSTGRESQL_* env vars..
INFO  ==> Querying all partner nodes for common upstream node...
INFO  ==> There are no nodes with primary role. Assuming the primary role...
INFO  ==> Preparing PostgreSQL configuration...
INFO  ==> postgresql.conf file not detected. Generating it...
INFO  ==> Preparing repmgr configuration...
INFO  ==> Initializing Repmgr...
INFO  ==> Initializing PostgreSQL database...
INFO  ==> Cleaning stale /bitnami/postgresql/data/postmaster.pid file
INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/postgresql.conf detected
INFO  ==> Custom configuration /opt/bitnami/postgresql/conf/pg_hba.conf detected
INFO  ==> Deploying PostgreSQL with persisted data...
INFO  ==> Configuring replication parameters
INFO  ==> Configuring fsync
INFO  ==> Stopping PostgreSQL...
INFO  ==> ** PostgreSQL with Replication Manager setup finished! **
INFO  ==> Starting PostgreSQL in background...
INFO  ==> ** Starting repmgrd **
[NOTICE] repmgrd (repmgrd 5.1.0) starting up
[ERROR] repmgr extension not found on this node
[DETAIL] repmgr extension is available but not installed in database "repmgr"
[HINT] check that this node is part of a repmgr cluster

No prior PV exists, doing it from scratch.

vainkop on 4 Sep 2020

Hi @vainkop ,
Thank you for sharing your logs. We didn't have the time to work on this yet, but it will be useful for us.
We will update this thread once we have news.
Regards.

miguelaeh on 7 Sep 2020

I tried to use this chart with enabled persistence mode and experienced the same issue. I did some deep debugging and found the cause for this issue. Somehow, when using persistence mode, the shutdown process of the database during initialization takes lot more time than without persistence.
Without using persistence, the shutdown procedure takes only less than 1 second (see Stopping PostgreSQL...):

postgresql-repmgr 20:43:42.32 INFO  ==> Creating repmgr database: repmgr
CREATE DATABASE
postgresql-repmgr 20:43:42.78 INFO  ==> Stopping PostgreSQL...
2020-09-24 20:43:42.788 GMT [116] LOG:  received smart shutdown request
2020-09-24 20:43:42.793 GMT [116] LOG:  background worker "logical replication launcher" (PID 125) exited with exit code 1
2020-09-24 20:43:42.796 GMT [119] LOG:  shutting down
2020-09-24 20:43:43.046 GMT [116] LOG:  database system is shut down
postgresql-repmgr 20:43:43.79 INFO  ==> Starting PostgreSQL in background...
waiting for server to start....2020-09-24 20:43:43.831 GMT [195] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2020-09-24 20:43:43.903 GMT [195] LOG:  listening on IPv6 address "::", port 5432
2020-09-24 20:43:43.908 GMT [195] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2020-09-24 20:43:43.919 GMT [195] LOG:  redirecting log output to logging collector process
2020-09-24 20:43:43.919 GMT [195] HINT:  Future log output will appear in directory "/opt/bitnami/postgresql/logs".
2020-09-24 20:43:43.922 GMT [197] LOG:  database system was shut down at 2020-09-24 20:43:43 GMT
2020-09-24 20:43:43.927 GMT [195] LOG:  database system is ready to accept connections
 done
server started
postgresql-repmgr 20:43:44.03 INFO  ==> Registering Primary...
NOTICE: attempting to install extension "repmgr"
NOTICE: "repmgr" extension successfully installed

When using the persistence mode, the shutdown takes longer than 10s, but the function stop_service_using_pid(), which is used to wait until the process is stopped, only waits for 10s and finishes even before the process is stopped. So in this case, the shutdown procedure of postgres is still on progress when the script execution continues and tries to start postgres again, which fails, because the port is still allocated from the terminating process.

postgresql-repmgr 20:35:45.70 INFO  ==> Creating repmgr database: repmgr
CREATE DATABASE
postgresql-repmgr 20:35:54.62 INFO  ==> Stopping PostgreSQL...
2020-09-24 20:35:54.704 GMT [116] LOG:  received smart shutdown request
2020-09-24 20:35:54.727 GMT [116] LOG:  background worker "logical replication launcher" (PID 125) exited with exit code 1
postgresql-repmgr 20:36:04.73 INFO  ==> Starting PostgreSQL in background...
postgresql-repmgr 20:36:04.74 INFO  ==> Registering Primary...
ERROR: connection to database failed
DETAIL: 
could not connect to server: Connection refused
    Is the server running on host "sftpgo-postgresql-ha-postgresql-0.sftpgo-postgresql-ha-postgresql-headless.default.svc.cluster.local" (10.42.192.5) and accepting
    TCP/IP connections on port 5432?

DETAIL: attempted to connect using:
  user=repmgr password=QL9U6zOmwF connect_timeout=5 dbname=repmgr host=sftpgo-postgresql-ha-postgresql-0.sftpgo-postgresql-ha-postgresql-headless.default.svc.cluster.local port=5432 fallback_application_name=repmgr
postgresql-repmgr 20:36:04.76 INFO  ==> Stopping PostgreSQL...

To check the real time which the process needs to stop, I increased the counter in stop_service_using_pid() from 10 to 1000. Then in my test, I discovered the process stopped after 15s:

postgresql-repmgr 20:26:25.75 INFO  ==> Creating repmgr database: repmgr
CREATE DATABASE
postgresql-repmgr 20:26:39.36 INFO  ==> Stopping PostgreSQL...
2020-09-24 20:26:39.369 GMT [118] LOG:  received smart shutdown request
2020-09-24 20:26:39.404 GMT [118] LOG:  background worker "logical replication launcher" (PID 127) exited with exit code 1
2020-09-24 20:26:39.405 GMT [121] LOG:  shutting down
2020-09-24 20:26:54.347 GMT [118] LOG:  database system is shut down
postgresql-repmgr 20:26:54.42 INFO  ==> Starting PostgreSQL in background...

So to solve this issue, the counter of the function stop_service_using_pid() must be increased. I suggest at least 30s. In addition, in my opinion, the function should throw an error if the process did not stop in the given time and stop the execution of the initialization.

@miguelaeh If you agree with my suggestion, I would open a PR.

smueller18 on 24 Sep 2020

Hi @smueller18 ,
I am really glad to hear that you found the issue!!
Thank you very much for the detailed explanation!! We are a small team and we really appreciate the help.
Please feel free to open that PR and we will be graceful to review it!

miguelaeh on 28 Sep 2020

Any update about PR ?
I cant deploy the chart at all at this moment