Repository: kubernetes-sigs/controller-runtime

Issue:
setup-envtest selecting older versions
When two versions are available, `setup-envtest use` picks the older version rather than the newer one:

```console
$ go run sigs.k8s.io/controller-runtime/tools/setup-envtest@latest use --print=overview 1.34.0
Version: 1.34.0
OS/Arch: linux/arm64

$ go run sigs.k8s.io/controller-runtime/tools/setup-envtest@latest use --print=overview 1.34.1
Version: 1.34.1
OS/Arch: linux/arm64

$ go run sigs.k8s.io/controller-runtime/tools/setup-envtest@latest use --print=overview 1.34.x
Version: 1.34.0 👈
OS/Arch: linux/arm64
```

The prior released version works correctly:

```console
$ go run sigs.k8s.io/controller-runtime/tools/setup-envtest@release-0.22 use --print=overview 1.34.x
Version: 1.34.1 👈
OS/Arch: linux/arm64
```

<details><summary>Tests are also failing:</summary>

```console
$ (cd ./tools/setup-envtest && go run github.com/onsi/ginkgo/v2/ginkgo -r --succinct)
[1762277146] Env Suite - 7/7 specs ••••••• SUCCESS! 535µs PASS
[1762277146] Store Suite - 15/15 specs ••
------------------------------
• [FAILED] [0.000 seconds]
Store listing items [It] should filter results by the given filter, sorted in version order (newest first)
controller-runtime/tools/setup-envtest/store/store_test.go:63
…
------------------------------
••••••••••••

Summarizing 1 Failure:
  [FAIL] Store listing items [It] should filter results by the given filter, sorted in version order (newest first)
  /home/cbandy/code/controller-runtime/tools/setup-envtest/store/store_test.go:69

Ran 15 of 15 Specs in 0.008 seconds
FAIL! -- 14 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestStore (0.01s)
FAIL

Ginkgo ran 5 suites in 902.063876ms

There were failures detected in the following suites:
  store ./store

Test Suite Failed
```

</details>

I suspect the order inadvertently changed in 0ddbc5205c01f30a1bc604e9e4857a22d6b57243.

Discussion:
@sbueringer: I would have expected that unit tests catch this, but maybe they are not covering .x@cbandy: > I would have expected that unit tests catch this, but maybe they are not covering .x

Is there a PR check that runs tests?@cbandy: When no versions are available locally, it selects the _oldest_ version available remotely:

```console
$ go run sigs.k8s.io/controller-runtime/tools/setup-envtest@latest cleanup
$ go run sigs.k8s.io/controller-runtime/tools/setup-envtest@latest use --print=overview
Version: 1.23.5
OS/Arch: linux/arm64
```@sbueringer: > Is there a PR check that runs tests?

Yes!

Solution patch:
diff --git a/Makefile b/Makefile
index 5dded974..86a5eddf 100644
--- a/Makefile
+++ b/Makefile
@@ -69,13 +69,9 @@ help:  ## Display this help
 ## --------------------------------------
 
 .PHONY: test
-test: test-tools ## Run the script check-everything.sh which will check all.
+test: ## Run the script check-everything.sh which will check all.
 	TRACE=1 ./hack/check-everything.sh
 
-.PHONY: test-tools
-test-tools: ## tests the tools codebase (setup-envtest)
-	cd tools/setup-envtest && go test ./...
-
 ## --------------------------------------
 ## Binaries
 ## --------------------------------------
diff --git a/hack/test-all.sh b/hack/test-all.sh
index 34d841cf..9363fa59 100755
--- a/hack/test-all.sh
+++ b/hack/test-all.sh
@@ -26,6 +26,7 @@ fi
 
 result=0
 go test -v -race ${P_FLAG} ${MOD_OPT} ./... --ginkgo.fail-fast ${GINKGO_ARGS} || result=$?
+(cd tools/setup-envtest && go test -v -race ${P_FLAG} ${MOD_OPT} ./... --ginkgo.fail-fast ${GINKGO_ARGS}) || result=$?
 
 if [[ -n ${ARTIFACTS:-} ]]; then
   mkdir -p ${ARTIFACTS}
diff --git a/pkg/internal/controller/controller.go b/pkg/internal/controller/controller.go
index 7dd06957..f2638b9d 100644
--- a/pkg/internal/controller/controller.go
+++ b/pkg/internal/controller/controller.go
@@ -39,6 +39,10 @@ import (
 	"sigs.k8s.io/controller-runtime/pkg/source"
 )
 
