Postgres Operator unable to connect to postgres database in bare-metal cluster setup, running in virtuablbox/cloud VMs.

devopsenggineer commented 2 years ago

Postgres Operator unable to connect to Postgres database in a bare-metal cluster setup, running in VirtualBox/cloud VMs.

Which image of the operator are you using? e.g. registry.opensource.zalan.do/acid/postgres-operator:v1.8.1 Ans: registry.opensource.zalan.do/acid/postgres-operator:v1.8.0
Where do you run it - cloud or metal? Kubernetes or OpenShift? [AWS K8s | GCP ... | Bare Metal K8s] Ans: Bare-Metal K8s in virtualbox/cloud VMs
Are you running Postgres Operator in production? [yes | no] Ans: Yes
Type of issue? [Bug report, question, feature request, etc.] Ans: Question

I have deployed a Highly Available Postgresql cluster using this Postgres-Operator with the following method, mentioned in operator docs.

# First, clone the repository and change to the directory
git clone https://github.com/zalando/postgres-operator.git
cd postgres-operator

# apply the manifests in the following order
kubectl create -f manifests/configmap.yaml  # configuration
kubectl create -f manifests/operator-service-account-rbac.yaml  # identity and permissions
kubectl create -f manifests/postgres-operator.yaml  # deployment
kubectl create -f manifests/api-service.yaml  # operator API to be used by UI

kubectl apply -k github.com/zalando/postgres-operator/manifests

All pods of Postgres are running fine.

NAME                                         READY   STATUS    RESTARTS      AGE   IP          NODE       NOMINATED NODE   READINESS GATES
pod/fx-postgres-0                            1/1     Running   0             46m   10.44.0.3   k-node1    <none>           <none>
pod/fx-postgres-1                            1/1     Running   0             46m   10.32.0.4   k-master   <none>           <none>
pod/nfs-client-provisioner-9b45f6874-928qd   1/1     Running   1 (52m ago)   59m   10.44.0.1   k-node1    <none>           <none>
pod/postgres-operator-5c5cfbb588-lwpz8       1/1     Running   0             44m   10.44.0.2   k-node1    <none>           <none>

NAME                         TYPE        CLUSTER-IP      EXTERNAL-IP   PORT(S)    AGE     SELECTOR
service/fx-postgres          ClusterIP   10.110.60.15    <none>        5432/TCP   58m     <none>
service/fx-postgres-config   ClusterIP   None            <none>        <none>     58m     <none>
service/fx-postgres-repl     ClusterIP   10.96.225.23    <none>        5432/TCP   58m     application=spilo,cluster-name=fx-postgres,spilo-role=replica
service/kubernetes           ClusterIP   10.96.0.1       <none>        443/TCP    3h16m   <none>
service/postgres-operator    ClusterIP   10.98.252.195   <none>        8080/TCP   58m     name=postgres-operator

Postgres Pod Logs

