Fix logrus logger hook data race condition

go.mod

@@ -41,7 +41,7 @@ require (
 	github.com/signalfx/defaults v1.2.2-0.20180531161417-70562fe60657
 	github.com/signalfx/golib/v3 v3.3.16
 	github.com/signalfx/signalfx-agent v1.0.1-0.20210322175059-8828c6244c88
-	github.com/sirupsen/logrus v1.8.0
+	github.com/sirupsen/logrus v1.8.1
 	github.com/spf13/viper v1.7.1
 	github.com/stretchr/testify v1.7.0
 	go.opentelemetry.io/collector v0.22.1-0.20210317222125-85804ff25770

go.sum

@@ -1317,7 +1317,6 @@ github.com/linode/linodego v0.7.1/go.mod h1:ga11n3ivecUrPCHN0rANxKmfWBJVkOXfLMZi
 github.com/logrusorgru/aurora v0.0.0-20181002194514-a7b3b318ed4e/go.mod h1:7rIyQOR62GCctdiQpZ/zOJlFyk6y+94wXzv6RNZgaR4=
 github.com/lucasb-eyer/go-colorful v1.0.2/go.mod h1:0MS4r+7BZKSJ5mw4/S5MPN+qHFF1fYclkSPilDOKW0s=
 github.com/lucasb-eyer/go-colorful v1.0.3/go.mod h1:R4dSotOR9KMtayYi1e77YzuveK+i7ruzyGqttikkLy0=
-github.com/magefile/mage v1.10.0 h1:3HiXzCUY12kh9bIuyXShaVe529fJfyqoVM42o/uom2g=
 github.com/magefile/mage v1.10.0/go.mod h1:z5UZb/iS3GoOSn0JgWuiw7dxlurVYTu+/jHXqQg881A=
 github.com/magiconair/properties v1.8.0/go.mod h1:PppfXfuXeibc/6YijjN8zIbojt8czPbwD3XqdrwzmxQ=
 github.com/magiconair/properties v1.8.1 h1:ZC2Vc7/ZFkGmsVC9KvOjumD+G5lXy2RtTKyzRKO2BQ4=
@@ -1887,8 +1886,9 @@ github.com/sirupsen/logrus v1.4.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPx
 github.com/sirupsen/logrus v1.4.1/go.mod h1:ni0Sbl8bgC9z8RoU9G6nDWqqs/fq4eDPysMBDgk/93Q=
 github.com/sirupsen/logrus v1.4.2/go.mod h1:tLMulIdttU9McNUspp0xgXVQah82FyeX6MwdIuYE2rE=
 github.com/sirupsen/logrus v1.6.0/go.mod h1:7uNnSEd1DgxDLC74fIahvMZmmYsHGZGEOFrfsX/uA88=
-github.com/sirupsen/logrus v1.8.0 h1:nfhvjKcUMhBMVqbKHJlk5RPrrfYr/NMo3692g0dwfWU=
 github.com/sirupsen/logrus v1.8.0/go.mod h1:4GuYW9TZmE769R5STWrRakJc4UqQ3+QQ95fyz7ENv1A=
+github.com/sirupsen/logrus v1.8.1 h1:dJKuHgqk1NNQlqoA6BTlM1Wf9DOH3NBjQyu0h9+AZZE=
+github.com/sirupsen/logrus v1.8.1/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0=
 github.com/smartystreets/assertions v0.0.0-20180725160413-e900ae048470/go.mod h1:OnSkiWE9lh6wB0YB77sQom3nweQdgAjqCqsofrRNTgc=
 github.com/smartystreets/assertions v0.0.0-20180927180507-b2de0cb4f26d/go.mod h1:OnSkiWE9lh6wB0YB77sQom3nweQdgAjqCqsofrRNTgc=
 github.com/smartystreets/assertions v0.0.0-20190215210624-980c5ac6f3ac/go.mod h1:OnSkiWE9lh6wB0YB77sQom3nweQdgAjqCqsofrRNTgc=

internal/receiver/smartagentreceiver/log.go

@@ -187,23 +187,6 @@ func (l *logrusToZap) unRedirect(src logrusKey, dst *zap.Logger) {
 	l.loggerMap[src] = keep
 }
 
-func (l *logrusToZap) loggerMapValue0(src logrusKey) (*zap.Logger, bool) {
-	l.mu.Lock()
-	defer l.mu.Unlock()
-
-	if l.loggerMap == nil {
-		return nil, false
-	}
-
-	loggers, inMap := l.loggerMap[src]
-
-	if len(loggers) > 0 {
-		return loggers[0], inMap
-	}
-
-	return nil, inMap
-}
-
 // Levels is a logrus.Hook implementation that returns all logrus logging levels.
 func (l *logrusToZap) Levels() []logrus.Level {
 	return logrus.AllLevels
@@ -242,3 +225,20 @@ func (l *logrusToZap) Fire(e *logrus.Entry) error {
 
 	return nil
 }
+
+func (l *logrusToZap) loggerMapValue0(src logrusKey) (*zap.Logger, bool) {
+	l.mu.Lock()
+	defer l.mu.Unlock()
+
+	if l.loggerMap == nil {
+		return nil, false
+	}
+
+	loggers, inMap := l.loggerMap[src]
+
+	if len(loggers) > 0 {
+		return loggers[0], inMap
+	}
+
+	return nil, inMap
+}

internal/receiver/smartagentreceiver/log_test.go

@@ -19,6 +19,7 @@ import (
 	"testing"
 
 	"github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
@@ -53,18 +54,18 @@ func TestRedirectMonitorLogs(t *testing.T) {
 		}
 
 		// Simulating the creation of logrus entry/loggers in monitors (monitor1, monitor2).
-		monitor1Logger := logrus.WithFields(logrus.Fields{"monitorType": "monitor1"})
-		monitor2Logger := logrus.WithFields(logrus.Fields{"monitorType": "monitor2"})
+		monitor1LogrusLogger := logrus.WithFields(logrus.Fields{"monitorType": "monitor1"})
+		monitor2LogrusLogger := logrus.WithFields(logrus.Fields{"monitorType": "monitor2"})
 
 		// Case where logs do not have "monitorType" field
-		monitor3Logger := logrus.WithFields(logrus.Fields{})
+		monitor3LogrusLogger := logrus.WithFields(logrus.Fields{})
 
-		// Checking that the logrus standard logger is the logger for monitor1 and monitor2.
-		require.Same(t, logrus.StandardLogger(), monitor1Logger.Logger, "Expected the standard logrus logger")
-		require.Same(t, logrus.StandardLogger(), monitor2Logger.Logger, "Expected the standard logrus logger")
-		require.Same(t, logrus.StandardLogger(), monitor3Logger.Logger, "Expected the standard logrus logger")
+		// Checking that the logrus standard logger is the logger in the monitors.
+		require.Same(t, logrus.StandardLogger(), monitor1LogrusLogger.Logger, "Expected the standard logrus logger")
+		require.Same(t, logrus.StandardLogger(), monitor2LogrusLogger.Logger, "Expected the standard logrus logger")
+		require.Same(t, logrus.StandardLogger(), monitor3LogrusLogger.Logger, "Expected the standard logrus logger")
 
-		// Simulating the creation of logrus keys for monitor1 and monitor2 in the smart agent receiver where:
+		// Simulating the creation of logrus keys for the monitors where:
 		// 1. the monitor types (i.e. monitor1, monitor2) are known.
 		// 2. the logger is assumed to be the standard logrus logger.
 		monitor1LogrusKey := logrusKey{Logger: logrus.StandardLogger(), monitorType: "monitor1"}
@@ -76,7 +77,7 @@ func TestRedirectMonitorLogs(t *testing.T) {
 		monitor3ZapLogger, monitor3ZapLogs := newObservedLogs(zapLevel)
 		defaultZapLogger, defaultLogs := newObservedLogs(zapLevel)
 
-		// Simulating logrus to zap redirections in receiver.
+		// Logrus to zap redirections.
 		logToZap := newLogrusToZap(func() *zap.Logger { return defaultZapLogger })
 		logToZap.redirect(monitor1LogrusKey, monitor1ZapLogger)
 		logToZap.redirect(monitor2LogrusKey, monitor2ZapLogger)
@@ -86,24 +87,71 @@ func TestRedirectMonitorLogs(t *testing.T) {
 		logMsg2 := "a log msg2"
 		logMsg3 := "a log msg3"
 
-		// Simulating logging a message in the monitor1.
-		logAt(monitor1Logger, logrusLevel, logMsg1)
-		logAt(monitor2Logger, logrusLevel, logMsg2)
-		logAt(monitor3Logger, logrusLevel, logMsg3)
+		// Logrus logging.
+		logAt(monitor1LogrusLogger, logrusLevel, logMsg1)
+		logAt(monitor2LogrusLogger, logrusLevel, logMsg2)
+		logAt(monitor3LogrusLogger, logrusLevel, logMsg3)
 
-		// Checking the zap logger is logging the same number of messages logged by monitor1.
+		// Checking zap logs for redirected logrus logs.
 		require.Equal(t, 1, monitor1ZapLogs.Len(), fmt.Sprintf("Expected 1 log message, got %d", monitor1ZapLogs.Len()))
-		require.Equal(t, 1, monitor2ZapLogs.Len(), fmt.Sprintf("Expected 1 log message, got %d", monitor2ZapLogs.Len()))
-		require.Equal(t, 0, monitor3ZapLogs.Len(), fmt.Sprintf("Expected 0 log message, got %d", monitor3ZapLogs.Len()))
-		require.Equal(t, 1, defaultLogs.Len(), fmt.Sprintf("Expected 1 log message, got %d", defaultLogs.Len()))
-
-		// Checking that the zap logger is logging the message logged by monitor1.
 		require.Equal(t, logMsg1, monitor1ZapLogs.All()[0].Message, fmt.Sprintf("Expected message '%s', got '%s'", logMsg1, monitor1ZapLogs.All()[0].Message))
+
+		require.Equal(t, 1, monitor2ZapLogs.Len(), fmt.Sprintf("Expected 1 log message, got %d", monitor2ZapLogs.Len()))
 		require.Equal(t, logMsg2, monitor2ZapLogs.All()[0].Message, fmt.Sprintf("Expected message '%s', got '%s'", logMsg2, monitor2ZapLogs.All()[0].Message))
+
+		require.Equal(t, 0, monitor3ZapLogs.Len(), fmt.Sprintf("Expected 0 log message, got %d", monitor3ZapLogs.Len()))
 		require.Equal(t, logMsg3, defaultLogs.All()[0].Message, fmt.Sprintf("Expected message '%s', got '%s'", logMsg3, defaultLogs.All()[0].Message))
 
+		require.Equal(t, 1, defaultLogs.Len(), fmt.Sprintf("Expected 1 log message, got %d", defaultLogs.Len()))
+
 		logToZap.unRedirect(monitor1LogrusKey, monitor1ZapLogger)
 		logToZap.unRedirect(monitor2LogrusKey, monitor2ZapLogger)
+		logToZap.unRedirect(monitor3LogrusKey, monitor3ZapLogger)
+	}
+}
+
+func TestRedirectMonitorLogsWithNilLoggerMap(t *testing.T) {
+	for logrusLevel, zapLevel := range levelsMap {
+		//TODO: handle fatal and panic levels
+		if logrusLevel == logrus.FatalLevel || logrusLevel == logrus.PanicLevel {
+			continue
+		}
+
+		// Simulating the creation of logrus entry/logger in monitor1.
+		monitor1LogrusLogger := logrus.WithFields(logrus.Fields{"monitorType": "monitor1"})
+
+		// Simulating the creation of logrus key for monitor1 in the smart agent receiver where:
+		// 1. the monitor types (i.e. monitor1) are known.
+		// 2. the logger is assumed to be the standard logrus logger.
+		monitor1LogrusKey := logrusKey{Logger: logrus.StandardLogger(), monitorType: "monitor1"}
+
+		monitor1ZapLogger, monitor1ZapLogs := newObservedLogs(zapLevel)
+		defaultZapLogger, defaultZapLogs := newObservedLogs(zapLevel)
+
+		// Logrus to zap redirection.
+		logToZap := newLogrusToZap(func() *zap.Logger { return defaultZapLogger })
+		logToZap.redirect(monitor1LogrusKey, monitor1ZapLogger)
+
+		require.Len(t, logToZap.loggerMap, 1)
+		require.Len(t, logToZap.loggerMap[monitor1LogrusKey], 1)
+		require.Equal(t, monitor1ZapLogger, logToZap.loggerMap[monitor1LogrusKey][0])
+
+		// Setting loggerMap to nil
+		logToZap.loggerMap = nil
+
+		logMsg := "a log msg"
+
+		// Logrus logging.
+		logAt(monitor1LogrusLogger, logrusLevel, logMsg)
+
+		// Logrus logs should not be redirected to monitor1ZapLogger.
+		assert.Equal(t, 0, monitor1ZapLogs.Len(), fmt.Sprintf("Expected 0 log message, got %d", monitor1ZapLogs.Len()))
+
+		// Logrus logs should be redirected to defaultZapLogger when loggerMap is nil.
+		assert.Equal(t, 1, defaultZapLogs.Len(), fmt.Sprintf("Expected 1 log message, got %d", monitor1ZapLogs.Len()))
+		require.Equal(t, logMsg, defaultZapLogs.All()[0].Message, fmt.Sprintf("Expected message '%s', got '%s'", logMsg, defaultZapLogs.All()[0].Message))
+
+		logToZap.unRedirect(monitor1LogrusKey, monitor1ZapLogger)
 	}
 }
 
@@ -115,8 +163,8 @@ func TestRedirectSameMonitorManyInstancesLogs(t *testing.T) {
 		}
 
 		// Simulating the creation of logrus entry/loggers in instances of a monitor (monitor1).
-		instance1Logger := logrus.WithFields(logrus.Fields{"monitorType": "monitor1"})
-		instance2Logger := logrus.WithFields(logrus.Fields{"monitorType": "monitor1"})
+		instance1LogrusLogger := logrus.WithFields(logrus.Fields{"monitorType": "monitor1"})
+		instance2LogrusLogger := logrus.WithFields(logrus.Fields{"monitorType": "monitor1"})
 
 		// Simulating the creation of logrus keys for the instances of monitor1 in the smart agent receiver where:
 		// 1. the monitor type (i.e. monitor1) is known.
@@ -125,8 +173,8 @@ func TestRedirectSameMonitorManyInstancesLogs(t *testing.T) {
 		instance2LogrusKey := logrusKey{Logger: logrus.StandardLogger(), monitorType: "monitor1"}
 
 		// Checking that the logrus standard logger is the logger for both monitor1 instances.
-		require.Same(t, logrus.StandardLogger(), instance1Logger.Logger, "Expected the standard logrus logger")
-		require.Same(t, logrus.StandardLogger(), instance2Logger.Logger, "Expected the standard logrus logger")
+		require.Same(t, logrus.StandardLogger(), instance1LogrusLogger.Logger, "Expected the standard logrus logger")
+		require.Same(t, logrus.StandardLogger(), instance2LogrusLogger.Logger, "Expected the standard logrus logger")
 		// Checking that the logrus keys are equal.
 		require.Equal(t, instance1LogrusKey, instance2LogrusKey, "Expected the standard logrus logger")
 
@@ -142,8 +190,8 @@ func TestRedirectSameMonitorManyInstancesLogs(t *testing.T) {
 		logMsg2 := "a log msg2"
 
 		// Simulating logging messages in the instances of monitor1.
-		logAt(instance1Logger, logrusLevel, logMsg1)
-		logAt(instance2Logger, logrusLevel, logMsg2)
+		logAt(instance1LogrusLogger, logrusLevel, logMsg1)
+		logAt(instance2LogrusLogger, logrusLevel, logMsg2)
 
 		// Asserting that messages logged by all instances get logged by the zap logger of the first instance.
 		require.Equal(t, 2, instance1ZapLogs.Len(), fmt.Sprintf("Expected 2 log message, got %d", instance1ZapLogs.Len()))