logging review (#80)

* adjusting log levels and messages a bit * fixing test to watch debug logs
FairwindsOps · Jan 15, 2020 · b3c1994 · b3c1994
1 parent fcab9e9
commit b3c1994
Show file tree

Hide file tree

Showing 8 changed files with 35 additions and 35 deletions.
diff --git a/cmd/root.go b/cmd/root.go
@@ -113,11 +113,11 @@ func leaderElection(cmd *cobra.Command, args []string) {
 				run(ctx, cancel)
 			},
 			OnStoppedLeading: func() {
-				log.Infof("%s leaving", id)
+				log.Infof("%s is no longer the leader", id)
 			},
 			OnNewLeader: func(identity string) {
 				if id == identity {
-					log.Info("I'm now the leader")
+					log.Debug("I'm now the leader")
 					return
 				}
 				log.Infof("%s is now the leader", identity)
@@ -137,7 +137,7 @@ func run(ctx context.Context, cancel context.CancelFunc) {
 		log.Info("Exiting, received termination signal")
 		cancel()
 	}()
-
+	log.Info("Entering main run loop and starting watchers.")
 	controller.New(ctx)
 }
 

diff --git a/dd-manager b/dd-manager
diff --git a/pkg/config/config.go b/pkg/config/config.go
@@ -102,7 +102,7 @@ func (config *Config) getMatchingRulesets(annotations map[string]string, objectT
 					hasAllAnnotations = true
 				} else {
 					hasAllAnnotations = false
-					log.Infof("Annotation %s with value %s does not exist, so monitor %d does not match", annotation.Name, annotation.Value, monitorSetIdx)
+					log.Debugf("Annotation %s with value %s does not exist, so monitor %d does not match", annotation.Name, annotation.Value, monitorSetIdx)
 					break
 				}
 			}