root@k-master:~# kubectl logs pod/fx-postgres-0
2022-06-18 22:08:36,973 - bootstrapping - INFO - Figuring out my environment (Google? AWS? Openstack? Local?)
2022-06-18 22:08:39,002 - bootstrapping - INFO - Could not connect to 169.254.169.254, assuming local Docker setup
2022-06-18 22:08:39,004 - bootstrapping - INFO - No meta-data available for this provider
2022-06-18 22:08:39,008 - bootstrapping - INFO - Looks like your running local
2022-06-18 22:08:39,195 - bootstrapping - INFO - Configuring pam-oauth2
2022-06-18 22:08:39,196 - bootstrapping - INFO - Writing to file /etc/pam.d/postgresql
2022-06-18 22:08:39,196 - bootstrapping - INFO - Configuring bootstrap
2022-06-18 22:08:39,196 - bootstrapping - INFO - Configuring pgqd
2022-06-18 22:08:39,197 - bootstrapping - INFO - Configuring wal-e
2022-06-18 22:08:39,197 - bootstrapping - INFO - Configuring pgbouncer
2022-06-18 22:08:39,197 - bootstrapping - INFO - No PGBOUNCER_CONFIGURATION was specified, skipping
2022-06-18 22:08:39,197 - bootstrapping - INFO - Configuring crontab
2022-06-18 22:08:39,198 - bootstrapping - INFO - Skipping creation of renice cron job due to lack of SYS_NICE capability
2022-06-18 22:08:39,202 - bootstrapping - INFO - Configuring patroni
2022-06-18 22:08:39,241 - bootstrapping - INFO - Writing to file /run/postgres.yml
2022-06-18 22:08:39,254 - bootstrapping - INFO - Configuring log
2022-06-18 22:08:39,255 - bootstrapping - INFO - Configuring standby-cluster
2022-06-18 22:08:39,255 - bootstrapping - INFO - Configuring certificate
2022-06-18 22:08:39,255 - bootstrapping - INFO - Generating ssl self-signed certificate
2022-06-18 22:08:42,467 INFO: Selected new K8s API server endpoint https://192.168.0.2:6443
2022-06-18 22:08:42,564 INFO: No PostgreSQL configuration items changed, nothing to reload.
2022-06-18 22:08:42,625 WARNING: Postgresql is not running.
2022-06-18 22:08:42,626 INFO: Lock owner: None; I am fx-postgres-0
2022-06-18 22:08:42,647 INFO: pg_controldata:
  pg_control version number: 1002
  Catalog version number: 201707211
  Database system identifier: 7110686641305608261
  Database cluster state: shut down in recovery
  pg_control last modified: Sat Jun 18 22:07:24 2022
  Latest checkpoint location: 0/3105CC0
  Prior checkpoint location: 0/3105CC0
  Latest checkpoint's REDO location: 0/3105C88
  Latest checkpoint's REDO WAL file: 000000020000000000000003
  Latest checkpoint's TimeLineID: 2
  Latest checkpoint's PrevTimeLineID: 2
  Latest checkpoint's full_page_writes: on
  Latest checkpoint's NextXID: 0:1079
  Latest checkpoint's NextOID: 32768
  Latest checkpoint's NextMultiXactId: 1
  Latest checkpoint's NextMultiOffset: 0
  Latest checkpoint's oldestXID: 549
  Latest checkpoint's oldestXID's DB: 1
  Latest checkpoint's oldestActiveXID: 1079
  Latest checkpoint's oldestMultiXid: 1
  Latest checkpoint's oldestMulti's DB: 1
  Latest checkpoint's oldestCommitTsXid: 0
  Latest checkpoint's newestCommitTsXid: 0
  Time of latest checkpoint: Sat Jun 18 21:12:47 2022
  Fake LSN counter for unlogged rels: 0/1
  Minimum recovery ending location: 0/4000000
  Min recovery ending loc's timeline: 2
  Backup start location: 0/0
  Backup end location: 0/0
  End-of-backup record required: no
  wal_level setting: replica
  wal_log_hints setting: on
  max_connections setting: 100
  max_worker_processes setting: 8
  max_prepared_xacts setting: 0
  max_locks_per_xact setting: 64
  track_commit_timestamp setting: off
  Maximum data alignment: 8
  Database block size: 8192
  Blocks per segment of large relation: 131072
  WAL block size: 8192
  Bytes per WAL segment: 16777216
  Maximum length of identifiers: 64
  Maximum columns in an index: 32
  Maximum size of a TOAST chunk: 1996
  Size of a large-object chunk: 2048
  Date/time type storage: 64-bit integers
  Float4 argument passing: by value
  Float8 argument passing: by value
  Data page checksum version: 0
  Mock authentication nonce: 4c3a3928911cbc11b48ff9aa9e74df79154d5b5569f2807ffb2e9be522b4d7f7

