Postgres operator 1.8.0: Pooler schema does not appear to be created on new databases

[andhrs]

Please, answer some short questions which should help us to understand your problem / question better?

• Which image of the operator are you using? e.g. registry.opensource.zalan.do/acid/postgres-operator:v1.8.1 im using: registry.opensource.zalan.do/acid/postgres-operator:v1.8.0 installed the postgres operator with the helm chart.

• Where do you run it - cloud or metal? Kubernetes or OpenShift? [AWS K8s | GCP ... | Bare Metal K8s] Kubernetes on a k3d cluster

• Are you running Postgres Operator in production? [yes | no] no

• Type of issue? [Bug report, question, feature request, etc.] bug report

• Description

I have created a database cluster using the "postgresql.acid.zalan.do/v1" ressource, and enabled the connection pooler using the "enableConnectionPooler" property, the database cluster is then created, and I can connect using the pooler service to the preexisting default "postgres" database.

The issue seems to arise when I create a new database in the database cluster using the postgres user rather than the prepared databases approach. When I try to connect to the new database using psql, then an error is returned: (where dbhost is the pooler service and dbname is the newly created database.) psql -U 'dbname' -h dbhost sslmode=require psql: error: FATAL: bouncer config error

The log of the pooler also contains the same error: ( someIP contains an IP, but I have excluded it here. ) 2022-06-01 08:06:12.810 UTC [1] LOG C-0x55954b4c0b50: (nodb)/(nouser)@someIP:39712 registered new auto-database: db=dbname 2022-06-01 08:06:22.826 UTC [1] WARNING C-0x55954b4c0b50: dbname/(nouser)@someIP:39712 pooler error: bouncer config error

When I then look in the postgres log, for the database I tried to connect to, then there is the following entry: (SQL query for the log was: SELECT message, log_time, user_name, connection_from FROM public.postgres_log where database_name = 'dbname' ORDER BY log_time desc; ) message: schema "pooler" does not exist log_time: 2022-06-01 08:06:22.826+00 user_name: pooler (excluded the connection_from)

Looking at the database I created, it indeed does not have the pooler schema. I tried to wait for the resync, but that does not appear to add the schema to the database, I can also find no error logs in the postgres operator.

However, I did find one way in which I could have the postgres operator install the schema, and that was to restart the postgres operator. After restarting the operator, and seeing that it had created the schema, then I tried another login using psql, which went through.

The postgres operator also logs that it is installing the lookup function in the database, after it has been restarted: (dbClusterName is the excluded database clustername)

time="2022-06-01T10:37:50Z" level=info msg="install pooler lookup function into database 'dbname'" cluster-name=postgresdb/dbClusterName pkg=cluster time="2022-06-01T10:37:50Z" level=debug msg="closing database connection" cluster-name=postgresdb/dbClusterName pkg=cluster

I did find an older issue, that appears to be similar in the sense that the pooler schema is missing, but the issue appears to be closed, and the release note for 1.7.0 indicates that the issue is fixed: https://newreleases.io/project/github/zalando/postgres-operator/release/v1.7.0 https://github.com/zalando/postgres-operator/issues/1060

Let me know, if there is more information that you'd like.

[cdmikechen]

@andhrs I think you can see https://github.com/zalando/postgres-operator/blob/d8a159ef1a17491813f68c7bdff600aeb811802d/pkg/cluster/database.go#L73-L92

The operator generates a pooler's user_lookup function for each database created, and you need to connect to the operator-generated database in order to do so.

[haroonb]

I just ran into the same issue with a clean install of postgres-operator-1.10.0 and restarting the operator fixed the issue for me as well. prior it was the exact same error at metioned above.

[haroonb]

I have some operator logs, which might be useful.

This is the log, after the creation of the database, but before the restart of the operator.