@@ -210,7 +210,7 @@ func (config *Config) reloadRulesets() {
 	}
 
 	for _, cfg := range config.MonitorDefinitionsPath {
-		log.Infof("Loading rulesets from %s", cfg)
+		log.Debugf("Loading rulesets from %s", cfg)
 		rSet := &ruleset{}
 
 		yml, err := loadFromPath(cfg)
@@ -257,11 +257,11 @@ func loadFromPath(path string) ([]byte, error) {
 }
 
 func getEnv(key string, defaultVal string) string {
-	log.Infof("Getting environment variable %s", key)
+	log.Debugf("Getting environment variable %s", key)
 	if value, exists := os.LookupEnv(key); exists {
 		return value
 	}
-	log.Info(fmt.Sprintf("Using default value %s for %s", defaultVal, key))
+	log.Debugf(fmt.Sprintf("Using default value %s for %s", defaultVal, key))
 	return defaultVal
 }
 
@@ -277,7 +277,7 @@ func envAsBool(key string, defaultVal bool) bool {
 	if val, err := strconv.ParseBool(val); err == nil {
 		return val
 	}
-	log.Info(fmt.Sprintf("Using default value %t for %s", defaultVal, key))
+	log.Debugf("Using default value %t for %s", defaultVal, key)
 	return defaultVal
 }
 
@@ -286,6 +286,6 @@ func envAsInt(key string, defaultVal int) int {
 	if val, err := strconv.Atoi(val); err == nil {
 		return val
 	}
-	log.Info(fmt.Sprintf("Using default value %d for %s", defaultVal, key))
+	log.Debugf("Using default value %d for %s", defaultVal, key)
 	return defaultVal
 }
diff --git a/pkg/controller/controller.go b/pkg/controller/controller.go
@@ -45,7 +45,7 @@ type KubeResourceWatcher struct {
 
 // Watch tells the KubeResourceWatcher to start waiting for events
 func (watcher *KubeResourceWatcher) Watch(term <-chan struct{}) {
-	log.Infof("Starting watcher.")
+	log.Debugf("Starting watcher.")
 
 	defer watcher.wq.ShutDown()
 	defer rt.HandleCrash()
@@ -57,7 +57,7 @@ func (watcher *KubeResourceWatcher) Watch(term <-chan struct{}) {
 		return
 	}
 
-	log.Infof("Watcher synced.")
+	log.Debugf("Watcher synced.")
 	wait.Until(watcher.waitForEvents, time.Second, term)
 }
 
@@ -103,7 +103,7 @@ func (watcher *KubeResourceWatcher) next() bool {
 		// limit the number of retries
 		if watcher.wq.NumRequeues(evt) < 5 {
 			log.Errorf("Error running queued item %s: %v", evt.(config.Event).Key, processErr)
-			log.Infof("Retry processing item %s", evt.(config.Event).Key)
+			log.Errorf("Retry processing item %s", evt.(config.Event).Key)
 			watcher.wq.AddRateLimited(evt)
 		} else {
 			log.Errorf("Giving up trying to run queued item %s: %v", evt.(config.Event).Key, processErr)
@@ -116,9 +116,9 @@ func (watcher *KubeResourceWatcher) next() bool {
 
 // New starts a controller for watching Kubernetes objects.
 func New(ctx context.Context) {
-	log.Info("Starting controller.")
+	log.Debug("Starting controller.")
 	kubeClient := kube.GetInstance()
-	log.Infof("Creating watcher for Deployments.")
+	log.Debug("Creating watcher for Deployments.")
 	DeploymentInformer := cache.NewSharedIndexInformer(
 		&cache.ListWatch{
 			ListFunc: func(options metav1.ListOptions) (runtime.Object, error) {
@@ -137,7 +137,7 @@ func New(ctx context.Context) {
 	defer close(dTerm)
 	go DeployWatcher.Watch(dTerm)
 
-	log.Infof("Creating watcher for Namespaces.")
+	log.Debug("Creating watcher for Namespaces.")
 	NSInformer := cache.NewSharedIndexInformer(
 		&cache.ListWatch{
 			ListFunc: func(options metav1.ListOptions) (runtime.Object, error) {
@@ -165,7 +165,7 @@ func New(ctx context.Context) {
 }
 
 func createController(kubeClient kubernetes.Interface, informer cache.SharedIndexInformer, resource string) *KubeResourceWatcher {
-	log.Infof("Creating controller for resource type %s", resource)
+	log.Debugf("Creating controller for resource type %s", resource)
 	wq := workqueue.NewRateLimitingQueue(workqueue.DefaultControllerRateLimiter())
 
 	informer.AddEventHandler(cache.ResourceEventHandlerFuncs{
@@ -183,7 +183,7 @@ func createController(kubeClient kubernetes.Interface, informer cache.SharedInde
 			evt.Namespace = objectMeta(obj).Namespace
 			evt.NewMeta = &objMeta
 			evt.OldMeta = new(metav1.ObjectMeta)
-			log.Infof("%s/%s has been added.", resource, evt.Key)
+			log.Debugf("%s/%s has been added.", resource, evt.Key)
 			wq.Add(evt)
 		},
 		DeleteFunc: func(obj interface{}) {
@@ -200,7 +200,7 @@ func createController(kubeClient kubernetes.Interface, informer cache.SharedInde
 			evt.Namespace = objectMeta(obj).Namespace
 			evt.NewMeta = new(metav1.ObjectMeta)
 			evt.OldMeta = &objMeta
-			log.Infof("%s/%s has been deleted.", resource, evt.Key)
+			log.Debugf("%s/%s has been deleted.", resource, evt.Key)
 			wq.Add(evt)
 		},
 		UpdateFunc: func(old interface{}, new interface{}) {
@@ -218,7 +218,7 @@ func createController(kubeClient kubernetes.Interface, informer cache.SharedInde
 			evt.Namespace = objectMeta(new).Namespace
 			evt.OldMeta = &oldMeta
 			evt.NewMeta = &newMeta
-			log.Infof("%s/%s has been updated.", resource, evt.Key)
+			log.Debugf("%s/%s has been updated.", resource, evt.Key)
 			wq.Add(evt)
 		},
 	})

diff --git a/pkg/controller/controller_test.go b/pkg/controller/controller_test.go
@@ -15,7 +15,7 @@ import (
 	"k8s.io/client-go/tools/cache"
 	"k8s.io/client-go/util/workqueue"
 
-	"github.com/sirupsen/logrus"
+	log "github.com/sirupsen/logrus"
 	"github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 
@@ -61,9 +61,9 @@ func TestCreateDeploymentController(t *testing.T) {
 }
 
 func TestNewController(t *testing.T) {
+	log.SetLevel(log.DebugLevel)
 	_, hook := test.NewNullLogger()
-	logrus.AddHook(hook)
-	logrus.SetLevel(logrus.InfoLevel)
+	log.AddHook(hook)
 	kube.SetAndGetMock()
 	os.Setenv("DEFINITIONS_PATH", "../config/test_conf.yml")
 	ctx, cancel := context.WithCancel(context.Background())

diff --git a/pkg/datadog/datadog.go b/pkg/datadog/datadog.go
@@ -59,14 +59,15 @@ func GetInstance() *DDMonitorManager {
 // AddOrUpdate will create a monitor if it doesn't exist or update one if it does.
 // It returns the Id of the monitor created or updated.
 func (ddman *DDMonitorManager) AddOrUpdate(monitor *ddapi.Monitor) (*ddapi.Monitor, error) {
-	log.Infof("Update templated monitor: %v", *monitor.Name)
+	log.Debugf("Update templated monitor: %v", *monitor.Name)
 	ddman.mux.Lock()
 	defer ddman.mux.Unlock()
 
 	// check if monitor exists
 	ddMonitor, err := ddman.GetProvisionedMonitor(monitor)
 	if err != nil {
 		//monitor doesn't exist
+		log.Infof("Creating new monitor: %v", *monitor.Name)
 		provisioned, err := ddman.Datadog.CreateMonitor(monitor)
 
 		if err != nil {
@@ -83,14 +84,14 @@ func (ddman *DDMonitorManager) AddOrUpdate(monitor *ddapi.Monitor) (*ddapi.Monit
 	}
 	//monitor exists
 	if reflect.DeepEqual(*merged, *ddMonitor) {
-		log.Infof("Monitor %d exists and is up to date.", *ddMonitor.Id)
+		log.Infof("Monitor exists and is up to date: %v", *ddMonitor.Name)
 	} else {
 		// monitor exists and needs updating.
-		log.Infof("Monitor %d needs updating.", *ddMonitor.Id)
+		log.Infof("Monitor needs updating: %v", *ddMonitor.Name)
 		err := ddman.Datadog.UpdateMonitor(merged)
 		if err != nil {
 			metrics.DatadogErrCounter.Inc()
-			log.Errorf("Could not update monitor %d: %s", *ddMonitor.Id, err)
+			log.Errorf("Could not update monitor: %v, error: %s", *ddMonitor.Name, err)
 			return ddMonitor, err
 		}
 	}
@@ -131,13 +132,13 @@ func (ddman *DDMonitorManager) DeleteMonitor(monitor *ddapi.Monitor) error {
 // DeleteMonitors deletes monitors containing the specified tags.
 func (ddman *DDMonitorManager) DeleteMonitors(tags []string) error {
 	monitors, err := ddman.Datadog.GetMonitorsByMonitorTags(tags)
-
-	log.Infof("Deleting %d monitors.", len(monitors))
 	if err != nil {
 		metrics.DatadogErrCounter.Inc()
 		return err
 	}
 
+	log.Infof("Deleting %d monitors.", len(monitors))
+
 	for _, ddMonitor := range monitors {
 		log.Infof("Deleting monitor with id %d", *ddMonitor.Id)
 		err := ddman.Datadog.DeleteMonitor(*ddMonitor.Id)
@@ -161,7 +162,7 @@ func DeleteExtinctMonitors(monitors []string, tags []string) error {
 	for _, monitor := range existing {
 		if !contains(monitors, monitor) {
 			// monitor should no longer exist
-			log.Infof("Found monitor %s that shouldn't exist.", *monitor.Name)
+			log.Infof("Removing monitor: %v", *monitor.Name)
 			err = ddMan.Datadog.DeleteMonitor(*monitor.Id)
 			if err != nil {
 				metrics.DatadogErrCounter.Inc()

diff --git a/pkg/handler/deployments.go b/pkg/handler/deployments.go
@@ -39,7 +39,7 @@ func OnDeploymentChanged(deployment *appsv1.Deployment, event config.Event) {
 	switch strings.ToLower(event.EventType) {
 	case "delete":
 		if cfg.DryRun == false {
-			log.Info("Deleting resource monitors.")
+			log.Debug("Deleting resource monitors.")
 			metrics.ChangeCounter.WithLabelValues("deployments", "delete").Inc()
 			dd.DeleteMonitors([]string{cfg.OwnerTag, fmt.Sprintf("astro:object_type:%s", event.ResourceType), fmt.Sprintf("astro:resource:%s", event.Key)})
 		}
@@ -61,7 +61,7 @@ func OnDeploymentChanged(deployment *appsv1.Deployment, event config.Event) {
 				log.Errorf("Error applying template for monitor %s: %v", *monitor.Name, err)
 				return
 			}
-			log.Infof("Reconcile monitor %s", *monitor.Name)
+			log.Debugf("Reconcile monitor %s", *monitor.Name)
 			if cfg.DryRun == false {
 				_, err := dd.AddOrUpdate(&monitor)
 				metrics.ChangeCounter.WithLabelValues("deployments", "create_update").Inc()

diff --git a/pkg/handler/handler.go b/pkg/handler/handler.go
@@ -34,7 +34,7 @@ import (
 // obj is the Kubernetes object that was updated.
 // event is the Event metadata representing the update.
 func OnUpdate(obj interface{}, event config.Event) {
-	log.Infof("Handler got an OnUpdate event of type %s", event.ResourceType)
+	log.Debugf("Handler got an OnUpdate event of type %s", event.ResourceType)
 
 	if event.EventType == "delete" {
 		onDelete(event)
@@ -45,7 +45,7 @@ func OnUpdate(obj interface{}, event config.Event) {
 	newMeta := *event.NewMeta
 
 	if reflect.DeepEqual(oldMeta.Annotations, newMeta.Annotations) {
-		log.Infof("Old annotations match new, not updating: %s", event.Key)
+		log.Debugf("Old annotations match new, not updating: %s", event.Key)
 		return
 	}
 
@@ -60,7 +60,6 @@ func OnUpdate(obj interface{}, event config.Event) {
 }
 
 func onDelete(event config.Event) {
-	log.Info("OnDelete()")
 	switch strings.ToLower(event.ResourceType) {
 	case "namespace":
 		OnNamespaceChanged(&corev1.Namespace{}, event)
@@ -175,7 +174,7 @@ func isOverride(annotationKey string) bool {
 		log.Errorf("Error parsing regexp of annotation key: %v", annotationKey)
 	}
 	if matched {
-		log.Infof("Override found with annotation '%s'", annotationKey)
+		log.Debugf("Override found with annotation '%s'", annotationKey)
 	}
 	return matched
 }