+// errReconciliationTimeout is the error used as the cause when the ReconciliationTimeout guardrail fires.
+// This allows us to distinguish wrapper timeouts from user-initiated context cancellations.
+var errReconciliationTimeout = errors.New("reconciliation timeout")
+
 // Options are the arguments for creating a new Controller.
 type Options[request comparable] struct {
 	// Reconciler is a function that can be called at any time with the Name / Namespace of an object and
@@ -207,13 +211,26 @@ func (c *Controller[request]) Reconcile(ctx context.Context, req request) (_ rec
 		}
 	}()
 
+	var timeoutCause error
 	if c.ReconciliationTimeout > 0 {
+		timeoutCause = errReconciliationTimeout
 		var cancel context.CancelFunc
-		ctx, cancel = context.WithTimeout(ctx, c.ReconciliationTimeout)
+		ctx, cancel = context.WithTimeoutCause(ctx, c.ReconciliationTimeout, timeoutCause)
 		defer cancel()
 	}
 
-	return c.Do.Reconcile(ctx, req)
+	res, err := c.Do.Reconcile(ctx, req)
+
+	// Check if the reconciliation timed out due to our wrapper timeout guardrail.
+	// We check ctx.Err() == context.DeadlineExceeded first to ensure the context was actually
+	// cancelled due to a deadline (not parent cancellation or other reasons), then verify it was
+	// our specific timeout cause. This prevents false positives from parent context cancellations
+	// or other timeout scenarios.
+	if timeoutCause != nil && ctx.Err() == context.DeadlineExceeded && errors.Is(context.Cause(ctx), timeoutCause) {
+		ctrlmetrics.ReconcileTimeouts.WithLabelValues(c.Name).Inc()
+	}
+
+	return res, err
 }
 
 // Watch implements controller.Controller.
@@ -437,6 +454,7 @@ func (c *Controller[request]) initMetrics() {
 	ctrlmetrics.ReconcileErrors.WithLabelValues(c.Name).Add(0)
 	ctrlmetrics.TerminalReconcileErrors.WithLabelValues(c.Name).Add(0)
 	ctrlmetrics.ReconcilePanics.WithLabelValues(c.Name).Add(0)
+	ctrlmetrics.ReconcileTimeouts.WithLabelValues(c.Name).Add(0)
 	ctrlmetrics.WorkerCount.WithLabelValues(c.Name).Set(float64(c.MaxConcurrentReconciles))
 	ctrlmetrics.ActiveWorkers.WithLabelValues(c.Name).Set(0)
 }
diff --git a/pkg/internal/controller/metrics/metrics.go b/pkg/internal/controller/metrics/metrics.go
index 450e9ae2..39b435c4 100644
--- a/pkg/internal/controller/metrics/metrics.go
+++ b/pkg/internal/controller/metrics/metrics.go
@@ -80,6 +80,15 @@ var (
 		Name: "controller_runtime_active_workers",
 		Help: "Number of currently used workers per controller",
 	}, []string{"controller"})
