Merge pull request #61 from telenornms/feat/more-standardized-logging

Introduce skogul.Logger() and use it

common.go

@@ -25,6 +25,7 @@ package skogul
 
 import (
 	"fmt"
+	"github.com/sirupsen/logrus"
 	"runtime"
 	"time"
 )
@@ -223,6 +224,14 @@ func (h Handler) Verify() error {
 	return nil
 }
 
+// Logger returns a logrus.Entry pre-populated with standard Skogul fields.
+// sourceType is the typical family of the code/module:
+// sender/receiver/parser/transformer/core, while sourceName is the local
+// implementation.
+func Logger(sourceType, sourceName string) *logrus.Entry {
+	return logrus.WithField("source", sourceType).WithField(sourceType, sourceName)
+}
+
 // AssertErrors counts the number of assert errors
 var AssertErrors int
 

config/parse.go

@@ -42,6 +42,8 @@ import (
 	"github.com/telenornms/skogul/transformer"
 )
 
+var confLog = skogul.Logger("core", "config")
+
 // Sender wraps the skogul.Sender for configuration parsing.
 type Sender struct {
 	Type   string
@@ -260,7 +262,7 @@ func Bytes(b []byte) (*Config, error) {
 func File(f string) (*Config, error) {
 	dat, err := ioutil.ReadFile(f)
 	if err != nil {
-		log.WithError(err).Fatal("Failed to read config file")
+		confLog.WithError(err).Fatal("Failed to read config file")
 		return nil, skogul.Error{Source: "config parser", Reason: "Failed to read config file", Next: err}
 	}
 	return Bytes(dat)
@@ -271,10 +273,10 @@ func File(f string) (*Config, error) {
 // completion.
 func resolveSenders(c *Config) error {
 	for _, s := range skogul.SenderMap {
-		log.WithField("sender", s.Name).Debug("Resolving sender")
+		confLog.WithField("sender", s.Name).Debug("Resolving sender")
 
 		if c.Senders[s.Name] == nil {
-			log.WithField("sender", s.Name).Error("Unresolved sender reference")
+			confLog.WithField("sender", s.Name).Error("Unresolved sender reference")
 			return skogul.Error{Source: "config parser", Reason: fmt.Sprintf("Unresolved sender reference %s", s.Name)}
 		}
 		s.S = c.Senders[s.Name].Sender
@@ -291,7 +293,7 @@ func resolveSenders(c *Config) error {
 // It then zeroes the skogul.HandlerMap
 func resolveHandlers(c *Config) error {
 	for _, h := range c.Handlers {
-		logger := log.WithField("parser", h.Parser)
+		logger := confLog.WithField("parser", h.Parser)
 
 		h.Handler.Sender = h.Sender.S
 		h.Handler.Transformers = make([]skogul.Transformer, 0)
@@ -343,7 +345,7 @@ func secondPass(c *Config, jsonData *map[string]interface{}) (*Config, error) {
 	}
 
 	for idx, h := range c.Handlers {
-		log.WithField("handler", idx).Debug("Verifying handler configuration")
+		confLog.WithField("handler", idx).Debug("Verifying handler configuration")
 		if err := verifyItem("handler", idx, h.Handler); err != nil {
 			return nil, err
 		}
@@ -352,7 +354,7 @@ func secondPass(c *Config, jsonData *map[string]interface{}) (*Config, error) {
 		verifyOnlyRequiredConfigProps(jsonData, "handlers", idx, configStruct)
 	}
 	for idx, t := range c.Transformers {
-		log.WithField("transformer", idx).Debug("Verifying transformer configuration")
+		confLog.WithField("transformer", idx).Debug("Verifying transformer configuration")
 		if err := verifyItem("transformer", idx, t.Transformer); err != nil {
 			return nil, err
 		}
@@ -361,7 +363,7 @@ func secondPass(c *Config, jsonData *map[string]interface{}) (*Config, error) {
 		verifyOnlyRequiredConfigProps(jsonData, "transformers", idx, configStruct)
 	}
 	for idx, s := range c.Senders {
-		log.WithField("sender", idx).Debug("Verifying sender configuration")
+		confLog.WithField("sender", idx).Debug("Verifying sender configuration")
 		if err := verifyItem("sender", idx, s.Sender); err != nil {
 			return nil, err
 		}
@@ -370,7 +372,7 @@ func secondPass(c *Config, jsonData *map[string]interface{}) (*Config, error) {
 		verifyOnlyRequiredConfigProps(jsonData, "senders", idx, configStruct)
 	}
 	for idx, r := range c.Receivers {
-		log.WithField("receiver", idx).Debug("Verifying receiver configuration")
+		confLog.WithField("receiver", idx).Debug("Verifying receiver configuration")
 		if err := verifyItem("receiver", idx, r.Receiver); err != nil {
 			return nil, err
 		}
@@ -387,15 +389,15 @@ func secondPass(c *Config, jsonData *map[string]interface{}) (*Config, error) {
 func verifyItem(family string, name string, item interface{}) error {
 	i, ok := item.(skogul.Verifier)
 	if !ok {
-		log.WithFields(log.Fields{"family": family, "name": name}).Trace("No verifier found")
+		confLog.WithFields(log.Fields{"family": family, "name": name}).Trace("No verifier found")
 		return nil
 	}
 	err := i.Verify()
 	if err != nil {
-		log.WithFields(log.Fields{"family": family, "name": name}).Error("Invalid item configuration")
+		confLog.WithFields(log.Fields{"family": family, "name": name}).Error("Invalid item configuration")
 		return skogul.Error{Source: "config parser", Reason: fmt.Sprintf("%s %s isn't valid", family, name), Next: err}
 	}
-	log.WithFields(log.Fields{"family": family, "name": name}).Trace("Verified OK")
+	confLog.WithFields(log.Fields{"family": family, "name": name}).Trace("Verified OK")
 	return nil
 }
 
@@ -421,7 +423,7 @@ func findFieldsOfStruct(T reflect.Type) []string {
 func getRelevantRawConfigSection(rawConfig *map[string]interface{}, family, section string) map[string]interface{} {
 	configFamily, ok := (*rawConfig)[family].(map[string]interface{})
 	if !ok {
-		log.WithFields(log.Fields{
+		confLog.WithFields(log.Fields{
 			"family":  family,
 			"section": section,
 		}).Warnf("Failed to cast config family to map[string]interface{}")
@@ -430,7 +432,7 @@ func getRelevantRawConfigSection(rawConfig *map[string]interface{}, family, sect
 
 	configSection, ok := configFamily[section].(map[string]interface{})
 	if !ok {
-		log.WithFields(log.Fields{
+		confLog.WithFields(log.Fields{
 			"family":  family,
 			"section": section,
 		}).Warnf("Failed to cast config section to map[string]interface{}")
@@ -462,7 +464,7 @@ func verifyOnlyRequiredConfigProps(rawConfig *map[string]interface{}, family, ha
 		}
 		if !propertyDefined {
 			superfluousProperties = append(superfluousProperties, prop)
-			log.WithField("property", prop).Warn("Configuration property configured but not defined in code (this property won't change anything, is it wrongly defined?)")
+			confLog.WithField("property", prop).Warn("Configuration property configured but not defined in code (this property won't change anything, is it wrongly defined?)")
 		}
 	}
 

data.go

@@ -27,10 +27,10 @@ import (
 	"encoding/json"
 	"fmt"
 	"time"
-
-	log "github.com/sirupsen/logrus"
 )
 
+var dataLog = Logger("core", "data")
+
 /*
 Container is the top-level object for one or more metric.
 
@@ -187,7 +187,7 @@ func (c *Container) Validate() error {
 func (c Container) String() string {
 	b, err := json.MarshalIndent(c, "", "  ")
 	if err != nil {
-		log.WithError(err).Error("Unable to marshal JSON")
+		dataLog.WithError(err).Error("Unable to marshal JSON")
 		return ""
 	}
 	return fmt.Sprintf("%s", b)

parser/protobuf.go

@@ -30,12 +30,13 @@ import (
 	"time"
 
 	"github.com/golang/protobuf/proto"
-	log "github.com/sirupsen/logrus"
 
 	"github.com/telenornms/skogul"
 	pb "github.com/telenornms/skogul/gen/junos/telemetry"
 )
 
+var pbLog = skogul.Logger("parser", "protobuf")
+
 // ProtoBuf parses a byte string-representation of a Container
 type ProtoBuf struct{}
 
@@ -103,19 +104,19 @@ func createData(telemetry *pb.TelemetryStream) map[string]interface{} {
 		if err != nil {
 			systemId := telemetry.GetSystemId()
 			sensorName := telemetry.GetSensorName()
-			log.Printf("Failed to read protobuf telemetry data. SystemID: %v SensorName: %v", systemId, sensorName)
+			pbLog.Printf("Failed to read protobuf telemetry data. SystemID: %v SensorName: %v", systemId, sensorName)
 		}
 	}()
 
 	extension, err := proto.GetExtension(telemetry.GetEnterprise(), pb.E_JuniperNetworks)
 	if err != nil {
-		log.Debug("Failed to get Juniper protobuf extension, is this really a Juniper protobuf message?")
+		pbLog.Debug("Failed to get Juniper protobuf extension, is this really a Juniper protobuf message?")
 		return nil
 	}
 
 	enterpriseExtension, ok := extension.(proto.Message)
 	if !ok {
-		log.Debug("Failed to cast to juniper message")
+		pbLog.Debug("Failed to cast to juniper message")
 		return nil
 	}
 
@@ -136,19 +137,19 @@ func createData(telemetry *pb.TelemetryStream) map[string]interface{} {
 		}
 
 		if found {
-			log.Debug("Multiple extensions found, don't know what to do!")
+			pbLog.Debug("Multiple extensions found, don't know what to do!")
 			return nil
 		}
 
 		messageOnly, ok := ext.(proto.Message)
 		if !ok {
-			log.Debugf("Failed to cast to message: %v", ext)
+			pbLog.Debugf("Failed to cast to message: %v", ext)
 			return nil
 		}
 
 		jsonMessage, err = json.Marshal(messageOnly)
 		if err != nil {
-			log.WithError(err).Fatal("Failed to marshal to JSON")
+			pbLog.WithError(err).Fatal("Failed to marshal to JSON")
 			return nil
 		}
 
@@ -157,7 +158,7 @@ func createData(telemetry *pb.TelemetryStream) map[string]interface{} {
 
 	var metrics map[string]interface{}
 	if err = json.Unmarshal(jsonMessage, &metrics); err != nil {
-		log.WithError(err).Debug("Unmarshalling JSON data to string/interface map failed")
+		pbLog.WithError(err).Debug("Unmarshalling JSON data to string/interface map failed")
 		return nil
 	}
 

receiver/http.go

@@ -30,10 +30,11 @@ import (
 	"net/http"
 
 	log "github.com/sirupsen/logrus"
-
 	"github.com/telenornms/skogul"
 )
 
+var httpLog = skogul.Logger("receiver", "http")
+
 /*
 HTTP accepts HTTP connections on the Address specified, and requires at
 least one handler to be set up, using Handle. This is done implicitly
@@ -86,7 +87,7 @@ func (rcvr receiver) handle(w http.ResponseWriter, r *http.Request) (int, error)
 	b := make([]byte, r.ContentLength)
 
 	if n, err := io.ReadFull(r.Body, b); err != nil {
-		log.WithFields(log.Fields{
+		httpLog.WithFields(log.Fields{
 			"address":  r.RemoteAddr,
 			"error":    err,
 			"numbytes": n,
@@ -121,19 +122,19 @@ func (htt *HTTP) Start() error {
 	serveMux := http.NewServeMux()
 	server.Handler = serveMux
 	if htt.Username != "" {
-		log.WithField("username", htt.Username).Debug("Enforcing basic authentication")
+		httpLog.WithField("username", htt.Username).Debug("Enforcing basic authentication")
 		if htt.Password == "" {
-			log.Fatal("HTTP receiver has a Username provided, but not a password? Probably a mistake.")
+			httpLog.Fatal("HTTP receiver has a Username provided, but not a password? Probably a mistake.")
 		}
 		htt.auth = true
 	} else {
 		if htt.Password != "" {
-			log.Fatal("Password provided for HTTP receiver, but not a username? Probably a mistake.")
+			httpLog.Fatal("Password provided for HTTP receiver, but not a username? Probably a mistake.")
 		}
 		htt.auth = false
 	}
 	for idx, h := range htt.Handlers {
-		log.WithFields(log.Fields{
+		httpLog.WithFields(log.Fields{
 			"configuredHandler": idx,
 			"selectedHandler":   h.Name,
 		}).Debug("Adding handler")
@@ -142,24 +143,24 @@ func (htt *HTTP) Start() error {
 
 	server.Addr = htt.Address
 	if htt.Certfile != "" {
-		log.WithField("address", htt.Address).Info("Starting http receiver with TLS")
-		log.Fatal(server.ListenAndServeTLS(htt.Certfile, htt.Keyfile))
+		httpLog.WithField("address", htt.Address).Info("Starting http receiver with TLS")
+		httpLog.Fatal(server.ListenAndServeTLS(htt.Certfile, htt.Keyfile))
 	} else {
-		log.WithField("address", htt.Address).Info("Starting INSECURE http receiver (no TLS)")
-		log.Fatal(server.ListenAndServe())
+		httpLog.WithField("address", htt.Address).Info("Starting INSECURE http receiver (no TLS)")
+		httpLog.Fatal(server.ListenAndServe())
 	}
 	return skogul.Error{Reason: "Shouldn't reach this"}
 }
 
 // Verify verifies the configuration for the HTTP receiver
 func (htt *HTTP) Verify() error {
 	if htt.Handlers == nil || len(htt.Handlers) == 0 {
-		log.Error("No handlers specified. Need at least one.")
+		httpLog.Error("No handlers specified. Need at least one.")
 		return skogul.Error{Source: "http receiver", Reason: "No handlers specified. Need at least one."}
 	}
 
 	if htt.Address == "" {
-		log.Warn("Missing listen address for http receiver, using Go default")
+		httpLog.Warn("Missing listen address for http receiver, using Go default")
 	}
 
 	return nil

receiver/linefile.go

@@ -28,11 +28,11 @@ import (
 	"os"
 	"time"
 
-	log "github.com/sirupsen/logrus"
-
 	"github.com/telenornms/skogul"
 )
 
+var lfLog = skogul.Logger("receiver", "linefile")
+
 // LineFile will keep reading File over and over again, assuming one
 // collection per line. Best suited for pointing at a FIFO, which will
 // allow you to 'cat' stuff to Skogul.
@@ -46,18 +46,18 @@ type LineFile struct {
 func (lf *LineFile) read() error {
 	f, err := os.Open(lf.File)
 	if err != nil {
-		log.WithError(err).WithField("file", lf.File).Error("Unable to open file")
+		lfLog.WithError(err).WithField("file", lf.File).Error("Unable to open file")
 		return err
 	}
 	scanner := bufio.NewScanner(f)
 	for scanner.Scan() {
 		bytes := scanner.Bytes()
 		if err := lf.Handler.H.Handle(bytes); err != nil {
-			log.WithError(err).Error("Failed to send metric")
+			lfLog.WithError(err).Error("Failed to send metric")
 		}
 	}
 	if err := scanner.Err(); err != nil {
-		log.WithError(err).Error("Error reading file")
+		lfLog.WithError(err).Error("Error reading file")
 		return skogul.Error{Reason: "Error reading file"}
 	}
 	return nil

receiver/mqtt.go

@@ -30,9 +30,10 @@ import (
 	skmqtt "github.com/telenornms/skogul/internal/mqtt"
 
 	mqtt "github.com/eclipse/paho.mqtt.golang"
-	log "github.com/sirupsen/logrus"
 )
 
+var mqttLog = skogul.Logger("receiver", "mqtt")
+
 /*
 MQTT connects to a MQTT broker and listens for messages on a topic.
 */
@@ -49,7 +50,7 @@ type MQTT struct {
 func (handler *MQTT) receiver(msg mqtt.Message) {
 	err := handler.Handler.H.Handle(msg.Payload())
 	if err != nil {
-		log.WithError(err).Error("Unable to handle payload")
+		mqttLog.WithError(err).Error("Unable to handle payload")
 	}
 }
 
@@ -60,7 +61,7 @@ func (handler *MQTT) Start() error {
 	handler.mc.Password = handler.Password
 	handler.mc.Init()
 	handler.mc.Subscribe(handler.mc.Topic, handler.receiver)
-	log.WithField("address", handler.Address).Debug("Starting MQTT receiver")
+	mqttLog.WithField("address", handler.Address).Debug("Starting MQTT receiver")
 	handler.mc.Connect()
 	// Note that handler.listen() DOES return, because it only sets up
 	// subscriptions. This sillyness is to satisfy the requirement that