2022-06-18 22:08:42,704 INFO: Lock owner: None; I am fx-postgres-0
2022-06-18 22:08:42,895 INFO: starting as a secondary
2022-06-18 22:08:44,240 INFO: postmaster pid=58
2022-06-18 22:08:44 UTC [58]: [1-1] 62ae4cec.3a 0     LOG:  Auto detecting pg_stat_kcache.linux_hz parameter...
2022-06-18 22:08:44 UTC [58]: [2-1] 62ae4cec.3a 0     LOG:  pg_stat_kcache.linux_hz is set to 250000
2022-06-18 22:08:44 UTC [58]: [3-1] 62ae4cec.3a 0     LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-06-18 22:08:44 UTC [58]: [4-1] 62ae4cec.3a 0     LOG:  listening on IPv6 address "::", port 5432
2022-06-18 22:08:44 UTC [58]: [5-1] 62ae4cec.3a 0     LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-06-18 22:08:44 UTC [58]: [6-1] 62ae4cec.3a 0     LOG:  redirecting log output to logging collector process
2022-06-18 22:08:44 UTC [58]: [7-1] 62ae4cec.3a 0     HINT:  Future log output will appear in directory "../pg_log".
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - accepting connections
2022-06-18 22:08:46,063 INFO: establishing a new patroni connection to the postgres cluster
2022-06-18 22:08:46,272 WARNING: Could not activate Linux watchdog device: "Can't open watchdog device: [Errno 2] No such file or directory: '/dev/watchdog'"
2022-06-18 22:08:46,382 INFO: promoted self to leader by acquiring session lock
server promoting
2022-06-18 22:08:46,454 INFO: cleared rewind state after becoming the leader
2022-06-18 22:08:46,424 INFO: Lock owner: fx-postgres-0; I am fx-postgres-0
2022-06-18 22:08:46,642 INFO: updated leader lock during promote
2022-06-18 22:08:48,130 INFO: no action. I am (fx-postgres-0), the leader with the lock
DO
NOTICE:  role "admin" is already a member of role "cron_admin"
GRANT ROLE
DO
DO
NOTICE:  extension "pg_auth_mon" already exists, skipping
CREATE EXTENSION
NOTICE:  version "1.1" of extension "pg_auth_mon" is already installed
ALTER EXTENSION
GRANT
NOTICE:  extension "pg_cron" already exists, skipping
CREATE EXTENSION
DO
NOTICE:  version "1.4" of extension "pg_cron" is already installed
ALTER EXTENSION
ALTER POLICY
REVOKE
GRANT
REVOKE
GRANT
ALTER POLICY
REVOKE
GRANT
CREATE FUNCTION
REVOKE
GRANT
REVOKE
GRANT
REVOKE
GRANT
REVOKE
GRANT
REVOKE
GRANT
REVOKE
GRANT
REVOKE
GRANT
REVOKE
GRANT
NOTICE:  extension "file_fdw" already exists, skipping
CREATE EXTENSION
DO
NOTICE:  relation "postgres_log" already exists, skipping
CREATE TABLE
GRANT
NOTICE:  relation "postgres_log_0" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_1" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_2" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_3" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_4" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_5" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_6" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_7" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
RESET
SET
NOTICE:  drop cascades to 3 other objects
DETAIL:  drop cascades to type zmon_utils.system_information
drop cascades to function zmon_utils.get_database_cluster_information()
drop cascades to function zmon_utils.get_database_cluster_system_information()
DROP SCHEMA
NOTICE:  extension "plpython3u" already exists, skipping
DO
NOTICE:  language "plpythonu" does not exist, skipping
DROP LANGUAGE
NOTICE:  function plpython_call_handler() does not exist, skipping
DROP FUNCTION
NOTICE:  function plpython_inline_handler(internal) does not exist, skipping
DROP FUNCTION
NOTICE:  function plpython_validator(oid) does not exist, skipping
DROP FUNCTION
CREATE SCHEMA
GRANT
SET
CREATE TYPE
CREATE FUNCTION
CREATE FUNCTION
GRANT
You are now connected to database "postgres" as user "postgres".
NOTICE:  schema "user_management" already exists, skipping
CREATE SCHEMA
GRANT
SET
CREATE FUNCTION
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
GRANT
RESET
NOTICE:  extension "pg_stat_statements" already exists, skipping
CREATE EXTENSION
NOTICE:  extension "pg_stat_kcache" already exists, skipping
CREATE EXTENSION
NOTICE:  extension "set_user" already exists, skipping
CREATE EXTENSION
NOTICE:  version "3.0" of extension "set_user" is already installed
ALTER EXTENSION
GRANT
GRANT
GRANT
NOTICE:  schema "metric_helpers" already exists, skipping
CREATE SCHEMA
GRANT
GRANT
SET
CREATE FUNCTION
REVOKE
GRANT
GRANT
CREATE VIEW
REVOKE
GRANT
GRANT
CREATE FUNCTION
REVOKE
GRANT
GRANT
CREATE VIEW
REVOKE
GRANT
GRANT
CREATE FUNCTION
REVOKE
GRANT
GRANT
CREATE VIEW
REVOKE
GRANT
GRANT
RESET
You are now connected to database "template1" as user "postgres".
NOTICE:  schema "user_management" already exists, skipping
CREATE SCHEMA
GRANT
SET
CREATE FUNCTION
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
GRANT
RESET
NOTICE:  extension "pg_stat_statements" already exists, skipping
CREATE EXTENSION
NOTICE:  extension "pg_stat_kcache" already exists, skipping
CREATE EXTENSION
NOTICE:  extension "set_user" already exists, skipping
CREATE EXTENSION
NOTICE:  version "3.0" of extension "set_user" is already installed
ALTER EXTENSION
GRANT
GRANT
GRANT
NOTICE:  schema "metric_helpers" already exists, skipping
CREATE SCHEMA
GRANT
GRANT
SET
CREATE FUNCTION
REVOKE
GRANT
GRANT
CREATE VIEW
REVOKE
GRANT
GRANT
CREATE FUNCTION
REVOKE
GRANT
GRANT
CREATE VIEW
REVOKE
GRANT
GRANT
CREATE FUNCTION
REVOKE
GRANT
GRANT
CREATE VIEW
REVOKE
GRANT
GRANT
RESET
2022-06-18 22:08:58,342 INFO: no action. I am (fx-postgres-0), the leader with the lock
2022-06-18 22:09:08,364 INFO: no action. I am (fx-postgres-0), the leader with the lock
2022-06-18 22:09:18,418 INFO: no action. I am (fx-postgres-0), the leader with the lock
2022-06-18 22:09:28,270 INFO: no action. I am (fx-postgres-0), the leader with the lock
2022-06-18 22:09:38,278 INFO: no action. I am (fx-postgres-0), the leader with the lock
2022-06-18 22:09:41.239 25 LOG Starting pgqd 3.3
2022-06-18 22:09:41.240 25 LOG auto-detecting dbs ...

Postgres-Operator Logs

