WIP: debug events

.github/workflows/test.yaml

@@ -45,7 +45,6 @@ jobs:
           retention-days: 1
 
   kubernetes-k3d:
-    if: "${{ github.repository == 'CrunchyData/postgres-operator' }}"
     runs-on: ubuntu-latest
     needs: [go-test]
     strategy:
@@ -84,8 +83,9 @@ jobs:
               template: {
                 metadata: { labels: $labels },
                 spec: {
-                  initContainers: to_entries | map({ name: "c\(.key)", command: ["true"], image: .value }),
-                  containers: [{ name: "pause", image: "k8s.gcr.io/pause:3.5" }]
+                  containers: to_entries | map({
+                    name: "c\(.key)", image: .value, command: ["sleep", "15m"],
+                  }),
                 }
               }
             }

config/crd/bases/postgres-operator.crunchydata.com_postgresclusters.yaml

@@ -9151,12 +9151,11 @@ spec:
                       format: int32
                       type: integer
                     replicas:
-                      description: Total number of non-terminated pods.
+                      description: Total number of pods.
                       format: int32
                       type: integer
                     updatedReplicas:
-                      description: Total number of non-terminated pods that have the
-                        desired specification.
+                      description: Total number of pods that have the desired specification.
                       format: int32
                       type: integer
                   required:

internal/controller/postgrescluster/delete_test.go

@@ -28,7 +28,6 @@ import (
 
 	"go.opentelemetry.io/otel"
 	"gotest.tools/v3/assert"
-	appsv1 "k8s.io/api/apps/v1"
 	corev1 "k8s.io/api/core/v1"
 	apierrors "k8s.io/apimachinery/pkg/api/errors"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
@@ -42,6 +41,7 @@ import (
 	"sigs.k8s.io/yaml"
 
 	"github.com/crunchydata/postgres-operator/internal/patroni"
+	"github.com/crunchydata/postgres-operator/internal/testing/events"
 	"github.com/crunchydata/postgres-operator/internal/testing/require"
 	"github.com/crunchydata/postgres-operator/pkg/apis/postgres-operator.crunchydata.com/v1beta1"
 )
@@ -201,29 +201,24 @@ func TestReconcilerHandleDelete(t *testing.T) {
 				"cluster should immediately have a finalizer")
 
 			// Continue until instances are healthy.
-			var instances []appsv1.StatefulSet
-			var ready int32
-			assert.NilError(t, wait.Poll(time.Second, Scale(time.Minute), func() (bool, error) {
-				mustReconcile(t, cluster)
-
-				list := appsv1.StatefulSetList{}
-				selector, err := labels.Parse(strings.Join([]string{
-					"postgres-operator.crunchydata.com/cluster=" + cluster.Name,
-					"postgres-operator.crunchydata.com/instance",
-				}, ","))
-				assert.NilError(t, err)
-				assert.NilError(t, cc.List(ctx, &list,
-					client.InNamespace(cluster.Namespace),
-					client.MatchingLabelsSelector{Selector: selector}))
-
-				instances = list.Items
-
-				ready = int32(0)
-				for i := range instances {
-					ready += instances[i].Status.ReadyReplicas
-				}
-				return ready >= test.waitForRunningInstances, nil
-			}), "expected %v instances to be ready, got:\n%v", test.waitForRunningInstances, ready)
+			if ready, start := int32(0), time.Now(); !assert.Check(t,
+				wait.Poll(time.Second, Scale(time.Minute), func() (bool, error) {
+					mustReconcile(t, cluster)
+					assert.NilError(t, cc.Get(ctx, client.ObjectKeyFromObject(cluster), cluster))
+
+					ready = 0
+					for _, set := range cluster.Status.InstanceSets {
+						ready += set.ReadyReplicas
+					}
+					return ready >= test.waitForRunningInstances, nil
+				}), "expected %v instances to be ready, got: %v", test.waitForRunningInstances, ready,
+			) {
+				list := corev1.EventList{}
+				assert.NilError(t, cc.List(ctx, &list, client.InNamespace(cluster.Namespace)))
+
+				events.SortByTimestamp(list.Items)
+				t.Fatalf("Events:\n%v", events.FormatList(events.Since(list.Items, start)))
+			}
 
 			if test.beforeDelete != nil {
 				test.beforeDelete(t, cluster)
@@ -412,27 +407,24 @@ func TestReconcilerHandleDeleteNamespace(t *testing.T) {
 				client.Merge.Type(), []byte(`{"metadata":{"finalizers":[]}}`)))))
 	})
 
-	var instances []appsv1.StatefulSet
-	var ready int32
-	assert.NilError(t, wait.Poll(time.Second, Scale(time.Minute), func() (bool, error) {
-		list := appsv1.StatefulSetList{}
-		selector, err := labels.Parse(strings.Join([]string{
-			"postgres-operator.crunchydata.com/cluster=" + cluster.Name,
-			"postgres-operator.crunchydata.com/instance",
-		}, ","))
-		assert.NilError(t, err)
-		assert.NilError(t, cc.List(ctx, &list,
-			client.InNamespace(cluster.Namespace),
-			client.MatchingLabelsSelector{Selector: selector}))
-
-		instances = list.Items
-
-		ready = 0
-		for i := range instances {
-			ready += instances[i].Status.ReadyReplicas
-		}
-		return ready >= 2, nil
-	}), "expected 2 instances to be ready, got:\n%v", ready)
+	// Wait until instances are healthy.
+	if ready, start := int32(0), time.Now(); !assert.Check(t,
+		wait.Poll(time.Second, Scale(time.Minute), func() (bool, error) {
+			assert.NilError(t, cc.Get(ctx, client.ObjectKeyFromObject(cluster), cluster))
+
+			ready = 0
+			for _, set := range cluster.Status.InstanceSets {
+				ready += set.ReadyReplicas
+			}
+			return ready >= 2, nil
+		}), "expected 2 instances to be ready, got: %v", ready,
+	) {
+		list := corev1.EventList{}
+		assert.NilError(t, cc.List(ctx, &list, client.InNamespace(cluster.Namespace)))
+
+		events.SortByTimestamp(list.Items)
+		t.Fatalf("Events:\n%v", events.FormatList(events.Since(list.Items, start)))
+	}
 
 	// Delete the namespace.
 	assert.NilError(t, cc.Delete(ctx, ns))

