Merge pull request #2666 from weaveworks/issues/2633-json-events

Log objects via JSON for better debugging

npc/controller.go

@@ -3,12 +3,12 @@ package npc
 import (
 	"sync"
 
-	log "github.com/Sirupsen/logrus"
 	"github.com/coreos/go-iptables/iptables"
 	"github.com/pkg/errors"
 	coreapi "k8s.io/client-go/pkg/api/v1"
 	extnapi "k8s.io/client-go/pkg/apis/extensions/v1beta1"
 
+	"github.com/weaveworks/weave/common"
 	"github.com/weaveworks/weave/npc/ipset"
 )
 
@@ -86,7 +86,7 @@ func (npc *controller) AddPod(obj *coreapi.Pod) error {
 	npc.Lock()
 	defer npc.Unlock()
 
-	log.Infof("EVENT AddPod %#v", obj)
+	common.Log.Debugf("EVENT AddPod %s", js(obj))
 	return npc.withNS(obj.ObjectMeta.Namespace, func(ns *ns) error {
 		return errors.Wrap(ns.addPod(obj), "add pod")
 	})
@@ -96,7 +96,7 @@ func (npc *controller) UpdatePod(oldObj, newObj *coreapi.Pod) error {
 	npc.Lock()
 	defer npc.Unlock()
 
-	log.Infof("EVENT UpdatePod %#v %#v", oldObj, newObj)
+	common.Log.Debugf("EVENT UpdatePod %s %s", js(oldObj), js(newObj))
 	return npc.withNS(oldObj.ObjectMeta.Namespace, func(ns *ns) error {
 		return errors.Wrap(ns.updatePod(oldObj, newObj), "update pod")
 	})
@@ -106,7 +106,7 @@ func (npc *controller) DeletePod(obj *coreapi.Pod) error {
 	npc.Lock()
 	defer npc.Unlock()
 
-	log.Infof("EVENT DeletePod %#v", obj)
+	common.Log.Debugf("EVENT DeletePod %s", js(obj))
 	return npc.withNS(obj.ObjectMeta.Namespace, func(ns *ns) error {
 		return errors.Wrap(ns.deletePod(obj), "delete pod")
 	})
@@ -116,7 +116,7 @@ func (npc *controller) AddNetworkPolicy(obj *extnapi.NetworkPolicy) error {
 	npc.Lock()
 	defer npc.Unlock()
 
-	log.Infof("EVENT AddNetworkPolicy %#v", obj)
+	common.Log.Infof("EVENT AddNetworkPolicy %s", js(obj))
 	return npc.withNS(obj.ObjectMeta.Namespace, func(ns *ns) error {
 		return errors.Wrap(ns.addNetworkPolicy(obj), "add network policy")
 	})
@@ -126,7 +126,7 @@ func (npc *controller) UpdateNetworkPolicy(oldObj, newObj *extnapi.NetworkPolicy
 	npc.Lock()
 	defer npc.Unlock()
 
-	log.Infof("EVENT UpdateNetworkPolicy %#v %#v", oldObj, newObj)
+	common.Log.Infof("EVENT UpdateNetworkPolicy %s %s", js(oldObj), js(newObj))
 	return npc.withNS(oldObj.ObjectMeta.Namespace, func(ns *ns) error {
 		return errors.Wrap(ns.updateNetworkPolicy(oldObj, newObj), "update network policy")
 	})
@@ -136,7 +136,7 @@ func (npc *controller) DeleteNetworkPolicy(obj *extnapi.NetworkPolicy) error {
 	npc.Lock()
 	defer npc.Unlock()
 
-	log.Infof("EVENT DeleteNetworkPolicy %#v", obj)
+	common.Log.Infof("EVENT DeleteNetworkPolicy %s", js(obj))
 	return npc.withNS(obj.ObjectMeta.Namespace, func(ns *ns) error {
 		return errors.Wrap(ns.deleteNetworkPolicy(obj), "delete network policy")
 	})
@@ -146,7 +146,7 @@ func (npc *controller) AddNamespace(obj *coreapi.Namespace) error {
 	npc.Lock()
 	defer npc.Unlock()
 
-	log.Infof("EVENT AddNamespace %#v", obj)
+	common.Log.Infof("EVENT AddNamespace %s", js(obj))
 	return npc.withNS(obj.ObjectMeta.Name, func(ns *ns) error {
 		return errors.Wrap(ns.addNamespace(obj), "add namespace")
 	})
@@ -156,7 +156,7 @@ func (npc *controller) UpdateNamespace(oldObj, newObj *coreapi.Namespace) error
 	npc.Lock()
 	defer npc.Unlock()
 
-	log.Infof("EVENT UpdateNamespace%#v %#v", oldObj, newObj)
+	common.Log.Infof("EVENT UpdateNamespace %s %s", js(oldObj), js(newObj))
 	return npc.withNS(oldObj.ObjectMeta.Name, func(ns *ns) error {
 		return errors.Wrap(ns.updateNamespace(oldObj, newObj), "update namespace")
 	})
@@ -166,7 +166,7 @@ func (npc *controller) DeleteNamespace(obj *coreapi.Namespace) error {
 	npc.Lock()
 	defer npc.Unlock()
 
-	log.Infof("EVENT DeleteNamespace %#v", obj)
+	common.Log.Infof("EVENT DeleteNamespace %s", js(obj))
 	return npc.withNS(obj.ObjectMeta.Name, func(ns *ns) error {
 		return errors.Wrap(ns.deleteNamespace(obj), "delete namespace")
 	})

npc/json.go

@@ -0,0 +1,10 @@
+package npc
+
+import (
+	"encoding/json"
+)
+
+func js(v interface{}) string {
+	a, _ := json.Marshal(v)
+	return string(a)
+}

npc/namespace.go

@@ -3,7 +3,6 @@ package npc
 import (
 	"encoding/json"
 
-	log "github.com/Sirupsen/logrus"
 	"github.com/coreos/go-iptables/iptables"
 	"k8s.io/client-go/pkg/api/unversioned"
 	coreapi "k8s.io/client-go/pkg/api/v1"
@@ -11,6 +10,7 @@ import (
 	"k8s.io/client-go/pkg/types"
 	"k8s.io/client-go/pkg/util/uuid"
 
+	"github.com/weaveworks/weave/common"
 	"github.com/weaveworks/weave/npc/ipset"
 )
 
@@ -327,7 +327,7 @@ func isDefaultDeny(namespace *coreapi.Namespace) bool {
 
 	var nnp NamespaceNetworkPolicy
 	if err := json.Unmarshal([]byte(nnpJSON), &nnp); err != nil {
-		log.Warn("Ignoring network policy annotation: unmarshal failed:", err)
+		common.Log.Warn("Ignoring network policy annotation: unmarshal failed:", err)
 		// If we can't understand the annotation, behave as if it isn't present
 		return false
 	}

npc/rule.go

@@ -3,9 +3,10 @@ package npc
 import (
 	"strings"
 
-	log "github.com/Sirupsen/logrus"
 	"github.com/coreos/go-iptables/iptables"
 	"k8s.io/client-go/pkg/types"
+
+	"github.com/weaveworks/weave/common"
 )
 
 type ruleSpec struct {
@@ -47,7 +48,7 @@ func (rs *ruleSet) deprovision(user types.UID, current, desired map[string]*rule
 		if _, found := desired[key]; !found {
 			delete(rs.users[key], user)
 			if len(rs.users[key]) == 0 {
-				log.Infof("deleting rule: %v", spec.args)
+				common.Log.Infof("deleting rule: %v", spec.args)
 				if err := rs.ipt.Delete(TableFilter, IngressChain, spec.args...); err != nil {
 					return err
 				}
@@ -63,7 +64,7 @@ func (rs *ruleSet) provision(user types.UID, current, desired map[string]*ruleSp
 	for key, spec := range desired {
 		if _, found := current[key]; !found {
 			if _, found := rs.users[key]; !found {
-				log.Infof("adding rule: %v", spec.args)
+				common.Log.Infof("adding rule: %v", spec.args)
 				if err := rs.ipt.Append(TableFilter, IngressChain, spec.args...); err != nil {
 					return err
 				}

npc/selector.go

@@ -1,11 +1,11 @@
 package npc
 
 import (
-	log "github.com/Sirupsen/logrus"
 	"k8s.io/client-go/pkg/api/unversioned"
 	"k8s.io/client-go/pkg/labels"
 	"k8s.io/client-go/pkg/types"
 
+	"github.com/weaveworks/weave/common"
 	"github.com/weaveworks/weave/npc/ipset"
 )
 
@@ -43,12 +43,12 @@ func (s *selector) matches(labelMap map[string]string) bool {
 }
 
 func (s *selector) addEntry(entry string) error {
-	log.Infof("adding entry %s to %s", entry, s.spec.ipsetName)
+	common.Log.Infof("adding entry %s to %s", entry, s.spec.ipsetName)
 	return s.ips.AddEntry(s.spec.ipsetName, entry)
 }
 
 func (s *selector) delEntry(entry string) error {
-	log.Infof("deleting entry %s from %s", entry, s.spec.ipsetName)
+	common.Log.Infof("deleting entry %s from %s", entry, s.spec.ipsetName)
 	return s.ips.DelEntry(s.spec.ipsetName, entry)
 }
 
@@ -96,7 +96,7 @@ func (ss *selectorSet) deprovision(user types.UID, current, desired map[string]*
 		if _, found := desired[key]; !found {
 			delete(ss.users[key], user)
 			if len(ss.users[key]) == 0 {
-				log.Infof("destroying ipset: %#v", spec)
+				common.Log.Infof("destroying ipset: %#v", spec)
 				if err := ss.ips.Destroy(spec.ipsetName); err != nil {
 					return err
 				}
@@ -112,7 +112,7 @@ func (ss *selectorSet) provision(user types.UID, current, desired map[string]*se
 	for key, spec := range desired {
 		if _, found := current[key]; !found {
 			if _, found := ss.users[key]; !found {
-				log.Infof("creating ipset: %#v", spec)
+				common.Log.Infof("creating ipset: %#v", spec)
 				if err := ss.ips.Create(spec.ipsetName, spec.ipsetType); err != nil {
 					return err
 				}

prog/weave-npc/main.go

@@ -5,7 +5,6 @@ import (
 	"os/signal"
 	"syscall"
 
-	log "github.com/Sirupsen/logrus"
 	"github.com/coreos/go-iptables/iptables"
 	"github.com/spf13/cobra"
 	"k8s.io/client-go/kubernetes"
@@ -17,6 +16,7 @@ import (
 	"k8s.io/client-go/rest"
 	"k8s.io/client-go/tools/cache"
 
+	"github.com/weaveworks/weave/common"
 	"github.com/weaveworks/weave/npc"
 	"github.com/weaveworks/weave/npc/ipset"
 	"github.com/weaveworks/weave/npc/metrics"
@@ -26,13 +26,10 @@ import (
 var (
 	version     = "unreleased"
 	metricsAddr string
+	logLevel    string
 )
 
-func handleError(err error) {
-	if err != nil {
-		log.Fatal(err)
-	}
-}
+func handleError(err error) { common.CheckFatal(err) }
 
 func makeController(getter cache.Getter, resource string,
 	objType runtime.Object, handlers cache.ResourceEventHandlerFuncs) *cache.Controller {
@@ -89,30 +86,25 @@ func resetIPSets(ips ipset.Interface) error {
 }
 
 func root(cmd *cobra.Command, args []string) {
-	log.Infof("Starting Weaveworks NPC %s", version)
+	common.SetLogLevel(logLevel)
+	common.Log.Infof("Starting Weaveworks NPC %s", version)
 
 	if err := metrics.Start(metricsAddr); err != nil {
-		log.Fatalf("Failed to start metrics: %v", err)
+		common.Log.Fatalf("Failed to start metrics: %v", err)
 	}
 
 	if err := ulogd.Start(); err != nil {
-		log.Fatalf("Failed to start ulogd: %v", err)
+		common.Log.Fatalf("Failed to start ulogd: %v", err)
 	}
 
 	config, err := rest.InClusterConfig()
-	if err != nil {
-		log.Fatal(err)
-	}
+	handleError(err)
 
 	client, err := kubernetes.NewForConfig(config)
-	if err != nil {
-		log.Fatal(err)
-	}
+	handleError(err)
 
 	ipt, err := iptables.New()
-	if err != nil {
-		log.Fatal(err)
-	}
+	handleError(err)
 
 	ips := ipset.New()
 
@@ -163,7 +155,7 @@ func root(cmd *cobra.Command, args []string) {
 
 	signals := make(chan os.Signal, 1)
 	signal.Notify(signals, syscall.SIGINT, syscall.SIGTERM)
-	log.Fatalf("Exiting: %v", <-signals)
+	common.Log.Fatalf("Exiting: %v", <-signals)
 }
 
 func main() {
@@ -173,8 +165,7 @@ func main() {
 		Run:   root}
 
 	rootCmd.PersistentFlags().StringVar(&metricsAddr, "metrics-addr", ":6781", "metrics server bind address")
+	rootCmd.PersistentFlags().StringVar(&logLevel, "-log-level", "debug", "logging level (debug, info, warning, error)")
 
-	if err := rootCmd.Execute(); err != nil {
-		log.Fatal(err)
-	}
+	handleError(rootCmd.Execute())
 }