Delayed cluster creation due to missing pod_environment_secret and wrong configuration

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

• Which image of the operator are you using?
  1.8.2
• Where do you run it - cloud or metal? Kubernetes or OpenShift? [AWS K8s | GCP ... | Bare Metal K8s]
  Kubernetes
• Are you running Postgres Operator in production? [yes | no]
  yes
• Type of issue? [Bug report, question, feature request, etc.]
  Bug report

Hello,

we experienced a delayed Postgres cluster creation by the Operator lately. It took the Operator about 10 minutes to create the actual statefulset for the cluster and proceed with it's work. There was no status in the CRD shown and the logs showed this:

time="2022-07-06T08:04:02Z" level=debug msg="added new cluster: \"default/postgres-test\"" pkg=controller
time="2022-07-06T08:04:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:04:02Z" level=info msg="ADD event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:04:02Z" level=info msg="syncing of the cluster started" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:04:02Z" level=debug msg="team API is disabled" cluster-name=default/postgres-test pkg=cluster
time="2022-07-06T08:04:02Z" level=info msg="syncing secrets" cluster-name=default/postgres-test pkg=cluster
time="2022-07-06T08:04:07Z" level=debug msg="syncing master service" cluster-name=default/postgres-test pkg=cluster
time="2022-07-06T08:04:09Z" level=debug msg="syncing replica service" cluster-name=default/postgres-test pkg=cluster
time="2022-07-06T08:04:11Z" level=debug msg="syncing volumes using \"off\" storage resize mode" cluster-name=default/postgres-test pkg=cluster
time="2022-07-06T08:04:11Z" level=info msg="Storage resize is disabled (storage_resize_mode is off). Skipping volume sync." cluster-name=default/postgres-test pkg=cluster
time="2022-07-06T08:04:11Z" level=debug msg="syncing statefulsets" cluster-name=default/postgres-test pkg=cluster
time="2022-07-06T08:04:11Z" level=info msg="cluster's statefulset does not exist" cluster-name=default/postgres-test pkg=cluster
time="2022-07-06T08:04:32Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:05:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:05:32Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:06:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:06:32Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:07:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:07:32Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:08:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:08:32Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:09:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:09:32Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:10:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:10:32Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:11:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:11:32Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:12:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:12:32Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:13:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:13:32Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:14:02Z" level=info msg="SYNC event has been queued" cluster-name=default/postgres-test pkg=controller worker=3
time="2022-07-06T08:14:09Z" level=warning msg="could not read Secret PodEnvironmentSecretName: still failing after 200 retries: secrets \"pod-config\" not found" cluster-name=default/postgres-test pkg=cluster
time="2022-07-06T08:14:10Z" level=debug msg="created new statefulset \"default/postgres-test\", uid: \"ad39a93d-7e52-4a67-9298-2bb8340ef18f\"" cluster-name=default/postgres-test pkg=cluster
...

As you can see, he added the newly created cluster to the sync queue over and over again but didn't start to build it. The second last line in the log brought some light in the issue. He searched for the pod-config secret in the default namespace which he wasn't able to find. This message we would have wished in the beginning. But more problematic to us is the fact, that he proceeded with the Cluster creation then after the 200 retries. This could (and has in this case) lead to a misformed configuration you probably might get aware of when you already have some trouble with a running cluster.

In my opinion, this is a misbehavior of the Operator and I would suggest to let the operator stop the cluster creation at this point and print out the error / warning as the reason.

What are your thoughts on this?

Kind regards.
Philip

Start by tracing the sync queue in pkg/controller and the secret and StatefulSet handling in pkg/cluster, focusing on PodEnvironmentSecretName and the missing pod-config Secret. Reproduce a cluster with that Secret absent and observe the retry behavior. Done means the operator clearly reports the missing Secret and does not create a StatefulSet with incomplete configuration.