root@k-master:~# kubectl logs pod/postgres-operator-5c5cfbb588-lwpz8
time="2022-06-18T21:09:14Z" level=info msg="Fully qualified configmap name: default/postgres-operator"
time="2022-06-18T21:09:14Z" level=info msg="Spilo operator v1.8.0\n"
time="2022-06-18T21:09:14Z" level=info msg="Parse role bindings" pkg=controller
time="2022-06-18T21:09:14Z" level=info msg="successfully parsed" pkg=controller
time="2022-06-18T21:09:14Z" level=info msg="Listening to all namespaces" pkg=controller
time="2022-06-18T21:09:14Z" level=info msg="customResourceDefinition \"postgresqls.acid.zalan.do\" is already registered and will only be updated" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="{" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ReadyWaitInterval\": 3000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ReadyWaitTimeout\": 30000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ResyncPeriod\": 1800000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"RepairPeriod\": 300000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableCRDRegistration\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableCRDValidation\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"CRDCategories\": [" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="      \"all\"" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   ]," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ResourceCheckInterval\": 3000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ResourceCheckTimeout\": 600000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodLabelWaitTimeout\": 600000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodDeletionWaitTimeout\": 600000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"SpiloRunAsUser\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"SpiloRunAsGroup\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"SpiloFSGroup\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodPriorityClassName\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ClusterDomain\": \"cluster.local\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"SpiloPrivileged\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"SpiloAllowPrivilegeEscalation\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"AdditionalPodCapabilities\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ClusterLabels\": {" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="      \"application\": \"spilo\"" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   }," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"InheritedLabels\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"InheritedAnnotations\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"DownscalerAnnotations\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"IgnoredAnnotations\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ClusterNameLabel\": \"cluster-name\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"DeleteAnnotationDateKey\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"DeleteAnnotationNameKey\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodRoleLabel\": \"spilo-role\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodToleration\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"DefaultCPURequest\": \"100m\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"DefaultMemoryRequest\": \"100Mi\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"DefaultCPULimit\": \"1\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"DefaultMemoryLimit\": \"500Mi\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"MinCPULimit\": \"250m\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"MinMemoryLimit\": \"250Mi\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodEnvironmentConfigMap\": \"/\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodEnvironmentSecret\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"NodeReadinessLabel\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"NodeReadinessLabelMerge\": \"OR\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"MaxInstances\": -1," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"MinInstances\": -1," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ShmVolume\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"SecretNameTemplate\": \"{username}.{cluster}.credentials.{tprkind}.{tprgroup}\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PamRoleName\": \"zalandos\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PamConfiguration\": \"https://info.example.com/oauth2/tokeninfo?access_token= uid realm=/employees\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"TeamsAPIUrl\": \"https://teams.example.com/api/\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"OAuthTokenSecretName\": \"default/postgresql-operator\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"InfrastructureRolesSecretName\": \"/\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"InfrastructureRoles\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"InfrastructureRolesDefs\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"SuperUsername\": \"postgres\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ReplicationUsername\": \"standby\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"AdditionalOwnerRoles\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnablePasswordRotation\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PasswordRotationInterval\": 90," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PasswordRotationUserRetention\": 180," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ScalyrAPIKey\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ScalyrImage\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ScalyrServerURL\": \"https://upload.eu.scalyr.com\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ScalyrCPURequest\": \"100m\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ScalyrMemoryRequest\": \"50Mi\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ScalyrCPULimit\": \"1\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ScalyrMemoryLimit\": \"500Mi\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupSchedule\": \"30 00 * * *\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupDockerImage\": \"registry.opensource.zalan.do/acid/logical-backup:v1.8.0\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupProvider\": \"s3\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupS3Bucket\": \"my-bucket-url\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupS3Region\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupS3Endpoint\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupS3AccessKeyID\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupS3SecretAccessKey\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupS3SSE\": \"AES256\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupS3RetentionTime\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupGoogleApplicationCredentials\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogicalBackupJobPrefix\": \"logical-backup-\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"NumberOfInstances\": 2," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"Schema\": \"pooler\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"User\": \"pooler\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"Image\": \"registry.opensource.zalan.do/acid/pgbouncer:master-22\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"Mode\": \"transaction\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"MaxDBConnections\": 60," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ConnectionPoolerDefaultCPURequest\": \"500m\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ConnectionPoolerDefaultMemoryRequest\": \"100Mi\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ConnectionPoolerDefaultCPULimit\": \"1\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ConnectionPoolerDefaultMemoryLimit\": \"100Mi\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"WatchedNamespace\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"KubernetesUseConfigMaps\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EtcdHost\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"DockerImage\": \"registry.opensource.zalan.do/acid/spilo-14:2.1-p5\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"SidecarImages\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"SidecarContainers\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodServiceAccountName\": \"postgres-pod\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodServiceAccountDefinition\": \"{\\\"apiVersion\\\":\\\"v1\\\",\\\"kind\\\":\\\"ServiceAccount\\\",\\\"metadata\\\":{\\\"name\\\":\\\"postgres-pod\\\"}}\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodServiceAccountRoleBindingDefinition\": \"{\\\"apiVersion\\\":\\\"rbac.authorization.k8s.io/v1\\\",\\\"kind\\\":\\\"RoleBinding\\\",\\\"metadata\\\":{\\\"name\\\":\\\"postgres-pod\\\"},\\\"roleRef\\\":{\\\"apiGroup\\\":\\\"rbac.authorization.k8s.io\\\",\\\"kind\\\":\\\"ClusterRole\\\",\\\"name\\\":\\\"postgres-pod\\\"},\\\"subjects\\\":[{\\\"kind\\\":\\\"ServiceAccount\\\",\\\"name\\\":\\\"postgres-pod\\\"}]}\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"MasterPodMoveTimeout\": 1200000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"DbHostedZone\": \"db.example.com\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"AWSRegion\": \"eu-central-1\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"WALES3Bucket\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"LogS3Bucket\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"KubeIAMRole\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"WALGSBucket\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"GCPCredentials\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"WALAZStorageAccount\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"AdditionalSecretMount\": \"\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"AdditionalSecretMountPath\": \"/meta/credentials\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableEBSGp3Migration\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableEBSGp3MigrationMaxSize\": 1000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"DebugLogging\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableDBAccess\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableTeamsAPI\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableTeamSuperuser\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"TeamAdminRole\": \"admin\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"RoleDeletionSuffix\": \"_deleted\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableTeamMemberDeprecation\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableAdminRoleForUsers\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnablePostgresTeamCRD\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnablePostgresTeamCRDSuperusers\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableMasterLoadBalancer\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableMasterPoolerLoadBalancer\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableReplicaLoadBalancer\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableReplicaPoolerLoadBalancer\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"CustomServiceAnnotations\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"CustomPodAnnotations\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnablePodAntiAffinity\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodAntiAffinityTopologyKey\": \"kubernetes.io/hostname\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"StorageResizeMode\": \"pvc\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableLoadBalancer\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ExternalTrafficPolicy\": \"Cluster\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"MasterDNSNameFormat\": \"{cluster}.{team}.{hostedzone}\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ReplicaDNSNameFormat\": \"{cluster}-repl.{team}.{hostedzone}\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PDBNameFormat\": \"postgres-{cluster}-pdb\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnablePodDisruptionBudget\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableInitContainers\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableSidecars\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"Workers\": 8," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"APIPort\": 8080," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"RingLogLines\": 100," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ClusterHistoryEntries\": 1000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"TeamAPIRoleConfiguration\": {" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="      \"log_statement\": \"all\"" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   }," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodTerminateGracePeriod\": 300000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PodManagementPolicy\": \"ordered_ready\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"ProtectedRoles\": [" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="      \"admin\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="      \"cron_admin\"" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   ]," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PostgresSuperuserTeams\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"SetMemoryRequestToLimit\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableLazySpiloUpgrade\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableCrossNamespaceSecret\": false," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnablePgVersionEnvVar\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"EnableSpiloWalPathCompat\": true," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"MajorVersionUpgradeMode\": \"manual\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"MajorVersionUpgradeTeamAllowList\": null," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"MinimalMajorVersion\": \"9.6\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"TargetMajorVersion\": \"14\"," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PatroniAPICheckInterval\": 1000000000," pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="   \"PatroniAPICheckTimeout\": 5000000000" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="}" pkg=controller
time="2022-06-18T21:09:18Z" level=debug msg="acquiring initial list of clusters" pkg=controller
time="2022-06-18T21:09:18Z" level=debug msg="added new cluster: \"default/fx-postgres\"" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="SYNC event has been queued" cluster-name=default/fx-postgres pkg=controller worker=0
time="2022-06-18T21:09:18Z" level=info msg="there are 1 clusters running" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="started working in background" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="listening on :8080" pkg=apiserver
time="2022-06-18T21:09:18Z" level=debug msg="new node has been added: /k-master ()" pkg=controller
time="2022-06-18T21:09:18Z" level=debug msg="new node has been added: /k-node1 ()" pkg=controller
time="2022-06-18T21:09:18Z" level=info msg="ADD event has been queued" cluster-name=default/fx-postgres pkg=controller worker=0
time="2022-06-18T21:09:18Z" level=info msg="syncing of the cluster started" cluster-name=default/fx-postgres pkg=controller worker=0
time="2022-06-18T21:09:18Z" level=debug msg="team API is disabled" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:18Z" level=info msg="syncing secrets" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:18Z" level=debug msg="syncing master service" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:18Z" level=debug msg="syncing replica service" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:19Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:19Z" level=info msg="volume claims do not require changes" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:19Z" level=debug msg="syncing statefulsets" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:19Z" level=debug msg="making GET http request: http://10.44.0.3:8008/config" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:19Z" level=debug msg="patching Postgres config via Patroni API on pod default/fx-postgres-0 with following options: {\"pg_hba\":[\"hostssl all +fx_admin all pam\",\"local all all trust\",\"local replication all trust\",\"host replication standby all md5\",\"hostssl all all 0.0.0.0/0 md5\",\"host    all all 0.0.0.0/0 md5\"]}" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:19Z" level=debug msg="making PATCH http request: http://10.44.0.3:8008/config" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:32Z" level=debug msg="making GET http request: http://10.44.0.3:8008/patroni" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:32Z" level=debug msg="making GET http request: http://10.32.0.4:8008/patroni" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:32Z" level=debug msg="syncing pod disruption budgets" cluster-name=default/fx-postgres pkg=cluster
W0618 21:09:32.028189       1 warnings.go:70] policy/v1beta1 PodDisruptionBudget is deprecated in v1.21+, unavailable in v1.25+; use policy/v1 PodDisruptionBudget
time="2022-06-18T21:09:32Z" level=debug msg="syncing roles" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:32Z" level=warning msg="could not connect to Postgres database: dial tcp 142.132.201.230:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:09:47Z" level=warning msg="could not connect to Postgres database: dial tcp 142.132.201.230:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:10:02Z" level=warning msg="could not connect to Postgres database: dial tcp 142.132.201.230:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:10:17Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:10:32Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:10:47Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:11:02Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:11:17Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:11:17Z" level=warning msg="error while syncing cluster state: could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:11:17Z" level=error msg="could not sync cluster: could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=default/fx-postgres pkg=controller worker=0
time="2022-06-18T21:11:17Z" level=info msg="recieved add event for already existing Postgres cluster" cluster-name=default/fx-postgres pkg=controller worker=0
time="2022-06-18T21:39:18Z" level=info msg="SYNC event has been queued" cluster-name=default/fx-postgres pkg=controller worker=0
time="2022-06-18T21:39:18Z" level=info msg="there are 1 clusters running" pkg=controller
time="2022-06-18T21:39:18Z" level=info msg="syncing of the cluster started" cluster-name=default/fx-postgres pkg=controller worker=0
time="2022-06-18T21:39:18Z" level=debug msg="team API is disabled" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:18Z" level=info msg="syncing secrets" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:18Z" level=debug msg="syncing master service" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:18Z" level=debug msg="syncing replica service" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:19Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:19Z" level=info msg="volume claims do not require changes" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:19Z" level=debug msg="syncing statefulsets" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:19Z" level=debug msg="making GET http request: http://10.44.0.3:8008/config" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:31Z" level=debug msg="making GET http request: http://10.44.0.3:8008/patroni" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:31Z" level=debug msg="making GET http request: http://10.32.0.4:8008/patroni" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:31Z" level=debug msg="syncing pod disruption budgets" cluster-name=default/fx-postgres pkg=cluster
W0618 21:39:31.680951       1 warnings.go:70] policy/v1beta1 PodDisruptionBudget is deprecated in v1.21+, unavailable in v1.25+; use policy/v1 PodDisruptionBudget
time="2022-06-18T21:39:31Z" level=debug msg="syncing roles" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:32Z" level=warning msg="could not connect to Postgres database: dial tcp 142.132.201.230:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:39:47Z" level=warning msg="could not connect to Postgres database: dial tcp 142.132.201.230:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:40:02Z" level=warning msg="could not connect to Postgres database: dial tcp 142.132.201.230:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:40:17Z" level=warning msg="could not connect to Postgres database: dial tcp 142.132.201.230:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:40:34Z" level=warning msg="could not connect to Postgres database: dial tcp 142.132.201.230:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:40:47Z" level=warning msg="could not connect to Postgres database: dial tcp 142.132.201.230:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:41:03Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:41:17Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:41:17Z" level=warning msg="error while syncing cluster state: could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T21:41:17Z" level=error msg="could not sync cluster: could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=default/fx-postgres pkg=controller worker=0
time="2022-06-18T22:09:18Z" level=info msg="SYNC event has been queued" cluster-name=default/fx-postgres pkg=controller worker=0
time="2022-06-18T22:09:18Z" level=info msg="there are 1 clusters running" pkg=controller
time="2022-06-18T22:09:18Z" level=info msg="syncing of the cluster started" cluster-name=default/fx-postgres pkg=controller worker=0
time="2022-06-18T22:09:18Z" level=debug msg="team API is disabled" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:18Z" level=info msg="syncing secrets" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:19Z" level=debug msg="syncing master service" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:19Z" level=debug msg="syncing replica service" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:19Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:19Z" level=info msg="volume claims do not require changes" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:19Z" level=debug msg="syncing statefulsets" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:19Z" level=debug msg="making GET http request: http://10.44.0.3:8008/config" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:31Z" level=debug msg="making GET http request: http://10.32.0.4:8008/patroni" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:31Z" level=debug msg="making GET http request: http://10.44.0.3:8008/patroni" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:31Z" level=debug msg="syncing pod disruption budgets" cluster-name=default/fx-postgres pkg=cluster
W0618 22:09:31.692330       1 warnings.go:70] policy/v1beta1 PodDisruptionBudget is deprecated in v1.21+, unavailable in v1.25+; use policy/v1 PodDisruptionBudget
time="2022-06-18T22:09:31Z" level=debug msg="syncing roles" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:33Z" level=warning msg="could not connect to Postgres database: dial tcp 213.239.194.188:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:09:47Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:10:02Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:10:17Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:10:32Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:10:47Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:11:02Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:11:17Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:11:17Z" level=warning msg="error while syncing cluster state: could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:11:17Z" level=error msg="could not sync cluster: could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=default/fx-postgres pkg=controller worker=0

