diff --git a/pkg/l4lb/l4controller.go b/pkg/l4lb/l4controller.go index 6538534c3c..5963e5111d 100644 --- a/pkg/l4lb/l4controller.go +++ b/pkg/l4lb/l4controller.go @@ -197,10 +197,17 @@ func (l4c *L4Controller) shouldProcessService(service *v1.Service) bool { // processServiceCreateOrUpdate ensures load balancer resources for the given service, as needed. // Returns an error if processing the service update failed. -func (l4c *L4Controller) processServiceCreateOrUpdate(key string, service *v1.Service) *loadbalancers.L4ILBSyncResult { +func (l4c *L4Controller) processServiceCreateOrUpdate(service *v1.Service) *loadbalancers.L4ILBSyncResult { if !l4c.shouldProcessService(service) { return nil } + + startTime := time.Now() + klog.Infof("Syncing L4 ILB service %s/%s", service.Namespace, service.Name) + defer func() { + klog.Infof("Finished syncing L4 ILB service %s/%s, time taken: %v", service.Namespace, service.Name, time.Since(startTime)) + }() + // Ensure v2 finalizer if err := common.EnsureServiceFinalizer(service, common.ILBFinalizerV2, l4c.ctx.KubeClient); err != nil { return &loadbalancers.L4ILBSyncResult{Error: fmt.Errorf("Failed to attach finalizer to service %s/%s, err %w", service.Namespace, service.Name, err)} @@ -277,6 +284,12 @@ func (l4c *L4Controller) emitEnsuredDualStackEvent(service *v1.Service) { } func (l4c *L4Controller) processServiceDeletion(key string, svc *v1.Service) *loadbalancers.L4ILBSyncResult { + startTime := time.Now() + klog.Infof("Deleting L4 ILB service %s/%s", svc.Namespace, svc.Name) + defer func() { + klog.Infof("Finished deleting L4 ILB service %s/%s, time taken: %v", svc.Namespace, svc.Name, time.Since(startTime)) + }() + l4ilbParams := &loadbalancers.L4ILBParams{ Service: svc, Cloud: l4c.ctx.Cloud, @@ -367,7 +380,7 @@ func (l4c *L4Controller) sync(key string) error { // longer needing an ILB. if wantsILB, _ := annotations.WantsL4ILB(svc); wantsILB { klog.V(2).Infof("Ensuring ILB resources for service %s managed by L4 controller", key) - result = l4c.processServiceCreateOrUpdate(key, svc) + result = l4c.processServiceCreateOrUpdate(svc) if result == nil { // result will be nil if the service was ignored(due to presence of service controller finalizer). return nil diff --git a/pkg/l4lb/l4netlbcontroller.go b/pkg/l4lb/l4netlbcontroller.go index f3bf4cc692..62d4a4ba2a 100644 --- a/pkg/l4lb/l4netlbcontroller.go +++ b/pkg/l4lb/l4netlbcontroller.go @@ -426,6 +426,12 @@ func (lc *L4NetLBController) syncInternal(service *v1.Service) *loadbalancers.L4 return nil } + startTime := time.Now() + klog.Infof("Syncing L4 NetLB RBS service %s/%s", service.Namespace, service.Name) + defer func() { + klog.Infof("Finished syncing L4 NetLB RBS service %s/%s, time taken: %v", service.Namespace, service.Name, time.Since(startTime)) + }() + if err := common.EnsureServiceFinalizer(service, common.NetLBFinalizerV2, lc.ctx.KubeClient); err != nil { return &loadbalancers.L4NetLBSyncResult{Error: fmt.Errorf("Failed to attach L4 External LoadBalancer finalizer to service %s/%s, err %w", service.Namespace, service.Name, err)} } @@ -519,6 +525,12 @@ func (lc *L4NetLBController) ensureInstanceGroups(service *v1.Service, nodeNames // garbageCollectRBSNetLB cleans-up all gce resources related to service and removes NetLB finalizer func (lc *L4NetLBController) garbageCollectRBSNetLB(key string, svc *v1.Service) *loadbalancers.L4NetLBSyncResult { + startTime := time.Now() + klog.Infof("Deleting L4 NetLB RBS service %s/%s", svc.Namespace, svc.Name) + defer func() { + klog.Infof("Finished deleting L4 NetLB service %s/%s, time taken: %v", svc.Namespace, svc.Name, time.Since(startTime)) + }() + l4NetLBParams := &loadbalancers.L4NetLBParams{ Service: svc, Cloud: lc.ctx.Cloud, diff --git a/pkg/loadbalancers/forwarding_rules.go b/pkg/loadbalancers/forwarding_rules.go index 9f66bc0c3a..fcb5bb9013 100644 --- a/pkg/loadbalancers/forwarding_rules.go +++ b/pkg/loadbalancers/forwarding_rules.go @@ -194,13 +194,19 @@ func (l7 *L7) getEffectiveIP() (string, bool, error) { return "", true, nil } -// ensureForwardingRule creates a forwarding rule with the given name, if it does not exist. It updates the existing +// ensureIPv4ForwardingRule creates a forwarding rule with the given name, if it does not exist. It updates the existing // forwarding rule if needed. -func (l4 *L4) ensureForwardingRule(bsLink string, options gce.ILBOptions, existingFwdRule *composite.ForwardingRule, subnetworkURL, ipToUse string) (*composite.ForwardingRule, error) { +func (l4 *L4) ensureIPv4ForwardingRule(bsLink string, options gce.ILBOptions, existingFwdRule *composite.ForwardingRule, subnetworkURL, ipToUse string) (*composite.ForwardingRule, error) { // version used for creating the existing forwarding rule. version := meta.VersionGA frName := l4.GetFRName() + start := time.Now() + klog.V(2).Infof("Ensuring internal forwarding rule %s for L4 ILB Service %s/%s, backend service link: %s", frName, l4.Service.Namespace, l4.Service.Name, bsLink) + defer func() { + klog.V(2).Infof("Finished ensuring internal forwarding rule %s for L4 ILB Service %s/%s, time taken: %v", frName, l4.Service.Namespace, l4.Service.Name, time.Since(start)) + }() + servicePorts := l4.Service.Spec.Ports ports := utils.GetPorts(servicePorts) protocol := utils.GetProtocol(servicePorts) @@ -238,19 +244,19 @@ func (l4 *L4) ensureForwardingRule(bsLink string, options gce.ILBOptions, existi } if equal { // nothing to do - klog.V(2).Infof("ensureForwardingRule: Skipping update of unchanged forwarding rule - %s", fr.Name) + klog.V(2).Infof("ensureIPv4ForwardingRule: Skipping update of unchanged forwarding rule - %s", fr.Name) return existingFwdRule, nil } frDiff := cmp.Diff(existingFwdRule, fr) // If the forwarding rule pointed to a backend service which does not match the controller naming scheme, // that resouce could be leaked. It is not being deleted here because that is a user-managed resource. - klog.V(2).Infof("ensureForwardingRule: forwarding rule changed - Existing - %+v\n, New - %+v\n, Diff(-existing, +new) - %s\n. Deleting existing forwarding rule.", existingFwdRule, fr, frDiff) + klog.V(2).Infof("ensureIPv4ForwardingRule: forwarding rule changed - Existing - %+v\n, New - %+v\n, Diff(-existing, +new) - %s\n. Deleting existing forwarding rule.", existingFwdRule, fr, frDiff) if err = l4.forwardingRules.Delete(existingFwdRule.Name); err != nil { return nil, err } l4.recorder.Eventf(l4.Service, corev1.EventTypeNormal, events.SyncIngress, "ForwardingRule %q deleted", existingFwdRule.Name) } - klog.V(2).Infof("ensureForwardingRule: Creating/Recreating forwarding rule - %s", fr.Name) + klog.V(2).Infof("ensureIPv4ForwardingRule: Creating/Recreating forwarding rule - %s", fr.Name) if err = l4.forwardingRules.Create(fr); err != nil { return nil, err } @@ -271,9 +277,9 @@ func (l4netlb *L4NetLB) ensureExternalForwardingRule(bsLink string) (*composite. frName := l4netlb.GetFRName() start := time.Now() - klog.V(2).Infof("Ensuring external forwarding rule %s, backend service link: %s", frName, bsLink) + klog.V(2).Infof("Ensuring external forwarding rule %s for L4 NetLB Service %s/%s, backend service link: %s", l4netlb.Service.Namespace, l4netlb.Service.Name, frName, bsLink) defer func() { - klog.V(2).Infof("Finished ensuring external forwarding rule %s, time taken: %v", frName, time.Since(start)) + klog.V(2).Infof("Finished ensuring external forwarding rule %s for L4 NetLB Service %s/%s, time taken: %v", l4netlb.Service.Namespace, l4netlb.Service.Name, frName, time.Since(start)) }() // version used for creating the existing forwarding rule. diff --git a/pkg/loadbalancers/forwarding_rules_ipv6.go b/pkg/loadbalancers/forwarding_rules_ipv6.go index 187da00409..1b9f104212 100644 --- a/pkg/loadbalancers/forwarding_rules_ipv6.go +++ b/pkg/loadbalancers/forwarding_rules_ipv6.go @@ -18,6 +18,7 @@ package loadbalancers import ( "fmt" + "time" "github.com/GoogleCloudPlatform/k8s-cloud-provider/pkg/cloud" "github.com/google/go-cmp/cmp" @@ -36,6 +37,12 @@ func (l4 *L4) ensureIPv6ForwardingRule(bsLink string, options gce.ILBOptions) (* return nil, fmt.Errorf("l4.buildExpectedIPv6ForwardingRule(%s, %v) returned error %w, want nil", bsLink, options, err) } + start := time.Now() + klog.V(2).Infof("Ensuring internal ipv6 forwarding rule %s for L4 ILB Service %s/%s, backend service link: %s", expectedIPv6FwdRule.Name, l4.Service.Namespace, l4.Service.Name, bsLink) + defer func() { + klog.V(2).Infof("Finished ensuring internal ipv6 forwarding rule %s for L4 ILB Service %s/%s, time taken: %v", expectedIPv6FwdRule.Name, l4.Service.Namespace, l4.Service.Name, time.Since(start)) + }() + existingIPv6FwdRule, err := l4.forwardingRules.Get(expectedIPv6FwdRule.Name) if err != nil { return nil, fmt.Errorf("l4.forwardingRules.GetForwardingRule(%s) returned error %w, want nil", expectedIPv6FwdRule.Name, err) diff --git a/pkg/loadbalancers/l4.go b/pkg/loadbalancers/l4.go index e8a81556e9..11a0baabf8 100644 --- a/pkg/loadbalancers/l4.go +++ b/pkg/loadbalancers/l4.go @@ -115,7 +115,7 @@ func (l4 *L4) getILBOptions() gce.ILBOptions { // EnsureInternalLoadBalancerDeleted performs a cleanup of all GCE resources for the given loadbalancer service. func (l4 *L4) EnsureInternalLoadBalancerDeleted(svc *corev1.Service) *L4ILBSyncResult { - klog.V(2).Infof("EnsureInternalLoadBalancerDeleted(%s): attempting delete of load balancer resources", l4.NamespacedName.String()) + klog.V(2).Infof("EnsureInternalLoadBalancerDeleted(%s): deleting L4 ILB LoadBalancer resources", l4.NamespacedName.String()) result := &L4ILBSyncResult{SyncType: SyncTypeDelete, StartTime: time.Now()} l4.deleteIPv4ResourcesOnDelete(result) @@ -163,6 +163,7 @@ func (l4 *L4) EnsureInternalLoadBalancerDeleted(svc *corev1.Service) *L4ILBSyncR // If annotation was deleted, but resource still exists, it will be left till the Service deletion, // where we delete all resources, no matter if they exist in annotations. func (l4 *L4) deleteIPv4ResourcesOnSync(result *L4ILBSyncResult) { + klog.Infof("Deleting IPv4 resources for L4 ILB Service %s/%s on sync, with checking for existence in annotation", l4.Service.Namespace, l4.Service.Name) l4.deleteIPv4ResourcesAnnotationBased(result, false) } @@ -172,6 +173,7 @@ func (l4 *L4) deleteIPv4ResourcesOnSync(result *L4ILBSyncResult) { // so they could be leaked, if annotation was deleted. // That's why on service deletion we delete all IPv4 resources, ignoring their existence in annotations func (l4 *L4) deleteIPv4ResourcesOnDelete(result *L4ILBSyncResult) { + klog.Infof("Deleting IPv4 resources for L4 ILB Service %s/%s on delete, without checking for existence in annotation", l4.Service.Namespace, l4.Service.Name) l4.deleteIPv4ResourcesAnnotationBased(result, true) } @@ -184,9 +186,8 @@ func (l4 *L4) deleteIPv4ResourcesOnDelete(result *L4ILBSyncResult) { // This function does not delete Backend Service and Health Check, because they are shared between IPv4 and IPv6. // IPv4 Firewall Rule for Health Check also will not be deleted here, and will be left till the Service Deletion. func (l4 *L4) deleteIPv4ResourcesAnnotationBased(result *L4ILBSyncResult, shouldIgnoreAnnotations bool) { - frName := l4.GetFRName() if shouldIgnoreAnnotations || l4.hasAnnotation(annotations.TCPForwardingRuleKey) || l4.hasAnnotation(annotations.UDPForwardingRuleKey) { - err := l4.forwardingRules.Delete(frName) + err := l4.deleteIPv4ForwardingRule() if err != nil { klog.Errorf("Failed to delete forwarding rule for internal loadbalancer service %s, err %v", l4.NamespacedName.String(), err) result.Error = err @@ -196,7 +197,7 @@ func (l4 *L4) deleteIPv4ResourcesAnnotationBased(result *L4ILBSyncResult, should // Deleting non-existent address do not print error audit logs, and we don't store address in annotations // that's why we can delete it without checking annotation - err := ensureAddressDeleted(l4.cloud, frName, l4.cloud.Region()) + err := l4.deleteIPv4Address() if err != nil { klog.Errorf("Failed to delete address for internal loadbalancer service %s, err %v", l4.NamespacedName.String(), err) result.Error = err @@ -205,16 +206,51 @@ func (l4 *L4) deleteIPv4ResourcesAnnotationBased(result *L4ILBSyncResult, should // delete firewall rule allowing load balancer source ranges if shouldIgnoreAnnotations || l4.hasAnnotation(annotations.FirewallRuleKey) { - firewallName := l4.namer.L4Firewall(l4.Service.Namespace, l4.Service.Name) - err = l4.deleteFirewall(firewallName) + err := l4.deleteIPv4NodesFirewall() if err != nil { - klog.Errorf("Failed to delete firewall rule %s for internal loadbalancer service %s, err %v", firewallName, l4.NamespacedName.String(), err) + klog.Errorf("Failed to delete firewall rule for internal loadbalancer service %s, err %v", l4.NamespacedName.String(), err) result.GCEResourceInError = annotations.FirewallRuleResource result.Error = err } } } +func (l4 *L4) deleteIPv4ForwardingRule() error { + frName := l4.GetFRName() + + start := time.Now() + klog.Infof("Deleting IPv4 forwarding rule %s for L4 ILB Service %s/%s", frName, l4.Service.Namespace, l4.Service.Name) + defer func() { + klog.Infof("Finished deleting IPv4 forwarding rule %s for L4 ILB Service %s/%s, time taken: %v", frName, l4.Service.Namespace, l4.Service.Name, time.Since(start)) + }() + + return l4.forwardingRules.Delete(frName) +} + +func (l4 *L4) deleteIPv4Address() error { + addressName := l4.GetFRName() + + start := time.Now() + klog.Infof("Deleting IPv4 address %s for L4 ILB Service %s/%s", addressName, l4.Service.Namespace, l4.Service.Name) + defer func() { + klog.Infof("Finished deleting IPv4 address %s for L4 ILB Service %s/%s, time taken: %v", addressName, l4.Service.Namespace, l4.Service.Name, time.Since(start)) + }() + + return ensureAddressDeleted(l4.cloud, addressName, l4.cloud.Region()) +} + +func (l4 *L4) deleteIPv4NodesFirewall() error { + firewallName := l4.namer.L4Firewall(l4.Service.Namespace, l4.Service.Name) + + start := time.Now() + klog.Infof("Deleting IPv4 nodes firewall %s for L4 ILB Service %s/%s", firewallName, l4.Service.Namespace, l4.Service.Name) + defer func() { + klog.Infof("Finished deleting IPv4 nodes firewall %s for L4 ILB Service %s/%s, time taken: %v", firewallName, l4.Service.Namespace, l4.Service.Name, time.Since(start)) + }() + + return l4.deleteFirewall(firewallName) +} + func (l4 *L4) deleteFirewall(name string) error { err := firewalls.EnsureL4FirewallRuleDeleted(l4.cloud, name) if err != nil { @@ -352,9 +388,8 @@ func (l4 *L4) EnsureInternalLoadBalancer(nodeNames []string, svc *corev1.Service func (l4 *L4) provideHealthChecks(nodeNames []string, result *L4ILBSyncResult) string { if l4.enableDualStack { return l4.provideDualStackHealthChecks(nodeNames, result) - } else { - return l4.provideIPv4HealthChecks(nodeNames, result) } + return l4.provideIPv4HealthChecks(nodeNames, result) } func (l4 *L4) provideDualStackHealthChecks(nodeNames []string, result *L4ILBSyncResult) string { @@ -406,9 +441,9 @@ func (l4 *L4) ensureDualStackResources(result *L4ILBSyncResult, nodeNames []stri // - IPv4 Forwarding Rule // - IPv4 Firewall func (l4 *L4) ensureIPv4Resources(result *L4ILBSyncResult, nodeNames []string, options gce.ILBOptions, bs *composite.BackendService, existingFR *composite.ForwardingRule, subnetworkURL, ipToUse string) { - fr, err := l4.ensureForwardingRule(bs.SelfLink, options, existingFR, subnetworkURL, ipToUse) + fr, err := l4.ensureIPv4ForwardingRule(bs.SelfLink, options, existingFR, subnetworkURL, ipToUse) if err != nil { - klog.Errorf("EnsureInternalLoadBalancer: Failed to create forwarding rule - %v", err) + klog.Errorf("ensureIPv4Resources: Failed to ensure forwarding rule for L4 ILB Service %s/%s, error: %v", l4.Service.Namespace, l4.Service.Name, err) result.GCEResourceInError = annotations.ForwardingRuleResource result.Error = err return @@ -419,36 +454,52 @@ func (l4 *L4) ensureIPv4Resources(result *L4ILBSyncResult, nodeNames []string, o result.Annotations[annotations.UDPForwardingRuleKey] = fr.Name } - // ensure firewalls - sourceRanges, err := helpers.GetLoadBalancerSourceRanges(l4.Service) - if err != nil { - result.Error = err + l4.ensureIPv4NodesFirewall(nodeNames, fr.IPAddress, result) + if result.Error != nil { + klog.Errorf("ensureIPv4Resources: Failed to ensure nodes firewall for L4 ILB Service %s/%s, error: %v", l4.Service.Namespace, l4.Service.Name, err) return } + result.Status = utils.AddIPToLBStatus(result.Status, fr.IPAddress) +} + +func (l4 *L4) ensureIPv4NodesFirewall(nodeNames []string, ipAddress string, result *L4ILBSyncResult) { + start := time.Now() + firewallName := l4.namer.L4Firewall(l4.Service.Namespace, l4.Service.Name) servicePorts := l4.Service.Spec.Ports protocol := utils.GetProtocol(servicePorts) portRanges := utils.GetServicePortRanges(servicePorts) + + klog.V(2).Infof("Ensuring IPv4 nodes firewall %s for L4 ILB Service %s/%s, ipAddress: %s, protocol: %s, len(nodeNames): %v, portRanges: %v", firewallName, l4.Service.Namespace, l4.Service.Name, ipAddress, protocol, len(nodeNames), portRanges) + defer func() { + klog.V(2).Infof("Finished ensuring IPv4 nodes firewall %s for L4 ILB Service %s/%s, time taken: %v", firewallName, l4.Service.Namespace, l4.Service.Name, time.Since(start)) + }() + + // ensure firewalls + sourceRanges, err := helpers.GetLoadBalancerSourceRanges(l4.Service) + if err != nil { + result.Error = err + return + } // Add firewall rule for ILB traffic to nodes nodesFWRParams := firewalls.FirewallParams{ PortRanges: portRanges, SourceRanges: sourceRanges.StringSlice(), - DestinationRanges: []string{fr.IPAddress}, + DestinationRanges: []string{ipAddress}, Protocol: string(protocol), Name: firewallName, NodeNames: nodeNames, L4Type: utils.ILB, } - if err := firewalls.EnsureL4LBFirewallForNodes(l4.Service, &nodesFWRParams, l4.cloud, l4.recorder); err != nil { + err = firewalls.EnsureL4LBFirewallForNodes(l4.Service, &nodesFWRParams, l4.cloud, l4.recorder) + if err != nil { result.GCEResourceInError = annotations.FirewallRuleResource result.Error = err return } result.Annotations[annotations.FirewallRuleKey] = firewallName - - result.Status = utils.AddIPToLBStatus(result.Status, fr.IPAddress) } func (l4 *L4) getServiceSubnetworkURL(options gce.ILBOptions) (string, error) { diff --git a/pkg/loadbalancers/l4ipv6.go b/pkg/loadbalancers/l4ipv6.go index 4478f134fe..11a2b476fc 100644 --- a/pkg/loadbalancers/l4ipv6.go +++ b/pkg/loadbalancers/l4ipv6.go @@ -18,6 +18,7 @@ package loadbalancers import ( "strings" + "time" corev1 "k8s.io/api/core/v1" "k8s.io/ingress-gce/pkg/annotations" @@ -35,7 +36,7 @@ import ( func (l4 *L4) ensureIPv6Resources(syncResult *L4ILBSyncResult, nodeNames []string, options gce.ILBOptions, bsLink string) { ipv6fr, err := l4.ensureIPv6ForwardingRule(bsLink, options) if err != nil { - klog.Errorf("ensureIPv6Resources: Failed to create ipv6 forwarding rule - %v", err) + klog.Errorf("ensureIPv6Resources: Failed to ensure ipv6 forwarding rule - %v", err) syncResult.GCEResourceInError = annotations.ForwardingRuleIPv6Resource syncResult.Error = err return @@ -47,14 +48,11 @@ func (l4 *L4) ensureIPv6Resources(syncResult *L4ILBSyncResult, nodeNames []strin syncResult.Annotations[annotations.UDPForwardingRuleIPv6Key] = ipv6fr.Name } - firewallName := l4.namer.L4IPv6Firewall(l4.Service.Namespace, l4.Service.Name) - err = l4.ensureIPv6Firewall(ipv6fr, firewallName, nodeNames) - if err != nil { - syncResult.GCEResourceInError = annotations.FirewallRuleIPv6Resource - syncResult.Error = err + l4.ensureIPv6NodesFirewall(ipv6fr, nodeNames, syncResult) + if syncResult.Error != nil { + klog.Errorf("ensureIPv6Resources: Failed to ensure ipv6 nodes firewall for L4 ILB - %v", err) return } - syncResult.Annotations[annotations.FirewallRuleIPv6Key] = firewallName trimmedIPv6Address := strings.Split(ipv6fr.IPAddress, "/")[0] syncResult.Status = utils.AddIPToLBStatus(syncResult.Status, trimmedIPv6Address) @@ -67,6 +65,7 @@ func (l4 *L4) ensureIPv6Resources(syncResult *L4ILBSyncResult, nodeNames []strin // If annotation was deleted, but resource still exists, it will be left till the Service deletion, // where we delete all resources, no matter if they exist in annotations. func (l4 *L4) deleteIPv6ResourcesOnSync(syncResult *L4ILBSyncResult) { + klog.Infof("Deleting IPv6 resources for L4 ILB Service %s/%s on sync, with checking for existence in annotation", l4.Service.Namespace, l4.Service.Name) l4.deleteIPv6ResourcesAnnotationBased(syncResult, true) } @@ -76,6 +75,7 @@ func (l4 *L4) deleteIPv6ResourcesOnSync(syncResult *L4ILBSyncResult) { // so they could be leaked, if annotation was deleted. // That's why on service deletion we delete all IPv4 resources, ignoring their existence in annotations func (l4 *L4) deleteIPv6ResourcesOnDelete(syncResult *L4ILBSyncResult) { + klog.Infof("Deleting IPv6 resources for L4 ILB Service %s/%s on delete, without checking for existence in annotation", l4.Service.Namespace, l4.Service.Name) l4.deleteIPv6ResourcesAnnotationBased(syncResult, false) } @@ -98,7 +98,7 @@ func (l4 *L4) deleteIPv6ResourcesAnnotationBased(syncResult *L4ILBSyncResult, sh } if !shouldCheckAnnotations || l4.hasAnnotation(annotations.FirewallRuleIPv6Key) { - err := l4.deleteIPv6Firewall() + err := l4.deleteIPv6NodesFirewall() if err != nil { klog.Errorf("Failed to delete ipv6 firewall rule for internal loadbalancer service %s, err %v", l4.NamespacedName.String(), err) syncResult.GCEResourceInError = annotations.FirewallRuleIPv6Resource @@ -116,11 +116,20 @@ func (l4 *L4) getIPv6FRNameWithProtocol(protocol string) string { return l4.namer.L4IPv6ForwardingRule(l4.Service.Namespace, l4.Service.Name, strings.ToLower(protocol)) } -func (l4 *L4) ensureIPv6Firewall(forwardingRule *composite.ForwardingRule, firewallName string, nodeNames []string) error { +func (l4 *L4) ensureIPv6NodesFirewall(forwardingRule *composite.ForwardingRule, nodeNames []string, result *L4ILBSyncResult) { + start := time.Now() + + firewallName := l4.namer.L4IPv6Firewall(l4.Service.Namespace, l4.Service.Name) + svcPorts := l4.Service.Spec.Ports portRanges := utils.GetServicePortRanges(svcPorts) protocol := utils.GetProtocol(svcPorts) + klog.V(2).Infof("Ensuring IPv6 nodes firewall %s for L4 ILB Service %s/%s, ipAddress: %s, protocol: %s, len(nodeNames): %v, portRanges: %v", firewallName, l4.Service.Namespace, l4.Service.Name, forwardingRule.IPAddress, protocol, len(nodeNames), portRanges) + defer func() { + klog.V(2).Infof("Finished ensuring IPv6 nodes firewall %s for L4 ILB Service %s/%s, time taken: %v", l4.Service.Namespace, l4.Service.Name, firewallName, time.Since(start)) + }() + ipv6nodesFWRParams := firewalls.FirewallParams{ PortRanges: portRanges, // TODO(panslava): support .spec.loadBalancerSourceRanges @@ -132,15 +141,35 @@ func (l4 *L4) ensureIPv6Firewall(forwardingRule *composite.ForwardingRule, firew L4Type: utils.ILB, } - return firewalls.EnsureL4LBFirewallForNodes(l4.Service, &ipv6nodesFWRParams, l4.cloud, l4.recorder) + err := firewalls.EnsureL4LBFirewallForNodes(l4.Service, &ipv6nodesFWRParams, l4.cloud, l4.recorder) + if err != nil { + result.GCEResourceInError = annotations.FirewallRuleIPv6Resource + result.Error = err + return + } + result.Annotations[annotations.FirewallRuleIPv6Key] = firewallName } func (l4 *L4) deleteIPv6ForwardingRule() error { ipv6FrName := l4.getIPv6FRName() + + start := time.Now() + klog.V(2).Infof("Deleting IPv6 forwarding rule %s for L4 ILB Service %s/%s", ipv6FrName, l4.Service.Namespace, l4.Service.Name) + defer func() { + klog.V(2).Infof("Finished deleting IPv6 forwarding rule %s for L4 ILB Service %s/%s, time taken: %v", ipv6FrName, l4.Service.Namespace, l4.Service.Name, time.Since(start)) + }() + return l4.forwardingRules.Delete(ipv6FrName) } -func (l4 *L4) deleteIPv6Firewall() error { +func (l4 *L4) deleteIPv6NodesFirewall() error { ipv6FirewallName := l4.namer.L4IPv6Firewall(l4.Service.Namespace, l4.Service.Name) + + start := time.Now() + klog.V(2).Infof("Deleting IPv6 nodes firewall %s for L4 ILB Service %s/%s", ipv6FirewallName, l4.Service.Namespace, l4.Service.Name) + defer func() { + klog.V(2).Infof("Finished deleting IPv6 nodes firewall %s for L4 ILB Service %s/%s, time taken: %v", ipv6FirewallName, l4.Service.Namespace, l4.Service.Name, time.Since(start)) + }() + return l4.deleteFirewall(ipv6FirewallName) } diff --git a/pkg/loadbalancers/l4netlb.go b/pkg/loadbalancers/l4netlb.go index debe231d52..5d39659ef2 100644 --- a/pkg/loadbalancers/l4netlb.go +++ b/pkg/loadbalancers/l4netlb.go @@ -248,9 +248,9 @@ func (l4netlb *L4NetLB) deleteBackendService(result *L4NetLBSyncResult) { func (l4netlb *L4NetLB) deleteHealthChecksWithFirewall(result *L4NetLBSyncResult) { start := time.Now() - klog.V(2).Infof("Deleting all health checks and firewalls for health checks for service %s/%s", l4netlb.Service.Namespace, l4netlb.Service.Name) + klog.V(2).Infof("Deleting all health checks and firewalls for health checks for L4 NetLB service %s/%s", l4netlb.Service.Namespace, l4netlb.Service.Name) defer func() { - klog.V(2).Infof("Finished deleting all health checks and firewalls for health checks for service %s/%s, time taken: %v", l4netlb.Service.Namespace, l4netlb.Service.Name, time.Since(start)) + klog.V(2).Infof("Finished deleting all health checks and firewalls for health checks for for L4 NetLB service %s/%s, time taken: %v", l4netlb.Service.Namespace, l4netlb.Service.Name, time.Since(start)) }() // Delete healthcheck @@ -278,9 +278,9 @@ func (l4netlb *L4NetLB) GetFRName() string { func (l4netlb *L4NetLB) ensureNodesFirewall(name string, nodeNames []string, ipAddress string, portRanges []string, protocol string) *L4NetLBSyncResult { start := time.Now() - klog.V(2).Infof("Ensuring l4 NetLB nodes firewall %s, ipAddress: %s, protocol: %s, len(nodeNames): %v, portRanges: %v", name, ipAddress, protocol, len(nodeNames), portRanges) + klog.V(2).Infof("Ensuring nodes firewall %s for L4 NetLB Service, ipAddress: %s, protocol: %s, len(nodeNames): %v, portRanges: %v", name, l4netlb.Service.Namespace, l4netlb.Service.Name, ipAddress, protocol, len(nodeNames), portRanges) defer func() { - klog.V(2).Infof("Finished ensuring l4 NetLB nodes firewall %s, time taken: %v", name, time.Since(start)) + klog.V(2).Infof("Finished ensuring nodes firewall %s for L4 NetLB Service, time taken: %v", name, l4netlb.Service.Namespace, l4netlb.Service.Name, time.Since(start)) }() result := &L4NetLBSyncResult{}