time="2023-05-26T11:53:07Z" level=info msg="Spilo operator v1.10.0\n"
time="2023-05-26T11:53:07Z" level=info msg="Parse role bindings" pkg=controller
time="2023-05-26T11:53:07Z" level=info msg="successfully parsed" pkg=controller
time="2023-05-26T11:53:07Z" level=info msg="Listening to all namespaces" pkg=controller
time="2023-05-26T11:53:07Z" level=info msg="customResourceDefinition \"postgresqls.acid.zalan.do\" is already registered and will only be updated" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="{" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ReadyWaitInterval\": 3000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ReadyWaitTimeout\": 30000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ResyncPeriod\": 1800000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"RepairPeriod\": 300000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableCRDRegistration\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableCRDValidation\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"CRDCategories\": [" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="      \"all\"" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   ]," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ResourceCheckInterval\": 3000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ResourceCheckTimeout\": 600000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodLabelWaitTimeout\": 600000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodDeletionWaitTimeout\": 600000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SpiloRunAsUser\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SpiloRunAsGroup\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SpiloFSGroup\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodPriorityClassName\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ClusterDomain\": \"cluster.local\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SpiloPrivileged\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SpiloAllowPrivilegeEscalation\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"AdditionalPodCapabilities\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ClusterLabels\": {" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="      \"application\": \"spilo\"" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   }," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"InheritedLabels\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"InheritedAnnotations\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"DownscalerAnnotations\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"IgnoredAnnotations\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ClusterNameLabel\": \"cluster-name\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"DeleteAnnotationDateKey\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"DeleteAnnotationNameKey\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodRoleLabel\": \"spilo-role\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodToleration\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"DefaultCPURequest\": \"100m\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"DefaultMemoryRequest\": \"100Mi\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"DefaultCPULimit\": \"1\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"DefaultMemoryLimit\": \"500Mi\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MinCPULimit\": \"250m\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MinMemoryLimit\": \"250Mi\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MaxCPURequest\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MaxMemoryRequest\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodEnvironmentConfigMap\": \"/\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodEnvironmentSecret\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"NodeReadinessLabel\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"NodeReadinessLabelMerge\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ShmVolume\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MaxInstances\": -1," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MinInstances\": -1," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"IgnoreInstanceLimitsAnnotationKey\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SecretNameTemplate\": \"{username}.{cluster}.credentials.{tprkind}.{tprgroup}\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PamRoleName\": \"zalandos\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PamConfiguration\": \"https://info.example.com/oauth2/tokeninfo?access_token= uid realm=/employees\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"TeamsAPIUrl\": \"https://teams.example.com/api/\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"OAuthTokenSecretName\": \"postgres/postgres-operator\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"InfrastructureRolesSecretName\": \"/\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"InfrastructureRoles\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"InfrastructureRolesDefs\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SuperUsername\": \"postgres\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ReplicationUsername\": \"standby\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"AdditionalOwnerRoles\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnablePasswordRotation\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PasswordRotationInterval\": 90," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PasswordRotationUserRetention\": 180," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ScalyrAPIKey\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ScalyrImage\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ScalyrServerURL\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ScalyrCPURequest\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ScalyrMemoryRequest\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ScalyrCPULimit\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ScalyrMemoryLimit\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupSchedule\": \"30 00 * * *\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupDockerImage\": \"registry.opensource.zalan.do/acid/logical-backup:v1.10.0\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupProvider\": \"s3\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupAzureStorageAccountName\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupAzureStorageContainer\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupAzureStorageAccountKey\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupS3Bucket\": \"my-bucket-url\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupS3Region\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupS3Endpoint\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupS3AccessKeyID\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupS3SecretAccessKey\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupS3SSE\": \"AES256\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupS3RetentionTime\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupGoogleApplicationCredentials\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupJobPrefix\": \"logical-backup-\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupCPURequest\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupMemoryRequest\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupCPULimit\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogicalBackupMemoryLimit\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"NumberOfInstances\": 3," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"Schema\": \"pooler\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"User\": \"pooler\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"Image\": \"registry.opensource.zalan.do/acid/pgbouncer:master-27\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"Mode\": \"transaction\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MaxDBConnections\": 100," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ConnectionPoolerDefaultCPURequest\": \"100m\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ConnectionPoolerDefaultMemoryRequest\": \"10Mi\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ConnectionPoolerDefaultCPULimit\": \"500m\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ConnectionPoolerDefaultMemoryLimit\": \"100Mi\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"WatchedNamespace\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"KubernetesUseConfigMaps\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EtcdHost\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"DockerImage\": \"ghcr.io/zalando/spilo-15:3.0-p1\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SidecarImages\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SidecarContainers\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodServiceAccountName\": \"postgres-pod\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodServiceAccountDefinition\": \"{\\\"apiVersion\\\":\\\"v1\\\",\\\"kind\\\":\\\"ServiceAccount\\\",\\\"metadata\\\":{\\\"name\\\":\\\"postgres-pod\\\"}}\"," pkg=controller
time="2023-05-26T11:53:11Z" 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="2023-05-26T11:53:11Z" level=info msg="   \"MasterPodMoveTimeout\": 1200000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"DbHostedZone\": \"db.example.com\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"AWSRegion\": \"eu-central-1\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"WALES3Bucket\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"LogS3Bucket\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"KubeIAMRole\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"WALGSBucket\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"GCPCredentials\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"WALAZStorageAccount\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"AdditionalSecretMount\": \"\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"AdditionalSecretMountPath\": \"/meta/credentials\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableEBSGp3Migration\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableEBSGp3MigrationMaxSize\": 1000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"DebugLogging\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableDBAccess\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableTeamsAPI\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableTeamSuperuser\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"TeamAdminRole\": \"admin\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"RoleDeletionSuffix\": \"_deleted\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableTeamMemberDeprecation\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableAdminRoleForUsers\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnablePostgresTeamCRD\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnablePostgresTeamCRDSuperusers\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableMasterLoadBalancer\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableMasterPoolerLoadBalancer\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableReplicaLoadBalancer\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableReplicaPoolerLoadBalancer\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"CustomServiceAnnotations\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"CustomPodAnnotations\": {" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="      \"cluster-autoscaler.kubernetes.io/safe-to-evict\": \"true\"" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   }," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnablePodAntiAffinity\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodAntiAffinityPreferredDuringScheduling\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodAntiAffinityTopologyKey\": \"kubernetes.io/hostname\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"StorageResizeMode\": \"pvc\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableLoadBalancer\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ExternalTrafficPolicy\": \"Cluster\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MasterDNSNameFormat\": \"{cluster}.{namespace}.{hostedzone}\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MasterLegacyDNSNameFormat\": \"{cluster}.{team}.{hostedzone}\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ReplicaDNSNameFormat\": \"{cluster}-repl.{namespace}.{hostedzone}\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ReplicaLegacyDNSNameFormat\": \"{cluster}-repl.{team}.{hostedzone}\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PDBNameFormat\": \"postgres-{cluster}-pdb\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnablePodDisruptionBudget\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableInitContainers\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableSidecars\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SharePgSocketWithSidecars\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"Workers\": 8," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"APIPort\": 8080," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"RingLogLines\": 100," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ClusterHistoryEntries\": 1000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"TeamAPIRoleConfiguration\": {" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="      \"log_statement\": \"all\"" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   }," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodTerminateGracePeriod\": 300000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PodManagementPolicy\": \"ordered_ready\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableReadinessProbe\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"ProtectedRoles\": [" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="      \"admin\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="      \"cron_admin\"" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   ]," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PostgresSuperuserTeams\": [" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="      \"postgres_superusers\"" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   ]," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"SetMemoryRequestToLimit\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableLazySpiloUpgrade\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableCrossNamespaceSecret\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnablePgVersionEnvVar\": true," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableSpiloWalPathCompat\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnableTeamIdClusternamePrefix\": false," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MajorVersionUpgradeMode\": \"off\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MajorVersionUpgradeTeamAllowList\": null," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"MinimalMajorVersion\": \"11\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"TargetMajorVersion\": \"15\"," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PatroniAPICheckInterval\": 1000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"PatroniAPICheckTimeout\": 5000000000," pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="   \"EnablePatroniFailsafeMode\": false" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="}" pkg=controller
time="2023-05-26T11:53:11Z" level=debug msg="acquiring initial list of clusters" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="no clusters running" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="started working in background" pkg=controller
time="2023-05-26T11:53:11Z" level=info msg="listening on :8080" pkg=apiserver
time="2023-05-26T11:53:11Z" level=debug msg="new node has been added: /perftest-w6 ()" pkg=controller
time="2023-05-26T11:53:11Z" level=debug msg="new node has been added: /perftest-m1 ()" pkg=controller
time="2023-05-26T11:53:11Z" level=debug msg="new node has been added: /perftest-m2 ()" pkg=controller
time="2023-05-26T11:53:11Z" level=debug msg="new node has been added: /perftest-w2 ()" pkg=controller
time="2023-05-26T11:53:11Z" level=debug msg="new node has been added: /perftest-w3 ()" pkg=controller
time="2023-05-26T11:53:11Z" level=debug msg="new node has been added: /perftest-w1 ()" pkg=controller
time="2023-05-26T11:53:18Z" level=info msg="ADD event has been queued" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T11:53:18Z" level=info msg="creating pod service account \"postgres-pod\" in the \"postgres\" namespace" pkg=controller
time="2023-05-26T11:53:18Z" level=info msg="successfully deployed the pod service account \"postgres-pod\" to the \"postgres\" namespace" pkg=controller
time="2023-05-26T11:53:18Z" level=info msg="Creating the role binding \"postgres-pod\" in the \"postgres\" namespace" pkg=controller
time="2023-05-26T11:53:18Z" level=info msg="successfully deployed the role binding for the pod service account \"postgres-pod\" to the \"postgres\" namespace" pkg=controller
time="2023-05-26T11:53:18Z" level=info msg="creating a new Postgres cluster" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T11:53:18Z" level=warning msg="master is not running, generated master endpoint does not contain any addresses" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=info msg="endpoint \"postgres/test-postgres-cluster\" has been successfully created" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=info msg="master service \"postgres/test-postgres-cluster\" has been successfully created" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=info msg="replica service \"postgres/test-postgres-cluster-repl\" has been successfully created" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=debug msg="team API is disabled" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=debug msg="team API is disabled" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=info msg="users have been initialized" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=info msg="syncing secrets" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=debug msg="created new secret postgres/postgres.test-postgres-cluster.credentials.postgresql.acid.zalan.do, namespace: postgres, uid: 21373633-c85a-4375-948b-3aaa1478217b" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=debug msg="created new secret postgres/standby.test-postgres-cluster.credentials.postgresql.acid.zalan.do, namespace: postgres, uid: 7ab3868a-6f2f-4950-ad91-8f72ab6e1221" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=debug msg="created new secret postgres/pooler.test-postgres-cluster.credentials.postgresql.acid.zalan.do, namespace: postgres, uid: ddfca4c6-8254-4081-a41e-90923923e1ac" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=info msg="secrets have been successfully created" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=info msg="pod disruption budget \"postgres/postgres-test-postgres-cluster-pdb\" has been successfully created" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=debug msg="created new statefulset \"postgres/test-postgres-cluster\", uid: \"fdc0db37-4cf3-41d4-8bd7-8a892f56aa9d\"" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=info msg="statefulset \"postgres/test-postgres-cluster\" has been successfully created" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=info msg="waiting for the cluster being ready" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:53:18Z" level=info msg="ADD event has been queued" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T11:53:19Z" level=info msg="creating a new Postgres cluster" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T11:53:19Z" level=warning msg="master is not running, generated master endpoint does not contain any addresses" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:19Z" level=info msg="endpoint \"postgres/ops-postgres-cluster\" has been successfully created" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:20Z" level=info msg="master service \"postgres/ops-postgres-cluster\" has been successfully created" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:20Z" level=info msg="replica service \"postgres/ops-postgres-cluster-repl\" has been successfully created" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:20Z" level=debug msg="team API is disabled" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:20Z" level=debug msg="team API is disabled" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:20Z" level=info msg="users have been initialized" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:20Z" level=info msg="syncing secrets" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:21Z" level=debug msg="created new secret postgres/postgres.ops-postgres-cluster.credentials.postgresql.acid.zalan.do, namespace: postgres, uid: 8e193366-4103-456f-9388-50d48bf56e9a" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:21Z" level=debug msg="created new secret postgres/standby.ops-postgres-cluster.credentials.postgresql.acid.zalan.do, namespace: postgres, uid: 9186b6b7-cd28-4399-8ac1-7445e88659e7" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:21Z" level=debug msg="created new secret postgres/pooler.ops-postgres-cluster.credentials.postgresql.acid.zalan.do, namespace: postgres, uid: 5ca67e82-9b36-4462-8bfd-d5beff1f307d" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:21Z" level=info msg="secrets have been successfully created" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:21Z" level=info msg="pod disruption budget \"postgres/postgres-ops-postgres-cluster-pdb\" has been successfully created" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:21Z" level=debug msg="created new statefulset \"postgres/ops-postgres-cluster\", uid: \"9f027352-c6a8-4a63-ae8f-9065ccedcd75\"" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:21Z" level=info msg="statefulset \"postgres/ops-postgres-cluster\" has been successfully created" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:53:21Z" level=info msg="waiting for the cluster being ready" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:03Z" level=debug msg="Waiting for 3 pods to become ready" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:18Z" level=debug msg="Waiting for 3 pods to become ready" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:54:45Z" level=info msg="pods are ready" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="Create roles" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="users have been successfully created" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="databases have been successfully created" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found pod disruption budget: \"postgres/postgres-ops-postgres-cluster-pdb\" (uid: \"9e69ed2a-1c50-49df-a15a-55532b0f9343\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found statefulset: \"postgres/ops-postgres-cluster\" (uid: \"9f027352-c6a8-4a63-ae8f-9065ccedcd75\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found secret: \"postgres/postgres.ops-postgres-cluster.credentials.postgresql.acid.zalan.do\" (uid: \"8e193366-4103-456f-9388-50d48bf56e9a\") namesapce: postgres" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found secret: \"postgres/standby.ops-postgres-cluster.credentials.postgresql.acid.zalan.do\" (uid: \"9186b6b7-cd28-4399-8ac1-7445e88659e7\") namesapce: postgres" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found secret: \"postgres/pooler.ops-postgres-cluster.credentials.postgresql.acid.zalan.do\" (uid: \"5ca67e82-9b36-4462-8bfd-d5beff1f307d\") namesapce: postgres" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found master endpoint: \"postgres/ops-postgres-cluster\" (uid: \"095d8a9e-6cd0-4eef-a821-b4caed92f3aa\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found master service: \"postgres/ops-postgres-cluster\" (uid: \"1438a4da-569d-4c7e-b965-75e253dea1d1\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found replica service: \"postgres/ops-postgres-cluster-repl\" (uid: \"0c7e0ed1-e6f5-47d9-89b3-167da754d949\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found pod: \"postgres/ops-postgres-cluster-0\" (uid: \"0fd30dfe-f0d6-40b2-b397-bf696d7cf3f6\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found pod: \"postgres/ops-postgres-cluster-1\" (uid: \"ab37f679-fde2-41aa-be8c-00963aa9b3bd\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found pod: \"postgres/ops-postgres-cluster-2\" (uid: \"72d03cb0-721c-4df3-92d9-79ba9930b88f\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found PVC: \"postgres/pgdata-ops-postgres-cluster-0\" (uid: \"4a4a6ad1-9ef7-4f1a-9af2-455afb7ad2a0\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found PVC: \"postgres/pgdata-ops-postgres-cluster-1\" (uid: \"ca7e6e8b-2355-449a-aa82-61c7484b4363\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="found PVC: \"postgres/pgdata-ops-postgres-cluster-2\" (uid: \"0df31b92-cc17-4b91-9e60-72b97e1dfa1e\")" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=debug msg="syncing connection pooler (master, replica) from (false, nil) to (true, true)" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="Installing lookup function" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="install pooler lookup function into database 'postgres'" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=info msg="pooler lookup function installed into postgres" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=warning msg="deployment ops-postgres-cluster-pooler for connection pooler synchronization is not found, create it" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:45Z" level=warning msg="service ops-postgres-cluster-pooler for connection pooler synchronization is not found, create it" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:46Z" level=info msg="Installing lookup function" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:46Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:46Z" level=info msg="install pooler lookup function into database 'postgres'" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:46Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:46Z" level=info msg="pooler lookup function installed into postgres" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:46Z" level=warning msg="deployment ops-postgres-cluster-pooler-repl for connection pooler synchronization is not found, create it" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:46Z" level=warning msg="service ops-postgres-cluster-pooler-repl for connection pooler synchronization is not found, create it" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T11:54:46Z" level=info msg="cluster has been created" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T11:55:06Z" level=info msg="pods are ready" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:06Z" level=info msg="Create roles" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:06Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:06Z" level=info msg="users have been successfully created" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="databases have been successfully created" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found pod disruption budget: \"postgres/postgres-test-postgres-cluster-pdb\" (uid: \"38074c46-7ccf-4617-85f1-9bc8d33fa868\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found statefulset: \"postgres/test-postgres-cluster\" (uid: \"fdc0db37-4cf3-41d4-8bd7-8a892f56aa9d\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found secret: \"postgres/postgres.test-postgres-cluster.credentials.postgresql.acid.zalan.do\" (uid: \"21373633-c85a-4375-948b-3aaa1478217b\") namesapce: postgres" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found secret: \"postgres/standby.test-postgres-cluster.credentials.postgresql.acid.zalan.do\" (uid: \"7ab3868a-6f2f-4950-ad91-8f72ab6e1221\") namesapce: postgres" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found secret: \"postgres/pooler.test-postgres-cluster.credentials.postgresql.acid.zalan.do\" (uid: \"ddfca4c6-8254-4081-a41e-90923923e1ac\") namesapce: postgres" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found master endpoint: \"postgres/test-postgres-cluster\" (uid: \"2dafa2dd-eee4-47fa-acc2-a0155afd06d6\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found master service: \"postgres/test-postgres-cluster\" (uid: \"68fa3ed4-2e22-489b-b402-3ae5e5f630d5\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found replica service: \"postgres/test-postgres-cluster-repl\" (uid: \"13ae5f24-e9fe-4cab-ad2e-9e7ae5bd1e10\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found pod: \"postgres/test-postgres-cluster-0\" (uid: \"63e279e7-7c9b-4174-a9c3-5ebe80af1378\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found pod: \"postgres/test-postgres-cluster-1\" (uid: \"90a4a68d-5ffb-4160-95a2-533653149719\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found pod: \"postgres/test-postgres-cluster-2\" (uid: \"7a2efc9a-592f-4830-8055-3c8f6190bbbb\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found PVC: \"postgres/pgdata-test-postgres-cluster-0\" (uid: \"90a09792-a730-4234-98d4-b9c9f86184a4\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found PVC: \"postgres/pgdata-test-postgres-cluster-1\" (uid: \"08cc0d76-eb19-4268-ae6d-f51cac0d4181\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="found PVC: \"postgres/pgdata-test-postgres-cluster-2\" (uid: \"9bb59493-6821-46f5-b322-51722c7fb122\")" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=debug msg="syncing connection pooler (master, replica) from (false, nil) to (true, true)" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="Installing lookup function" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="install pooler lookup function into database 'postgres'" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=info msg="pooler lookup function installed into postgres" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:11Z" level=warning msg="deployment test-postgres-cluster-pooler for connection pooler synchronization is not found, create it" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:12Z" level=warning msg="service test-postgres-cluster-pooler for connection pooler synchronization is not found, create it" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:12Z" level=info msg="Installing lookup function" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:12Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:12Z" level=info msg="install pooler lookup function into database 'postgres'" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:12Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:12Z" level=info msg="pooler lookup function installed into postgres" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:12Z" level=warning msg="deployment test-postgres-cluster-pooler-repl for connection pooler synchronization is not found, create it" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:12Z" level=warning msg="service test-postgres-cluster-pooler-repl for connection pooler synchronization is not found, create it" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T11:55:12Z" level=info msg="cluster has been created" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T12:23:11Z" level=info msg="SYNC event has been queued" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T12:23:11Z" level=info msg="SYNC event has been queued" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T12:23:11Z" level=info msg="there are 2 clusters running" pkg=controller
time="2023-05-26T12:23:11Z" level=info msg="syncing of the cluster started" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T12:23:11Z" level=debug msg="team API is disabled" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:11Z" level=debug msg="team API is disabled" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:11Z" level=info msg="syncing secrets" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:11Z" level=info msg="syncing of the cluster started" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T12:23:11Z" level=debug msg="team API is disabled" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:11Z" level=debug msg="team API is disabled" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:11Z" level=info msg="syncing secrets" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:12Z" level=debug msg="syncing master service" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:12Z" level=debug msg="syncing master service" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:12Z" level=debug msg="syncing replica service" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:13Z" level=debug msg="syncing replica service" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:13Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:13Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:14Z" level=info msg="volume claims do not require changes" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:14Z" level=debug msg="syncing statefulsets" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:14Z" level=info msg="volume claims do not require changes" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:14Z" level=debug msg="syncing statefulsets" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:14Z" level=debug msg="syncing Patroni config" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:14Z" level=debug msg="making GET http request: http://10.244.5.10:8008/config" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:14Z" level=debug msg="patching Postgres config via Patroni API on pod postgres/ops-postgres-cluster-0 with following options: {\"pg_hba\":[\"local       all         all                     trust\",\"local       replication standby                 md5\",\"hostssl     replication standby   all           md5\",\"hostssl     replication postgres  all           md5\",\"hostssl     all         all       all           md5\",\"hostnossl   all         all       all           reject\"]}" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:14Z" level=debug msg="making PATCH http request: http://10.244.5.10:8008/config" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:15Z" level=debug msg="syncing Patroni config" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:15Z" level=debug msg="making GET http request: http://10.244.4.8:8008/config" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:15Z" level=debug msg="patching Postgres config via Patroni API on pod postgres/test-postgres-cluster-0 with following options: {\"pg_hba\":[\"local       all         all                     trust\",\"local       replication standby                 md5\",\"hostssl     replication standby   all           md5\",\"hostssl     replication postgres  all           md5\",\"hostssl     all         all       all           md5\",\"hostnossl   all         all       all           reject\"]}" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:15Z" level=debug msg="making PATCH http request: http://10.244.4.8:8008/config" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:26Z" level=debug msg="making GET http request: http://10.244.4.10:8008/patroni" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:26Z" level=debug msg="making GET http request: http://10.244.3.8:8008/patroni" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:26Z" level=debug msg="making GET http request: http://10.244.5.10:8008/patroni" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:26Z" level=debug msg="syncing pod disruption budgets" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:26Z" level=debug msg="syncing roles" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:26Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:26Z" level=debug msg="syncing databases" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:27Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:27Z" level=debug msg="syncing prepared databases with schemas" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:27Z" level=debug msg="syncing connection pooler (master, replica) from (true, true) to (true, true)" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:23:27Z" level=debug msg="making GET http request: http://10.244.3.7:8008/patroni" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:27Z" level=debug msg="making GET http request: http://10.244.5.12:8008/patroni" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:27Z" level=debug msg="making GET http request: http://10.244.4.8:8008/patroni" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:27Z" level=debug msg="syncing pod disruption budgets" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:27Z" level=debug msg="syncing roles" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:27Z" level=info msg="cluster has been synced" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T12:23:27Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:27Z" level=debug msg="syncing databases" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:27Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:27Z" level=debug msg="syncing prepared databases with schemas" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:27Z" level=debug msg="syncing connection pooler (master, replica) from (true, true) to (true, true)" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:23:27Z" level=info msg="cluster has been synced" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T12:45:34Z" level=debug msg="new node has been added: /perftest-m3 ()" pkg=controller
time="2023-05-26T12:46:05Z" level=debug msg="new node has been added: /perftest-w4 ()" pkg=controller
time="2023-05-26T12:46:06Z" level=debug msg="new node has been added: /perftest-w5 ()" pkg=controller
time="2023-05-26T12:53:11Z" level=info msg="SYNC event has been queued" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T12:53:11Z" level=info msg="SYNC event has been queued" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T12:53:11Z" level=info msg="there are 2 clusters running" pkg=controller
time="2023-05-26T12:53:11Z" level=info msg="syncing of the cluster started" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T12:53:11Z" level=debug msg="team API is disabled" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:11Z" level=debug msg="team API is disabled" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:11Z" level=info msg="syncing secrets" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:11Z" level=info msg="syncing of the cluster started" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T12:53:11Z" level=debug msg="team API is disabled" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:11Z" level=debug msg="team API is disabled" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:11Z" level=info msg="syncing secrets" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:12Z" level=debug msg="syncing master service" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:12Z" level=debug msg="syncing master service" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:12Z" level=debug msg="syncing replica service" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:13Z" level=debug msg="syncing replica service" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:13Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:13Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:14Z" level=info msg="volume claims do not require changes" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="syncing statefulsets" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=info msg="volume claims do not require changes" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:14Z" level=debug msg="syncing statefulsets" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:14Z" level=debug msg="syncing Patroni config" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="making GET http request: http://10.244.5.10:8008/config" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="making GET http request: http://10.244.4.10:8008/config" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="making GET http request: http://10.244.3.8:8008/config" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="making GET http request: http://10.244.4.10:8008/patroni" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="making GET http request: http://10.244.3.8:8008/patroni" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="making GET http request: http://10.244.5.10:8008/patroni" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="syncing pod disruption budgets" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="syncing roles" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:14Z" level=debug msg="syncing databases" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:15Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:15Z" level=debug msg="syncing prepared databases with schemas" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:15Z" level=debug msg="syncing connection pooler (master, replica) from (true, true) to (true, true)" cluster-name=postgres/ops-postgres-cluster pkg=cluster worker=1
time="2023-05-26T12:53:15Z" level=debug msg="syncing Patroni config" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="making GET http request: http://10.244.4.8:8008/config" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="making GET http request: http://10.244.3.7:8008/config" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="making GET http request: http://10.244.5.12:8008/config" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="making GET http request: http://10.244.3.7:8008/patroni" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="making GET http request: http://10.244.5.12:8008/patroni" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="making GET http request: http://10.244.4.8:8008/patroni" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="syncing pod disruption budgets" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="syncing roles" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="syncing databases" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="syncing prepared databases with schemas" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:15Z" level=debug msg="syncing connection pooler (master, replica) from (true, true) to (true, true)" cluster-name=postgres/test-postgres-cluster pkg=cluster worker=0
time="2023-05-26T12:53:16Z" level=info msg="cluster has been synced" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T12:53:16Z" level=info msg="cluster has been synced" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0