Getting below errors Postgres-operator pod also mentioned in above logs as well.

time="2022-06-18T22:11:17Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:11:17Z" level=warning msg="error while syncing cluster state: could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=default/fx-postgres pkg=cluster
time="2022-06-18T22:11:17Z" level=error msg="could not sync cluster: could not sync roles: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=default/fx-postgres pkg=controller worker=0

Because of the above error operator is not able to create specified roles, DB user and database(See below spec file)

apiVersion: "acid.zalan.do/v1"
kind: postgresql
metadata:
  name: fx-postgres
  namespace: default
spec:
  teamId: "fx"
  volume:
    size: 2Gi
    storageClass: pg-storage-class
  numberOfInstances: 2
  users:
    fx_admin:
    - superuser
    - createdb
  databases:
    fx: fx_admin  # dbname: owner
  preparedDatabases:
    fx:
      defaultUsers: false
      extensions:
        pg_partman: public
        pgcrypto: public
      schemas:
        data: {}
        history:
          defaultRoles: false
          defaultUsers: false
  patroni:
    pg_hba:
      - hostssl all +fx_admin all pam
      - local all all trust
      - local replication all trust
      - host replication standby all md5
      - hostssl all all 0.0.0.0/0 md5
      - host    all all 0.0.0.0/0 md5
  postgresql:
    version: "10"