+
+	// ReconcileTimeouts is a prometheus counter metric which holds the total
+	// number of reconciliations that timed out due to the ReconciliationTimeout
+	// context timeout. This metric only increments when the wrapper timeout fires,
+	// not when user reconcilers cancels the context or completes before the timeout.
+	ReconcileTimeouts = prometheus.NewCounterVec(prometheus.CounterOpts{
+		Name: "controller_runtime_reconcile_timeouts_total",
+		Help: "Total number of reconciliation timeouts per controller",
+	}, []string{"controller"})
 )
 
 func init() {
@@ -91,6 +100,7 @@ func init() {
 		ReconcileTime,
 		WorkerCount,
 		ActiveWorkers,
+		ReconcileTimeouts,
 		// expose process metrics like CPU, Memory, file descriptor usage etc.
 		collectors.NewProcessCollector(collectors.ProcessCollectorOpts{}),
 		// expose all Go runtime metrics like GC stats, memory stats etc.



Test patch:
diff --git a/pkg/internal/controller/controller_test.go b/pkg/internal/controller/controller_test.go
index 6d62b80e..259f6669 100644
--- a/pkg/internal/controller/controller_test.go
+++ b/pkg/internal/controller/controller_test.go
@@ -155,6 +155,128 @@ var _ = Describe("controller", func() {
 			Expect(err).To(Equal(context.DeadlineExceeded))
 		})
 
+		Context("prometheus metric reconcile_timeouts", func() {
+			var reconcileTimeouts dto.Metric
+
+			BeforeEach(func() {
+				ctrlmetrics.ReconcileTimeouts.Reset()
+				reconcileTimeouts.Reset()
+				ctrl.Name = testControllerName
+				Expect(ctrlmetrics.ReconcileTimeouts.WithLabelValues(ctrl.Name).Write(&reconcileTimeouts)).To(Succeed())
+				Expect(reconcileTimeouts.GetCounter().GetValue()).To(Equal(0.0))
+			})
+
+			It("should increment when ReconciliationTimeout context timeout hits DeadlineExceeded", func(ctx SpecContext) {
+				ctrl.ReconciliationTimeout = time.Duration(1)
+				ctrl.Do = reconcile.Func(func(ctx context.Context, _ reconcile.Request) (reconcile.Result, error) {
+					<-ctx.Done()
+					return reconcile.Result{}, ctx.Err()
+				})
+				_, err := ctrl.Reconcile(ctx,
+					reconcile.Request{NamespacedName: types.NamespacedName{Namespace: "foo", Name: "bar"}})
+				Expect(err).To(HaveOccurred())
+				Expect(err).To(Equal(context.DeadlineExceeded))
+
+				Expect(ctrlmetrics.ReconcileTimeouts.WithLabelValues(ctrl.Name).Write(&reconcileTimeouts)).To(Succeed())
+				Expect(reconcileTimeouts.GetCounter().GetValue()).To(Equal(1.0))
+			})
+
+			It("should not increment when user code cancels context earlier than the ReconciliationTimeout", func(ctx SpecContext) {
+				ctrl.ReconciliationTimeout = 10 * time.Second
+				userCancelCause := errors.New("user cancellation")
+				ctrl.Do = reconcile.Func(func(ctx context.Context, _ reconcile.Request) (reconcile.Result, error) {
+					// User code creates its own timeout with a different cause
+					userCtx, cancel := context.WithTimeoutCause(ctx, time.Millisecond, userCancelCause)
+					defer cancel()
+					<-userCtx.Done()
+					return reconcile.Result{}, context.Cause(userCtx)
+				})
+				_, err := ctrl.Reconcile(ctx,
+					reconcile.Request{NamespacedName: types.NamespacedName{Namespace: "foo", Name: "bar"}})
+				Expect(err).To(HaveOccurred())
+				Expect(errors.Is(err, userCancelCause)).To(BeTrue())
+
+				// Metric should not be incremented because the context timeout didn't hit DeadlineExceeded
+				Expect(ctrlmetrics.ReconcileTimeouts.WithLabelValues(ctrl.Name).Write(&reconcileTimeouts)).To(Succeed())
+				Expect(reconcileTimeouts.GetCounter().GetValue()).To(Equal(0.0))
+			})
+
+			It("should not increment when reconciliation completes before timeout", func(ctx SpecContext) {
+				ctrl.ReconciliationTimeout = 10 * time.Second
+				ctrl.Do = reconcile.Func(func(ctx context.Context, _ reconcile.Request) (reconcile.Result, error) {
+					// Reconcile completes successfully before timeout
+					return reconcile.Result{}, nil
+				})
+				_, err := ctrl.Reconcile(ctx,
+					reconcile.Request{NamespacedName: types.NamespacedName{Namespace: "foo", Name: "bar"}})
+				Expect(err).NotTo(HaveOccurred())
+
+				// Metric should not be incremented because the timeout was not exceeded
+				Expect(ctrlmetrics.ReconcileTimeouts.WithLabelValues(ctrl.Name).Write(&reconcileTimeouts)).To(Succeed())
+				Expect(reconcileTimeouts.GetCounter().GetValue()).To(Equal(0.0))
+			})
+
+			It("should increment multiple times when multiple reconciles timeout", func(ctx SpecContext) {
+				ctrl.ReconciliationTimeout = time.Duration(1)
+				ctrl.Do = reconcile.Func(func(ctx context.Context, _ reconcile.Request) (reconcile.Result, error) {
+					<-ctx.Done()
+					return reconcile.Result{}, ctx.Err()
+				})
+
+				const numTimeouts = 3
+				// Call Reconcile multiple times, each should timeout and increment the metric
+				for i := range numTimeouts {
+					_, err := ctrl.Reconcile(ctx,
+						reconcile.Request{NamespacedName: types.NamespacedName{Namespace: "foo", Name: fmt.Sprintf("bar%d", i)}})
+					Expect(err).To(HaveOccurred())
+					Expect(err).To(Equal(context.DeadlineExceeded))
+				}
+
+				// Metric should be incremented 3 times
+				Expect(ctrlmetrics.ReconcileTimeouts.WithLabelValues(ctrl.Name).Write(&reconcileTimeouts)).To(Succeed())
+				Expect(reconcileTimeouts.GetCounter().GetValue()).To(Equal(float64(numTimeouts)))
+			})
+
+			It("should not increment when parent context is cancelled", func(ctx SpecContext) {
+				parentCtx, cancel := context.WithCancel(ctx)
+				defer cancel()
+
+				ctrl.ReconciliationTimeout = 10 * time.Second
+				ctrl.Do = reconcile.Func(func(ctx context.Context, _ reconcile.Request) (reconcile.Result, error) {
+					// Wait for parent cancellation
+					<-ctx.Done()
+					return reconcile.Result{}, ctx.Err()
+				})
+
+				// Cancel parent context immediately
+				cancel()
+
+				_, err := ctrl.Reconcile(parentCtx,
+					reconcile.Request{NamespacedName: types.NamespacedName{Namespace: "foo", Name: "bar"}})
+				Expect(err).To(HaveOccurred())
+				Expect(err).To(Equal(context.Canceled))
+
+				// Metric should not be incremented because the wrapper timeout didn't fire
+				Expect(ctrlmetrics.ReconcileTimeouts.WithLabelValues(ctrl.Name).Write(&reconcileTimeouts)).To(Succeed())
+				Expect(reconcileTimeouts.GetCounter().GetValue()).To(Equal(0.0))
+			})
+
+			It("should not increment when ReconciliationTimeout is zero", func(ctx SpecContext) {
+				// Ensure ReconciliationTimeout is zero (not set)
+				ctrl.ReconciliationTimeout = 0
+				ctrl.Do = reconcile.Func(func(ctx context.Context, _ reconcile.Request) (reconcile.Result, error) {
+					return reconcile.Result{}, nil
+				})
+				_, err := ctrl.Reconcile(ctx,
+					reconcile.Request{NamespacedName: types.NamespacedName{Namespace: "foo", Name: "bar"}})
+				Expect(err).NotTo(HaveOccurred())
+
+				// Metric should not be incremented because ReconciliationTimeout is not set
+				Expect(ctrlmetrics.ReconcileTimeouts.WithLabelValues(ctrl.Name).Write(&reconcileTimeouts)).To(Succeed())
+				Expect(reconcileTimeouts.GetCounter().GetValue()).To(Equal(0.0))
+			})
+		})
+
 		It("should not configure a timeout if ReconciliationTimeout is zero", func(ctx SpecContext) {
 			ctrl.Do = reconcile.Func(func(ctx context.Context, _ reconcile.Request) (reconcile.Result, error) {
 				defer GinkgoRecover()
diff --git a/tools/setup-envtest/remote/http_client.go b/tools/setup-envtest/remote/http_client.go
index a87ef1f1..7cbe3ee1 100644
--- a/tools/setup-envtest/remote/http_client.go
+++ b/tools/setup-envtest/remote/http_client.go
@@ -88,7 +88,7 @@ func (c *HTTPClient) ListVersions(ctx context.Context) ([]versions.Set, error) {
 	}
 	// sort in inverse order so that the newest one is first
 	slices.SortStableFunc(res, func(i, j versions.Set) int {
-		return i.Version.Compare(j.Version)
+		return j.Version.Compare(i.Version)
 	})
 
 	return res, nil
diff --git a/tools/setup-envtest/store/store.go b/tools/setup-envtest/store/store.go
index 1e1d4beb..1e8053e0 100644
--- a/tools/setup-envtest/store/store.go
+++ b/tools/setup-envtest/store/store.go
@@ -105,7 +105,8 @@ func (s *Store) List(ctx context.Context, matching Filter) ([]Item, error) {
 
 	slices.SortStableFunc(res, func(i, j Item) int {
 		if !i.Version.Matches(j.Version) {
-			return i.Version.Compare(j.Version)
+			// sort in inverse order so that the newest one is first
+			return j.Version.Compare(i.Version)
 		}
 		return orderPlatforms(i.Platform, j.Platform)
 	})
diff --git a/tools/setup-envtest/versions/misc_test.go b/tools/setup-envtest/versions/misc_test.go
index 1c0dbb68..187218f8 100644
--- a/tools/setup-envtest/versions/misc_test.go
+++ b/tools/setup-envtest/versions/misc_test.go
@@ -17,6 +17,9 @@ limitations under the License.
 package versions_test
 
 import (
+	"math/rand/v2"
+	"slices"
+
 	. "github.com/onsi/ginkgo/v2"
 	. "github.com/onsi/gomega"
 
@@ -44,6 +47,23 @@ var _ = Describe("Concrete", func() {
 		Specify("newer major should be newer", func() {
 			Expect(ver1163.Compare(Concrete{Major: 0, Minor: 16, Patch: 3})).To(Equal(1))
 		})
+
+		Describe("sorting", func() {
+			ver16 := Concrete{Major: 1, Minor: 16}
+			ver17 := Concrete{Major: 1, Minor: 17}
+			many := []Concrete{ver16, ver17, ver1163}
+
+			BeforeEach(func() {
+				rand.Shuffle(len(many), func(i, j int) {
+					many[i], many[j] = many[j], many[i]
+				})
+			})
+
+			Specify("newer versions are later", func() {
+				slices.SortStableFunc(many, Concrete.Compare)
+				Expect(many).To(Equal([]Concrete{ver16, ver1163, ver17}))
+			})
+		})
 	})
 })