This is the operator log after creation of the db and restart of the operator.

time="2023-05-26T13:16:15Z" level=info msg="Spilo operator v1.10.0\n"
time="2023-05-26T13:16:15Z" level=info msg="Parse role bindings" pkg=controller
time="2023-05-26T13:16:15Z" level=info msg="successfully parsed" pkg=controller
time="2023-05-26T13:16:15Z" level=info msg="Listening to all namespaces" pkg=controller
time="2023-05-26T13:16:15Z" level=info msg="customResourceDefinition \"postgresqls.acid.zalan.do\" is already registered and will only be updated" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="{" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ReadyWaitInterval\": 3000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ReadyWaitTimeout\": 30000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ResyncPeriod\": 1800000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"RepairPeriod\": 300000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableCRDRegistration\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableCRDValidation\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"CRDCategories\": [" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="      \"all\"" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   ]," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ResourceCheckInterval\": 3000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ResourceCheckTimeout\": 600000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodLabelWaitTimeout\": 600000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodDeletionWaitTimeout\": 600000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SpiloRunAsUser\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SpiloRunAsGroup\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SpiloFSGroup\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodPriorityClassName\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ClusterDomain\": \"cluster.local\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SpiloPrivileged\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SpiloAllowPrivilegeEscalation\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"AdditionalPodCapabilities\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ClusterLabels\": {" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="      \"application\": \"spilo\"" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   }," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"InheritedLabels\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"InheritedAnnotations\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"DownscalerAnnotations\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"IgnoredAnnotations\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ClusterNameLabel\": \"cluster-name\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"DeleteAnnotationDateKey\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"DeleteAnnotationNameKey\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodRoleLabel\": \"spilo-role\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodToleration\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"DefaultCPURequest\": \"100m\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"DefaultMemoryRequest\": \"100Mi\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"DefaultCPULimit\": \"1\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"DefaultMemoryLimit\": \"500Mi\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MinCPULimit\": \"250m\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MinMemoryLimit\": \"250Mi\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MaxCPURequest\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MaxMemoryRequest\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodEnvironmentConfigMap\": \"/\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodEnvironmentSecret\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"NodeReadinessLabel\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"NodeReadinessLabelMerge\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ShmVolume\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MaxInstances\": -1," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MinInstances\": -1," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"IgnoreInstanceLimitsAnnotationKey\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SecretNameTemplate\": \"{username}.{cluster}.credentials.{tprkind}.{tprgroup}\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PamRoleName\": \"zalandos\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PamConfiguration\": \"https://info.example.com/oauth2/tokeninfo?access_token= uid realm=/employees\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"TeamsAPIUrl\": \"https://teams.example.com/api/\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"OAuthTokenSecretName\": \"postgres/postgres-operator\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"InfrastructureRolesSecretName\": \"/\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"InfrastructureRoles\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"InfrastructureRolesDefs\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SuperUsername\": \"postgres\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ReplicationUsername\": \"standby\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"AdditionalOwnerRoles\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnablePasswordRotation\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PasswordRotationInterval\": 90," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PasswordRotationUserRetention\": 180," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ScalyrAPIKey\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ScalyrImage\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ScalyrServerURL\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ScalyrCPURequest\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ScalyrMemoryRequest\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ScalyrCPULimit\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ScalyrMemoryLimit\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupSchedule\": \"30 00 * * *\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupDockerImage\": \"registry.opensource.zalan.do/acid/logical-backup:v1.10.0\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupProvider\": \"s3\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupAzureStorageAccountName\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupAzureStorageContainer\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupAzureStorageAccountKey\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupS3Bucket\": \"my-bucket-url\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupS3Region\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupS3Endpoint\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupS3AccessKeyID\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupS3SecretAccessKey\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupS3SSE\": \"AES256\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupS3RetentionTime\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupGoogleApplicationCredentials\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupJobPrefix\": \"logical-backup-\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupCPURequest\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupMemoryRequest\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupCPULimit\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogicalBackupMemoryLimit\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"NumberOfInstances\": 3," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"Schema\": \"pooler\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"User\": \"pooler\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"Image\": \"registry.opensource.zalan.do/acid/pgbouncer:master-27\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"Mode\": \"transaction\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MaxDBConnections\": 100," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ConnectionPoolerDefaultCPURequest\": \"100m\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ConnectionPoolerDefaultMemoryRequest\": \"10Mi\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ConnectionPoolerDefaultCPULimit\": \"500m\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ConnectionPoolerDefaultMemoryLimit\": \"100Mi\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"WatchedNamespace\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"KubernetesUseConfigMaps\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EtcdHost\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"DockerImage\": \"ghcr.io/zalando/spilo-15:3.0-p1\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SidecarImages\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SidecarContainers\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodServiceAccountName\": \"postgres-pod\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodServiceAccountDefinition\": \"{\\\"apiVersion\\\":\\\"v1\\\",\\\"kind\\\":\\\"ServiceAccount\\\",\\\"metadata\\\":{\\\"name\\\":\\\"postgres-pod\\\"}}\"," pkg=controller
time="2023-05-26T13:16:19Z" 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="2023-05-26T13:16:19Z" level=info msg="   \"MasterPodMoveTimeout\": 1200000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"DbHostedZone\": \"db.example.com\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"AWSRegion\": \"eu-central-1\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"WALES3Bucket\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"LogS3Bucket\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"KubeIAMRole\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"WALGSBucket\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"GCPCredentials\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"WALAZStorageAccount\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"AdditionalSecretMount\": \"\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"AdditionalSecretMountPath\": \"/meta/credentials\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableEBSGp3Migration\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableEBSGp3MigrationMaxSize\": 1000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"DebugLogging\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableDBAccess\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableTeamsAPI\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableTeamSuperuser\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"TeamAdminRole\": \"admin\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"RoleDeletionSuffix\": \"_deleted\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableTeamMemberDeprecation\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableAdminRoleForUsers\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnablePostgresTeamCRD\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnablePostgresTeamCRDSuperusers\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableMasterLoadBalancer\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableMasterPoolerLoadBalancer\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableReplicaLoadBalancer\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableReplicaPoolerLoadBalancer\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"CustomServiceAnnotations\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"CustomPodAnnotations\": {" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="      \"cluster-autoscaler.kubernetes.io/safe-to-evict\": \"true\"" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   }," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnablePodAntiAffinity\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodAntiAffinityPreferredDuringScheduling\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodAntiAffinityTopologyKey\": \"kubernetes.io/hostname\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"StorageResizeMode\": \"pvc\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableLoadBalancer\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ExternalTrafficPolicy\": \"Cluster\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MasterDNSNameFormat\": \"{cluster}.{namespace}.{hostedzone}\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MasterLegacyDNSNameFormat\": \"{cluster}.{team}.{hostedzone}\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ReplicaDNSNameFormat\": \"{cluster}-repl.{namespace}.{hostedzone}\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ReplicaLegacyDNSNameFormat\": \"{cluster}-repl.{team}.{hostedzone}\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PDBNameFormat\": \"postgres-{cluster}-pdb\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnablePodDisruptionBudget\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableInitContainers\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableSidecars\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SharePgSocketWithSidecars\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"Workers\": 8," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"APIPort\": 8080," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"RingLogLines\": 100," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ClusterHistoryEntries\": 1000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"TeamAPIRoleConfiguration\": {" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="      \"log_statement\": \"all\"" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   }," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodTerminateGracePeriod\": 300000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PodManagementPolicy\": \"ordered_ready\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableReadinessProbe\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"ProtectedRoles\": [" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="      \"admin\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="      \"cron_admin\"" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   ]," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PostgresSuperuserTeams\": [" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="      \"postgres_superusers\"" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   ]," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"SetMemoryRequestToLimit\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableLazySpiloUpgrade\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableCrossNamespaceSecret\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnablePgVersionEnvVar\": true," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableSpiloWalPathCompat\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnableTeamIdClusternamePrefix\": false," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MajorVersionUpgradeMode\": \"off\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MajorVersionUpgradeTeamAllowList\": null," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"MinimalMajorVersion\": \"11\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"TargetMajorVersion\": \"15\"," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PatroniAPICheckInterval\": 1000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"PatroniAPICheckTimeout\": 5000000000," pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="   \"EnablePatroniFailsafeMode\": false" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="}" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="acquiring initial list of clusters" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="added new cluster: \"postgres/test-postgres-cluster\"" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="added new cluster: \"postgres/ops-postgres-cluster\"" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="SYNC event has been queued" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T13:16:19Z" level=info msg="SYNC event has been queued" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T13:16:19Z" level=info msg="there are 2 clusters running" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="started working in background" pkg=controller
time="2023-05-26T13:16:19Z" level=info msg="listening on :8080" pkg=apiserver
time="2023-05-26T13:16:19Z" level=info msg="ADD event has been queued" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T13:16:19Z" level=info msg="ADD event has been queued" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T13:16:19Z" level=info msg="syncing of the cluster started" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T13:16:19Z" level=debug msg="team API is disabled" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:19Z" level=debug msg="team API is disabled" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:19Z" level=info msg="syncing secrets" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:19Z" level=info msg="syncing of the cluster started" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T13:16:19Z" level=debug msg="team API is disabled" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:19Z" level=debug msg="team API is disabled" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:19Z" level=info msg="syncing secrets" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:19Z" level=debug msg="new node has been added: /perftest-w1 ()" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="new node has been added: /perftest-w2 ()" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="new node has been added: /perftest-w5 ()" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="new node has been added: /perftest-m1 ()" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="new node has been added: /perftest-m3 ()" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="new node has been added: /perftest-w6 ()" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="new node has been added: /perftest-w4 ()" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="new node has been added: /perftest-m2 ()" pkg=controller
time="2023-05-26T13:16:19Z" level=debug msg="new node has been added: /perftest-w3 ()" pkg=controller
time="2023-05-26T13:16:20Z" level=debug msg="syncing master service" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:20Z" level=debug msg="syncing master service" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:21Z" level=debug msg="syncing replica service" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:21Z" level=debug msg="syncing replica service" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:22Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:22Z" level=debug msg="syncing volumes using \"pvc\" storage resize mode" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:22Z" level=info msg="volume claims do not require changes" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:22Z" level=debug msg="syncing statefulsets" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:22Z" level=info msg="volume claims do not require changes" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:22Z" level=debug msg="syncing statefulsets" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing Patroni config" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.4.8:8008/config" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.3.7:8008/config" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.5.12:8008/config" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.3.7:8008/patroni" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.5.12:8008/patroni" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.4.8:8008/patroni" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing pod disruption budgets" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing roles" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing databases" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing prepared databases with schemas" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing connection pooler (master, replica) from (true, true) to (true, true)" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="Installing lookup function" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="install pooler lookup function into database 'testqs@testqs.DataExtractionTraining'" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing Patroni config" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.5.10:8008/config" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.4.10:8008/config" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.3.8:8008/config" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="pooler lookup function installed into testqs@testqs.DataExtractionTraining" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="install pooler lookup function into database 'testqs@testqs'" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.4.10:8008/patroni" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.3.8:8008/patroni" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="making GET http request: http://10.244.5.10:8008/patroni" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing pod disruption budgets" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing roles" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="pooler lookup function installed into testqs@testqs" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="install pooler lookup function into database 'postgres'" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing databases" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="pooler lookup function installed into postgres" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="install pooler lookup function into database 'wfl_testqs@testqs'" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing prepared databases with schemas" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="syncing connection pooler (master, replica) from (true, true) to (true, true)" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="Installing lookup function" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="pooler lookup function installed into wfl_testqs@testqs" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="Installing lookup function" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="install pooler lookup function into database 'postgres'" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:23Z" level=info msg="install pooler lookup function into database 'testqs@testqs.DataExtractionTraining'" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into postgres" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="install pooler lookup function into database 'keycloak'" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into testqs@testqs.DataExtractionTraining" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="install pooler lookup function into database 'testqs@testqs'" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into keycloak" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into testqs@testqs" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="install pooler lookup function into database 'postgres'" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="Installing lookup function" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="install pooler lookup function into database 'postgres'" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into postgres" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="install pooler lookup function into database 'wfl_testqs@testqs'" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into postgres" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="install pooler lookup function into database 'keycloak'" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=debug msg="closing database connection" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into wfl_testqs@testqs" cluster-name=postgres/test-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=debug msg="closing database connection" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into keycloak" cluster-name=postgres/ops-postgres-cluster pkg=cluster
time="2023-05-26T13:16:24Z" level=info msg="cluster has been synced" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T13:16:25Z" level=info msg="received add event for already existing Postgres cluster" cluster-name=postgres/test-postgres-cluster pkg=controller worker=0
time="2023-05-26T13:16:25Z" level=info msg="cluster has been synced" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1
time="2023-05-26T13:16:25Z" level=info msg="received add event for already existing Postgres cluster" cluster-name=postgres/ops-postgres-cluster pkg=controller worker=1