Same above Postgres operator specs are working fine in Azure, GCP, and AWS cloud Kubernetes service, even in minikube cluster running locally in my laptop with the same NFS as dynamic storage class without any issue.

But in the bare-metal k8s cluster, it's giving problems as mentioned operator logs. Here are the steps we followed to setup bare-metal k8s cluster

     # Common for all nodes
     sudo su
     tee /etc/modules-load.d/containerd.conf <<EOF
overlay
br_netfilter
EOF

      modprobe overlay
      modprobe br_netfilter
      tee /etc/sysctl.d/kubernetes.conf<<EOF
net.bridge.bridge-nf-call-ip6tables = 1
net.bridge.bridge-nf-call-iptables = 1
net.ipv4.ip_forward = 1
EOF

      sysctl --system

       curl -fsSL https://download.docker.com/linux/ubuntu/gpg | sudo apt-key add -
       apt install curl
       curl -fsSL https://download.docker.com/linux/ubuntu/gpg | sudo apt-key add -
       add-apt-repository "deb [arch=amd64] https://download.docker.com/linux/ubuntu $(lsb_release -cs) stable"
       apt update
       apt install -y docker.io
       swapoff -a
       sed -i '/ swap / s/^\(.*\)$/#\1/g' /etc/fstab
       cat <<EOF | sudo tee /etc/docker/daemon.json
{
  "exec-opts": ["native.cgroupdriver=systemd"],
  "log-driver": "json-file",
  "log-opts": {
    "max-size": "100m"
  },
  "storage-driver": "overlay2"
}
EOF

       systemctl enable docker
       sudo systemctl daemon-reload
       sudo systemctl restart docker
       sudo systemctl status docker
       sudo systemctl status containerd
       apt-get update && apt-get install -y apt-transport-https ca-certificates curl
       curl -fsSLo /usr/share/keyrings/kubernetes-archive-keyring.gpg https://packages.cloud.google.com/apt/doc/apt-key.gpg
       echo "deb [signed-by=/usr/share/keyrings/kubernetes-archive-keyring.gpg] https://apt.kubernetes.io/ kubernetes-xenial main" | sudo tee /etc/apt/sources.list.d/kubernetes.list
       KUBE_VERSION=1.23.0
       apt-get update
       apt-get install -y kubelet=${KUBE_VERSION}-00 kubeadm=${KUBE_VERSION}-00 kubectl=${KUBE_VERSION}-00 kubernetes-cni=0.8.7-00
       apt-mark hold kubelet kubeadm kubectl
       systemctl enable kubelet && systemctl start kubelet

       # Only in Master Node
       kubeadm init --kubernetes-version=${KUBE_VERSION} --pod-network-cidr=10.244.0.0/16
       mkdir -p $HOME/.kube
       sudo cp -i /etc/kubernetes/admin.conf $HOME/.kube/config
       sudo chown $(id -u):$(id -g) $HOME/.kube/config

       cp /etc/kubernetes/admin.conf $HOME/
       chown  $(id -u) $HOME/admin.conf
       export KUBECONFIG=$HOME/admin.conf
       kubectl get nodes
       kubectl apply -f "https://cloud.weave.works/k8s/net?k8s-version=$(kubectl version | base64 | tr -d '\n')"

     # Runing Pods in Kube-system namespace

