Repository: knative/client
Pull request #644 (2020-02-07 19:14:13)

fix(serving): Add an error window for ReadyCondition
A default error window of 2 seconds (not sure if this should be made configurable
as it is hard to explain/document) cause return an error during
sync operations only, if a ReadyCondition == false stays for that
long in false. This is needed to compensate situation where the
condition is false when a race between revision and route creation
occurse during a service creation.

This should fix the flakes we have in our E2E tests as described in #544.

knative-prow-robot: [APPROVALNOTIFIER] This PR is **APPROVED**

This pull-request has been approved by: *<a href="https://github.com/knative/client/pull/644#" title="Author self-approved">rhuss</a>*

The full list of commands accepted by this bot can be found [here](https://go.k8s.io/bot-commands?repo=knative%2Fclient).

The pull request process is described [here](https://git.k8s.io/community/contributors/guide/owners.md#the-code-review-process)

<details >
Needs approval from an approver in each of these files:

- ~~[OWNERS](https://github.com/knative/client/blob/master/OWNERS)~~ [rhuss]

Approvers can indicate their approval by writing `/approve` in a comment
Approvers can cancel approval by writing `/approve cancel` in a comment
</details>
<!-- META={"approvers":[]} -->
knative-metrics-robot: The following is the coverage report on the affected files.
Say `/test pull-knative-client-go-coverage` to re-run this coverage report

File | Old Coverage | New Coverage | Delta
---- |:------------:|:------------:|:-----:
[pkg/wait/wait_for_ready.go](https://storage.cloud.google.com/knative-prow/pr-logs/pull/knative_client/644/pull-knative-client-go-coverage/1225860479407099905/artifacts/line-cov.html#file0) | 70.5% | 69.1% | -1.4

knative-metrics-robot: The following is the coverage report on the affected files.
Say `/test pull-knative-client-go-coverage` to re-run this coverage report

File | Old Coverage | New Coverage | Delta
---- |:------------:|:------------:|:-----:
[pkg/wait/wait_for_ready.go](https://storage.cloud.google.com/knative-prow/pr-logs/pull/knative_client/644/pull-knative-client-go-coverage/1225865136451883009/artifacts/line-cov.html#file0) | 70.5% | 69.1% | -1.4

knative-metrics-robot: The following is the coverage report on the affected files.
Say `/test pull-knative-client-go-coverage` to re-run this coverage report

File | Old Coverage | New Coverage | Delta
---- |:------------:|:------------:|:-----:
[pkg/wait/wait_for_ready.go](https://storage.cloud.google.com/knative-prow/pr-logs/pull/knative_client/644/pull-knative-client-go-coverage/1225866142036267009/artifacts/line-cov.html#file0) | 70.5% | 66.7% | -3.8

knative-prow-robot: [APPROVALNOTIFIER] This PR is **APPROVED**

This pull-request has been approved by: *<a href="https://github.com/knative/client/pull/644#pullrequestreview-355406460" title="LGTM">navidshaikh</a>*, *<a href="https://github.com/knative/client/pull/644#" title="Author self-approved">rhuss</a>*

The full list of commands accepted by this bot can be found [here](https://go.k8s.io/bot-commands?repo=knative%2Fclient).

The pull request process is described [here](https://git.k8s.io/community/contributors/guide/owners.md#the-code-review-process)

<details >
Needs approval from an approver in each of these files:

- ~~[OWNERS](https://github.com/knative/client/blob/master/OWNERS)~~ [navidshaikh,rhuss]

Approvers can indicate their approval by writing `/approve` in a comment
Approvers can cancel approval by writing `/approve cancel` in a comment
</details>
<!-- META={"approvers":[]} -->

Patch:
diff --git a/pkg/wait/wait_for_ready.go b/pkg/wait/wait_for_ready.go
index 957fa0f4..d5a5c563 100644
--- a/pkg/wait/wait_for_ready.go
+++ b/pkg/wait/wait_for_ready.go
@@ -25,6 +25,10 @@ import (
 	"knative.dev/pkg/apis"
 )
 
+// Window for how long a ReadyCondition == false has to stay
+// for being considered as an error
+var ErrorWindow = 2 * time.Second
+
 // Callbacks and configuration used while waiting
 type waitForReadyConfig struct {
 	watchMaker          WatchMaker
@@ -87,7 +91,7 @@ func (w *waitForReadyConfig) Wait(name string, timeout time.Duration, msgCallbac
 	floatingTimeout := timeout
 	for {
 		start := time.Now()
-		retry, timeoutReached, err := w.waitForReadyCondition(start, name, floatingTimeout, msgCallback)
+		retry, timeoutReached, err := w.waitForReadyCondition(start, name, floatingTimeout, ErrorWindow, msgCallback)
 		if err != nil {
 			return err, time.Since(start)
 		}
@@ -104,18 +108,31 @@ func (w *waitForReadyConfig) Wait(name string, timeout time.Duration, msgCallbac
 	}
 }
 
-func (w *waitForReadyConfig) waitForReadyCondition(start time.Time, name string, timeout time.Duration, msgCallback MessageCallback) (retry bool, timeoutReached bool, err error) {
+func (w *waitForReadyConfig) waitForReadyCondition(start time.Time, name string, timeout time.Duration, errorWindow time.Duration, msgCallback MessageCallback) (retry bool, timeoutReached bool, err error) {
 
 	watcher, err := w.watchMaker(name, timeout)
 	if err != nil {
 		return false, false, err
 	}
-
 	defer watcher.Stop()
+
+	// channel used to transport the error
+	errChan := make(chan error)
+	var errorTimer *time.Timer
+	// Stop error timer if it has been started because of
+	// a ConditionReady has been set to false
+	defer (func() {
+		if errorTimer != nil {
+			errorTimer.Stop()
+		}
+	})()
+
 	for {
 		select {
 		case <-time.After(timeout):
 			return false, true, nil
+		case err = <-errChan:
+			return false, false, err
 		case event, ok := <-watcher.ResultChan():
 			if !ok || event.Object == nil {
 				return true, false, nil
@@ -140,7 +157,15 @@ func (w *waitForReadyConfig) waitForReadyCondition(start time.Time, name string,
 					case corev1.ConditionTrue:
 						return false, false, nil
 					case corev1.ConditionFalse:
-						return false, false, fmt.Errorf("%s: %s", cond.Reason, cond.Message)
+						// Fire up a timer waiting for the error window duration to still allow to reconcile
+						// to a true condition even after the condition went to false. If this is not the case within
+						// this window, then an error is returned.
+						// If there is already a timer running, we just log.
+						if errorTimer != nil {
+							errorTimer = time.AfterFunc(errorWindow, func() {
+								errChan <- fmt.Errorf("%s: %s", cond.Reason, cond.Message)
+							})
+						}
 					}
 					if cond.Message != "" {
 						msgCallback(time.Since(start), cond.Message)


Test patch:
diff --git a/pkg/wait/wait_for_ready_test.go b/pkg/wait/wait_for_ready_test.go
index fb20f43d..ad80ad19 100644
--- a/pkg/wait/wait_for_ready_test.go
+++ b/pkg/wait/wait_for_ready_test.go
@@ -79,6 +79,7 @@ func prepareTestCases(name string) []waitForReadyTestCase {
 		tc(peError, name, true),
 		tc(peWrongGeneration, name, true),
 		tc(peTimeout, name, true),
+		tc(peReadyFalseWithinErrorWindow, name, false),
 	}
 }
 
@@ -131,3 +132,11 @@ func peWrongGeneration(name string) ([]watch.Event, int) {
 		{watch.Modified, CreateTestServiceWithConditions(name, corev1.ConditionTrue, corev1.ConditionTrue, "", "", 1, 2)},
 	}, len(messages)
 }
+
+func peReadyFalseWithinErrorWindow(name string) ([]watch.Event, int) {
+	messages := pMessages(1)
+	return []watch.Event{
+		{watch.Added, CreateTestServiceWithConditions(name, corev1.ConditionFalse, corev1.ConditionFalse, "Route not ready", messages[0])},
+		{watch.Modified, CreateTestServiceWithConditions(name, corev1.ConditionTrue, corev1.ConditionTrue, "Route ready", "")},
+	}, len(messages)
+}