Inaccurate status-"RUNNING" shown when pod is stuck in pending state

[RavinaChidambaram]

• Which image of the operator are you using? e.g. ghcr.io/zalando/postgres-operator:v1.12.2
• Where do you run it - cloud or metal? Kubernetes or OpenShift? K8s
• Are you running Postgres Operator in production? yes
• Type of issue? Bug

Hi,
I deployed a PostgreSQL instance, and the pods were stuck in pending state. During this time, the PostgresClusterStatus was set to Creating. After some time the postgres status was set to CreateFailed and the following warning was observed in the operator logs:

time="2025-02-14T11:07:11Z" level=error msg="failed to create cluster: pod labels error: still failing after 200 retries" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:07:11Z" level=warning msg="cluster created failed: pod labels error: still failing after 200 retries" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:07:11Z" level=error msg="could not create cluster: pod labels error: still failing after 200 retries" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=controller worker=2

And later when the sync event is called, it patches the PostgresClusterStatus to Running which is incorrect as the pods are still stuck in pending state.

This incorrect status is misleading, as it serves as the primary way for users to track the PostgreSQL cluster's state.

Logs from the operator during this sync event:

time="2025-02-14T11:11:29Z" level=debug msg="syncing Patroni config" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:11:29Z" level=warning msg="Patroni config updated? false - errors during config sync: could not get Postgres config from pod test-pg-demo/tcl-minimal-cluster-demo-0: could not get Postgres config from pod test-pg-demo/tcl-minimal-cluster-demo-0:  is not a valid IP', 'could not get Postgres config from pod test-pg-demo/tcl-minimal-cluster-demo-1: could not get Postgres config from pod test-pg-demo/tcl-minimal-cluster-demo-1:  is not a valid IP" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:11:29Z" level=error msg="errors while restarting Postgres in pods via Patroni API: could not restart Postgres in  pod test-pg-demo/tcl-minimal-cluster-demo-0: could not get member data:  is not a valid IP', 'could not restart Postgres in  pod test-pg-demo/tcl-minimal-cluster-demo-1: could not get member data:  is not a valid IP" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:11:29Z" level=debug msg="syncing pod disruption budgets" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:11:29Z" level=debug msg="syncing roles" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:11:29Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:11:44Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:11:59Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:12:14Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:12:29Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:12:44Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:12:59Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:13:14Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:13:14Z" level=error msg="could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:13:14Z" level=debug msg="syncing databases" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:13:14Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:13:29Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:13:44Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:13:59Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:14:14Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:14:29Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:14:44Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:14:59Z" level=warning msg="could not connect to Postgres database: dial tcp 10.245.50.134:5432: connect: connection refused" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:14:59Z" level=error msg="could not sync databases: could not init database connection" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:14:59Z" level=debug msg="syncing prepared databases with schemas" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:14:59Z" level=debug msg="syncing connection pooler (master, replica) from (false, nil) to (false, nil)" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:14:59Z" level=info msg="identified non running pod, potentially skipping major version upgrade" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:14:59Z" level=info msg="identified non running pod, potentially skipping major version upgrade" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=cluster worker=2
time="2025-02-14T11:14:59Z" level=info msg="cluster has been synced" cluster-name=test-pg-demo/tcl-minimal-cluster-demo pkg=controller worker=2

[FxKu]

Interesting case. The SYNC completes even though no pod is running. Sounds like we should fail the sync when no pod is running.

[bergner]

Ran into a similar issue after we updated to chart version postgres-operator-1.14.0 but the Patroni restart error is different in my case:

time="2025-04-03T12:59:53Z" level=error msg="errors while restarting Postgres in pods via Patroni API: could not restart Postgres in  pod example/example-db-0: replica currently being initialized" cluster-name=example/example-db pkg=cluster

