K8SPS-172 add logs to operators (#950)

* K8SPS-172 add logs to operators

* fix

* change machine-type for GKE cluster

* Update pkg/controller/psbackup/controller.go

Co-authored-by: Andrii Dema <a.dema@jazzserve.com>

---------

Co-authored-by: Viacheslav Sarzhan <slava.sarzhan@percona.com>
Co-authored-by: Andrii Dema <a.dema@jazzserve.com>

Author: 3 people

Jenkinsfile

@@ -13,7 +13,7 @@ void createCluster(String CLUSTER_SUFFIX) {
                 gcloud auth activate-service-account --key-file $CLIENT_SECRET_FILE
                 gcloud config set project $GCP_PROJECT
                 gcloud container clusters list --filter $CLUSTER_NAME-${CLUSTER_SUFFIX} --zone $region --format='csv[no-heading](name)' | xargs gcloud container clusters delete --zone $region --quiet || true
-                gcloud container clusters create --zone $region $CLUSTER_NAME-${CLUSTER_SUFFIX} --cluster-version=1.30 --machine-type=n1-standard-4 --preemptible --disk-size 30 --num-nodes=\$NODES_NUM --network=jenkins-vpc --subnetwork=jenkins-${CLUSTER_SUFFIX} --no-enable-autoupgrade --cluster-ipv4-cidr=/21 --labels delete-cluster-after-hours=6 --enable-ip-alias && \
+                gcloud container clusters create --zone $region $CLUSTER_NAME-${CLUSTER_SUFFIX} --cluster-version=1.30 --machine-type=c2d-standard-4 --preemptible --disk-size 30 --num-nodes=\$NODES_NUM --network=jenkins-vpc --subnetwork=jenkins-${CLUSTER_SUFFIX} --no-enable-autoupgrade --cluster-ipv4-cidr=/21 --labels delete-cluster-after-hours=6 --enable-ip-alias && \
                 kubectl create clusterrolebinding cluster-admin-binding --clusterrole cluster-admin --user jenkins@"$GCP_PROJECT".iam.gserviceaccount.com || ret_val=\$?
                 if [ \${ret_val} -eq 0 ]; then break; fi
                 ret_num=\$((ret_num + 1))

pkg/controller/ps/controller.go

@@ -127,6 +127,7 @@ func (r *PerconaServerMySQLReconciler) Reconcile(
 	}
 
 	if cr.ObjectMeta.DeletionTimestamp != nil {
+		log.Info("CR marked for deletion, applying finalizers", "name", cr.Name)
 		if err := r.applyFinalizers(ctx, cr); err != nil {
 			return ctrl.Result{}, errors.Wrap(err, "apply finalizers")
 		}
@@ -231,17 +232,18 @@ func (r *PerconaServerMySQLReconciler) deleteMySQLPods(ctx context.Context, cr *
 			return errors.Wrap(err, "get cluster status")
 		}
 
-		log.Info("Got primary", "primary", clusterStatus.DefaultReplicaSet.Primary)
+		log.Info("Cluster primary detected", "primary", clusterStatus.DefaultReplicaSet.Primary)
 
 		if !strings.HasPrefix(clusterStatus.DefaultReplicaSet.Primary, mysql.PodFQDN(cr, &firstPod)) {
 			log.Info("Primary is not pod-0", "primary", clusterStatus.DefaultReplicaSet.Primary)
 
 			log.Info("Ensuring pod-0 is the primary")
-			err := mysh.SetPrimaryInstanceWithExec(ctx, cr.InnoDBClusterName(), mysql.PodFQDN(cr, &firstPod))
+			podFQDN := mysql.PodFQDN(cr, &firstPod)
+			err := mysh.SetPrimaryInstanceWithExec(ctx, cr.InnoDBClusterName(), podFQDN)
 			if err != nil {
 				return errors.Wrap(err, "set primary instance")
 			}
-
+			log.Info("Setting primary instance", "pod", podFQDN)
 			return psrestore.ErrWaitingTermination
 		}
 
@@ -284,15 +286,16 @@ func (r *PerconaServerMySQLReconciler) deleteMySQLPods(ctx context.Context, cr *
 	}
 
 	if sts.Spec.Replicas == nil || *sts.Spec.Replicas != 1 {
+		log.Info("Downscaling StatefulSet to 1 replica", "sts", sts.Name)
 		dscaleTo := int32(1)
 		sts.Spec.Replicas = &dscaleTo
 		err = r.Client.Update(ctx, sts)
 		if err != nil {
 			return errors.Wrap(err, "downscale StatefulSet")
 		}
-		log.Info("Statefulset downscaled", "sts", sts)
+		log.Info("StatefulSet downscaled", "sts", sts.Name)
 	}
-
+	log.Info("MySQL pod deletion finished. Waiting for termination")
 	return psrestore.ErrWaitingTermination
 }
 
@@ -317,6 +320,7 @@ func (r *PerconaServerMySQLReconciler) deleteCerts(ctx context.Context, cr *apiv
 		if err != nil {
 			return errors.Wrapf(err, "delete issuer %s", issuerName)
 		}
+		log.Info("Issuer deleted", "name", issuerName)
 	}
 
 	certs := []string{
@@ -338,6 +342,7 @@ func (r *PerconaServerMySQLReconciler) deleteCerts(ctx context.Context, cr *apiv
 		if err != nil {
 			return errors.Wrapf(err, "delete certificate %s", certName)
 		}
+		log.Info("Certificate deleted", "name", certName)
 	}
 
 	secretNames := []string{
@@ -359,15 +364,15 @@ func (r *PerconaServerMySQLReconciler) deleteCerts(ctx context.Context, cr *apiv
 		if err != nil {
 			return errors.Wrapf(err, "delete secret %s", secretName)
 		}
+		log.Info("Secret deleted", "name", secretName)
 	}
-
+	log.V(1).Info("Finished deletion of SSL-related resources")
 	return nil
 }
 
 func (r *PerconaServerMySQLReconciler) deleteMySQLPvc(ctx context.Context, cr *apiv1alpha1.PerconaServerMySQL) error {
 	log := logf.FromContext(ctx)
-
-	log.Info(fmt.Sprintf("Applying %s finalizer", naming.FinalizerDeleteMySQLPvc))
+	log.Info("Starting PVC and secret deletion for MySQL cluster", "cluster", cr.Name, "finilizer", naming.FinalizerDeleteMySQLPvc)
 
 	exposer := mysql.Exposer(*cr)
 
@@ -560,6 +565,7 @@ func (r *PerconaServerMySQLReconciler) reconcileDatabase(ctx context.Context, cr
 	}
 
 	if cr.Spec.UpdateStrategy == apiv1alpha1.SmartUpdateStatefulSetStrategyType {
+		log.Info("Performing smart update for StatefulSet")
 		return r.smartUpdate(ctx, sts, cr)
 	}
 
@@ -671,10 +677,12 @@ func (r *PerconaServerMySQLReconciler) reconcileMySQLAutoConfig(ctx context.Cont
 
 	// for single-node clusters, we need to set read_only=0 if orchestrator is disabled
 	if setWriteMode {
+		log.Info("Single-node write mode detected, setting read_only=0")
 		config = "\nsuper_read_only=0\nread_only=0"
 	}
 
 	if memory != nil {
+		log.V(1).Info("Generating auto-tune config based on memory", "memory", memory.String())
 		autotuneParams, err := mysql.GetAutoTuneParams(cr, memory)
 		if err != nil {
 			return err
@@ -800,6 +808,7 @@ func (r *PerconaServerMySQLReconciler) reconcileOrchestrator(ctx context.Context
 }
 
 func (r *PerconaServerMySQLReconciler) reconcileOrchestratorServices(ctx context.Context, cr *apiv1alpha1.PerconaServerMySQL) error {
+	log := logf.FromContext(ctx)
 	if err := k8s.EnsureService(ctx, r.Client, cr, orchestrator.Service(cr), r.Scheme, true); err != nil {
 		return errors.Wrap(err, "reconcile Service")
 	}
@@ -808,7 +817,7 @@ func (r *PerconaServerMySQLReconciler) reconcileOrchestratorServices(ctx context
 	if err := r.reconcileServicePerPod(ctx, cr, &exposer); err != nil {
 		return errors.Wrap(err, "reconcile service per pod")
 	}
-
+	log.Info("Finished reconciling orchestrator services")
 	return nil
 }
 
@@ -945,7 +954,7 @@ func (r *PerconaServerMySQLReconciler) reconcileReplication(ctx context.Context,
 		return errors.Wrap(err, "get cluster primary")
 	}
 	if primary.Alias == "" {
-		log.Info("mysql is not ready, orchestrator cluster primary alias is empty. skip")
+		log.Info("Mysql is not ready, orchestrator cluster primary alias is empty. skip")
 		return nil
 	}
 
@@ -963,6 +972,7 @@ func (r *PerconaServerMySQLReconciler) reconcileReplication(ctx context.Context,
 
 	// In the case of a cluster downscale, we need to forget replicas that are not part of the cluster
 	if len(clusterInstances) > int(cr.MySQLSpec().Size) {
+		log.Info("Detected possible downscale, checking for replicas to forget")
 		mysqlPods, err := k8s.PodsByLabels(ctx, r.Client, mysql.MatchLabels(cr), cr.Namespace)
 		if err != nil {
 			return errors.Wrap(err, "get mysql pods")
@@ -1008,7 +1018,7 @@ func (r *PerconaServerMySQLReconciler) reconcileBootstrapStatus(ctx context.Cont
 	log := logf.FromContext(ctx)
 
 	if cr.Status.MySQL.Ready == 0 || cr.Status.MySQL.Ready != cr.Spec.MySQL.Size {
-		log.V(1).Info("Waiting for MySQL pods to be ready")
+		log.V(1).Info("Waiting for all MySQL pods to be ready", "ready", cr.Status.MySQL.Ready, "expected", cr.Spec.MySQL.Size)
 		return nil
 	}
 
@@ -1380,6 +1390,7 @@ func (r *PerconaServerMySQLReconciler) cleanupOutdated(ctx context.Context, cr *
 }
 
 func (r *PerconaServerMySQLReconciler) getPrimaryFromOrchestrator(ctx context.Context, cr *apiv1alpha1.PerconaServerMySQL) (*orchestrator.Instance, error) {
+	log := logf.FromContext(ctx)
 	pod, err := getReadyOrcPod(ctx, r.Client, cr)
 	if err != nil {
 		return nil, err
@@ -1391,6 +1402,7 @@ func (r *PerconaServerMySQLReconciler) getPrimaryFromOrchestrator(ctx context.Co
 
 	if primary.Key.Hostname == "" {
 		primary.Key.Hostname = fmt.Sprintf("%s.%s.%s", primary.Alias, mysql.ServiceName(cr), cr.Namespace)
+		log.V(1).Info("Primary hostname was empty, constructed FQDN", "hostname", primary.Key.Hostname)
 	}
 
 	return primary, nil

pkg/controller/ps/status.go

@@ -192,6 +192,7 @@ func (r *PerconaServerMySQLReconciler) reconcileCRStatus(ctx context.Context, cr
 	}
 
 	if !loadBalancersReady {
+		log.Info("Not all load balancers are ready, setting state to initializing")
 		cr.Status.State = apiv1alpha1.StateInitializing
 	}
 
@@ -228,6 +229,7 @@ func (r *PerconaServerMySQLReconciler) reconcileCRStatus(ctx context.Context, cr
 func (r *PerconaServerMySQLReconciler) isGRReady(ctx context.Context, cr *apiv1alpha1.PerconaServerMySQL) (bool, error) {
 	log := logf.FromContext(ctx).WithName("groupReplicationStatus")
 	if cr.Status.MySQL.Ready != cr.Spec.MySQL.Size {
+		log.Info("Not all MySQL pods are ready", "ready", cr.Status.MySQL.Ready, "expected", cr.Spec.MySQL.Size)
 		return false, nil
 	}
 

pkg/controller/psbackup/controller.go

@@ -107,7 +107,7 @@ func (r *PerconaServerMySQLBackupReconciler) Reconcile(ctx context.Context, req
 			return r.Client.Status().Update(ctx, cr)
 		})
 		if err != nil {
-			log.Error(err, "failed to update status")
+			log.Error(err, "Failed to update backup status")
 		}
 	}()
 
@@ -214,6 +214,7 @@ func (r *PerconaServerMySQLBackupReconciler) Reconcile(ctx context.Context, req
 }
 
 func (r *PerconaServerMySQLBackupReconciler) isBackupJobRunning(ctx context.Context, job *batchv1.Job) (bool, error) {
+	log := logf.FromContext(ctx)
 	if len(job.Spec.Template.Spec.Containers) == 0 {
 		return false, nil
 	}
@@ -236,6 +237,7 @@ func (r *PerconaServerMySQLBackupReconciler) isBackupJobRunning(ctx context.Cont
 	}
 
 	if cfg == nil || cfg.Destination != destination {
+		log.Info("Running backup destination does not match expected or config is nil", "expected destination", destination)
 		return false, nil
 	}