Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add more logs to L4 NetLB #1845

Merged
merged 4 commits into from
Oct 25, 2022
Merged

Add more logs to L4 NetLB #1845

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
4fc49ba
Cleanup EnsureL4BackendService function
panslava Oct 24, 2022
3cb2595
Add logs to health checks + small refactor
panslava Oct 24, 2022
1063a36
Refactor l4netlb deletion. Create function for each resource
panslava Oct 24, 2022
9717abe
Add more logs to l4netlb
panslava Oct 24, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 11 additions & 3 deletions pkg/backends/backends.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ package backends
import (
"fmt"
"net/http"
"time"

"github.com/GoogleCloudPlatform/k8s-cloud-provider/pkg/cloud/meta"
"google.golang.org/api/compute/v1"
Expand Down Expand Up @@ -283,7 +284,13 @@ func (b *Backends) DeleteSignedUrlKey(be *composite.BackendService, keyName stri
}

// EnsureL4BackendService creates or updates the backend service with the given name.
func (b *Backends) EnsureL4BackendService(name, hcLink, protocol, sessionAffinity, scheme string, nm types.NamespacedName, version meta.Version) (*composite.BackendService, error) {
func (b *Backends) EnsureL4BackendService(name, hcLink, protocol, sessionAffinity, scheme string, nm types.NamespacedName) (*composite.BackendService, error) {
start := time.Now()
klog.V(2).Infof("EnsureL4BackendService(%v, %v, %v): started", name, scheme, protocol)
defer func() {
klog.V(2).Infof("EnsureL4BackendService(%v, %v, %v): finished, time taken: %v", name, scheme, protocol, time.Since(start))
}()

klog.V(2).Infof("EnsureL4BackendService(%v, %v, %v): checking existing backend service", name, scheme, protocol)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this log is now redundant

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not really, we can remove, but it gives info about what step is happening (checking existing backend service)

key, err := composite.CreateKey(b.cloud, name, meta.Regional)
if err != nil {
Expand All @@ -300,11 +307,11 @@ func (b *Backends) EnsureL4BackendService(name, hcLink, protocol, sessionAffinit
}
expectedBS := &composite.BackendService{
Name: name,
Protocol: string(protocol),
Protocol: protocol,
Description: desc,
HealthChecks: []string{hcLink},
SessionAffinity: utils.TranslateAffinityType(sessionAffinity),
LoadBalancingScheme: string(scheme),
LoadBalancingScheme: scheme,
}
if protocol == string(api_v1.ProtocolTCP) {
expectedBS.ConnectionDraining = &composite.ConnectionDraining{DrainingTimeoutSec: DefaultConnectionDrainingTimeoutSeconds}
panslava marked this conversation as resolved.
Show resolved Hide resolved
Expand All @@ -328,6 +335,7 @@ func (b *Backends) EnsureL4BackendService(name, hcLink, protocol, sessionAffinit
}

if backendSvcEqual(expectedBS, bs) {
klog.V(2).Infof("EnsureL4BackendService: backend service %s did not change, skipping update", name)
return bs, nil
}
if bs.ConnectionDraining != nil && bs.ConnectionDraining.DrainingTimeoutSec > 0 && protocol == string(api_v1.ProtocolTCP) {
Expand Down
3 changes: 1 addition & 2 deletions pkg/backends/regional_ig_linker_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,6 @@ import (
"testing"

"github.com/GoogleCloudPlatform/k8s-cloud-provider/pkg/cloud"
"github.com/GoogleCloudPlatform/k8s-cloud-provider/pkg/cloud/meta"
"github.com/GoogleCloudPlatform/k8s-cloud-provider/pkg/cloud/mock"
apiv1 "k8s.io/api/core/v1"
"k8s.io/apimachinery/pkg/types"
Expand Down Expand Up @@ -139,7 +138,7 @@ func createBackendService(t *testing.T, sp utils.ServicePort, backendPool *Backe
t.Helper()
namespacedName := types.NamespacedName{Name: "service.Name", Namespace: "service.Namespace"}
protocol := string(apiv1.ProtocolTCP)
if _, err := backendPool.EnsureL4BackendService(sp.BackendName(), hcLink, protocol, string(apiv1.ServiceAffinityNone), string(cloud.SchemeExternal), namespacedName, meta.VersionGA); err != nil {
if _, err := backendPool.EnsureL4BackendService(sp.BackendName(), hcLink, protocol, string(apiv1.ServiceAffinityNone), string(cloud.SchemeExternal), namespacedName); err != nil {
t.Fatalf("Error creating backend service %v", err)
}
}
110 changes: 73 additions & 37 deletions pkg/healthchecksl4/healthchecksl4.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ import (
"fmt"
"strconv"
"sync"
"time"

"github.com/GoogleCloudPlatform/k8s-cloud-provider/pkg/cloud/meta"
corev1 "k8s.io/api/core/v1"
Expand All @@ -46,8 +47,6 @@ const (
gceSharedHcUnhealthyThreshold = int64(3) // 3 * 8 = 24 seconds before the LB will steer traffic away
gceLocalHcUnhealthyThreshold = int64(2) // 2 * 3 = 6 seconds before the LB will steer traffic away
L4ILBIPv6HCRange = "2600:2d00:1:b029::/64"
shouldHandleIPV6 = true
shouldHandleIPV4 = true
)

var (
Expand Down Expand Up @@ -120,18 +119,19 @@ func (l4hc *l4HealthChecks) EnsureHealthCheckWithDualStackFirewalls(svc *corev1.

hcName := namer.L4HealthCheck(svc.Namespace, svc.Name, sharedHC)
hcPath, hcPort := helpers.GetServiceHealthCheckPathPort(svc)
klog.V(3).Infof("Ensuring L4 healthcheck: %s for service %s, shared: %v.", hcName, namespacedName.String(), sharedHC)
klog.V(3).Infof("Ensuring L4 healthcheck %s with firewalls for service %s, shared: %v.", hcName, namespacedName.String(), sharedHC)

if sharedHC {
hcPath, hcPort = gce.GetNodesHealthCheckPath(), gce.GetNodesHealthCheckPort()
// We need to acquire a controller-wide mutex to ensure that in the case of a healthcheck shared between loadbalancers that the sync of the GCE resources is not performed in parallel.
l4hc.sharedResourcesLock.Lock()
defer l4hc.sharedResourcesLock.Unlock()
}
klog.V(3).Infof("L4 Healthcheck %s, path: %q, port %d", hcName, hcPath, hcPort)
klog.V(3).Infof("L4 Healthcheck %s, expected path: %q, expected port %d", hcName, hcPath, hcPort)

hcLink, err := l4hc.ensureHealthCheck(hcName, namespacedName, sharedHC, hcPath, hcPort, scope, l4Type)
if err != nil {
klog.Errorf("Error while ensuring hc %s, error: %v", hcName, err)
return &EnsureHealthCheckResult{
GceResourceInError: annotations.HealthcheckResource,
Err: err,
Expand All @@ -144,35 +144,25 @@ func (l4hc *l4HealthChecks) EnsureHealthCheckWithDualStackFirewalls(svc *corev1.
}

if needsIPv4 {
hcFwName := namer.L4HealthCheckFirewall(svc.Namespace, svc.Name, sharedHC)
klog.V(3).Infof("Ensuring IPv4 firewall rule %s for health check %s for service %s", hcFwName, hcName, namespacedName.String())
err = l4hc.ensureIPv4Firewall(svc, hcFwName, hcPort, sharedHC, nodeNames)
if err != nil {
return &EnsureHealthCheckResult{
GceResourceInError: annotations.FirewallForHealthcheckResource,
Err: err,
}
}
hcResult.HCFirewallRuleName = hcFwName
klog.V(3).Infof("Ensuring IPv4 firewall rule for health check %s for service %s", hcName, namespacedName.String())
l4hc.ensureIPv4Firewall(svc, namer, hcPort, sharedHC, nodeNames, hcResult)
}

if needsIPv6 {
ipv6HCFWName := namer.L4IPv6HealthCheckFirewall(svc.Namespace, svc.Name, sharedHC)
klog.V(3).Infof("Ensuring IPv6 firewall rule %s for health check %s for service %s", ipv6HCFWName, hcName, namespacedName.String())
err = l4hc.ensureIPv6Firewall(svc, ipv6HCFWName, hcPort, sharedHC, nodeNames)
if err != nil {
return &EnsureHealthCheckResult{
GceResourceInError: annotations.FirewallForHealthcheckIPv6Resource,
Err: err,
}
}
hcResult.HCFirewallRuleIPv6Name = ipv6HCFWName
klog.V(3).Infof("Ensuring IPv6 firewall rule for health check %s for service %s", hcName, namespacedName.String())
l4hc.ensureIPv6Firewall(svc, namer, hcPort, sharedHC, nodeNames, hcResult)
}

return hcResult
}

func (l4hc *l4HealthChecks) ensureHealthCheck(hcName string, svcName types.NamespacedName, shared bool, path string, port int32, scope meta.KeyType, l4Type utils.L4LBType) (string, error) {
start := time.Now()
klog.V(2).Infof("Ensuring healthcheck %s for service %s, shared = %v, path = %s, port = %d, scope = %s, l4Type = %s", hcName, svcName, shared, path, port, scope, l4Type)
defer func() {
klog.V(2).Infof("Finished ensuring healthcheck %s for service %s, time taken: %v", hcName, svcName, time.Since(start))
}()

hc, err := l4hc.hcProvider.Get(hcName, scope)
if err != nil {
return "", err
Expand Down Expand Up @@ -200,7 +190,7 @@ func (l4hc *l4HealthChecks) ensureHealthCheck(hcName string, svcName types.Names
selfLink := hc.SelfLink
if !needToUpdateHealthChecks(hc, expectedHC) {
// nothing to do
klog.V(3).Infof("Healthcheck %v already exists", hcName)
klog.V(3).Infof("Healthcheck %s already exists and does not require update", hcName)
return selfLink, nil
}
mergeHealthChecks(hc, expectedHC)
Expand All @@ -216,26 +206,56 @@ func (l4hc *l4HealthChecks) ensureHealthCheck(hcName string, svcName types.Names
//
// L4 ILB and L4 NetLB Services with ExternalTrafficPolicy=Cluster use the same firewall
// rule at global scope.
func (l4hc *l4HealthChecks) ensureIPv4Firewall(svc *corev1.Service, hcFwName string, hcPort int32, sharedHC bool, nodeNames []string) error {
func (l4hc *l4HealthChecks) ensureIPv4Firewall(svc *corev1.Service, namer namer.L4ResourcesNamer, hcPort int32, isSharedHC bool, nodeNames []string, hcResult *EnsureHealthCheckResult) {
Copy link
Contributor

@code-elinka code-elinka Oct 24, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like the old way of returning the error more than not returning it.
Pros of the old approach:

  • easier to test
  • you can customize log messages based on error

Cons:

  • you need to check for an error everywhere, where you use this function

Copy link
Contributor Author

@panslava panslava Oct 24, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree, I also like returning errors...
I find the main problem is -- we use single EnsureHealthCheckResult for storing too much stuff. We should not store error there. Even if we want more context about errors (like now we use GceResourceInError), we should just create custom error type
But changing this will require changing too much logic...
hcResult also stores HCFirewallRuleName, that's why I passed it here, cause I don't want to create firewallName on the level above...

Copy link
Contributor

@code-elinka code-elinka Oct 24, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I see. Yes, I tried to find a nice way to handle it and I would rather keep the error logic inside of the function. Thank you for the reasoning 👍

hcFwName := namer.L4HealthCheckFirewall(svc.Namespace, svc.Name, isSharedHC)

start := time.Now()
klog.V(2).Infof("Ensuring IPv4 Firewall %s for health check for service %s/%s, health check port %s, shared health check: %t, len(nodeNames): %d", hcFwName, svc.Namespace, svc.Name, hcPort, isSharedHC, len(nodeNames))
defer func() {
klog.V(2).Infof("Finished ensuring IPv4 firewall %s for service %s/%s, time taken %v", hcFwName, svc.Namespace, svc.Name, time.Since(start))
}()

hcFWRParams := firewalls.FirewallParams{
PortRanges: []string{strconv.Itoa(int(hcPort))},
SourceRanges: gce.L4LoadBalancerSrcRanges(),
Protocol: string(corev1.ProtocolTCP),
Name: hcFwName,
NodeNames: nodeNames,
}
return firewalls.EnsureL4LBFirewallForHc(svc, sharedHC, &hcFWRParams, l4hc.cloud, l4hc.recorder)
err := firewalls.EnsureL4LBFirewallForHc(svc, isSharedHC, &hcFWRParams, l4hc.cloud, l4hc.recorder)
if err != nil {
klog.Errorf("Error ensuring IPv4 Firewall %s for health check for service %s/%s, error %v", hcFwName, svc.Namespace, svc.Name, err)
hcResult.GceResourceInError = annotations.FirewallForHealthcheckResource
hcResult.Err = err
return
}
hcResult.HCFirewallRuleName = hcFwName
}

func (l4hc *l4HealthChecks) ensureIPv6Firewall(svc *corev1.Service, ipv6HCFWName string, hcPort int32, isSharedHC bool, nodeNames []string) error {
func (l4hc *l4HealthChecks) ensureIPv6Firewall(svc *corev1.Service, namer namer.L4ResourcesNamer, hcPort int32, isSharedHC bool, nodeNames []string, hcResult *EnsureHealthCheckResult) {
ipv6HCFWName := namer.L4IPv6HealthCheckFirewall(svc.Namespace, svc.Name, isSharedHC)

start := time.Now()
klog.V(2).Infof("Ensuring IPv6 Firewall %s for health check for service %s/%s, health check port %s, shared health check: %t, len(nodeNames): %d", ipv6HCFWName, svc.Namespace, svc.Name, hcPort, isSharedHC, len(nodeNames))
defer func() {
klog.V(2).Infof("Finished ensuring IPv6 firewall %s for service %s/%s, time taken %v", ipv6HCFWName, svc.Namespace, svc.Name, time.Since(start))
}()

hcFWRParams := firewalls.FirewallParams{
PortRanges: []string{strconv.Itoa(int(hcPort))},
SourceRanges: []string{L4ILBIPv6HCRange},
Protocol: string(corev1.ProtocolTCP),
Name: ipv6HCFWName,
NodeNames: nodeNames,
}
return firewalls.EnsureL4LBFirewallForHc(svc, isSharedHC, &hcFWRParams, l4hc.cloud, l4hc.recorder)
err := firewalls.EnsureL4LBFirewallForHc(svc, isSharedHC, &hcFWRParams, l4hc.cloud, l4hc.recorder)
if err != nil {
klog.Errorf("Error ensuring IPv6 Firewall %s for health check for service %s/%s, error %v", ipv6HCFWName, svc.Namespace, svc.Name, err)
hcResult.GceResourceInError = annotations.FirewallForHealthcheckIPv6Resource
hcResult.Err = err
return
}
hcResult.HCFirewallRuleIPv6Name = ipv6HCFWName
}

func (l4hc *l4HealthChecks) DeleteHealthCheckWithFirewall(svc *corev1.Service, namer namer.L4ResourcesNamer, sharedHC bool, scope meta.KeyType, l4Type utils.L4LBType) (string, error) {
Expand Down Expand Up @@ -282,7 +302,13 @@ func (l4hc *l4HealthChecks) deleteHealthCheckWithDualStackFirewalls(svc *corev1.

func (l4hc *l4HealthChecks) deleteHealthCheck(svc *corev1.Service, namer namer.L4ResourcesNamer, sharedHC bool, scope meta.KeyType) (bool, error) {
hcName := namer.L4HealthCheck(svc.Namespace, svc.Name, sharedHC)

start := time.Now()
klog.V(3).Infof("Deleting L4 healthcheck %s for service %s/%s, shared: %v, scope: %v", hcName, svc.Namespace, svc.Name, sharedHC, scope)
defer func() {
klog.V(3).Infof("Finished deleting L4 healthcheck %s for service %s/%s, time taken: %v", hcName, svc.Namespace, svc.Name, time.Since(start))
}()

err := l4hc.hcProvider.Delete(hcName, scope)
if err != nil {
// Ignore deletion error due to health check in use by another resource.
Expand All @@ -296,20 +322,30 @@ func (l4hc *l4HealthChecks) deleteHealthCheck(svc *corev1.Service, namer namer.L
return true, nil
}

func (l4hc *l4HealthChecks) deleteIPv4HealthCheckFirewall(svc *corev1.Service, namer namer.L4ResourcesNamer, sharedHC bool, l4type utils.L4LBType) (string, error) {
hcName := namer.L4HealthCheck(svc.Namespace, svc.Name, sharedHC)
hcFwName := namer.L4HealthCheckFirewall(svc.Namespace, svc.Name, sharedHC)
func (l4hc *l4HealthChecks) deleteIPv4HealthCheckFirewall(svc *corev1.Service, namer namer.L4ResourcesNamer, isSharedHC bool, l4type utils.L4LBType) (string, error) {
hcName := namer.L4HealthCheck(svc.Namespace, svc.Name, isSharedHC)
hcFwName := namer.L4HealthCheckFirewall(svc.Namespace, svc.Name, isSharedHC)

start := time.Now()
klog.V(3).Infof("Deleting IPv4 Firewall %s for health check %s", hcFwName, hcName)
return l4hc.deleteHealthCheckFirewall(svc, hcName, hcFwName, sharedHC, l4type)
defer func() {
klog.V(3).Infof("Finished deleting IPv4 Firewall %s for health check %s, time taken: %v", hcFwName, hcName, time.Since(start))
}()

return l4hc.deleteHealthCheckFirewall(svc, hcName, hcFwName, isSharedHC, l4type)
}

func (l4hc *l4HealthChecks) deleteIPv6HealthCheckFirewall(svc *corev1.Service, namer namer.L4ResourcesNamer, sharedHC bool, l4type utils.L4LBType) (string, error) {
hcName := namer.L4HealthCheck(svc.Namespace, svc.Name, sharedHC)
ipv6hcFwName := namer.L4IPv6HealthCheckFirewall(svc.Namespace, svc.Name, sharedHC)
func (l4hc *l4HealthChecks) deleteIPv6HealthCheckFirewall(svc *corev1.Service, namer namer.L4ResourcesNamer, isSharedHC bool, l4type utils.L4LBType) (string, error) {
hcName := namer.L4HealthCheck(svc.Namespace, svc.Name, isSharedHC)
ipv6hcFwName := namer.L4IPv6HealthCheckFirewall(svc.Namespace, svc.Name, isSharedHC)

start := time.Now()
klog.V(3).Infof("Deleting IPv6 Firewall %s for health check %s", ipv6hcFwName, hcName)
return l4hc.deleteHealthCheckFirewall(svc, hcName, ipv6hcFwName, sharedHC, l4type)
defer func() {
klog.V(3).Infof("Finished deleting IPv6 Firewall %s for health check %s, time taken: %v", ipv6hcFwName, hcName, time.Since(start))
}()

return l4hc.deleteHealthCheckFirewall(svc, hcName, ipv6hcFwName, isSharedHC, l4type)
}

func (l4hc *l4HealthChecks) deleteHealthCheckFirewall(svc *corev1.Service, hcName, hcFwName string, sharedHC bool, l4Type utils.L4LBType) (string, error) {
Expand Down
1 change: 1 addition & 0 deletions pkg/instances/instances.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -98,6 +98,7 @@ func (i *Instances) EnsureInstanceGroupsAndPorts(name string, ports []int64) (ig
}

func (i *Instances) ensureInstanceGroupAndPorts(name, zone string, ports []int64) (*compute.InstanceGroup, error) {
klog.V(3).Infof("Ensuring instance group %s in zone %s. Ports: %v", name, zone, ports)
ig, err := i.Get(name, zone)
if err != nil && !utils.IsHTTPErrorCode(err, http.StatusNotFound) {
klog.Errorf("Failed to get instance group %v/%v, err: %v", zone, name, err)
Expand Down
4 changes: 4 additions & 0 deletions pkg/l4lb/l4lbcommon.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -65,8 +65,10 @@ func mergeAnnotations(existing, lbAnnotations map[string]string, keysToRemove []

// updateL4ResourcesAnnotations this function checks if new annotations should be added to service and patch service metadata if needed.
func updateL4ResourcesAnnotations(ctx *context.ControllerContext, svc *v1.Service, newL4LBAnnotations map[string]string) error {
klog.V(3).Infof("Updating annotations of service %s/%s", svc.Namespace, svc.Name)
newObjectMeta := computeNewAnnotationsIfNeeded(svc, newL4LBAnnotations, loadbalancers.L4LBResourceAnnotationKeys)
if newObjectMeta == nil {
klog.V(3).Infof("Service annotations not changed, skipping patch for service %s/%s", svc.Namespace, svc.Name)
return nil
}
klog.V(3).Infof("Patching annotations of service %v/%v", svc.Namespace, svc.Name)
Expand Down Expand Up @@ -106,7 +108,9 @@ func deleteAnnotation(ctx *context.ControllerContext, svc *v1.Service, annotatio

// updateServiceStatus this faction checks if LoadBalancer status changed and patch service if needed.
func updateServiceStatus(ctx *context.ControllerContext, svc *v1.Service, newStatus *v1.LoadBalancerStatus) error {
klog.V(2).Infof("Updating service status, service: %s/%s, new status: %+v", svc.Namespace, svc.Name, newStatus)
if helpers.LoadBalancerStatusEqual(&svc.Status.LoadBalancer, newStatus) {
klog.V(2).Infof("New and old statuses are equal, skipping patch. Service: %s/%s", svc.Namespace, svc.Name)
return nil
}
return patch.PatchServiceLoadBalancerStatus(ctx.KubeClient.CoreV1(), svc, *newStatus)
Expand Down
20 changes: 17 additions & 3 deletions pkg/l4lb/l4netlbcontroller.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ package l4lb
import (
"fmt"
"reflect"
"time"

"github.com/GoogleCloudPlatform/k8s-cloud-provider/pkg/cloud"
"github.com/GoogleCloudPlatform/k8s-cloud-provider/pkg/cloud/meta"
Expand Down Expand Up @@ -106,6 +107,7 @@ func NewL4NetLBController(
svcKey := utils.ServiceKeyFunc(curSvc.Namespace, curSvc.Name)
if l4netLBc.shouldProcessService(curSvc, oldSvc) {
klog.V(3).Infof("L4 External LoadBalancer Service %s updated, enqueuing", svcKey)
l4netLBc.ctx.Recorder(curSvc.Namespace).Eventf(curSvc, v1.EventTypeNormal, "UPDATE", svcKey)
l4netLBc.svcQueue.Enqueue(curSvc)
l4netLBc.enqueueTracker.Track()
return
Expand Down Expand Up @@ -213,7 +215,7 @@ func (lc *L4NetLBController) needsUpdate(newSvc, oldSvc *v1.Service) bool {
return false
}

// shouldProcessUpdate checks if given service should be process by controller
// shouldProcessService checks if given service should be process by controller
func (lc *L4NetLBController) shouldProcessService(newSvc, oldSvc *v1.Service) bool {
if !lc.isRBSBasedService(newSvc) {
return false
Expand Down Expand Up @@ -260,7 +262,7 @@ func (lc *L4NetLBController) preventLegacyServiceHandling(service *v1.Service, k
if utils.HasL4NetLBFinalizerV2(service) {
// If we found that RBS finalizer was attached to service, it means that RBS controller
// had a race condition on Service creation with Legacy Controller.
// It should only happen during service creation and we should clean up RBS resources
// It should only happen during service creation, and we should clean up RBS resources
return true, lc.preventTargetPoolRaceWithRBSOnCreation(service, key)
} else {
// Target Pool to RBS migration is NOT yet supported and causes service to break (for now).
Expand Down Expand Up @@ -369,7 +371,7 @@ func (lc *L4NetLBController) sync(key string) error {
lc.syncTracker.Track()
svc, exists, err := lc.ctx.Services().GetByKey(key)
if err != nil {
return fmt.Errorf("Failed to lookup L4 External LoadBalancer service for key %s : %w", key, err)
return fmt.Errorf("failed to lookup L4 External LoadBalancer service for key %s : %w", key, err)
}
if !exists || svc == nil {
klog.V(3).Infof("Ignoring sync of non-existent service %s", key)
Expand Down Expand Up @@ -476,6 +478,12 @@ func (lc *L4NetLBController) syncInternal(service *v1.Service) *loadbalancers.L4
}

func (lc *L4NetLBController) ensureBackendLinking(service *v1.Service) error {
start := time.Now()
klog.V(2).Infof("Linking backend service with instance groups for service %s/%s", service.Namespace, service.Name)
defer func() {
klog.V(2).Infof("Finished linking backend service with instance groups for service %s/%s, time taken: %v", service.Namespace, service.Name, time.Since(start))
}()

zones, err := lc.translator.ListZones(utils.CandidateNodesPredicate)
if err != nil {
return err
Expand All @@ -496,6 +504,12 @@ func (lc *L4NetLBController) ensureBackendLinking(service *v1.Service) error {
func (lc *L4NetLBController) ensureInstanceGroups(service *v1.Service, nodeNames []string) error {
// TODO(kl52752) Move instance creation and deletion logic to NodeController
// to avoid race condition between controllers
start := time.Now()
klog.V(2).Infof("Ensuring instance groups for L4 NetLB Service %s/%s, len(nodeNames): %v", service.Namespace, service.Name, len(nodeNames))
defer func() {
klog.V(2).Infof("Finished ensuring instance groups for L4 NetLB Service %s/%s, time taken: %v", service.Namespace, service.Name, time.Since(start))
}()

nodePorts := utils.GetNodePorts(service.Spec.Ports)
_, err := lc.instancePool.EnsureInstanceGroupsAndPorts(lc.ctx.ClusterNamer.InstanceGroup(), nodePorts)
if err != nil {
Expand Down
Loading