Fix issue with logrus logs being emitted multiple times

When reloading the configuration, new instances of `CrowdSec` are
created and then initalized through `Init`. This resulted in
multiple invocations of `overrideLogrusLogger`, adding multiple
hooks to the standard logrus logger. This commit replaces all
hooks instead.

go.mod

@@ -12,6 +12,7 @@ require (
 	github.com/mholt/caddy-l4 v0.0.0-20231016112149-a362a1fbf652
 	github.com/sirupsen/logrus v1.9.3
 	github.com/stretchr/testify v1.8.4
+	go.uber.org/goleak v1.2.1
 	go.uber.org/zap v1.26.0
 )
 
@@ -127,7 +128,6 @@ require (
 	go.step.sm/cli-utils v0.8.0 // indirect
 	go.step.sm/crypto v0.36.1 // indirect
 	go.step.sm/linkedca v0.20.1 // indirect
-	go.uber.org/goleak v1.2.1 // indirect
 	go.uber.org/mock v0.3.0 // indirect
 	go.uber.org/multierr v1.11.0 // indirect
 	golang.org/x/crypto v0.14.0 // indirect

internal/bouncer/bouncer.go

@@ -217,13 +217,15 @@ func (b *Bouncer) Run() {
 func (b *Bouncer) Shutdown() error {
 	b.startMu.Lock()
 	defer b.startMu.Unlock()
+	if !b.started || b.stopped {
+		return nil
+	}
 	b.logger.Info("stopping", b.zapField())
 	defer func() {
 		b.stopped = true
+		b.logger.Info("finished", b.zapField())
+		b.logger.Sync()
 	}()
-	if !b.started || b.stopped {
-		return nil
-	}
 
 	// the LiveBouncer has nothing to do on shutdown
 	if !b.useStreamingBouncer {
@@ -233,9 +235,6 @@ func (b *Bouncer) Shutdown() error {
 	b.cancel()
 	b.wg.Wait()
 
-	b.logger.Info("finished", b.zapField())
-	b.logger.Sync() // nolint
-
 	// TODO: clean shutdown of the streaming bouncer channel reading
 	//b.store = nil // TODO(hs): setting this to nil without reinstantiating it, leads to errors; do this properly.
 	return nil

internal/bouncer/logging.go

@@ -3,28 +3,46 @@ package bouncer
 import (
 	"errors"
 	"io"
+	"unicode"
+	"unicode/utf8"
 
 	"github.com/sirupsen/logrus"
 	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
 )
 
+// overrideLogrusLogger overrides the (default) settings of the standard
+// logrus logger. The logrus logger is used by the `go-cs-bouncer` package,
+// whereas Caddy uses zap. The output of the standard logger is discarded,
+// and a hook is used to send messages to Caddy's zap logger instead.
+//
+// Note that this method changes global state, but only after a new Bouncer
+// is provisioned, validated and has just been started. This should thus
+// generally not be a problem.
 func (b *Bouncer) overrideLogrusLogger() {
+	// the CrowdSec go-cs-bouncer uses the standard logrus logger
+	std := logrus.StandardLogger()
+
 	// silence the default CrowdSec logrus logging
-	logrus.SetOutput(io.Discard)
+	std.SetOutput(io.Discard)
 
-	// catch log entries and log them using the *zap.Logger instead
-	logrus.AddHook(&zapAdapterHook{
+	// replace all hooks on the standard logrus logger
+	hooks := logrus.LevelHooks{}
+	hooks.Add(&zapAdapterHook{
 		logger:         b.logger,
 		shouldFailHard: b.shouldFailHard,
 		address:        b.streamingBouncer.APIUrl,
+		instanceID:     b.instanceID,
 	})
+
+	std.ReplaceHooks(hooks)
 }
 
 type zapAdapterHook struct {
 	logger         *zap.Logger
 	shouldFailHard bool
 	address        string
+	instanceID     string
 }
 
 func (zh *zapAdapterHook) Levels() []logrus.Level {
@@ -43,28 +61,40 @@ func (zh *zapAdapterHook) Fire(entry *logrus.Entry) error {
 	// TODO: extract details from entry.Data? But doesn't seem to be used by CrowdSec today.
 
 	msg := entry.Message
-	fields := []zapcore.Field{zap.String("address", zh.address)}
+	fields := []zapcore.Field{zap.String("instance_id", zh.instanceID), zap.String("address", zh.address)}
 	switch {
 	case entry.Level <= logrus.ErrorLevel: // error, fatal, panic
 		fields = append(fields, zap.Error(errors.New(msg)))
 		if zh.shouldFailHard {
 			// TODO: if we keep this Fatal and the "shouldFailhard" around, ensure we
 			// shut the bouncer down nicely
-			zh.logger.Fatal(msg, fields...)
+			zh.logger.Fatal(firstToLower(msg), fields...)
 		} else {
-			zh.logger.Error(msg, fields...)
+			zh.logger.Error(firstToLower(msg), fields...)
 		}
 	default:
 		level := zapcore.DebugLevel
 		if l, ok := levelAdapter[entry.Level]; ok {
 			level = l
 		}
-		zh.logger.Log(level, msg, fields...)
+		zh.logger.Log(level, firstToLower(msg), fields...)
 	}
 
 	return nil
 }
 
+func firstToLower(s string) string {
+	r, size := utf8.DecodeRuneInString(s)
+	if r == utf8.RuneError && size <= 1 {
+		return s
+	}
+	lc := unicode.ToLower(r)
+	if r == lc {
+		return s
+	}
+	return string(lc) + s[size:]
+}
+
 var levelAdapter = map[logrus.Level]zapcore.Level{
 	logrus.TraceLevel: zapcore.DebugLevel, // no trace level in zap
 	logrus.DebugLevel: zapcore.DebugLevel,