e2e: Improve detection of missing DNSRecord for Gateway

- Add more logs to the logic of DNSRecord ensuring to see when DNSRecord is
  updated or left untouched.
- Add more logs to the logic of generation of desired DNSRecord to see
  why Gateway service is not taken.
- Add more logs to Gateway service enqueue logic to see when reconciling
  hits or does not hit.
- Ensure the `Programmed` condition is checked on the Gateway resource
  in the e2e test.

Author: alebedev87

pkg/operator/controller/gateway-service-dns/controller.go

@@ -78,7 +78,11 @@ func NewUnmanaged(mgr manager.Manager, config Config) (controller.Controller, er
 			// A DNSRecord CR needs to be updated if, and only if,
 			// the hostname has changed (a listener's port and
 			// protocol have no bearing on the DNS record).
-			return gatewayListenersHostnamesChanged(old, new)
+			changed := gatewayListenersHostnamesChanged(old, new)
+			if changed {
+				log.Info("listener hostname changed", "gateway", e.ObjectNew.(*gatewayapiv1.Gateway).Name)
+			}
+			return changed
 		},
 	}
 	isInOperandNamespace := predicate.NewPredicateFuncs(func(o client.Object) bool {
@@ -103,6 +107,7 @@ func NewUnmanaged(mgr manager.Manager, config Config) (controller.Controller, er
 				},
 			}
 			requests = append(requests, request)
+			log.Info("enqueuing service for gateway", "gateway", o.GetName(), "service", request.NamespacedName)
 		}
 		return requests
 	}

pkg/resources/dnsrecord/dns.go

@@ -83,9 +83,11 @@ func EnsureDNSRecord(client client.Client, name types.NamespacedName, dnsRecordL
 		if updated, err := updateDNSRecord(client, current, desired); err != nil {
 			return true, current, fmt.Errorf("failed to update dnsrecord %s/%s: %v", desired.Namespace, desired.Name, err)
 		} else if updated {
+			log.Info("updated dnsrecord", "dnsrecord", desired)
 			return CurrentDNSRecord(client, name)
 		}
 	}
+	log.Info("no desired dnsrecord")
 
 	return haveWC, current, nil
 }
