CBG-3713 use atomic pointers for loggers

base/logger_audit_test.go

@@ -13,6 +13,7 @@ import (
 	"maps"
 	"testing"
 
+	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 )
 
@@ -133,9 +134,11 @@ func TestAuditLoggerGlobalFields(t *testing.T) {
 			if testCase.contextFields != nil {
 				ctx = AuditLogCtx(ctx, testCase.contextFields)
 			}
-			var err error
-			auditLogger, err = NewAuditLogger(ctx, &AuditLoggerConfig{FileLoggerConfig: FileLoggerConfig{Enabled: BoolPtr(true)}}, tmpdir, 0, nil, testCase.globalFields)
+			logger, err := NewAuditLogger(ctx, &AuditLoggerConfig{FileLoggerConfig: FileLoggerConfig{Enabled: BoolPtr(true)}}, tmpdir, 0, nil, testCase.globalFields)
 			require.NoError(t, err)
+			defer assert.NoError(t, logger.Close())
+			auditLogger.Store(logger)
+
 			startWarnCount := SyncGatewayStats.GlobalStats.ResourceUtilizationStats().WarnCount.Value()
 			output := AuditLogContents(t, func(tb testing.TB) {
 				// Test basic audit event

base/logger_file.go

@@ -183,6 +183,7 @@ func (l *FileLogger) logf(format string, args ...interface{}) {
 	}
 }
 
+// conditionalPrintf will log the message if the log level is enabled.
 func (l *FileLogger) conditionalPrintf(logLevel LogLevel, format string, args ...interface{}) {
 	if l.shouldLog(logLevel) {
 		l.logf(format, args...)

base/logging.go

@@ -109,6 +109,11 @@ func RotateLogfiles(ctx context.Context) {
 }
 
 func init() {
+	initializeLoggers(context.Background())
+}
+
+// initializeLoggers should be called once per program in init. This is also called to reset logging in a test context.
+func initializeLoggers(ctx context.Context) {
 	// We'll initilise a default consoleLogger so we can still log stuff before/during parsing logging configs.
 	// This maintains consistent formatting (timestamps, levels, etc) in the output,
 	// and allows a single set of logging functions to be used, rather than fmt.Printf()
@@ -388,12 +393,10 @@ func LogLevelEnabled(ctx context.Context, level LogLevel, logKey LogKey) bool {
 
 // AssertLogContains asserts that the logs produced by function f contain string s.
 func AssertLogContains(t *testing.T, s string, f func()) {
-	FlushLogBuffers()
 	// Temporarily override logger output
 	b := &bytes.Buffer{}
 	mw := io.MultiWriter(b, os.Stderr)
 	consoleLogger.Load().logger.SetOutput(mw)
-	fmt.Printf("consoleLogger.Keys: %v\n", consoleLogger.Load().LogKeyMask.String())
 	// Call the given function
 	f()
 

base/logging_config.go

@@ -176,17 +176,8 @@ func InitializeMemoryLoggers() {
 }
 
 func FlushLoggerBuffers() {
-	for _, logger := range []*FileLogger{
-		errorLogger.Load(),
-		warnLogger.Load(),
-		infoLogger.Load(),
-		debugLogger.Load(),
-		traceLogger.Load(),
-		statsLogger.Load(),
-	} {
-		if logger != nil {
-			logger.FlushBufferToLog()
-		}
+	for _, logger := range getFileLoggers() {
+		logger.FlushBufferToLog()
 	}
 }
 

base/main_test_bucket_pool.go

@@ -716,7 +716,7 @@ func TestBucketPoolMain(ctx context.Context, m *testing.M, bucketReadierFunc TBP
 	options TestBucketPoolOptions) {
 	// can't use defer because of os.Exit
 	teardownFuncs := make([]func(), 0)
-	teardownFuncs = append(teardownFuncs, SetUpGlobalTestLogging(ctx, m))
+	teardownFuncs = append(teardownFuncs, SetUpGlobalTestLogging(ctx))
 	teardownFuncs = append(teardownFuncs, SetUpGlobalTestProfiling(m))
 	teardownFuncs = append(teardownFuncs, SetUpGlobalTestMemoryWatermark(m, options.MemWatermarkThresholdMB))
 

base/util_testing.go

@@ -568,7 +568,7 @@ var GlobalTestLoggingSet = AtomicBool{}
 
 // SetUpGlobalTestLogging sets a global log level at runtime by using the SG_TEST_LOG_LEVEL environment variable.
 // This global level overrides any tests that specify their own test log level with SetUpTestLogging.
-func SetUpGlobalTestLogging(ctx context.Context, m *testing.M) (teardownFn func()) {
+func SetUpGlobalTestLogging(ctx context.Context) (teardownFn func()) {
 	if logLevel := os.Getenv(TestEnvGlobalLogLevel); logLevel != "" {
 		var l LogLevel
 		err := l.UnmarshalText([]byte(logLevel))
@@ -600,55 +600,14 @@ func SetUpTestLogging(tb testing.TB, logLevel LogLevel, logKeys ...LogKey) {
 
 // ResetGlobalTestLogging will ensure that the loggers are replaced at the endof the the test. This is only safe to call with go:build !race since swapping the global loggers can trigger a race condition from background processes of the test harness.
 func ResetGlobalTestLogging(t *testing.T) {
-	oldErrorLogger := errorLogger.Load()
-	oldWarnLogger := warnLogger.Load()
-	oldInfoLogger := infoLogger.Load()
-	oldDebugLogger := debugLogger.Load()
-	oldTraceLogger := traceLogger.Load()
-	oldStatsLogger := statsLogger.Load()
-	oldAuditLogger := auditLogger.Load()
-	oldConsoleLogger := consoleLogger.Load()
 	t.Cleanup(func() {
-		logger := errorLogger.Load()
-		if logger != nil {
-			assert.NoError(t, logger.Close())
+		for _, logger := range getFileLoggers() {
+			logger.Close()
 		}
-		errorLogger.Store(oldErrorLogger)
-		logger = warnLogger.Load()
-		if logger != nil {
-			assert.NoError(t, logger.Close())
-		}
-		warnLogger.Store(oldWarnLogger)
-		logger = infoLogger.Load()
-		if logger != nil {
-			assert.NoError(t, logger.Close())
-		}
-		infoLogger.Store(oldInfoLogger)
-		logger = debugLogger.Load()
-		if logger != nil {
-			assert.NoError(t, logger.Close())
-		}
-		debugLogger.Store(oldDebugLogger)
-		logger = traceLogger.Load()
-		if logger != nil {
-			assert.NoError(t, logger.Close())
-		}
-		traceLogger.Store(oldTraceLogger)
-		logger = statsLogger.Load()
-		if logger != nil {
-			assert.NoError(t, logger.Close())
-		}
-		statsLogger.Store(oldStatsLogger)
-		aLogger := auditLogger.Load()
-		if aLogger != nil {
-			assert.NoError(t, aLogger.Close())
-		}
-		auditLogger.Store(oldAuditLogger)
-		cLogger := consoleLogger.Load()
-		if cLogger != nil {
-			assert.NoError(t, cLogger.Close())
-		}
-		consoleLogger.Store(oldConsoleLogger)
+		ctx := TestCtx(t)
+		initializeLoggers(ctx)
+		SetUpGlobalTestLogging(ctx)
+
 	})
 }
 
@@ -696,9 +655,7 @@ func setTestLogging(logLevel LogLevel, caller string, logKeys ...LogKey) (teardo
 	// Check that a previous invocation has not forgotten to call teardownFn
 	if *logger.LogLevel != initialLogLevel ||
 		*logger.LogKeyMask != *initialLogKey {
-		fmt.Println("logger.LogLevel=", *logger.LogLevel, " initialLogLevel=", initialLogLevel)
-		fmt.Println("logger.LogKeyMask=", *logger.LogKeyMask, "initialLogKey=", *initialLogKey)
-		panic("Logging is in an unexpected state! Did a previous test forget to call the teardownFn of SetUpTestLogging?")
+		panic(fmt.Sprintf("Logging is in an unexpected state! Did a previous test forget to call the teardownFn of SetUpTestLogging?, LogLevel=%s, expected=%s; LogKeyMask=%s, expected=%s", logger.LogLevel, initialLogLevel, logger.LogKeyMask, initialLogKey))
 	}
 
 	logger.LogLevel.Set(logLevel)

channels/main_test.go

@@ -22,7 +22,7 @@ func TestMain(m *testing.M) {
 	ctx := context.Background() // start of test process
 	// can't use defer because of os.Exit
 	teardownFuncs := make([]func(), 0)
-	teardownFuncs = append(teardownFuncs, base.SetUpGlobalTestLogging(ctx, m))
+	teardownFuncs = append(teardownFuncs, base.SetUpGlobalTestLogging(ctx))
 	teardownFuncs = append(teardownFuncs, base.SetUpGlobalTestProfiling(m))
 	teardownFuncs = append(teardownFuncs, base.SetUpGlobalTestMemoryWatermark(m, 128))