diff --git a/pkg/operator/controller/gateway-service-dns/controller.go b/pkg/operator/controller/gateway-service-dns/controller.go index f15f559bd5..40ce839566 100644 --- a/pkg/operator/controller/gateway-service-dns/controller.go +++ b/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 } diff --git a/pkg/resources/dnsrecord/dns.go b/pkg/resources/dnsrecord/dns.go index 79fc6f1990..b0dbea880e 100644 --- a/pkg/resources/dnsrecord/dns.go +++ b/pkg/resources/dnsrecord/dns.go @@ -77,15 +77,17 @@ func EnsureDNSRecord(client client.Client, name types.NamespacedName, dnsRecordL if err := client.Create(context.TODO(), desired); err != nil { return false, nil, fmt.Errorf("failed to create dnsrecord %s/%s: %v", desired.Namespace, desired.Name, err) } - log.Info("created dnsrecord", "dnsrecord", desired) + log.Info("Created dnsrecord", "dnsrecord", desired) return CurrentDNSRecord(client, name) case wantWC && haveWC: 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", "service", service) 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.Error(nil, "Both load balancer hostname and IP are set", "dnsrecord", name, "service", service.Name) return false, nil } diff --git a/test/e2e/util_gatewayapi_test.go b/test/e2e/util_gatewayapi_test.go index 6c7cd022fe..002a258a14 100644 --- a/test/e2e/util_gatewayapi_test.go +++ b/test/e2e/util_gatewayapi_test.go @@ -594,10 +594,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 } @@ -609,30 +610,58 @@ func assertGatewaySuccessful(t *testing.T, namespace, name string) (*gatewayapiv gw := &gatewayapiv1.Gateway{} nsName := types.NamespacedName{Namespace: namespace, Name: name} - recordedConditionMsg := "not found" + recordedAcceptedConditionMsg, recordedProgrammedConditionMsg := "", "" - err := wait.PollUntilContextTimeout(context.Background(), 1*time.Second, 1*time.Minute, false, func(context context.Context) (bool, error) { + // Wait for the gateway to be accepted and programmed. + // Load balancer provisioning can take several minutes on some platforms. + // Therefore, a timeout of 3 minutes is set to accommodate potential delays. + 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 + t.Logf("[%s] Found gateway %v as Accepted", time.Now().Format(time.DateTime), nsName) + 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("[%s] Found gateway %v as Programmed", time.Now().Format(time.DateTime), nsName) + programmedConditionFound = true } } } + if acceptedConditionFound && programmedConditionFound { + return true, nil + } + t.Logf("[%s] Not all expected gateway conditions are found, checking gateway service...", time.Now().Format(time.DateTime)) + + // The creation of the gateway service may be delayed. + // Check the current status of the service to see where we are. + svc := &corev1.Service{} + svcNsName := types.NamespacedName{Namespace: namespace, Name: gw.Name + "-" + string(gw.Spec.GatewayClassName)} + if err := kclient.Get(context, svcNsName, svc); err != nil { + t.Logf("Failed to get gateway service %v: %v; retrying...", svcNsName, err) + return false, nil + } + t.Logf("[%s] Found gateway service: %+v", time.Now().Format(time.DateTime), svc) 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 status messages for Accepted: %q, Programmed: %q", nsName, recordedAcceptedConditionMsg, recordedProgrammedConditionMsg) } - t.Logf("Observed that gateway %v has been accepted: %+v", nsName, gw.Status) + t.Logf("[%s] Observed that gateway %v has been accepted: %+v", time.Now().Format(time.DateTime), nsName, gw.Status) return gw, nil } @@ -1037,21 +1066,27 @@ func assertDNSRecord(t *testing.T, recordName types.NamespacedName) error { err := wait.PollUntilContextTimeout(context.Background(), 10*time.Second, 10*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. + reason := "missing published condition" 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) - return true, nil + if condition.Type == v1.DNSRecordPublishedConditionType { + reason = "unexpected published condition value" + if condition.Status == string(metav1.ConditionTrue) { + t.Logf("[%s] Found DNSRecord %v %s=%s", time.Now().Format(time.DateTime), recordName, condition.Type, condition.Status) + return true, nil + } } } } + } else { + reason = "missing zones" } - 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 due to %s; retrying...", time.Now().Format(time.DateTime), recordName, reason) return false, nil }) return err