Merge pull request #42 from crowdsecurity/fix_logging

Logging cleanup and fixes

Makefile

@@ -62,6 +62,7 @@ else
 	@echo "Required golang version is $(REQUIRE_GOVERSION). The current one is $(CURRENT_GOVERSION). Exiting.."
 	@exit 1;
 endif
+	@bash ./scripts/build_plugins.sh
 
 
 cscli_static:

cmd/crowdsec/main.go

@@ -1,7 +1,6 @@
 package main
 
 import (
-	"fmt"
 	"strings"
 
 	"io/ioutil"
@@ -19,7 +18,6 @@ import (
 
 	log "github.com/sirupsen/logrus"
 
-	"gopkg.in/natefinch/lumberjack.v2"
 	"gopkg.in/tomb.v2"
 	"gopkg.in/yaml.v2"
 )
@@ -39,33 +37,6 @@ var (
 	lastProcessedItem time.Time /*keep track of last item timestamp in time-machine. it is used to GC buckets when we dump them.*/
 )
 
-func configureLogger(logMode string, logFolder string, logLevel log.Level) error {
-	/*Configure logs*/
-	if logMode == "file" {
-		log.SetOutput(&lumberjack.Logger{
-			Filename:   logFolder + "/crowdsec.log",
-			MaxSize:    500, //megabytes
-			MaxBackups: 3,
-			MaxAge:     28,   //days
-			Compress:   true, //disabled by default
-		})
-		log.SetFormatter(&log.TextFormatter{TimestampFormat: "02-01-2006 15:04:05", FullTimestamp: true})
-	} else if logMode != "stdout" {
-		return fmt.Errorf("log mode '%s' unknown", logMode)
-	}
-
-	log.Printf("setting loglevel to %s", logLevel)
-	log.SetLevel(logLevel)
-	log.SetFormatter(&log.TextFormatter{FullTimestamp: true})
-	if logLevel >= log.InfoLevel {
-		log.SetFormatter(&log.TextFormatter{TimestampFormat: "02-01-2006 15:04:05", FullTimestamp: true})
-	}
-	if logLevel >= log.DebugLevel {
-		log.SetReportCaller(true)
-	}
-	return nil
-}
-
 func main() {
 	var (
 		err                 error
@@ -92,7 +63,7 @@ func main() {
 		log.Fatalf(err.Error())
 	}
 
-	if err = configureLogger(cConfig.LogMode, cConfig.LogFolder, cConfig.LogLevel); err != nil {
+	if err = types.SetDefaultLoggerConfig(cConfig.LogMode, cConfig.LogFolder, cConfig.LogLevel); err != nil {
 		log.Fatal(err.Error())
 	}
 

config/user.yaml

@@ -8,9 +8,9 @@ log_mode: stdout
 log_level: info
 profiling: false
 sqlite_path: ${DATA}/crowdsec.db
-apimode: true
+apimode: false
 daemon: false
-prometheus: true
+prometheus: false
 #for prometheus agent / golang debugging
 http_listen: 127.0.0.1:6060
 plugin:

pkg/leakybucket/manager.go

@@ -146,7 +146,7 @@ func LoadBuckets(files []string) ([]BucketFactory, chan types.Event, error) {
 			}
 			//check compat
 			if g.FormatVersion == "" {
-				log.Warningf("no version in %s : %s, assuming '1.0'", g.Name, f)
+				log.Debugf("no version in %s : %s, assuming '1.0'", g.Name, f)
 				g.FormatVersion = "1.0"
 			}
 			ok, err := cwversion.Statisfies(g.FormatVersion, cwversion.Constraint_scenario)
@@ -191,7 +191,9 @@ func LoadBucket(g *BucketFactory) error {
 	var err error
 	if g.Debug {
 		var clog = logrus.New()
-		clog.SetFormatter(&log.TextFormatter{FullTimestamp: true})
+		if err := types.ConfigureLogger(clog); err != nil {
+			log.Fatalf("While creating bucket-specific logger : %s", err)
+		}
 		clog.SetLevel(log.DebugLevel)
 		g.logger = clog.WithFields(log.Fields{
 			"cfg":  g.BucketName,

pkg/parser/node.go

@@ -252,10 +252,15 @@ func (n *Node) process(p *types.Event, ctx UnixParserCtx) (bool, error) {
 				//return false, nil
 			}
 		}
-
+		var groklabel string
+		if n.Grok.RegexpName == "" {
+			groklabel = fmt.Sprintf("%5.5s...", n.Grok.RegexpValue)
+		} else {
+			groklabel = n.Grok.RegexpName
+		}
 		grok := n.Grok.RunTimeRegexp.Parse(gstr)
 		if len(grok) > 0 {
-			clog.Debugf("+ Grok '%s' returned %d entries to merge in Parsed", n.Grok.RegexpName, len(grok))
+			clog.Debugf("+ Grok '%s' returned %d entries to merge in Parsed", groklabel, len(grok))
 			//We managed to grok stuff, merged into parse
 			for k, v := range grok {
 				clog.Debugf("\t.Parsed['%s'] = '%s'", k, v)
@@ -268,7 +273,7 @@ func (n *Node) process(p *types.Event, ctx UnixParserCtx) (bool, error) {
 			}
 		} else {
 			//grok failed, node failed
-			clog.Debugf("+ Grok '%s' didn't return data on '%s'", n.Grok.RegexpName, gstr)
+			clog.Debugf("+ Grok '%s' didn't return data on '%s'", groklabel, gstr)
 			//clog.Tracef("on '%s'", gstr)
 			NodeState = false
 		}
@@ -336,6 +341,9 @@ func (n *Node) compile(pctx *UnixParserCtx) error {
 	that will be used only for processing this node ;) */
 	if n.Debug {
 		var clog = logrus.New()
+		if err := types.ConfigureLogger(clog); err != nil {
+			log.Fatalf("While creating bucket-specific logger : %s", err)
+		}
 		clog.SetLevel(log.DebugLevel)
 		n.logger = clog.WithFields(log.Fields{
 			"id": n.rn,
@@ -411,6 +419,9 @@ func (n *Node) compile(pctx *UnixParserCtx) error {
 	/* compile leafs if present */
 	if len(n.SuccessNodes) > 0 {
 		for idx := range n.SuccessNodes {
+			if n.SuccessNodes[idx].Name == "" {
+				n.SuccessNodes[idx].Name = fmt.Sprintf("child-%s", n.Name)
+			}
 			/*propagate debug/stats to child nodes*/
 			if !n.SuccessNodes[idx].Debug && n.Debug {
 				n.SuccessNodes[idx].Debug = true

pkg/parser/stage.go

@@ -76,7 +76,7 @@ func LoadStages(stageFiles []Stagefile, pctx *UnixParserCtx) ([]Node, error) {
 
 			//check for empty bucket
 			if node.Name == "" && node.Description == "" && node.Author == "" {
-				log.Infof("Node has no name,author or description. Skipping.")
+				log.Infof("Node in %s has no name,author or description. Skipping.", stageFile.Filename)
 				continue
 			}
 			//check compat

pkg/types/utils.go

@@ -2,7 +2,12 @@ package types
 
 import (
 	"encoding/binary"
+	"fmt"
+	"io"
 	"net"
+
+	log "github.com/sirupsen/logrus"
+	"gopkg.in/natefinch/lumberjack.v2"
 )
 
 func IP2Int(ip net.IP) uint32 {
@@ -40,3 +45,51 @@ func LastAddress(n *net.IPNet) net.IP {
 		ip[2]|^n.Mask[2],
 		ip[3]|^n.Mask[3])
 }
+
+var logFormatter log.Formatter
+var logOutput io.Writer
+var logLevel log.Level
+var logReportCaller bool
+
+func SetDefaultLoggerConfig(cfgMode string, cfgFolder string, cfgLevel log.Level) error {
+
+	/*Configure logs*/
+	if cfgMode == "file" {
+		logOutput = &lumberjack.Logger{
+			Filename:   cfgFolder + "/crowdsec.log",
+			MaxSize:    500, //megabytes
+			MaxBackups: 3,
+			MaxAge:     28,   //days
+			Compress:   true, //disabled by default
+		}
+		log.SetOutput(logOutput)
+	} else if cfgMode != "stdout" {
+		return fmt.Errorf("log mode '%s' unknown", cfgMode)
+	}
+	logLevel = cfgLevel
+	log.SetLevel(logLevel)
+	if logLevel >= log.InfoLevel {
+		logFormatter = &log.TextFormatter{TimestampFormat: "02-01-2006 15:04:05", FullTimestamp: true}
+		log.SetFormatter(logFormatter)
+	}
+	if logLevel >= log.DebugLevel {
+		logReportCaller = true
+		log.SetReportCaller(true)
+	}
+	return nil
+}
+
+func ConfigureLogger(clog *log.Logger) error {
+	/*Configure logs*/
+	if logOutput != nil {
+		clog.SetOutput(logOutput)
+	}
+	if logReportCaller {
+		clog.SetReportCaller(true)
+	}
+	if logFormatter != nil {
+		clog.SetFormatter(logFormatter)
+	}
+	clog.SetLevel(logLevel)
+	return nil
+}