OCPBUGS-23514: Better a message upon long CO updating

When it takes too long (90m+ for machine-config and 30m+ for
others) to upgrade a cluster operator, clusterversion shows
a message with the indication that the upgrade might hit
some issue.

This will cover the case in the related OCPBUGS-23538: for some
reason, the pod under the deployment that manages the CO hit
CrashLoopBackOff. Deployment controller does not give useful
conditions in this situation [1]. Otherwise, checkDeploymentHealth [2]
would detect it.

Instead of CVO's figuring out the underlying pod's
CrashLoopBackOff which might be better to be implemented by
deployment controller, it is expected that our cluster admin
starts to dig into the cluster when such a message pops up.

For now, we just modify the condition's message. We could propagate
Fail=True in case such requirements are collected from customers.

[1]. kubernetes/kubernetes#106054

[2]. https://github.com/openshift/cluster-version-operator/blob/08c0459df5096e9f16fad3af2831b62d06d415ee/lib/resourcebuilder/apps.go#L79-L136

Author: hongkailiu

pkg/cvo/status.go

@@ -555,6 +555,14 @@ func convertErrorToProgressing(now time.Time, statusFailure error) (reason strin
 	case payload.UpdateEffectReport:
 		return uErr.Reason, uErr.Error(), false
 	case payload.UpdateEffectNone:
+		m := time.Duration(30)
+		// It takes longer to upgrade MCO
+		if uErr.Name == "machine-config" {
+			m = 3 * m
+		}
+		if !payload.COUpdateStartTimesGet(uErr.Name).IsZero() && payload.COUpdateStartTimesGet(uErr.Name).Before(now.Add(-(m * time.Minute))) {
+			return uErr.Reason, fmt.Sprintf("waiting on %s over %d minutes which is longer than expected", uErr.Name, m), true
+		}
 		return uErr.Reason, fmt.Sprintf("waiting on %s", uErr.Name), true
 	case payload.UpdateEffectFail:
 		return "", "", false

pkg/cvo/status_test.go

@@ -5,6 +5,7 @@ import (
 	"fmt"
 	"reflect"
 	"testing"
+	"time"
 
 	"github.com/google/go-cmp/cmp"
 	"github.com/google/go-cmp/cmp/cmpopts"
@@ -358,12 +359,22 @@ func TestUpdateClusterVersionStatus_FilteringMultipleErrorsForFailingCondition(t
 	type args struct {
 		syncWorkerStatus *SyncWorkerStatus
 	}
+	payload.COUpdateStartTimesEnsure("co-not-timeout")
+	payload.COUpdateStartTimesAt("co-timeout", time.Now().Add(-60*time.Minute))
+	payload.COUpdateStartTimesAt("machine-config", time.Now().Add(-60*time.Minute))
+	defer func() {
+		payload.COUpdateStartTimesRemove("co-not-timeout")
+		payload.COUpdateStartTimesRemove("co-timeout")
+		payload.COUpdateStartTimesRemove("machine-config")
+	}()
+
 	tests := []struct {
 		name                                             string
 		args                                             args
 		shouldModifyWhenNotReconcilingAndHistoryNotEmpty bool
 		expectedConditionNotModified                     *configv1.ClusterOperatorStatusCondition
 		expectedConditionModified                        *configv1.ClusterOperatorStatusCondition
+		expectedProgressingCondition                     *configv1.ClusterOperatorStatusCondition
 	}{
 		{
 			name: "no errors are present",
@@ -394,10 +405,74 @@ func TestUpdateClusterVersionStatus_FilteringMultipleErrorsForFailingCondition(t
 			name: "single UpdateEffectNone error",
 			args: args{
 				syncWorkerStatus: &SyncWorkerStatus{
+					Actual: configv1.Release{Version: "1.2.3"},
+					Failure: &payload.UpdateError{
+						UpdateEffect: payload.UpdateEffectNone,
+						Reason:       "ClusterOperatorUpdating",
+						Message:      "Cluster operator A is updating",
+						Name:         "co-not-timeout",
+					},
+				},
+			},
+			expectedConditionNotModified: &configv1.ClusterOperatorStatusCondition{
+				Type:    ClusterStatusFailing,
+				Status:  configv1.ConditionTrue,
+				Reason:  "ClusterOperatorUpdating",
+				Message: "Cluster operator A is updating",
+			},
+			shouldModifyWhenNotReconcilingAndHistoryNotEmpty: true,
+			expectedConditionModified: &configv1.ClusterOperatorStatusCondition{
+				Type:   ClusterStatusFailing,
+				Status: configv1.ConditionFalse,
+			},
+			expectedProgressingCondition: &configv1.ClusterOperatorStatusCondition{
+				Type:    configv1.OperatorProgressing,
+				Status:  configv1.ConditionTrue,
+				Reason:  "ClusterOperatorUpdating",
+				Message: "Working towards 1.2.3: waiting on co-not-timeout",
+			},
+		},
+		{
+			name: "single UpdateEffectNone error and timeout",
+			args: args{
+				syncWorkerStatus: &SyncWorkerStatus{
+					Actual: configv1.Release{Version: "1.2.3"},
+					Failure: &payload.UpdateError{
+						UpdateEffect: payload.UpdateEffectNone,
+						Reason:       "ClusterOperatorUpdating",
+						Message:      "Cluster operator A is updating",
+						Name:         "co-timeout",
+					},
+				},
+			},
+			expectedConditionNotModified: &configv1.ClusterOperatorStatusCondition{
+				Type:    ClusterStatusFailing,
+				Status:  configv1.ConditionTrue,
+				Reason:  "ClusterOperatorUpdating",
+				Message: "Cluster operator A is updating",
+			},
+			shouldModifyWhenNotReconcilingAndHistoryNotEmpty: true,
+			expectedConditionModified: &configv1.ClusterOperatorStatusCondition{
+				Type:   ClusterStatusFailing,
+				Status: configv1.ConditionFalse,
+			},
+			expectedProgressingCondition: &configv1.ClusterOperatorStatusCondition{
+				Type:    configv1.OperatorProgressing,
+				Status:  configv1.ConditionTrue,
+				Reason:  "ClusterOperatorUpdating",
+				Message: "Working towards 1.2.3: waiting on co-timeout over 30 minutes which is longer than expected",
+			},
+		},
+		{
+			name: "single UpdateEffectNone error and machine-config",
+			args: args{
+				syncWorkerStatus: &SyncWorkerStatus{
+					Actual: configv1.Release{Version: "1.2.3"},
 					Failure: &payload.UpdateError{
 						UpdateEffect: payload.UpdateEffectNone,
 						Reason:       "ClusterOperatorUpdating",
 						Message:      "Cluster operator A is updating",
+						Name:         "machine-config",
 					},
 				},
 			},
@@ -412,6 +487,12 @@ func TestUpdateClusterVersionStatus_FilteringMultipleErrorsForFailingCondition(t
 				Type:   ClusterStatusFailing,
 				Status: configv1.ConditionFalse,
 			},
+			expectedProgressingCondition: &configv1.ClusterOperatorStatusCondition{
+				Type:    configv1.OperatorProgressing,
+				Status:  configv1.ConditionTrue,
+				Reason:  "ClusterOperatorUpdating",
+				Message: "Working towards 1.2.3: waiting on machine-config",
+			},
 		},
 		{
 			name: "single condensed UpdateEffectFail UpdateError",
@@ -621,6 +702,13 @@ func TestUpdateClusterVersionStatus_FilteringMultipleErrorsForFailingCondition(t
 				if diff := cmp.Diff(expectedCondition, condition, ignoreLastTransitionTime); diff != "" {
 					t.Errorf("unexpected condition when Reconciling == %t && isHistoryEmpty == %t\n:%s", c.isReconciling, c.isHistoryEmpty, diff)
 				}
+
+				if tc.expectedProgressingCondition != nil && !c.isReconciling && !c.isHistoryEmpty {
+					progressingCondition := resourcemerge.FindOperatorStatusCondition(cvStatus.Conditions, configv1.OperatorProgressing)
+					if diff := cmp.Diff(tc.expectedProgressingCondition, progressingCondition, ignoreLastTransitionTime); diff != "" {
+						t.Errorf("unexpected progressingCondition when Reconciling == %t && isHistoryEmpty == %t\n:%s", c.isReconciling, c.isHistoryEmpty, diff)
+					}
+				}
 			}
 		})
 	}

pkg/payload/task.go

@@ -47,9 +47,15 @@ func InitCOUpdateStartTimes() {
 // COUpdateStartTimesEnsure adds name to clusterOperatorUpdateStartTimes map and sets to
 // current time if name does not already exist in map.
 func COUpdateStartTimesEnsure(name string) {
+	COUpdateStartTimesAt(name, time.Now())
+}
+
+// COUpdateStartTimesAt adds name to clusterOperatorUpdateStartTimes map and sets to
+// t if name does not already exist in map.
+func COUpdateStartTimesAt(name string, t time.Time) {
 	clusterOperatorUpdateStartTimes.lock.Lock()
 	if _, ok := clusterOperatorUpdateStartTimes.m[name]; !ok {
-		clusterOperatorUpdateStartTimes.m[name] = time.Now()
+		clusterOperatorUpdateStartTimes.m[name] = t
 	}
 	clusterOperatorUpdateStartTimes.lock.Unlock()
 }