When the Postgresql manifest was applied two different things could happen. In the first case which failed statefulset pod 1 was the primary because pod 0 started off waiting for pod 1 to claim its master lock (for reasons I don't really know). The database named in the Postgresql manifest and the user account(s) specified in the Postgresql manifest were never bootstrapped, but the Postgresql manifest did report status Running and both the 0 and 1 pod were running for me in the end but subsequent steps in our deployment process failed because the designated database and user didn't exist.

time="2025-04-03T12:59:52Z" level=info msg="ADD event has been queued" cluster-name=example/example-db pkg=controller worker=0
time="2025-04-03T12:59:52Z" level=info msg="syncing of the cluster started" cluster-name=example/example-db pkg=controller worker=0
time="2025-04-03T12:59:52Z" level=debug msg="team API is disabled" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="team API is disabled" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="syncing secrets" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="new node has been added: /ip-10-24-1-3.us-west-2.compute.internal (aws:///us-west-2a/i-0c66e686cccf94e8c)" pkg=controller
time="2025-04-03T12:59:52Z" level=debug msg="new node has been added: /ip-10-24-15-217.us-west-2.compute.internal (aws:///us-west-2a/i-04f8fb9f535d52eba)" pkg=controller
time="2025-04-03T12:59:52Z" level=debug msg="new node has been added: /ip-10-24-3-53.us-west-2.compute.internal (aws:///us-west-2a/i-0c582a71b2566d930)" pkg=controller
time="2025-04-03T12:59:52Z" level=debug msg="new node has been added: /ip-10-24-4-242.us-west-2.compute.internal (aws:///us-west-2a/i-0303bf0f0811dee4e)" pkg=controller
time="2025-04-03T12:59:52Z" level=debug msg="new node has been added: /ip-10-24-49-250.us-west-2.compute.internal (aws:///us-west-2b/i-0caf996a8b7c467cc)" pkg=controller
time="2025-04-03T12:59:52Z" level=debug msg="syncing master service" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="syncing replica service" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="syncing example-db-config service" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="syncing example-db-leader config map" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="syncing example-db-config config map" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="syncing example-db-sync config map" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="syncing example-db-failover config map" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="volume claim for volume \"pgdata-example-db-0\" do not require updates" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="volume claim for volume \"pgdata-example-db-1\" do not require updates" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="volume claims have been synced successfully" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:52Z" level=debug msg="syncing statefulsets" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:53Z" level=debug msg="syncing Patroni config" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:53Z" level=debug msg="making GET http request: http://10.128.2.139:8008/config" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:53Z" level=debug msg="making GET http request: http://10.129.2.125:8008/config" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:53Z" level=debug msg="making GET http request: http://10.128.2.139:8008/patroni" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:53Z" level=debug msg="making GET http request: http://10.129.2.125:8008/patroni" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:53Z" level=error msg="errors while restarting Postgres in pods via Patroni API: could not restart Postgres in  pod example/example-db-0: replica currently being initialized" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:53Z" level=debug msg="syncing pod disruption budgets" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:53Z" level=debug msg="syncing roles" cluster-name=example/example-db pkg=cluster
time="2025-04-03T12:59:53Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:00:08Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:00:23Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:00:38Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:00:53Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:01:08Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:01:23Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:01:38Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:01:38Z" level=error msg="could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:01:38Z" level=debug msg="syncing databases" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:01:38Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:01:53Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:02:08Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:02:23Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:02:38Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:02:53Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:03:08Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:03:23Z" level=warning msg="could not connect to Postgres database: pq: password authentication failed for user \"postgres\"" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:03:23Z" level=error msg="could not sync databases: could not init database connection" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:03:23Z" level=debug msg="syncing prepared databases with schemas" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:03:23Z" level=debug msg="syncing connection pooler (master, replica) from (false, nil) to (false, nil)" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:03:23Z" level=debug msg="making GET http request: http://10.128.2.139:8008/patroni" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:03:23Z" level=info msg="identified non running pod, potentially skipping major version upgrade" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:03:23Z" level=debug msg="making GET http request: http://10.129.2.125:8008/patroni" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:03:23Z" level=info msg="recheck cluster version is already up to date. current: 150010, min desired: 150000" cluster-name=example/example-db pkg=cluster
time="2025-04-03T13:03:23Z" level=info msg="cluster has been synced" cluster-name=example/example-db pkg=controller worker=0
time="2025-04-03T13:03:23Z" level=info msg="received add event for already existing Postgres cluster" cluster-name=example/example-db pkg=controller worker=0

After removing the Postgresql manifest and ensuring I had no lingering PVC or PV I recreated the Postgresql manifest and it worked ok:

time="2025-04-03T13:17:48Z" level=info msg="ADD event has been queued" cluster-name=example/example-db pkg=controller worker=0
time="2025-04-03T13:17:48Z" level=info msg="creating a new Postgres cluster" cluster-name=example/example-db pkg=controller worker=0
time="2025-04-03T13:17:48Z" level=info msg="master service \"example/example-db\" has been successfully created" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=info msg="replica service \"example/example-db-repl\" has been successfully created" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=debug msg="team API is disabled" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=debug msg="team API is disabled" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=info msg="users have been initialized" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=debug msg="syncing secrets" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=info msg="created new secret example/ardome.example-db.credentials.postgresql.acid.zalan.do, namespace: example, uid: a0f81789-5eb5-4d3a-a0bd-4457dcdbe47d" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=info msg="created new secret example/postgres.example-db.credentials.postgresql.acid.zalan.do, namespace: example, uid: 5c2be9bc-1637-4939-950a-127954b00f72" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=info msg="created new secret example/standby.example-db.credentials.postgresql.acid.zalan.do, namespace: example, uid: 3f19f77d-62d8-495a-8357-615cb3414670" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=info msg="secrets have been successfully created" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=info msg="pod disruption budget \"example/postgres-example-db-pdb\" has been successfully created" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=debug msg="created new statefulset \"example/example-db\", uid: \"528decdb-90a0-4578-8d1c-d1a3d1a23da4\"" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=info msg="statefulset \"example/example-db\" has been successfully created" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:48Z" level=info msg="waiting for the cluster being ready" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:17:57Z" level=debug msg="Waiting for 2 pods to become ready" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="pods are ready" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="volume claim for volume \"pgdata-example-db-0\" do not require updates" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="volume claim for volume \"pgdata-example-db-1\" do not require updates" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="volume claims have been synced successfully" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="syncing example-db-config service" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="syncing example-db-leader config map" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="syncing example-db-config config map" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="syncing example-db-sync config map" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="syncing example-db-failover config map" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="Create roles" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="closing database connection" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="users have been successfully created" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="creating database \"example\" owner \"ardome\"" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="closing database connection" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="databases have been successfully created" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=debug msg="syncing connection pooler (master, replica) from (false, nil) to (false, nil)" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found pod disruption budget: \"example/postgres-example-db-pdb\" (uid: \"24cfd25e-f989-482c-8f24-33e083cba8a4\")" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found statefulset: \"example/example-db\" (uid: \"528decdb-90a0-4578-8d1c-d1a3d1a23da4\")" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found secret: \"example/ardome.example-db.credentials.postgresql.acid.zalan.do\" (uid: \"a0f81789-5eb5-4d3a-a0bd-4457dcdbe47d\") namespace: example" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found secret: \"example/postgres.example-db.credentials.postgresql.acid.zalan.do\" (uid: \"5c2be9bc-1637-4939-950a-127954b00f72\") namespace: example" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found secret: \"example/standby.example-db.credentials.postgresql.acid.zalan.do\" (uid: \"3f19f77d-62d8-495a-8357-615cb3414670\") namespace: example" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found master service: \"example/example-db\" (uid: \"eee1409e-0a58-494e-a8ca-b32e4b0d10f4\")" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found replica service: \"example/example-db-repl\" (uid: \"b38ae23a-a282-44b3-911f-45af0c437073\")" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found leader Patroni config map: \"example/example-db-leader\" (uid: \"78f7a5f9-e090-419e-942c-9f4abfb68737\")" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found config Patroni config map: \"example/example-db-config\" (uid: \"1b7291c8-ff04-43f5-a999-c8963020836b\")" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found pod: \"example/example-db-0\" (uid: \"13b26b56-45ce-402c-9af3-08e789019bd9\")" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found pod: \"example/example-db-1\" (uid: \"dd1dd7dc-5058-4446-b4e8-caf2affff630\")" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found persistent volume claim: \"example/pgdata-example-db-0\" (uid: \"d63dec98-dc76-46a0-adfb-b5d36ace3e4c\")" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="found persistent volume claim: \"example/pgdata-example-db-1\" (uid: \"16546bda-b684-4a4d-8cfe-9c84537f0e0e\")" cluster-name=example/example-db pkg=cluster worker=0
time="2025-04-03T13:18:45Z" level=info msg="cluster has been created" cluster-name=example/example-db pkg=controller worker=0

[bergner]

Also managed to reproduce something that maybe more resembles the original reported problem:

1. Ensured I deleted previous Postgresql manifest and ensured there was no lingering PVC and PV.
2. Created Postgresql manifest with single replica.
3. Operator starts provisioning resources and Postgres/spilo pod starts.
4. Postgres/spilo pod logs repeatedly say: "INFO: Lock owner: ; I am simple-db-0" and "INFO: waiting for leader to bootstrap". That seems wrong to me, but not sure if that's a Spilo/Patroni issue or an issue caused by the way the Postgres operator deploys it.
5. After 10 minutes Postgres operator gives up but Postgresql resource ends up in status "Running" anyway

time="2025-04-03T13:57:55Z" level=info msg="ADD event has been queued" cluster-name=example/simple-db pkg=controller worker=1
time="2025-04-03T13:57:55Z" level=info msg="creating a new Postgres cluster" cluster-name=example/simple-db pkg=controller worker=1
time="2025-04-03T13:57:55Z" level=info msg="master service \"example/simple-db\" has been successfully created" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=info msg="replica service \"example/simple-db-repl\" has been successfully created" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=debug msg="team API is disabled" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=debug msg="team API is disabled" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=info msg="users have been initialized" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=debug msg="syncing secrets" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=info msg="created new secret example/postgres.simple-db.credentials.postgresql.acid.zalan.do, namespace: example, uid: d720716d-b034-481c-94a0-8e788e854c00" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=info msg="created new secret example/standby.simple-db.credentials.postgresql.acid.zalan.do, namespace: example, uid: 20fe892a-0b4d-4a03-935b-501d5a8b0fcc" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=info msg="created new secret example/simple.simple-db.credentials.postgresql.acid.zalan.do, namespace: example, uid: 03efe7a1-6cd4-487c-9274-8e534cf00599" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=info msg="secrets have been successfully created" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=info msg="pod disruption budget \"example/postgres-simple-db-pdb\" has been successfully created" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=debug msg="created new statefulset \"example/simple-db\", uid: \"47573e9d-d5a4-4da9-8a14-4249e509993a\"" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=info msg="statefulset \"example/simple-db\" has been successfully created" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:55Z" level=info msg="waiting for the cluster being ready" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:57:58Z" level=debug msg="Waiting for 1 pods to become ready" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T13:59:52Z" level=info msg="SYNC event has been queued" cluster-name=example/simple-db pkg=controller worker=1
time="2025-04-03T13:59:52Z" level=info msg="there are 2 clusters running" pkg=controller
time="2025-04-03T14:07:55Z" level=error msg="failed to create cluster: pod labels error: still failing after 200 retries" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=warning msg="cluster created failed: pod labels error: still failing after 200 retries" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=error msg="could not create cluster: pod labels error: still failing after 200 retries" cluster-name=example/simple-db pkg=controller worker=1
time="2025-04-03T14:07:55Z" level=info msg="syncing of the cluster started" cluster-name=example/simple-db pkg=controller worker=1
time="2025-04-03T14:07:55Z" level=debug msg="team API is disabled" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="team API is disabled" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="syncing secrets" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="syncing master service" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="syncing replica service" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="syncing simple-db-config service" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="syncing simple-db-leader config map" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="syncing simple-db-config config map" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="syncing simple-db-sync config map" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="syncing simple-db-failover config map" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="volume claim for volume \"pgdata-simple-db-0\" do not require updates" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:55Z" level=debug msg="volume claims have been synced successfully" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:56Z" level=debug msg="syncing statefulsets" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:56Z" level=debug msg="syncing Patroni config" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:56Z" level=debug msg="making GET http request: http://10.128.2.149:8008/config" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:56Z" level=debug msg="making GET http request: http://10.128.2.149:8008/patroni" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:56Z" level=debug msg="syncing pod disruption budgets" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:56Z" level=debug msg="syncing roles" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:07:56Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:08:11Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:08:26Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:08:41Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:08:56Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:09:11Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:09:26Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:09:41Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:09:41Z" level=error msg="could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:09:41Z" level=debug msg="syncing databases" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:09:41Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:09:56Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:10:11Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:10:26Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:10:41Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:10:56Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:11:11Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:11:26Z" level=warning msg="could not connect to Postgres database: dial tcp 172.30.124.45:5432: connect: connection refused" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:11:26Z" level=error msg="could not sync databases: could not init database connection" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:11:26Z" level=debug msg="syncing prepared databases with schemas" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:11:26Z" level=debug msg="syncing connection pooler (master, replica) from (false, nil) to (false, nil)" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:11:26Z" level=debug msg="making GET http request: http://10.128.2.149:8008/patroni" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:11:26Z" level=info msg="identified non running pod, potentially skipping major version upgrade" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:11:26Z" level=info msg="no master in the cluster, skipping major version upgrade" cluster-name=example/simple-db pkg=cluster worker=1
time="2025-04-03T14:11:26Z" level=info msg="cluster has been synced" cluster-name=example/simple-db pkg=controller worker=1

The end result here is that the Postgres pod doesn't have a Postgresql instance accepting connections on port 5432. A process listing inside the pod looks like this:

$ ps auxwf
USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
postgres       1  0.0  0.0   2656  1408 ?        Ss   13:58   0:00 /usr/bin/dumb-init -c --rewrite 1:0 -- /bin/sh /launch.sh
postgres       7  0.0  0.0   2904  1792 ?        S    13:58   0:00 /bin/sh /launch.sh
postgres      34  0.0  0.0   2824  1280 ?        S    13:58   0:00  \_ /usr/bin/runsvdir -P /etc/service
postgres      35  0.0  0.0   2672  1408 ?        Ss   13:58   0:00      \_ runsv pgqd
postgres      37  0.0  0.0   4364  3200 ?        S    13:58   0:00      |   \_ /bin/bash /scripts/patroni_wait.sh --role primary -- /usr/bin/pgqd /home/postgres/pgq_ticker.ini
postgres     148  0.0  0.0   2792  1536 ?        S    14:22   0:00      |       \_ sleep 60
postgres      36  0.0  0.0   2672  1280 ?        Ss   13:58   0:00      \_ runsv patroni
postgres      38  0.0  0.1 493404 39724 ?        Sl   13:58   0:00          \_ /usr/bin/python3 /usr/local/bin/patroni /home/postgres/postgres.yml

EDIT: Retrying the same Postgresql manifest installation a second time after cleanup worked ok. In that case the Postgres pod log said "Lock owner: None; ..." instead of "Lock owner: ; ...". So some kind of null/nil/None vs empty string problem is lurking here somewhere.

2025-04-03 14:35:25,585 INFO: Lock owner: None; I am simple-db-0
2025-04-03 14:35:25,651 INFO: trying to bootstrap a new cluster

EDIT#2: Retrying with a 3rd database was similar. I also tried deleting the db-0 and db-1 pods on that database over and over again to see if at some point logged lock owner "None" instead of empty string but after 10+ such attempts they all insisted on empty string and logging that over and over. Starting from scratch by deleting the Postgresql manifest and PVCs a few times and I was able to eventually get the database to deploy. It seems like you have to get lucky and get it to the "Lock owner: None" state on the first attempt and otherwise you're screwed and have to start over.