Merge pull request #42480 from kargakis/update-log-verbosity-deployments

Automatic merge from submit-queue (batch tested with PRs 42456, 42457, 42414, 42480, 42370)

controller: reduce log verbosity for deployments

Fixes https://github.com/kubernetes/kubernetes/issues/41187

Labeling as a bug fix since I think excessive logging should be considered as a bug.

@kubernetes/sig-apps-bugs

pkg/controller/deployment/deployment_controller.go

@@ -334,6 +334,7 @@ func (dc *DeploymentController) deletePod(obj interface{}) {
 			return
 		}
 	}
+	glog.V(4).Infof("Pod %s deleted.", pod.Name)
 	if d := dc.getDeploymentForPod(pod); d != nil && d.Spec.Strategy.Type == extensions.RecreateDeploymentStrategyType {
 		podList, err := dc.listPods(d)
 		if err == nil && len(podList.Items) == 0 {
@@ -480,7 +481,7 @@ func (dc *DeploymentController) syncDeployment(key string) error {
 	}
 	deployment, err := dc.dLister.Deployments(namespace).Get(name)
 	if errors.IsNotFound(err) {
-		glog.Infof("Deployment has been deleted %v", key)
+		glog.V(2).Infof("Deployment %v has been deleted", key)
 		return nil
 	}
 	if err != nil {

pkg/controller/deployment/progress.go

@@ -64,15 +64,11 @@ func (dc *DeploymentController) hasFailed(d *extensions.Deployment) (bool, error
 
 	// If the deployment is complete or it is progressing, there is no need to check if it
 	// has timed out.
-	// TODO: Switch to a much higher verbosity level
-	glog.V(2).Infof("Checking if deployment %q is complete or progressing", d.Name)
 	if util.DeploymentComplete(d, &newStatus) || util.DeploymentProgressing(d, &newStatus) {
 		return false, nil
 	}
 
 	// Check if the deployment has timed out.
-	// TODO: Switch to a much higher verbosity level
-	glog.V(2).Infof("Checking if deployment %q has timed out", d.Name)
 	return util.DeploymentTimedOut(d, &newStatus), nil
 }
 
@@ -231,11 +227,11 @@ func (dc *DeploymentController) requeueStuckDeployment(d *extensions.Deployment,
 	// Make it ratelimited so we stay on the safe side, eventually the Deployment should
 	// transition either to a Complete or to a TimedOut condition.
 	if after < time.Second {
-		glog.V(2).Infof("Queueing up deployment %q for a progress check now", d.Name)
+		glog.V(4).Infof("Queueing up deployment %q for a progress check now", d.Name)
 		dc.enqueueRateLimited(d)
 		return time.Duration(0)
 	}
-	glog.V(2).Infof("Queueing up deployment %q for a progress check after %ds", d.Name, int(after.Seconds()))
+	glog.V(4).Infof("Queueing up deployment %q for a progress check after %ds", d.Name, int(after.Seconds()))
 	dc.enqueueAfter(d, after)
 	return after
 }

pkg/controller/deployment/rollback.go

@@ -66,7 +66,7 @@ func (dc *DeploymentController) rollback(deployment *extensions.Deployment, toRe
 
 func (dc *DeploymentController) rollbackToTemplate(deployment *extensions.Deployment, rs *extensions.ReplicaSet) (d *extensions.Deployment, performedRollback bool, err error) {
 	if !deploymentutil.EqualIgnoreHash(deployment.Spec.Template, rs.Spec.Template) {
-		glog.Infof("Rolling back deployment %s to template spec %+v", deployment.Name, rs.Spec.Template.Spec)
+		glog.V(4).Infof("Rolling back deployment %q to template spec %+v", deployment.Name, rs.Spec.Template.Spec)
 		deploymentutil.SetFromReplicaSetTemplate(deployment, rs.Spec.Template)
 		// set RS (the old RS we'll rolling back to) annotations back to the deployment;
 		// otherwise, the deployment's current annotations (should be the same as current new RS) will be copied to the RS after the rollback.

pkg/controller/deployment/sync.go

@@ -558,7 +558,7 @@ func (dc *DeploymentController) cleanupDeployment(oldRSs []*extensions.ReplicaSe
 	}
 
 	sort.Sort(controller.ReplicaSetsByCreationTimestamp(cleanableRSes))
-	glog.V(2).Infof("Looking to cleanup old replica sets for deployment %q", deployment.Name)
+	glog.V(4).Infof("Looking to cleanup old replica sets for deployment %q", deployment.Name)
 
 	var errList []error
 	// TODO: This should be parallelized.
@@ -568,7 +568,7 @@ func (dc *DeploymentController) cleanupDeployment(oldRSs []*extensions.ReplicaSe
 		if rs.Status.Replicas != 0 || *(rs.Spec.Replicas) != 0 || rs.Generation > rs.Status.ObservedGeneration || rs.DeletionTimestamp != nil {
 			continue
 		}
-		glog.V(2).Infof("Trying to cleanup replica set %q for deployment %q", rs.Name, deployment.Name)
+		glog.V(4).Infof("Trying to cleanup replica set %q for deployment %q", rs.Name, deployment.Name)
 		if err := dc.client.Extensions().ReplicaSets(rs.Namespace).Delete(rs.Name, nil); err != nil && !errors.IsNotFound(err) {
 			glog.V(2).Infof("Failed deleting old replica set %v for deployment %v: %v", rs.Name, deployment.Name, err)
 			errList = append(errList, err)

pkg/controller/deployment/util/deployment_util.go

@@ -388,8 +388,7 @@ func getIntFromAnnotation(rs *extensions.ReplicaSet, annotationKey string) (int3
 	}
 	intValue, err := strconv.Atoi(annotationValue)
 	if err != nil {
-		glog.Warningf("Cannot convert the value %q with annotation key %q for the replica set %q",
-			annotationValue, annotationKey, rs.Name)
+		glog.V(2).Infof("Cannot convert the value %q with annotation key %q for the replica set %q", annotationValue, annotationKey, rs.Name)
 		return int32(0), false
 	}
 	return int32(intValue), true
@@ -854,8 +853,7 @@ func DeploymentTimedOut(deployment *extensions.Deployment, newStatus *extensions
 	delta := time.Duration(*deployment.Spec.ProgressDeadlineSeconds) * time.Second
 	timedOut := from.Add(delta).Before(now)
 
-	// TODO: Switch to a much higher verbosity level
-	glog.V(2).Infof("Deployment %q timed out (%t) [last progress check: %v - now: %v]", deployment.Name, timedOut, from, now)
+	glog.V(4).Infof("Deployment %q timed out (%t) [last progress check: %v - now: %v]", deployment.Name, timedOut, from, now)
 	return timedOut
 }