The relevant events after the restart seem to be.

    Line 245: time="2023-05-26T13:16:23Z" level=info msg="install pooler lookup function into database 'testqs@testqs.DataExtractionTraining'" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 251: time="2023-05-26T13:16:23Z" level=info msg="pooler lookup function installed into testqs@testqs.DataExtractionTraining" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 252: time="2023-05-26T13:16:23Z" level=info msg="install pooler lookup function into database 'testqs@testqs'" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 259: time="2023-05-26T13:16:23Z" level=info msg="pooler lookup function installed into testqs@testqs" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 265: time="2023-05-26T13:16:23Z" level=info msg="install pooler lookup function into database 'wfl_testqs@testqs'" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 271: time="2023-05-26T13:16:23Z" level=info msg="pooler lookup function installed into wfl_testqs@testqs" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 276: time="2023-05-26T13:16:23Z" level=info msg="install pooler lookup function into database 'testqs@testqs.DataExtractionTraining'" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 281: time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into testqs@testqs.DataExtractionTraining" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 282: time="2023-05-26T13:16:24Z" level=info msg="install pooler lookup function into database 'testqs@testqs'" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 286: time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into testqs@testqs" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 293: time="2023-05-26T13:16:24Z" level=info msg="install pooler lookup function into database 'wfl_testqs@testqs'" cluster-name=postgres/test-postgres-cluster pkg=cluster
    Line 298: time="2023-05-26T13:16:24Z" level=info msg="pooler lookup function installed into wfl_testqs@testqs" cluster-name=postgres/test-postgres-cluster pkg=cluster

I hope this helps. I will try to investigate further, but I don't really know where to look.

[balait4]

Any update on this issue? Even with latest operator version we are facing this issue and after restarting the operator works fine.