root@k-master:~# kubectl -n kube-system get po,svc
NAME                                   READY   STATUS    RESTARTS       AGE
pod/coredns-64897985d-4xmmn            1/1     Running   0              3h53m
pod/coredns-64897985d-b8pzd            1/1     Running   0              3h53m
pod/etcd-k-master                      1/1     Running   3              3h54m
pod/kube-apiserver-k-master            1/1     Running   5              3h54m
pod/kube-controller-manager-k-master   1/1     Running   1 (89m ago)    3h54m
pod/kube-proxy-92rk7                   1/1     Running   0              3h53m
pod/kube-proxy-mhcgs                   1/1     Running   0              3h52m
pod/kube-scheduler-k-master            1/1     Running   15 (89m ago)   3h54m
pod/weave-net-mdcq4                    2/2     Running   0              3h52m
pod/weave-net-scfhz                    2/2     Running   0              3h52m

NAME               TYPE        CLUSTER-IP   EXTERNAL-IP   PORT(S)                  AGE
service/kube-dns   ClusterIP   10.96.0.10   <none>        53/UDP,53/TCP,9153/TCP   3h54m
root@k-master:~#

Does Zalando Postgres-operator works in the bare-metal cluster or not?

devopsenggineer commented 2 years ago

This activity Postgres-operator is not able to do it, which it does perfectly in aks, gke clusters