@@ -130,6 +132,7 @@ func desiredWildcardDNSRecord(name types.NamespacedName, dnsRecordLabels map[str
 func desiredDNSRecord(name types.NamespacedName, dnsRecordLabels map[string]string, ownerRef metav1.OwnerReference, domain string, dnsPolicy iov1.DNSManagementPolicy, service *corev1.Service) (bool, *iov1.DNSRecord) {
 	// No LB target exists for the domain record to point at.
 	if len(service.Status.LoadBalancer.Ingress) == 0 {
+		log.Info("no load balancer target for dnsrecord", "dnsrecord", name, "service", service.Name)
 		return false, nil
 	}
 
@@ -138,6 +141,7 @@ func desiredDNSRecord(name types.NamespacedName, dnsRecordLabels map[string]stri
 	// Quick sanity check since we don't know how to handle both being set (is
 	// that even a valid state?)
 	if len(ingress.Hostname) > 0 && len(ingress.IP) > 0 {
+		log.Info("no load balancer hostname or IP for dnsrecord", "dnsrecord", name, "service", service.Name)
 		return false, nil
 	}
 

test/e2e/util_gatewayapi_test.go

@@ -547,10 +547,11 @@ func assertGatewayClassSuccessful(t *testing.T, name string) (*gatewayapiv1.Gate
 		return false, nil
 	})
 	if err != nil {
+		t.Logf("[%s] Last observed gatewayclass:\n%s", time.Now().Format(time.DateTime), util.ToYaml(gwc))
 		return nil, fmt.Errorf("gatewayclass %s is not %v; last recorded status message: %s", name, gatewayapiv1.GatewayClassConditionStatusAccepted, recordedConditionMsg)
 	}
 
-	t.Logf("Observed that gatewayclass %s has been accepted: %+v", name, gwc.Status)
+	t.Logf("[%s] Observed that gatewayclass %s has been accepted: %+v", time.Now().Format(time.DateTime), name, gwc.Status)
 
 	return gwc, nil
 }
@@ -562,27 +563,42 @@ func assertGatewaySuccessful(t *testing.T, namespace, name string) (*gatewayapiv
 
 	gw := &gatewayapiv1.Gateway{}
 	nsName := types.NamespacedName{Namespace: namespace, Name: name}
-	recordedConditionMsg := "not found"
+	recordedAcceptedConditionMsg, recordedProgrammedConditionMsg := "not found", "not found"
 
-	err := wait.PollUntilContextTimeout(context.Background(), 1*time.Second, 1*time.Minute, false, func(context context.Context) (bool, error) {
+	err := wait.PollUntilContextTimeout(context.Background(), 3*time.Second, 3*time.Minute, false, func(context context.Context) (bool, error) {
 		if err := kclient.Get(context, nsName, gw); err != nil {
 			t.Logf("Failed to get gateway %v: %v; retrying...", nsName, err)
 			return false, nil
 		}
+		acceptedConditionFound, programmedConditionFound := false, false
 		for _, condition := range gw.Status.Conditions {
 			if condition.Type == string(gatewayapiv1.GatewayConditionAccepted) {
-				recordedConditionMsg = condition.Message
+				recordedAcceptedConditionMsg = condition.Message
 				if condition.Status == metav1.ConditionTrue {
 					t.Logf("Found gateway %v as Accepted", nsName)
-					return true, nil
+					acceptedConditionFound = true
 				}
 			}
+			// Ensuring the gateway configuration is ready.
+			// `AddressNotAssigned` may happen if the gateway service
+			// didn't get its load balancer target.
+			if condition.Type == string(gatewayapiv1.GatewayConditionProgrammed) {
+				recordedProgrammedConditionMsg = condition.Message
+				if condition.Status == metav1.ConditionTrue {
+					t.Logf("Found gateway %v as Programmed", nsName)
+					programmedConditionFound = true
+				}
+			}
+		}
+		if acceptedConditionFound && programmedConditionFound {
+			return true, nil
 		}
+		t.Logf("Not all expected gateway conditions are found, retrying...")
 		return false, nil
 	})
 	if err != nil {
-		t.Logf("Last observed gateway:\n%s", util.ToYaml(gw))
-		return nil, fmt.Errorf("gateway %v not %v, last recorded status message: %s", nsName, gatewayapiv1.GatewayConditionAccepted, recordedConditionMsg)
+		t.Logf("[%s] Last observed gateway:\n%s", time.Now().Format(time.DateTime), util.ToYaml(gw))
+		return nil, fmt.Errorf("gateway %v does not have all expected conditions, last recorded status messages: %q, %q", nsName, recordedAcceptedConditionMsg, recordedProgrammedConditionMsg)
 	}
 
 	t.Logf("Observed that gateway %v has been accepted: %+v", nsName, gw.Status)
@@ -851,21 +867,21 @@ func assertDNSRecord(t *testing.T, recordName types.NamespacedName) error {
 
 	err := wait.PollUntilContextTimeout(context.Background(), 1*time.Second, 1*time.Minute, false, func(context context.Context) (bool, error) {
 		if err := kclient.Get(context, recordName, dnsRecord); err != nil {
-			t.Logf("Failed to get DNSRecord %v: %v; retrying...", recordName, err)
+			t.Logf("[%s] Failed to get DNSRecord %v: %v; retrying...", time.Now().Format(time.DateTime), recordName, err)
 			return false, nil
 		}
 		// Determine the current state of the DNSRecord.
 		if len(dnsRecord.Status.Zones) > 0 {
 			for _, zone := range dnsRecord.Status.Zones {
 				for _, condition := range zone.Conditions {
 					if condition.Type == v1.DNSRecordPublishedConditionType && condition.Status == string(metav1.ConditionTrue) {
-						t.Logf("Found DNSRecord %v %s=%s", recordName, condition.Type, condition.Status)
+						t.Logf("[%s] Found DNSRecord %v %s=%s", time.Now().Format(time.DateTime), recordName, condition.Type, condition.Status)
 						return true, nil
 					}
 				}
 			}
 		}
-		t.Logf("Found DNSRecord %v but could not determine its readiness; retrying...", recordName)
+		t.Logf("[%s] Found DNSRecord %v but could not determine its readiness; retrying...", time.Now().Format(time.DateTime), recordName)
 		return false, nil
 	})
 	return err