Logging Cleanup - Part 4

Makefile

@@ -45,7 +45,7 @@ help: ## Display this help.
 
 .PHONY: run
 run: ## Run in development mode
-	go run cmd/aws-application-networking-k8s/main.go --debug -v 6
+	go run cmd/aws-application-networking-k8s/main.go --debug
 
 
 .PHONY: presubmit

cmd/aws-application-networking-k8s/main.go

@@ -90,9 +90,6 @@ func main() {
 	var probeAddr string
 	var debug bool
 
-	// setup glog level
-	flag.Lookup("logtostderr").Value.Set("true")
-
 	flag.StringVar(&metricsAddr, "metrics-bind-address", ":8080", "The address the metric endpoint binds to.")
 	flag.StringVar(&probeAddr, "health-probe-bind-address", ":8081", "The address the probe endpoint binds to.")
 	flag.BoolVar(&debug, "debug", false, "enable debug mode")

controllers/route_controller.go

@@ -19,6 +19,7 @@ package controllers
 import (
 	"context"
 	"fmt"
+
 	"github.com/aws/aws-application-networking-k8s/pkg/aws/services"
 	"github.com/aws/aws-application-networking-k8s/pkg/utils"
 
@@ -312,36 +313,26 @@ func (r *RouteReconciler) buildAndDeployModel(
 		return nil, nil, err
 	}
 
-	stackJSON, err := r.stackMarshaller.Marshal(stack)
+	_, err = r.stackMarshaller.Marshal(stack)
 	if err != nil {
-		//TODO
-		r.log.Infof("error on r.stackMarshaller.Marshal error %s", err)
+		r.log.Errorf("error on r.stackMarshaller.Marshal error %s", err)
 	}
 
-	r.log.Info("Successfully built model:", stackJSON, "")
-
 	if err := r.stackDeployer.Deploy(ctx, stack); err != nil {
-		r.log.Infof("RouteReconciler: Failed deploy %s due to err %s", route.Name(), err)
-
 		if errors.As(err, &lattice.RetryErr) {
 			r.eventRecorder.Event(route.K8sObject(), corev1.EventTypeNormal,
 				k8s.RouteEventReasonRetryReconcile, "retry reconcile...")
-
 		} else {
 			r.eventRecorder.Event(route.K8sObject(), corev1.EventTypeWarning,
-				k8s.RouteEventReasonFailedDeployModel, fmt.Sprintf("Failed deploy model due to %v", err))
+				k8s.RouteEventReasonFailedDeployModel, fmt.Sprintf("Failed deploy model due to %s", err))
 		}
 		return nil, nil, err
 	}
 
-	r.log.Info("Successfully deployed model")
-
 	return stack, latticeService, err
 }
 
 func (r *RouteReconciler) reconcileRouteResource(ctx context.Context, route core.Route) error {
-	r.log.Infof("Beginning -- reconcileRouteResource, [%v]", route)
-
 	if err := r.finalizerManager.AddFinalizers(ctx, route.K8sObject(), routeTypeToFinalizer[r.routeType]); err != nil {
 		r.eventRecorder.Event(route.K8sObject(), corev1.EventTypeWarning, k8s.RouteEventReasonFailedAddFinalizer, fmt.Sprintf("Failed add finalizer due to %v", err))
 	}
@@ -392,7 +383,7 @@ func (r *RouteReconciler) reconcileRouteResource(ctx context.Context, route core
 }
 
 func (r *RouteReconciler) updateRouteStatus(ctx context.Context, dns string, route core.Route) error {
-	r.log.Infof("updateRouteStatus: route name %s, namespace %s, dns %s", route.Name(), route.Namespace(), dns)
+	r.log.Debugf("Updating route %s-%s with DNS %s", route.Name(), route.Namespace(), dns)
 	routeOld := route.DeepCopy()
 
 	if len(route.K8sObject().GetAnnotations()) == 0 {
@@ -437,7 +428,7 @@ func (r *RouteReconciler) updateRouteStatus(ctx context.Context, dns string, rou
 		return fmt.Errorf("failed to update route status due to err %w", err)
 	}
 
-	r.log.Infof("updateRouteStatus patched dns %v", dns)
+	r.log.Debugf("Successfully updated route %s-%s with DNS %s", route.Name(), route.Namespace(), dns)
 	return nil
 }
 

controllers/service_controller.go

@@ -65,8 +65,8 @@ func RegisterServiceController(
 	client := mgr.GetClient()
 	scheme := mgr.GetScheme()
 	evtRec := mgr.GetEventRecorderFor("service")
-	modelBuild := gateway.NewTargetsBuilder(client, cloud, datastore)
-	stackDeploy := deploy.NewTargetsStackDeploy(cloud, client, datastore)
+	modelBuild := gateway.NewTargetsBuilder(log, client, cloud, datastore)
+	stackDeploy := deploy.NewTargetsStackDeploy(log, cloud, client, datastore)
 	stackMarshaller := deploy.NewDefaultStackMarshaller()
 	sr := &serviceReconciler{
 		log:              log,

controllers/serviceexport_controller.go

@@ -20,16 +20,17 @@ import (
 	"context"
 	"errors"
 	"fmt"
-	"github.com/aws/aws-application-networking-k8s/controllers/eventhandlers"
+
 	corev1 "k8s.io/api/core/v1"
 	"k8s.io/apimachinery/pkg/runtime"
 	"k8s.io/client-go/tools/record"
 	ctrl "sigs.k8s.io/controller-runtime"
 	"sigs.k8s.io/controller-runtime/pkg/client"
-	"sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/source"
 	mcs_api "sigs.k8s.io/mcs-api/pkg/apis/v1alpha1"
 
+	"github.com/aws/aws-application-networking-k8s/controllers/eventhandlers"
+
 	"github.com/aws/aws-application-networking-k8s/pkg/apis/applicationnetworking/v1alpha1"
 	"github.com/aws/aws-application-networking-k8s/pkg/aws"
 	"github.com/aws/aws-application-networking-k8s/pkg/deploy"
@@ -129,18 +130,17 @@ func (r *ServiceExportReconciler) reconcile(ctx context.Context, req ctrl.Reques
 	}
 
 	if srvExport.ObjectMeta.Annotations["multicluster.x-k8s.io/federation"] == "amazon-vpc-lattice" {
-		r.log.Infof("ServiceExportReconciler --- found matching service export --- %s\n", srvExport.Name)
+		r.log.Debugf("Found matching service export %s-%s", srvExport.Name, srvExport.Namespace)
 
 		if !srvExport.DeletionTimestamp.IsZero() {
-			r.log.Info("Deleting")
 			if err := r.cleanupServiceExportResources(ctx, srvExport); err != nil {
-				r.log.Infof("Failed to clean up service export %v, err :%v \n", srvExport, err)
 				return err
 			}
-
-			r.log.Info("Successfully delete")
-
-			r.finalizerManager.RemoveFinalizers(ctx, srvExport, serviceExportFinalizer)
+			err := r.finalizerManager.RemoveFinalizers(ctx, srvExport, serviceExportFinalizer)
+			if err != nil {
+				r.log.Errorf("Failed to remove finalizers for service export %s-%s due to %s",
+					srvExport.Name, srvExport.Namespace, err)
+			}
 			return nil
 		}
 
@@ -165,9 +165,10 @@ func (r *ServiceExportReconciler) reconcileServiceExportResources(ctx context.Co
 	return err
 }
 
-func (r *ServiceExportReconciler) buildAndDeployModel(ctx context.Context, srvExport *mcs_api.ServiceExport) (core.Stack, *latticemodel.TargetGroup, error) {
-	gwLog := log.FromContext(ctx)
-
+func (r *ServiceExportReconciler) buildAndDeployModel(
+	ctx context.Context,
+	srvExport *mcs_api.ServiceExport,
+) (core.Stack, *latticemodel.TargetGroup, error) {
 	stack, targetGroup, err := r.modelBuilder.Build(ctx, srvExport)
 
 	if err != nil {
@@ -182,22 +183,18 @@ func (r *ServiceExportReconciler) buildAndDeployModel(ctx context.Context, srvEx
 		// TODO continue deploy to trigger reconcile of stale SDK objects
 		//return stack, targetGroup, nil
 	}
-	r.log.Infof("buildAndDeployModel: stack=%v, targetgroup=%v, err = %v\n", stack, targetGroup, err)
-
-	stackJSON, err := r.stackMarshaller.Marshal(stack)
 
+	_, err = r.stackMarshaller.Marshal(stack)
 	if err != nil {
-		r.log.Infof("Error on marshalling serviceExport model for name: %v namespace: %v\n", srvExport.Name, srvExport.Namespace)
+		r.log.Errorf("Error on marshalling model for service export %s-%s", srvExport.Name, srvExport.Namespace)
 	}
 
-	gwLog.Info("Successfully built model", stackJSON, "")
-
 	if err := r.stackDeployer.Deploy(ctx, stack); err != nil {
 		r.eventRecorder.Event(srvExport, corev1.EventTypeWarning,
 			k8s.ServiceExportEventReasonFailedDeployModel, fmt.Sprintf("Failed deploy model due to %v", err))
 		return nil, nil, err
 	}
-	gwLog.Info("Successfully deployed model")
 
+	r.log.Debugf("Successfully deployed model for service export %s-%s", srvExport.Name, srvExport.Namespace)
 	return stack, targetGroup, err
 }

go.mod

@@ -5,7 +5,6 @@ go 1.20
 require (
 	github.com/aws/aws-sdk-go v1.44.321
 	github.com/go-logr/zapr v1.2.3
-	github.com/golang/glog v1.0.0
 	github.com/golang/mock v1.6.0
 	github.com/onsi/ginkgo v1.16.5
 	github.com/onsi/gomega v1.24.1

go.sum

@@ -211,8 +211,6 @@ github.com/gogo/protobuf v1.3.1/go.mod h1:SlYgWuQ5SjCEi6WLHjHCa1yvBfUnHcTbrrZtXP
 github.com/gogo/protobuf v1.3.2 h1:Ov1cvc58UF3b5XjBnZv7+opcTcQFZebYjWzi34vdm4Q=
 github.com/gogo/protobuf v1.3.2/go.mod h1:P1XiOD3dCwIKUDQYPy72D8LYyHL2YPYrpS2s69NZV8Q=
 github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q=
-github.com/golang/glog v1.0.0 h1:nfP3RFugxnNRyKgeWd4oI1nYvXpxrx8ck8ZrcizshdQ=
-github.com/golang/glog v1.0.0/go.mod h1:EWib/APOK0SL3dFbYqvxE3UYd8E6s1ouQ7iEp/0LWV4=
 github.com/golang/groupcache v0.0.0-20160516000752-02826c3e7903/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc=
 github.com/golang/groupcache v0.0.0-20190129154638-5b532d6fd5ef/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc=
 github.com/golang/groupcache v0.0.0-20190702054246-869f871628b6/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc=

pkg/aws/services/vpclattice.go

@@ -11,7 +11,6 @@ import (
 	"github.com/aws/aws-sdk-go/aws/session"
 	"github.com/aws/aws-sdk-go/service/vpclattice"
 	"github.com/aws/aws-sdk-go/service/vpclattice/vpclatticeiface"
-	"github.com/golang/glog"
 )
 
 //go:generate mockgen -destination vpclattice_mocks.go -package services github.com/aws/aws-application-networking-k8s/pkg/aws/services Lattice
@@ -73,8 +72,6 @@ func NewDefaultLattice(sess *session.Session, region string) *defaultLattice {
 
 	latticeSess = vpclattice.New(sess, aws.NewConfig().WithRegion(region).WithEndpoint(endpoint).WithMaxRetries(20))
 
-	glog.V(2).Infoln("Lattice Service EndPoint:", endpoint)
-
 	return &defaultLattice{latticeSess}
 }
 
@@ -196,11 +193,9 @@ func (d *defaultLattice) FindServiceNetwork(ctx context.Context, name string, op
 				return false
 			}
 			if !acctIdMatches {
-				glog.V(6).Infoln("ServiceNetwork found but does not match account id", name, r.Arn, optionalAccountId)
 				continue
 			}
 
-			glog.V(6).Infoln("Found ServiceNetwork", name, r.Arn, optionalAccountId)
 			tagsInput := vpclattice.ListTagsForResourceInput{
 				ResourceArn: r.Arn,
 			}
@@ -228,7 +223,6 @@ func (d *defaultLattice) FindServiceNetwork(ctx context.Context, name string, op
 		return nil, err
 	}
 	if snMatch == nil {
-		glog.V(6).Infoln("Service network for account not found ", name, optionalAccountId)
 		return nil, NewNotFoundError("Service network", name)
 	}
 
@@ -253,7 +247,6 @@ func (d *defaultLattice) FindService(ctx context.Context, nameProvider LatticeSe
 		return nil, err
 	}
 	if svcMatch == nil {
-		glog.V(6).Infoln("Service not found", serviceName)
 		return nil, NewNotFoundError("Service", serviceName)
 	}
 

pkg/deploy/lattice/targets_manager.go

@@ -4,27 +4,32 @@ import (
 	"context"
 	"errors"
 
-	"github.com/golang/glog"
-
 	"github.com/aws/aws-sdk-go/aws"
 	"github.com/aws/aws-sdk-go/service/vpclattice"
 
 	lattice_aws "github.com/aws/aws-application-networking-k8s/pkg/aws"
 	"github.com/aws/aws-application-networking-k8s/pkg/latticestore"
 	latticemodel "github.com/aws/aws-application-networking-k8s/pkg/model/lattice"
+	"github.com/aws/aws-application-networking-k8s/pkg/utils/gwlog"
 )
 
 type TargetsManager interface {
 	Create(ctx context.Context, targets *latticemodel.Targets) error
 }
 
 type defaultTargetsManager struct {
+	log       gwlog.Logger
 	cloud     lattice_aws.Cloud
 	datastore *latticestore.LatticeDataStore
 }
 
-func NewTargetsManager(cloud lattice_aws.Cloud, datastore *latticestore.LatticeDataStore) *defaultTargetsManager {
+func NewTargetsManager(
+	log gwlog.Logger,
+	cloud lattice_aws.Cloud,
+	datastore *latticestore.LatticeDataStore,
+) *defaultTargetsManager {
 	return &defaultTargetsManager{
+		log:       log,
 		cloud:     cloud,
 		datastore: datastore,
 	}
@@ -38,40 +43,36 @@ func NewTargetsManager(cloud lattice_aws.Cloud, datastore *latticestore.LatticeD
 //	otherwise:
 //	nil
 func (s *defaultTargetsManager) Create(ctx context.Context, targets *latticemodel.Targets) error {
-	glog.V(6).Infof("Update Lattice targets API call for %v \n", targets)
+	s.log.Debugf("Creating targets for target group %s-%s", targets.Spec.Name, targets.Spec.Namespace)
 
 	// Need to find TargetGroup ID from datastore
 	tgName := latticestore.TargetGroupName(targets.Spec.Name, targets.Spec.Namespace)
 	tg, err := s.datastore.GetTargetGroup(tgName, targets.Spec.RouteName, false) // isServiceImport=false
-
 	if err != nil {
-		glog.V(6).Infof("Failed to Create targets, service ( name %v namespace %v) not found, retry later\n", targets.Spec.Name, targets.Spec.Namespace)
+		s.log.Debugf("Failed to Create targets, service %s-%s was not found, will retry later",
+			targets.Spec.Name, targets.Spec.Namespace)
 		return errors.New(LATTICE_RETRY)
 	}
+
 	vpcLatticeSess := s.cloud.Lattice()
-	// find out sdk target list
 	listTargetsInput := vpclattice.ListTargetsInput{
 		TargetGroupIdentifier: &tg.ID,
 	}
-
 	var delTargetsList []*vpclattice.Target
 	listTargetsOutput, err := vpcLatticeSess.ListTargetsAsList(ctx, &listTargetsInput)
-	glog.V(6).Infof("TargetsManager-Create, listTargetsOutput %v, err %v \n", listTargetsOutput, err)
 	if err != nil {
-		glog.V(6).Infof("Failed to create target, tgName %v tg %v\n", tgName, tg)
 		return err
 	}
+
 	for _, sdkT := range listTargetsOutput {
 		// check if sdkT is in input target list
 		isStale := true
-
 		for _, t := range targets.Spec.TargetIPList {
 			if (aws.StringValue(sdkT.Id) == t.TargetIP) && (aws.Int64Value(sdkT.Port) == t.Port) {
 				isStale = false
 				break
 			}
 		}
-
 		if isStale {
 			delTargetsList = append(delTargetsList, &vpclattice.Target{Id: sdkT.Id, Port: sdkT.Port})
 		}
@@ -82,9 +83,12 @@ func (s *defaultTargetsManager) Create(ctx context.Context, targets *latticemode
 			TargetGroupIdentifier: &tg.ID,
 			Targets:               delTargetsList,
 		}
-		deRegisterTargetsOutput, err := vpcLatticeSess.DeregisterTargetsWithContext(ctx, &deRegisterTargetsInput)
-		glog.V(6).Infof("TargetManager-Create, deregister deleted targets input %v, output %v, err %v\n", deRegisterTargetsInput, deRegisterTargetsOutput, err)
+		_, err := vpcLatticeSess.DeregisterTargetsWithContext(ctx, &deRegisterTargetsInput)
+		if err != nil {
+			s.log.Errorf("Deregistering targets for target group %s failed due to %s", tg.ID, err)
+		}
 	}
+
 	// TODO following should be done at model level
 	var targetList []*vpclattice.Target
 	for _, target := range targets.Spec.TargetIPList {
@@ -106,21 +110,18 @@ func (s *defaultTargetsManager) Create(ctx context.Context, targets *latticemode
 		TargetGroupIdentifier: &tg.ID,
 		Targets:               targetList,
 	}
-	glog.V(6).Infof("Calling Lattice API register targets input %v \n", registerRouteInput)
 
 	resp, err := vpcLatticeSess.RegisterTargetsWithContext(ctx, &registerRouteInput)
-	glog.V(6).Infof("register pod to target group resp[%v]\n", resp)
-	glog.V(6).Infof("register pod to target group err[%v]\n", err)
 	if err != nil {
-		glog.V(6).Infof("Fail to register target err[%v]\n", err)
 		return err
 	}
 
 	isTargetRegisteredUnsuccessful := len(resp.Unsuccessful) > 0
 	if isTargetRegisteredUnsuccessful {
-		glog.V(6).Infof("Targets register unsuccessfully, will retry later\n")
+		s.log.Debugf("Failed to register targets for target group %s, will retry later", tg.ID)
 		return errors.New(LATTICE_RETRY)
 	}
-	glog.V(6).Infof("Targets register successfully\n")
+
+	s.log.Debugf("Successfully registered targets for target group %s", tg.ID)
 	return nil
 }