time="2022-06-06T15:11:06Z" level=debug msg="closing database connection" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-06T15:11:06Z" level=info msg="users have been successfully created" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-06T15:11:06Z" level=info msg="creating database \"fx\" owner \"fx_admin\"" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-06T15:11:06Z" level=warning msg="closing an existing connection before opening a new one to fx" cluster-name=default/fx-postgres pkg=cl>
time="2022-06-06T15:11:06Z" level=debug msg="closing database connection" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-06T15:11:06Z" level=debug msg="closing database connection" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-06T15:11:06Z" level=debug msg="syncing prepared database \"fx\"" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-06T15:11:06Z" level=info msg="creating database schema \"data\" owner \"fx_data_owner\"" cluster-name=default/fx-postgres pkg=cluster w>

Errors we are getting when setting it up in bare-metal clusters of Ubuntu OS in virtualbox/cloud VMs.

time="2022-06-20T02:56:46Z" level=info msg="Create roles" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-20T02:56:47Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-20T02:57:02Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-20T02:57:16Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-20T02:57:32Z" level=warning msg="could not connect to Postgres database: dial tcp 195.201.199.239:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-20T02:57:46Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-20T02:58:01Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-20T02:58:16Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-20T02:58:31Z" level=warning msg="could not connect to Postgres database: dial tcp 85.10.194.207:5432: connect: connection refused" cluster-name=default/fx-postgres pkg=cluster worker=0
time="2022-06-20T02:58:31Z" level=error msg="could not create cluster: could not create users: could not init db connection: could not init db connection: still failing after 8 retries" cluster-name=default/fx-postgres pkg=controller worker=0

Why is this strange behavior? Could anyone help over here?

MarkCupitt commented 1 year ago

I am getting this exact same issue on a bare metal cluster

nibbleshift commented 1 year ago

I am having this same issue on k3d.

Winor commented 1 year ago

Same here!

TeddyAndrieux commented 1 year ago

@devopsenggineer I think the IP 85.10.194.207 is kind of a "default" name resolution of your DNS configured on your hosts.

To me, the issue is because of the operator trying to resolve the full name

fmt.Sprintf("%s.%s.svc.%s", c.Name, c.Namespace, c.OpConfig.ClusterDomain)

Where it shouldn't, the ClusterDomain value is handled by default by search in resolv.conf used in the containers, so if you try to resolve directly the "full name" (including the ClusterDomain suffix) then it will use the search domain configured on the hosts (so the kube DNS will forward it to the host nameservers) before actually resolving the name

More explanation

To give some explanation, considering the cluster domain `cluster.local` On a "classic" Kubernetes deployment (using kubeadm for example, but I think it's likely the same for k3d) every pod will have the following `resolv.conf` file ``` search .svc.cluster.local svc.cluster.local cluster.local nameserver options ndots:5 ``` And by default, if Coredns is not able to resolve a request he fallback to host nameservers So a lookup on `..svc.cluster.local` will do the following resolution (in this order): 1. `..svc.cluster.local..svc.cluster.local` 2. `..svc.cluster.local.svc.cluster.local` 3. `..svc.cluster.local.cluster.local` 4. `..svc.cluster.local.` 5. `..svc.cluster.local` So, the first 1, 2, and 3 will just answer "not found" and 4 will be forwarded to the host nameservers and only if the host nameservers also answer “not found”, the actual 5 will be matched So as you can see it’s not efficient AND it’s a bug since you may not be able to resolve what you want at the end.

I would suggest removing the usage of OpConfig.ClusterDomain everywhere but I don't have enough knowledge of this operator to get the impact of such changes.

oneumyvakin commented 9 months ago

The issue happens because of search DOMAINS in your OS like

/etc/resolv.conf.

nameserver 127.0.0.53
options edns0 trust-ad
search DOMAINS

resolver adds 'domains' to postgresql-cluster.default.svc.cluster.local domain name:

# k exec -ti postgres-operator-6c5657ccd6-ldtv5 -- /bin/sh
/ $ nslookup postgresql-cluster.default.svc.cluster.local.domains
Server:     10.96.0.10
Address:    10.96.0.10:53

Non-authoritative answer:
Name:   postgresql-cluster.default.svc.cluster.local.domains
Address: 3.64.163.50

that why you get so strange resolving.

davidusken commented 2 months ago

Thanks @oneumyvakin I solved this by modifying values.yaml for the Helm chart. The value modified was cluster_domain, located under configKubernetes. After doing so, everything works as expected.

zalando / postgres-operator

Postgres Operator unable to connect to postgres database in bare-metal cluster setup, running in virtuablbox/cloud VMs. #1931