From cf3d21dbd4d2200760f0edf0198dfd4de2806477 Mon Sep 17 00:00:00 2001 From: Mark Mandel Date: Thu, 5 Mar 2020 15:36:01 -0800 Subject: [PATCH] Updated log levels in pkg (#1359) * updated log levels in sdkserver * updated log levels in pkg Co-authored-by: Mark Mandel --- pkg/fleetautoscalers/controller.go | 8 ++--- pkg/fleets/controller.go | 24 ++++++------- pkg/gameserverallocations/allocator.go | 8 ++--- pkg/gameserverallocations/ready_cache.go | 4 +-- pkg/gameservers/controller.go | 24 ++++++------- pkg/gameservers/health.go | 6 ++-- pkg/gameservers/pernodecounter.go | 2 +- pkg/gameservers/portallocator.go | 6 ++-- pkg/gameserversets/controller.go | 14 ++++---- pkg/sdkserver/localsdk.go | 32 ++++++++--------- pkg/sdkserver/sdkserver.go | 46 ++++++++++++------------ pkg/util/apiserver/apiserver.go | 6 ++-- 12 files changed, 90 insertions(+), 90 deletions(-) diff --git a/pkg/fleetautoscalers/controller.go b/pkg/fleetautoscalers/controller.go index ade2c1515c..7420e9de73 100644 --- a/pkg/fleetautoscalers/controller.go +++ b/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) diff --git a/pkg/fleets/controller.go b/pkg/fleets/controller.go index 66460960c3..064c89b058 100644 --- a/pkg/fleets/controller.go +++ b/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 { diff --git a/pkg/gameserverallocations/allocator.go b/pkg/gameserverallocations/allocator.go index 7fd2d0209b..7217b1ade8 100644 --- a/pkg/gameserverallocations/allocator.go +++ b/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 { diff --git a/pkg/gameserverallocations/ready_cache.go b/pkg/gameserverallocations/ready_cache.go index b68bb219a7..f921529f8a 100644 --- a/pkg/gameserverallocations/ready_cache.go +++ b/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() } diff --git a/pkg/gameservers/controller.go b/pkg/gameservers/controller.go index 0a185116a0..a88d389b20 100644 --- a/pkg/gameservers/controller.go +++ b/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}) diff --git a/pkg/gameservers/health.go b/pkg/gameservers/health.go index 383aa140fe..09b695e501 100644 --- a/pkg/gameservers/health.go +++ b/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 diff --git a/pkg/gameservers/pernodecounter.go b/pkg/gameservers/pernodecounter.go index 20a52c25a9..ba547cd481 100644 --- a/pkg/gameservers/pernodecounter.go +++ b/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") diff --git a/pkg/gameservers/portallocator.go b/pkg/gameservers/portallocator.go index 4f2ad76318..648dc0953e 100644 --- a/pkg/gameservers/portallocator.go +++ b/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 { diff --git a/pkg/gameserversets/controller.go b/pkg/gameserversets/controller.go index 70f1927cd1..06e3036d9b 100644 --- a/pkg/gameserversets/controller.go +++ b/pkg/gameserversets/controller.go @@ -160,7 +160,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.gameServerSetSynced) { return errors.New("failed to wait for caches to sync") } @@ -172,7 +172,7 @@ func (c *Controller) Run(workers int, stop <-chan struct{}) error { // updateValidationHandler that validates a GameServerSet when is updated // Should only be called on gameserverset update operations. func (c *Controller) updateValidationHandler(review admv1beta1.AdmissionReview) (admv1beta1.AdmissionReview, error) { - c.baseLogger.WithField("review", review).Info("updateValidationHandler") + c.baseLogger.WithField("review", review).Debug("updateValidationHandler") newGss := &agonesv1.GameServerSet{} oldGss := &agonesv1.GameServerSet{} @@ -213,7 +213,7 @@ func (c *Controller) updateValidationHandler(review admv1beta1.AdmissionReview) // creationValidationHandler that validates a GameServerSet when is created // Should only be called on gameserverset create 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") newGss := &agonesv1.GameServerSet{} @@ -238,7 +238,7 @@ func (c *Controller) creationValidationHandler(review admv1beta1.AdmissionReview Details: &details, } - c.loggerForGameServerSet(newGss).WithField("review", review).Info("Invalid GameServerSet update") + c.loggerForGameServerSet(newGss).WithField("review", review).Debug("Invalid GameServerSet update") return review, nil } @@ -258,7 +258,7 @@ func (c *Controller) gameServerEventHandler(obj interface{}) { gsSet, err := c.gameServerSetLister.GameServerSets(gs.ObjectMeta.Namespace).Get(ref.Name) if err != nil { if k8serrors.IsNotFound(err) { - c.baseLogger.WithField("ref", ref).Info("Owner GameServerSet no longer available for syncing") + c.baseLogger.WithField("ref", ref).Debug("Owner GameServerSet no longer available for syncing") } else { runtime.HandleError(c.baseLogger.WithField("gsKey", gs.ObjectMeta.Namespace+"/"+gs.ObjectMeta.Name).WithField("ref", ref), errors.Wrap(err, "error retrieving GameServer owner")) @@ -294,7 +294,7 @@ func (c *Controller) syncGameServerSet(key string) error { gsSet, err := c.gameServerSetLister.GameServerSets(namespace).Get(name) if err != nil { if k8serrors.IsNotFound(err) { - c.loggerForGameServerSetKey(key).Info("GameServerSet is no longer available for syncing") + c.loggerForGameServerSetKey(key).Debug("GameServerSet is no longer available for syncing") return nil } return errors.Wrapf(err, "error retrieving GameServerSet %s from namespace %s", name, namespace) @@ -331,7 +331,7 @@ func (c *Controller) syncGameServerSet(key string) error { WithField("isPartial", isPartial). WithField("status", status). WithFields(fields). - Info("Reconciling GameServerSet") + Debug("Reconciling GameServerSet") if isPartial { // we've determined that there's work to do, but we've decided not to do all the work in one shot // make sure we get a follow-up, by re-scheduling this GSS in the worker queue immediately before this diff --git a/pkg/sdkserver/localsdk.go b/pkg/sdkserver/localsdk.go index edcd548ab3..63b8af0f59 100644 --- a/pkg/sdkserver/localsdk.go +++ b/pkg/sdkserver/localsdk.go @@ -106,13 +106,13 @@ func NewLocalSDKServer(filePath string) (*LocalSDKServer, error) { if event.Op != fsnotify.Write { continue } - logrus.WithField("event", event).Info("File has been changed!") + logrus.WithField("event", event).Debug("File has been changed!") err := l.setGameServerFromFilePath(filePath) if err != nil { logrus.WithError(err).Error("error setting GameServer from file") continue } - logrus.Info("Sending watched GameServer!") + logrus.Debug("Sending watched GameServer!") l.update <- struct{}{} } }() @@ -125,7 +125,7 @@ func NewLocalSDKServer(filePath string) (*LocalSDKServer, error) { go func() { for value := range l.update { - logrus.Info("gameserver update received") + logrus.Debug("Gameserver update received") l.updateObservers.Range(func(observer, _ interface{}) bool { observer.(chan struct{}) <- value return true @@ -192,7 +192,7 @@ func (l *LocalSDKServer) updateState(newState agonesv1.GameServerState) { // Ready logs that the Ready request has been received func (l *LocalSDKServer) Ready(context.Context, *sdk.Empty) (*sdk.Empty, error) { - logrus.Info("Ready request has been received!") + logrus.Debug("Ready request has been received!") l.recordRequest("ready") l.gsMutex.Lock() defer l.gsMutex.Unlock() @@ -206,7 +206,7 @@ func (l *LocalSDKServer) Ready(context.Context, *sdk.Empty) (*sdk.Empty, error) // Allocate logs that an allocate request has been received func (l *LocalSDKServer) Allocate(context.Context, *sdk.Empty) (*sdk.Empty, error) { - logrus.Info("Allocate request has been received!") + logrus.Debug("Allocate request has been received!") l.recordRequest("allocate") l.gsMutex.Lock() defer l.gsMutex.Unlock() @@ -219,7 +219,7 @@ func (l *LocalSDKServer) Allocate(context.Context, *sdk.Empty) (*sdk.Empty, erro // Shutdown logs that the shutdown request has been received func (l *LocalSDKServer) Shutdown(context.Context, *sdk.Empty) (*sdk.Empty, error) { - logrus.Info("Shutdown request has been received!") + logrus.Debug("Shutdown request has been received!") l.recordRequest("shutdown") l.gsMutex.Lock() defer l.gsMutex.Unlock() @@ -234,20 +234,20 @@ func (l *LocalSDKServer) Health(stream sdk.SDK_HealthServer) error { for { _, err := stream.Recv() if err == io.EOF { - logrus.Info("Health stream closed.") + logrus.Debug("Health stream closed.") return stream.SendAndClose(&sdk.Empty{}) } if err != nil { return errors.Wrap(err, "Error with Health check") } l.recordRequest("health") - logrus.Info("Health Ping Received!") + logrus.Debug("Health Ping Received!") } } // SetLabel applies a Label to the backing GameServer metadata func (l *LocalSDKServer) SetLabel(_ context.Context, kv *sdk.KeyValue) (*sdk.Empty, error) { - logrus.WithField("values", kv).Info("Setting label") + logrus.WithField("values", kv).Debug("Setting label") l.gsMutex.Lock() defer l.gsMutex.Unlock() @@ -266,7 +266,7 @@ func (l *LocalSDKServer) SetLabel(_ context.Context, kv *sdk.KeyValue) (*sdk.Emp // SetAnnotation applies a Annotation to the backing GameServer metadata func (l *LocalSDKServer) SetAnnotation(_ context.Context, kv *sdk.KeyValue) (*sdk.Empty, error) { - logrus.WithField("values", kv).Info("Setting annotation") + logrus.WithField("values", kv).Debug("Setting annotation") l.gsMutex.Lock() defer l.gsMutex.Unlock() @@ -285,7 +285,7 @@ func (l *LocalSDKServer) SetAnnotation(_ context.Context, kv *sdk.KeyValue) (*sd // GetGameServer returns current GameServer configuration. func (l *LocalSDKServer) GetGameServer(context.Context, *sdk.Empty) (*sdk.GameServer, error) { - logrus.Info("getting GameServer details") + logrus.Debug("Getting GameServer details") l.recordRequest("gameserver") l.gsMutex.RLock() defer l.gsMutex.RUnlock() @@ -294,7 +294,7 @@ func (l *LocalSDKServer) GetGameServer(context.Context, *sdk.Empty) (*sdk.GameSe // WatchGameServer will return current GameServer configuration, 3 times, every 5 seconds func (l *LocalSDKServer) WatchGameServer(_ *sdk.Empty, stream sdk.SDK_WatchGameServerServer) error { - logrus.Info("connected to watch GameServer...") + logrus.Debug("Connected to watch GameServer...") observer := make(chan struct{}) defer func() { @@ -319,7 +319,7 @@ func (l *LocalSDKServer) WatchGameServer(_ *sdk.Empty, stream sdk.SDK_WatchGameS // Reserve moves this GameServer to the Reserved state for the Duration specified func (l *LocalSDKServer) Reserve(ctx context.Context, d *sdk.Duration) (*sdk.Empty, error) { - logrus.WithField("duration", d).Info("Reserve request has been received!") + logrus.WithField("duration", d).Debug("Reserve request has been received!") l.recordRequest("reserve") l.gsMutex.Lock() defer l.gsMutex.Unlock() @@ -387,18 +387,18 @@ func EqualSets(a, b []string) bool { // Close tears down all the things func (l *LocalSDKServer) compare() { - logrus.Info(fmt.Sprintf("Compare")) + logrus.Debug("Compare") if l.testMode { if !EqualSets(l.expectedSequence, l.requestSequence) { - logrus.Info(fmt.Sprintf("Testing Failed %v %v", l.expectedSequence, l.requestSequence)) + logrus.Debug(fmt.Sprintf("Testing Failed %v %v", l.expectedSequence, l.requestSequence)) os.Exit(1) } } } func (l *LocalSDKServer) setGameServerFromFilePath(filePath string) error { - logrus.WithField("filePath", filePath).Info("Reading GameServer configuration") + logrus.WithField("filePath", filePath).Debug("Reading GameServer configuration") reader, err := os.Open(filePath) // nolint: gosec defer reader.Close() // nolint: megacheck,errcheck diff --git a/pkg/sdkserver/sdkserver.go b/pkg/sdkserver/sdkserver.go index 2f7d063976..4c8c736a40 100644 --- a/pkg/sdkserver/sdkserver.go +++ b/pkg/sdkserver/sdkserver.go @@ -196,17 +196,17 @@ func (s *SDKServer) Run(stop <-chan struct{}) error { if gs.Spec.SdkServer.LogLevel != "" { logLevel = gs.Spec.SdkServer.LogLevel } - s.logger.WithField("logLevel", logLevel).Info("Setting LogLevel configuration") + s.logger.WithField("logLevel", logLevel).Debug("Setting LogLevel configuration") level, err := logrus.ParseLevel(strings.ToLower(string(logLevel))) if err == nil { s.logger.Logger.SetLevel(level) } else { - s.logger.WithError(err).Info("Specified wrong Logging.SdkServer. Setting default loglevel - Info") + s.logger.WithError(err).Warn("Specified wrong Logging.SdkServer. Setting default loglevel - Info") s.logger.Logger.SetLevel(logrus.InfoLevel) } s.health = gs.Spec.Health - s.logger.WithField("health", s.health).Info("Setting health configuration") + s.logger.WithField("health", s.health).Debug("Setting health configuration") s.healthTimeout = time.Duration(gs.Spec.Health.PeriodSeconds) * time.Second s.initHealthLastUpdated(time.Duration(gs.Spec.Health.InitialDelaySeconds) * time.Second) @@ -218,16 +218,16 @@ func (s *SDKServer) Run(stop <-chan struct{}) error { // start health checking running if !s.health.Disabled { - s.logger.Info("Starting GameServer health checking") + s.logger.Debug("Starting GameServer health checking") go wait.Until(s.runHealth, s.healthTimeout, stop) } // then start the http endpoints - s.logger.Info("Starting SDKServer http health check...") + s.logger.Debug("Starting SDKServer http health check...") go func() { if err := s.server.ListenAndServe(); err != nil { if err == http.ErrServerClosed { - s.logger.WithError(err).Info("Health check: http server closed") + s.logger.WithError(err).Error("Health check: http server closed") } else { err = errors.Wrap(err, "Could not listen on :8080") runtime.HandleError(s.logger.WithError(err), err) @@ -261,7 +261,7 @@ func (s *SDKServer) syncGameServer(key string) error { // updateState sets the GameServer Status's state to the one persisted in SDKServer, // i.e. SDKServer.gsState. func (s *SDKServer) updateState() error { - s.logger.WithField("state", s.gsState).Info("Updating state") + s.logger.WithField("state", s.gsState).Debug("Updating state") if len(s.gsState) == 0 { return errors.Errorf("could not update GameServer %s/%s to empty state", s.namespace, s.gameServerName) } @@ -274,13 +274,13 @@ func (s *SDKServer) updateState() error { // If we are currently in shutdown/being deleted, there is no escaping. if gs.IsBeingDeleted() { - s.logger.Info("GameServerState being shutdown. Skipping update.") + s.logger.Debug("GameServerState being shutdown. Skipping update.") return nil } // If the state is currently unhealthy, you can't go back to Ready. if gs.Status.State == agonesv1.GameServerStateUnhealthy { - s.logger.Info("GameServerState already unhealthy. Skipping update.") + s.logger.Debug("GameServerState already unhealthy. Skipping update.") return nil } @@ -333,7 +333,7 @@ func (s *SDKServer) gameServer() (*agonesv1.GameServer, error) { // updateLabels updates the labels on this GameServer to the ones persisted in SDKServer, // i.e. SDKServer.gsLabels, with the prefix of "agones.dev/sdk-" func (s *SDKServer) updateLabels() error { - s.logger.WithField("labels", s.gsLabels).Info("Updating label") + s.logger.WithField("labels", s.gsLabels).Debug("Updating label") gs, err := s.gameServer() if err != nil { return err @@ -357,7 +357,7 @@ func (s *SDKServer) updateLabels() error { // updateAnnotations updates the Annotations on this GameServer to the ones persisted in SDKServer, // i.e. SDKServer.gsAnnotations, with the prefix of "agones.dev/sdk-" func (s *SDKServer) updateAnnotations() error { - s.logger.WithField("annotations", s.gsAnnotations).Info("updating annotation") + s.logger.WithField("annotations", s.gsAnnotations).Debug("Updating annotation") gs, err := s.gameServer() if err != nil { return err @@ -390,7 +390,7 @@ func (s *SDKServer) enqueueState(state agonesv1.GameServerState) { // Ready enters the RequestReady state change for this GameServer into // the workqueue so it can be updated func (s *SDKServer) Ready(ctx context.Context, e *sdk.Empty) (*sdk.Empty, error) { - s.logger.Info("Received Ready request, adding to queue") + s.logger.Debug("Received Ready request, adding to queue") s.stopReserveTimer() s.enqueueState(agonesv1.GameServerStateRequestReady) return e, nil @@ -406,7 +406,7 @@ func (s *SDKServer) Allocate(ctx context.Context, e *sdk.Empty) (*sdk.Empty, err // Shutdown enters the Shutdown state change for this GameServer into // the workqueue so it can be updated func (s *SDKServer) Shutdown(ctx context.Context, e *sdk.Empty) (*sdk.Empty, error) { - s.logger.Info("Received Shutdown request, adding to queue") + s.logger.Debug("Received Shutdown request, adding to queue") s.stopReserveTimer() s.enqueueState(agonesv1.GameServerStateShutdown) return e, nil @@ -418,13 +418,13 @@ func (s *SDKServer) Health(stream sdk.SDK_HealthServer) error { for { _, err := stream.Recv() if err == io.EOF { - s.logger.Info("Health stream closed.") + s.logger.Debug("Health stream closed.") return stream.SendAndClose(&sdk.Empty{}) } if err != nil { return errors.Wrap(err, "Error with Health check") } - s.logger.Info("Health Ping Received") + s.logger.Debug("Health Ping Received") s.touchHealthLastUpdated() } } @@ -432,7 +432,7 @@ func (s *SDKServer) Health(stream sdk.SDK_HealthServer) error { // SetLabel adds the Key/Value to be used to set the label with the metadataPrefix to the `GameServer` // metdata func (s *SDKServer) SetLabel(_ context.Context, kv *sdk.KeyValue) (*sdk.Empty, error) { - s.logger.WithField("values", kv).Info("Adding SetLabel to queue") + s.logger.WithField("values", kv).Debug("Adding SetLabel to queue") s.gsUpdateMutex.Lock() s.gsLabels[kv.Key] = kv.Value @@ -445,7 +445,7 @@ func (s *SDKServer) SetLabel(_ context.Context, kv *sdk.KeyValue) (*sdk.Empty, e // SetAnnotation adds the Key/Value to be used to set the annotations with the metadataPrefix to the `GameServer` // metdata func (s *SDKServer) SetAnnotation(_ context.Context, kv *sdk.KeyValue) (*sdk.Empty, error) { - s.logger.WithField("values", kv).Info("Adding SetAnnotation to queue") + s.logger.WithField("values", kv).Debug("Adding SetAnnotation to queue") s.gsUpdateMutex.Lock() s.gsAnnotations[kv.Key] = kv.Value @@ -457,7 +457,7 @@ func (s *SDKServer) SetAnnotation(_ context.Context, kv *sdk.KeyValue) (*sdk.Emp // GetGameServer returns the current GameServer configuration and state from the backing GameServer CRD func (s *SDKServer) GetGameServer(context.Context, *sdk.Empty) (*sdk.GameServer, error) { - s.logger.Info("Received GetGameServer request") + s.logger.Debug("Received GetGameServer request") gs, err := s.gameServer() if err != nil { return nil, err @@ -469,7 +469,7 @@ func (s *SDKServer) GetGameServer(context.Context, *sdk.Empty) (*sdk.GameServer, // WatchGameServer sends events through the stream when changes occur to the // backing GameServer configuration / status func (s *SDKServer) WatchGameServer(_ *sdk.Empty, stream sdk.SDK_WatchGameServerServer) error { - s.logger.Info("Received WatchGameServer request, adding stream to connectedStreams") + s.logger.Debug("Received WatchGameServer request, adding stream to connectedStreams") s.streamMutex.Lock() s.connectedStreams = append(s.connectedStreams, stream) s.streamMutex.Unlock() @@ -492,7 +492,7 @@ func (s *SDKServer) Reserve(ctx context.Context, d *sdk.Duration) (*sdk.Empty, e s.gsUpdateMutex.Unlock() } - s.logger.Info("Received Reserve request, adding to queue") + s.logger.Debug("Received Reserve request, adding to queue") s.enqueueState(agonesv1.GameServerStateReserved) return e, nil @@ -525,7 +525,7 @@ func (s *SDKServer) stopReserveTimer() { // sendGameServerUpdate sends a watch game server event func (s *SDKServer) sendGameServerUpdate(gs *agonesv1.GameServer) { - s.logger.Info("Sending GameServer Event to connectedStreams") + s.logger.Debug("Sending GameServer Event to connectedStreams") s.streamMutex.RLock() defer s.streamMutex.RUnlock() @@ -548,7 +548,7 @@ func (s *SDKServer) sendGameServerUpdate(gs *agonesv1.GameServer) { func (s *SDKServer) runHealth() { s.checkHealth() if !s.healthy() { - s.logger.WithField("gameServerName", s.gameServerName).Info("GameServer has failed health check") + s.logger.WithField("gameServerName", s.gameServerName).Warn("GameServer has failed health check") s.enqueueState(agonesv1.GameServerStateUnhealthy) } } @@ -571,7 +571,7 @@ func (s *SDKServer) checkHealth() { s.healthMutex.Lock() defer s.healthMutex.Unlock() s.healthFailureCount++ - s.logger.WithField("failureCount", s.healthFailureCount).Infof("GameServer Health Check failed") + s.logger.WithField("failureCount", s.healthFailureCount).Warn("GameServer Health Check failed") } } diff --git a/pkg/util/apiserver/apiserver.go b/pkg/util/apiserver/apiserver.go index 253861a56f..cc1e0969cc 100644 --- a/pkg/util/apiserver/apiserver.go +++ b/pkg/util/apiserver/apiserver.go @@ -115,13 +115,13 @@ func (as *APIServer) AddAPIResource(groupVersion string, resource metav1.APIReso as.resourceList[groupVersion] = list pattern := fmt.Sprintf("/apis/%s", groupVersion) as.addSerializedHandler(pattern, list) - as.logger.WithField("groupversion", groupVersion).WithField("pattern", pattern).Info("Adding Discovery Handler") + as.logger.WithField("groupversion", groupVersion).WithField("pattern", pattern).Debug("Adding Discovery Handler") // e.g. /apis/agones.dev/v1/namespaces/default/gameservers // CRD handler pattern = fmt.Sprintf("/apis/%s/namespaces/", groupVersion) as.mux.HandleFunc(pattern, https.ErrorHTTPHandler(as.logger, as.resourceHandler(groupVersion))) - as.logger.WithField("groupversion", groupVersion).WithField("pattern", pattern).Info("Adding Resource Handler") + as.logger.WithField("groupversion", groupVersion).WithField("pattern", pattern).Debug("Adding Resource Handler") } // discovery resource @@ -131,7 +131,7 @@ func (as *APIServer) AddAPIResource(groupVersion string, resource metav1.APIReso key := fmt.Sprintf("%s/%s", groupVersion, resource.Name) as.delegates[key] = handler - as.logger.WithField("groupversion", groupVersion).WithField("apiresource", resource).Info("Adding APIResource") + as.logger.WithField("groupversion", groupVersion).WithField("apiresource", resource).Debug("Adding APIResource") } // resourceHandler handles namespaced resource calls, and sends them to the appropriate CRDHandler delegate