Updated log levels in pkg (#1359)

* updated log levels in sdkserver
* updated log levels in pkg

Co-authored-by: Mark Mandel <markmandel@google.com>

pkg/fleetautoscalers/controller.go

@@ -115,7 +115,7 @@ func (c *Controller) Run(workers int, stop <-chan struct{}) error {
 		return err
 	}
 
-	c.baseLogger.Info("Wait for cache sync")
+	c.baseLogger.Debug("Wait for cache sync")
 	if !cache.WaitForCacheSync(stop, c.fleetSynced, c.fleetAutoscalerSynced) {
 		return errors.New("failed to wait for caches to sync")
 	}
@@ -143,7 +143,7 @@ func (c *Controller) validationHandler(review admv1beta1.AdmissionReview) (admv1
 	fas := &autoscalingv1.FleetAutoscaler{}
 	err := json.Unmarshal(obj.Raw, fas)
 	if err != nil {
-		c.baseLogger.WithField("review", review).WithError(err).Info("validationHandler")
+		c.baseLogger.WithField("review", review).WithError(err).Error("validationHandler")
 		return review, errors.Wrapf(err, "error unmarshalling original FleetAutoscaler json: %s", obj.Raw)
 	}
 
@@ -184,7 +184,7 @@ func (c *Controller) syncFleetAutoscaler(key string) error {
 	fas, err := c.fleetAutoscalerLister.FleetAutoscalers(namespace).Get(name)
 	if err != nil {
 		if k8serrors.IsNotFound(err) {
-			c.loggerForFleetAutoscalerKey(key).Info(fmt.Sprintf("FleetAutoscaler %s from namespace %s is no longer available for syncing", name, namespace))
+			c.loggerForFleetAutoscalerKey(key).Debug(fmt.Sprintf("FleetAutoscaler %s from namespace %s is no longer available for syncing", name, namespace))
 			return nil
 		}
 		return errors.Wrapf(err, "error retrieving FleetAutoscaler %s from namespace %s", name, namespace)
@@ -194,7 +194,7 @@ func (c *Controller) syncFleetAutoscaler(key string) error {
 	fleet, err := c.fleetLister.Fleets(namespace).Get(fas.Spec.FleetName)
 	if err != nil {
 		if k8serrors.IsNotFound(err) {
-			c.loggerForFleetAutoscaler(fas).Warn("Could not find fleet for autoscaler. Skipping.")
+			c.loggerForFleetAutoscaler(fas).Debug("Could not find fleet for autoscaler. Skipping.")
 
 			c.recorder.Eventf(fas, corev1.EventTypeWarning, "FailedGetFleet",
 				"could not fetch fleet: %s", fas.Spec.FleetName)

pkg/fleets/controller.go

@@ -128,7 +128,7 @@ func NewController(
 // Should only be called on fleet create operations.
 // nolint:dupl
 func (c *Controller) creationMutationHandler(review admv1beta1.AdmissionReview) (admv1beta1.AdmissionReview, error) {
-	c.baseLogger.WithField("review", review).Info("creationMutationHandler")
+	c.baseLogger.WithField("review", review).Debug("creationMutationHandler")
 
 	obj := review.Request.Object
 	fleet := &agonesv1.Fleet{}
@@ -168,7 +168,7 @@ func (c *Controller) creationMutationHandler(review admv1beta1.AdmissionReview)
 // creationValidationHandler that validates a Fleet when it is created
 // Should only be called on Fleet create and Update operations.
 func (c *Controller) creationValidationHandler(review admv1beta1.AdmissionReview) (admv1beta1.AdmissionReview, error) {
-	c.baseLogger.WithField("review", review).Info("creationValidationHandler")
+	c.baseLogger.WithField("review", review).Debug("creationValidationHandler")
 
 	obj := review.Request.Object
 	fleet := &agonesv1.Fleet{}
@@ -193,7 +193,7 @@ func (c *Controller) creationValidationHandler(review admv1beta1.AdmissionReview
 			Details: &details,
 		}
 
-		c.loggerForFleet(fleet).WithField("review", review).Info("Invalid Fleet")
+		c.loggerForFleet(fleet).WithField("review", review).Warn("Invalid Fleet")
 		return review, nil
 	}
 
@@ -208,7 +208,7 @@ func (c *Controller) Run(workers int, stop <-chan struct{}) error {
 		return err
 	}
 
-	c.baseLogger.Info("Wait for cache sync")
+	c.baseLogger.Debug("Wait for cache sync")
 	if !cache.WaitForCacheSync(stop, c.gameServerSetSynced, c.fleetSynced) {
 		return errors.New("failed to wait for caches to sync")
 	}
@@ -241,7 +241,7 @@ func (c *Controller) gameServerSetEventHandler(obj interface{}) {
 	fleet, err := c.fleetLister.Fleets(gsSet.ObjectMeta.Namespace).Get(ref.Name)
 	if err != nil {
 		if k8serrors.IsNotFound(err) {
-			c.baseLogger.WithField("ref", ref).Info("Owner Fleet no longer available for syncing")
+			c.baseLogger.WithField("ref", ref).Warn("Owner Fleet no longer available for syncing")
 		} else {
 			runtime.HandleError(c.loggerForFleet(fleet).WithField("ref", ref),
 				errors.Wrap(err, "error retrieving GameServerSet owner"))
@@ -267,7 +267,7 @@ func (c *Controller) syncFleet(key string) error {
 	fleet, err := c.fleetLister.Fleets(namespace).Get(name)
 	if err != nil {
 		if k8serrors.IsNotFound(err) {
-			c.loggerForFleetKey(key).Info("Fleet is no longer available for syncing")
+			c.loggerForFleetKey(key).Debug("Fleet is no longer available for syncing")
 			return nil
 		}
 		return errors.Wrapf(err, "error retrieving fleet %s from namespace %s", name, namespace)
@@ -282,7 +282,7 @@ func (c *Controller) syncFleet(key string) error {
 
 	// if there isn't an active gameServerSet, create one (but don't persist yet)
 	if active == nil {
-		c.loggerForFleet(fleet).Info("could not find active GameServerSet, creating")
+		c.loggerForFleet(fleet).Debug("could not find active GameServerSet, creating")
 		active = fleet.GameServerSet()
 	}
 
@@ -389,7 +389,7 @@ func (c *Controller) recreateDeployment(fleet *agonesv1.Fleet, rest []*agonesv1.
 		if gsSet.Spec.Replicas == 0 {
 			continue
 		}
-		c.loggerForFleet(fleet).WithField("gameserverset", gsSet.ObjectMeta.Name).Info("applying recreate deployment: scaling to 0")
+		c.loggerForFleet(fleet).WithField("gameserverset", gsSet.ObjectMeta.Name).Debug("applying recreate deployment: scaling to 0")
 		gsSetCopy := gsSet.DeepCopy()
 		gsSetCopy.Spec.Replicas = 0
 		if _, err := c.gameServerSetGetter.GameServerSets(gsSetCopy.ObjectMeta.Namespace).Update(gsSetCopy); err != nil {
@@ -455,7 +455,7 @@ func (c *Controller) rollingUpdateActive(fleet *agonesv1.Fleet, active *agonesv1
 	}
 
 	c.loggerForFleet(fleet).WithField("gameserverset", active.ObjectMeta.Name).WithField("replicas", replicas).
-		Info("applying rolling update to active gameserverset")
+		Debug("applying rolling update to active gameserverset")
 
 	return replicas, nil
 }
@@ -488,9 +488,9 @@ func (c *Controller) rollingUpdateRest(fleet *agonesv1.Fleet, rest []*agonesv1.G
 		if gsSet.Status.ShutdownReplicas == 0 {
 			gsSetCopy.Spec.Replicas = fleet.LowerBoundReplicas(gsSetCopy.Spec.Replicas - unavailable)
 
-			c.loggerForFleet(fleet).Info(fmt.Sprintf("Shutdownreplicas %d", gsSet.Status.ShutdownReplicas))
+			c.loggerForFleet(fleet).Debug(fmt.Sprintf("Shutdownreplicas %d", gsSet.Status.ShutdownReplicas))
 			c.loggerForFleet(fleet).WithField("gameserverset", gsSet.ObjectMeta.Name).WithField("replicas", gsSetCopy.Spec.Replicas).
-				Info("applying rolling update to inactive gameserverset")
+				Debug("applying rolling update to inactive gameserverset")
 
 			if _, err := c.gameServerSetGetter.GameServerSets(gsSetCopy.ObjectMeta.Namespace).Update(gsSetCopy); err != nil {
 				return errors.Wrapf(err, "error updating gameserverset %s", gsSetCopy.ObjectMeta.Name)
@@ -509,7 +509,7 @@ func (c *Controller) rollingUpdateRest(fleet *agonesv1.Fleet, rest []*agonesv1.G
 // updateFleetStatus gets the GameServerSets for this Fleet and then
 // calculates the counts for the status, and updates the Fleet
 func (c *Controller) updateFleetStatus(fleet *agonesv1.Fleet) error {
-	c.loggerForFleet(fleet).Info("Update Fleet Status")
+	c.loggerForFleet(fleet).Debug("Update Fleet Status")
 
 	list, err := ListGameServerSetsByFleetOwner(c.gameServerSetLister, fleet)
 	if err != nil {

pkg/gameserverallocations/allocator.go

@@ -170,7 +170,7 @@ func (c *Allocator) Start(stop <-chan struct{}) error {
 
 // Sync waits for cache to sync
 func (c *Allocator) Sync(stop <-chan struct{}) error {
-	c.baseLogger.Info("Wait for Allocator cache sync")
+	c.baseLogger.Debug("Wait for Allocator cache sync")
 	if !cache.WaitForCacheSync(stop, c.secretSynced, c.allocationPolicySynced) {
 		return errors.New("failed to wait for caches to sync")
 	}
@@ -198,7 +198,7 @@ func (c *Allocator) Allocate(gsa *allocationv1.GameServerAllocation, stop <-chan
 		if err != nil {
 			return nil, errors.Wrap(err, "could not find objectkinds for status")
 		}
-		c.loggerForGameServerAllocation(gsa).Info("GameServerAllocation is invalid")
+		c.loggerForGameServerAllocation(gsa).Debug("GameServerAllocation is invalid")
 
 		status.TypeMeta = metav1.TypeMeta{Kind: gvks[0].Kind, APIVersion: gvks[0].Version}
 		return status, nil
@@ -264,7 +264,7 @@ func (c *Allocator) allocateFromLocalCluster(gsa *allocationv1.GameServerAllocat
 		gsa.Status.NodeName = gs.Status.NodeName
 	}
 
-	c.loggerForGameServerAllocation(gsa).Info("game server allocation")
+	c.loggerForGameServerAllocation(gsa).Debug("Game server allocation")
 	return gsa, nil
 }
 
@@ -339,7 +339,7 @@ func (c *Allocator) allocateFromRemoteCluster(gsa *allocationv1.GameServerAlloca
 	err = Retry(remoteAllocationRetry, func() error {
 		for i, ip := range connectionInfo.AllocationEndpoints {
 			endpoint := addPort(ip)
-			c.loggerForGameServerAllocationKey("remote-allocation").WithField("request", request).WithField("endpoint", endpoint).Info("forwarding allocation request")
+			c.loggerForGameServerAllocationKey("remote-allocation").WithField("request", request).WithField("endpoint", endpoint).Debug("forwarding allocation request")
 
 			allocationResponse, err = c.remoteAllocationCallback(endpoint, dialOpts, request)
 			if err != nil {

pkg/gameserverallocations/ready_cache.go

@@ -107,7 +107,7 @@ func (c *ReadyGameServerCache) RemoveFromReadyGameServer(gs *agonesv1.GameServer
 
 // Sync waits for cache to sync
 func (c *ReadyGameServerCache) Sync(stop <-chan struct{}) error {
-	c.baseLogger.Info("Wait for ReadyGameServerCache cache sync")
+	c.baseLogger.Debug("Wait for ReadyGameServerCache cache sync")
 	if !cache.WaitForCacheSync(stop, c.gameServerSynced) {
 		return errors.New("failed to wait for caches to sync")
 	}
@@ -234,7 +234,7 @@ func (c *ReadyGameServerCache) patchMetadata(gs *agonesv1.GameServer, fam alloca
 // SyncGameServers synchronises the GameServers to Gameserver cache. This is called when a failure
 // happened during the allocation. This method will sync and make sure the cache is up to date.
 func (c *ReadyGameServerCache) SyncGameServers(key string) error {
-	c.loggerForGameServerKey(key).Info("Refreshing Ready Gameserver cache")
+	c.loggerForGameServerKey(key).Debug("Refreshing Ready Gameserver cache")
 
 	return c.syncReadyGSServerCache()
 }

pkg/gameservers/controller.go

@@ -218,7 +218,7 @@ func (c *Controller) creationMutationHandler(review admv1beta1.AdmissionReview)
 	gs := &agonesv1.GameServer{}
 	err := json.Unmarshal(obj.Raw, gs)
 	if err != nil {
-		c.baseLogger.WithField("review", review).WithError(err).Info("creationMutationHandler failed to unmarshal JSON")
+		c.baseLogger.WithField("review", review).WithError(err).Error("creationMutationHandler failed to unmarshal JSON")
 		return review, errors.Wrapf(err, "error unmarshalling original GameServer json: %s", obj.Raw)
 	}
 
@@ -267,7 +267,7 @@ func (c *Controller) creationValidationHandler(review admv1beta1.AdmissionReview
 	gs := &agonesv1.GameServer{}
 	err := json.Unmarshal(obj.Raw, gs)
 	if err != nil {
-		c.baseLogger.WithField("review", review).WithError(err).Info("creationValidationHandler failed to unmarshal JSON")
+		c.baseLogger.WithField("review", review).WithError(err).Error("creationValidationHandler failed to unmarshal JSON")
 		return review, errors.Wrapf(err, "error unmarshalling original GameServer json: %s", obj.Raw)
 	}
 
@@ -306,7 +306,7 @@ func (c *Controller) Run(workers int, stop <-chan struct{}) error {
 		return err
 	}
 
-	c.baseLogger.Info("Wait for cache sync")
+	c.baseLogger.Debug("Wait for cache sync")
 	if !cache.WaitForCacheSync(stop, c.gameServerSynced, c.podSynced, c.nodeSynced) {
 		return errors.New("failed to wait for caches to sync")
 	}
@@ -371,7 +371,7 @@ func (c *Controller) syncGameServer(key string) error {
 	gs, err := c.gameServerLister.GameServers(namespace).Get(name)
 	if err != nil {
 		if k8serrors.IsNotFound(err) {
-			c.loggerForGameServerKey(key).Info("GameServer is no longer available for syncing")
+			c.loggerForGameServerKey(key).Debug("GameServer is no longer available for syncing")
 			return nil
 		}
 		return errors.Wrapf(err, "error retrieving GameServer %s from namespace %s", name, namespace)
@@ -411,7 +411,7 @@ func (c *Controller) syncGameServerDeletionTimestamp(gs *agonesv1.GameServer) (*
 		return gs, nil
 	}
 
-	c.loggerForGameServer(gs).Info("Syncing with Deletion Timestamp")
+	c.loggerForGameServer(gs).Debug("Syncing with Deletion Timestamp")
 
 	pod, err := c.gameServerPod(gs)
 	if err != nil && !k8serrors.IsNotFound(err) {
@@ -458,7 +458,7 @@ func (c *Controller) syncGameServerPortAllocationState(gs *agonesv1.GameServer)
 	gsCopy.Status.State = agonesv1.GameServerStateCreating
 	c.recorder.Event(gs, corev1.EventTypeNormal, string(gs.Status.State), "Port allocated")
 
-	c.loggerForGameServer(gsCopy).Info("Syncing Port Allocation GameServerState")
+	c.loggerForGameServer(gsCopy).Debug("Syncing Port Allocation GameServerState")
 	gs, err := c.gameServerGetter.GameServers(gs.ObjectMeta.Namespace).Update(gsCopy)
 	if err != nil {
 		// if the GameServer doesn't get updated with the port data, then put the port
@@ -480,7 +480,7 @@ func (c *Controller) syncGameServerCreatingState(gs *agonesv1.GameServer) (*agon
 		return gs, nil
 	}
 
-	c.loggerForGameServer(gs).Info("Syncing Create State")
+	c.loggerForGameServer(gs).Debug("Syncing Create State")
 
 	// Maybe something went wrong, and the pod was created, but the state was never moved to Starting, so let's check
 	_, err := c.gameServerPod(gs)
@@ -517,7 +517,7 @@ func (c *Controller) syncDevelopmentGameServer(gs *agonesv1.GameServer) (*agones
 	}
 
 	if !(gs.Status.State == agonesv1.GameServerStateReady) {
-		c.loggerForGameServer(gs).Info("GS is a development game server and will not be managed by Agones.")
+		c.loggerForGameServer(gs).Debug("GS is a development game server and will not be managed by Agones.")
 	}
 
 	gsCopy := gs.DeepCopy()
@@ -559,7 +559,7 @@ func (c *Controller) createGameServerPod(gs *agonesv1.GameServer) (*agonesv1.Gam
 	c.addGameServerHealthCheck(gs, pod)
 	c.addSDKServerEnvVars(gs, pod)
 
-	c.loggerForGameServer(gs).WithField("pod", pod).Info("creating Pod for GameServer")
+	c.loggerForGameServer(gs).WithField("pod", pod).Debug("Creating Pod for GameServer")
 	pod, err = c.podGetter.Pods(gs.ObjectMeta.Namespace).Create(pod)
 	if k8serrors.IsAlreadyExists(err) {
 		c.recorder.Event(gs, corev1.EventTypeNormal, string(gs.Status.State), "Pod already exists, reused")
@@ -719,7 +719,7 @@ func (c *Controller) syncGameServerStartingState(gs *agonesv1.GameServer) (*agon
 		return gs, nil
 	}
 
-	c.loggerForGameServer(gs).Info("Syncing Starting GameServerState")
+	c.loggerForGameServer(gs).Debug("Syncing Starting GameServerState")
 
 	// there should be a pod (although it may not have a scheduled container),
 	// so if there is an error of any kind, then move this to queue backoff
@@ -759,7 +759,7 @@ func (c *Controller) syncGameServerRequestReadyState(gs *agonesv1.GameServer) (*
 		return gs, nil
 	}
 
-	c.loggerForGameServer(gs).Info("Syncing RequestReady State")
+	c.loggerForGameServer(gs).Debug("Syncing RequestReady State")
 
 	gsCopy := gs.DeepCopy()
 
@@ -821,7 +821,7 @@ func (c *Controller) syncGameServerShutdownState(gs *agonesv1.GameServer) error
 		return nil
 	}
 
-	c.loggerForGameServer(gs).Info("Syncing Shutdown State")
+	c.loggerForGameServer(gs).Debug("Syncing Shutdown State")
 	// be explicit about where to delete.
 	p := metav1.DeletePropagationBackground
 	err := c.gameServerGetter.GameServers(gs.ObjectMeta.Namespace).Delete(gs.ObjectMeta.Name, &metav1.DeleteOptions{PropagationPolicy: &p})

pkg/gameservers/health.go

@@ -140,7 +140,7 @@ func (hc *HealthController) failedContainer(pod *corev1.Pod) bool {
 // Run processes the rate limited queue.
 // Will block until stop is closed
 func (hc *HealthController) Run(stop <-chan struct{}) error {
-	hc.baseLogger.Info("Wait for cache sync")
+	hc.baseLogger.Debug("Wait for cache sync")
 	if !cache.WaitForCacheSync(stop, hc.gameServerSynced, hc.podSynced) {
 		return errors.New("failed to wait for caches to sync")
 	}
@@ -177,7 +177,7 @@ func (hc *HealthController) syncGameServer(key string) error {
 	gs, err := hc.gameServerLister.GameServers(namespace).Get(name)
 	if err != nil {
 		if k8serrors.IsNotFound(err) {
-			hc.loggerForGameServerKey(key).Info("GameServer is no longer available for syncing")
+			hc.loggerForGameServerKey(key).Debug("GameServer is no longer available for syncing")
 			return nil
 		}
 		return errors.Wrapf(err, "error retrieving GameServer %s from namespace %s", name, namespace)
@@ -192,7 +192,7 @@ func (hc *HealthController) syncGameServer(key string) error {
 		return err
 	}
 
-	hc.loggerForGameServer(gs).Info("Issue with GameServer pod, marking as GameServerStateUnhealthy")
+	hc.loggerForGameServer(gs).Debug("Issue with GameServer pod, marking as GameServerStateUnhealthy")
 	gsCopy := gs.DeepCopy()
 	gsCopy.Status.State = agonesv1.GameServerStateUnhealthy
 

pkg/gameservers/pernodecounter.go

@@ -138,7 +138,7 @@ func (pnc *PerNodeCounter) Run(_ int, stop <-chan struct{}) error {
 	pnc.countMutex.Lock()
 	defer pnc.countMutex.Unlock()
 
-	pnc.logger.Info("Running")
+	pnc.logger.Debug("Running")
 
 	if !cache.WaitForCacheSync(stop, pnc.gameServerSynced) {
 		return errors.New("failed to wait for caches to sync")

pkg/gameservers/portallocator.go

@@ -91,7 +91,7 @@ func NewPortAllocator(minPort, maxPort int32,
 // Run sets up the current state of port allocations and
 // starts tracking Pod and Node changes
 func (pa *PortAllocator) Run(stop <-chan struct{}) error {
-	pa.logger.Info("Running")
+	pa.logger.Debug("Running")
 
 	if !cache.WaitForCacheSync(stop, pa.gameServerSynced, pa.nodeSynced) {
 		return errors.New("failed to wait for caches to sync")
@@ -211,7 +211,7 @@ func (pa *PortAllocator) DeAllocate(gs *agonesv1.GameServer) {
 // make the HostPort available
 func (pa *PortAllocator) syncDeleteGameServer(object interface{}) {
 	if gs, ok := object.(*agonesv1.GameServer); ok {
-		pa.logger.WithField("gs", gs).Info("syncing deleted GameServer")
+		pa.logger.WithField("gs", gs).Debug("Syncing deleted GameServer")
 		pa.DeAllocate(gs)
 	}
 }
@@ -226,7 +226,7 @@ func (pa *PortAllocator) syncAll() error {
 	pa.mutex.Lock()
 	defer pa.mutex.Unlock()
 
-	pa.logger.Info("Resetting Port Allocation")
+	pa.logger.Debug("Resetting Port Allocation")
 
 	nodes, err := pa.nodeLister.List(labels.Everything())
 	if err != nil {