internal/controller/postgrescluster/instance.go

@@ -353,16 +353,15 @@ func (r *Reconciler) observeInstances(
 	cluster.Status.InstanceSets = cluster.Status.InstanceSets[:0]
 	for _, name := range observed.setNames.List() {
 		status := v1beta1.PostgresInstanceSetStatus{Name: name}
+
 		for _, instance := range observed.bySet[name] {
+			status.Replicas += int32(len(instance.Pods))
+
 			if ready, known := instance.IsReady(); known && ready {
 				status.ReadyReplicas++
 			}
-			if terminating, known := instance.IsTerminating(); known && !terminating {
-				status.Replicas++
-
-				if matches, known := instance.PodMatchesPodTemplate(); known && matches {
-					status.UpdatedReplicas++
-				}
+			if matches, known := instance.PodMatchesPodTemplate(); known && matches {
+				status.UpdatedReplicas++
 			}
 		}
 

internal/testing/events/format.go

@@ -0,0 +1,92 @@
+/*
+ Copyright 2022 Crunchy Data Solutions, Inc.
+ Licensed under the Apache License, Version 2.0 (the "License");
+ you may not use this file except in compliance with the License.
+ You may obtain a copy of the License at
+
+ http://www.apache.org/licenses/LICENSE-2.0
+
+ Unless required by applicable law or agreed to in writing, software
+ distributed under the License is distributed on an "AS IS" BASIS,
+ WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ See the License for the specific language governing permissions and
+ limitations under the License.
+*/
+
+package events
+
+import (
+	"fmt"
+	"sort"
+	"strings"
+	"time"
+
+	corev1 "k8s.io/api/core/v1"
+	"k8s.io/apimachinery/pkg/util/duration"
+)
+
+// Format returns event in a format similar to `kubectl describe`.
+func Format(event corev1.Event) string {
+	source := event.Source.Component
+	if source == "" {
+		source = event.ReportingController
+	}
+
+	timestamp := event.EventTime.Time
+	if timestamp.IsZero() {
+		timestamp = event.FirstTimestamp.Time
+	}
+
+	interval := duration.HumanDuration(time.Since(timestamp))
+	if event.Series != nil {
+		interval = fmt.Sprintf("%s (x%d over %s)",
+			duration.HumanDuration(time.Since(event.Series.LastObservedTime.Time)),
+			event.Series.Count, interval)
+	} else if event.Count > 1 {
+		interval = fmt.Sprintf("%s (x%d over %s)",
+			duration.HumanDuration(time.Since(event.LastTimestamp.Time)),
+			event.Count, interval)
+	}
+
+	return fmt.Sprintf("%s\t%-8s\t%s\t%-8s\t%s",
+		event.Type, event.Reason, interval, source, event.Message)
+}
+
+// FormatList returns events formatted and separated by newlines.
+func FormatList(events []corev1.Event) string {
+	var buffer strings.Builder
+
+	if len(events) > 0 {
+		_, _ = buffer.WriteString(Format(events[0]))
+
+		for _, event := range events[1:] {
+			_, _ = buffer.WriteString("\n" + Format(event))
+		}
+	}
+
+	return buffer.String()
+}
+
+// Since returns events that occurred after t.
+func Since(events []corev1.Event, t time.Time) []corev1.Event {
+	var result []corev1.Event
+
+	for _, event := range events {
+		if event.EventTime.After(t) || event.FirstTimestamp.After(t) {
+			result = append(result, event)
+		} else if event.Series != nil && event.Series.LastObservedTime.After(t) {
+			result = append(result, event)
+		} else if event.Count > 1 && event.LastTimestamp.After(t) {
+			result = append(result, event)
+		}
+	}
+
+	return result
+}
+
+// SortByTimestamp sorts events by LastTimestamp, oldest first.
+func SortByTimestamp(events []corev1.Event) {
+	sort.Slice(events, func(i, j int) bool {
+		return events[i].LastTimestamp.Time.Before(events[j].LastTimestamp.Time)
+	})
+}

pkg/apis/postgres-operator.crunchydata.com/v1beta1/postgrescluster_types.go

@@ -493,11 +493,11 @@ type PostgresInstanceSetStatus struct {
 	// +optional
 	ReadyReplicas int32 `json:"readyReplicas,omitempty"`
 
-	// Total number of non-terminated pods.
+	// Total number of pods.
 	// +optional
 	Replicas int32 `json:"replicas,omitempty"`
 
-	// Total number of non-terminated pods that have the desired specification.
+	// Total number of pods that have the desired specification.
 	// +optional
 	UpdatedReplicas int32 `json:"updatedReplicas,omitempty"`
 }