Skip to content

Commit

Permalink
[3.2.1 backport] CBG-4194 switch loggers to use atomic pointers (#7091)
Browse files Browse the repository at this point in the history
  • Loading branch information
torcolvin authored Aug 23, 2024
1 parent 0d08117 commit 643494e
Show file tree
Hide file tree
Showing 23 changed files with 396 additions and 454 deletions.
40 changes: 24 additions & 16 deletions base/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ package base
import (
"log"
"math"
"slices"
"strings"
"sync"
"time"
Expand All @@ -21,27 +22,34 @@ import (
var flushLogBuffersWaitGroup sync.WaitGroup
var flushLogMutex sync.Mutex

// getFileLoggers returns a slice of all non-nil file loggers.
func getFileLoggers() []*FileLogger {
loggers := []*FileLogger{
traceLogger.Load(),
debugLogger.Load(),
infoLogger.Load(),
warnLogger.Load(),
errorLogger.Load(),
statsLogger.Load(),
}
rawAuditLogger := auditLogger.Load()
if rawAuditLogger != nil {
loggers = append(loggers, &rawAuditLogger.FileLogger)
}
rawConsoleLogger := consoleLogger.Load()
if rawConsoleLogger != nil {
loggers = append(loggers, &rawConsoleLogger.FileLogger)
}
return slices.DeleteFunc(loggers, func(l *FileLogger) bool { return l == nil })
}

// FlushLogBuffers will cause all log collation buffers to be flushed to the output before returning.
func FlushLogBuffers() {
flushLogMutex.Lock()
defer flushLogMutex.Unlock()

loggers := []*FileLogger{
traceLogger,
debugLogger,
infoLogger,
warnLogger,
errorLogger,
statsLogger,
&consoleLogger.FileLogger,
}

if auditLogger != nil {
loggers = append(loggers, &auditLogger.FileLogger)
}

for _, logger := range loggers {
if logger != nil && cap(logger.collateBuffer) > 1 {
for _, logger := range getFileLoggers() {
if cap(logger.collateBuffer) > 1 {
logger.collateBufferWg.Wait()
flushLogBuffersWaitGroup.Add(1)
logger.flushChan <- struct{}{}
Expand Down
26 changes: 18 additions & 8 deletions base/logger_audit.go
Original file line number Diff line number Diff line change
Expand Up @@ -119,20 +119,25 @@ func (f AuditFields) merge(ctx context.Context, overwrites AuditFields) AuditFie
func Audit(ctx context.Context, id AuditID, additionalData AuditFields) {
var fields AuditFields

logger := auditLogger.Load()
if IsDevMode() {
// NOTE: This check is expensive and indicates a dev-time mistake that needs addressing.
// Don't bother in production code, but also delay expandFields until we know we will log.
fields = expandFields(id, ctx, auditLogger.globalFields, additionalData)
var globalFields AuditFields
if logger != nil {
globalFields = logger.globalFields
}
fields = expandFields(id, ctx, globalFields, additionalData)
id.MustValidateFields(fields)
}

if !auditLogger.shouldLog(id, ctx) {
if !logger.shouldLog(id, ctx) {
return
}

// delayed expansion until after enabled checks in non-dev mode
if fields == nil {
fields = expandFields(id, ctx, auditLogger.globalFields, additionalData)
fields = expandFields(id, ctx, logger.globalFields, additionalData)
}

fieldsJSON, err := jsoniter.MarshalToString(fields)
Expand All @@ -141,12 +146,16 @@ func Audit(ctx context.Context, id AuditID, additionalData AuditFields) {
return
}

auditLogger.logf(fieldsJSON)
logger.logf(fieldsJSON)
}

// IsAuditEnabled checks if auditing is enabled for the SG node
func IsAuditEnabled() bool {
return auditLogger.FileLogger.shouldLog(LevelNone)
logger := auditLogger.Load()
if logger == nil {
return false
}
return logger.FileLogger.shouldLog(LevelNone)
}

// AuditLogger is a file logger with audit-specific behaviour.
Expand All @@ -164,10 +173,9 @@ func (l *AuditLogger) getAuditLoggerConfig() *AuditLoggerConfig {
if l != nil {
// Copy config struct to avoid mutating running config
c = l.config
c.FileLoggerConfig = *l.getFileLoggerConfig()
}

c.FileLoggerConfig = *l.getFileLoggerConfig()

return &c
}

Expand Down Expand Up @@ -229,7 +237,9 @@ func NewAuditLogger(ctx context.Context, config *AuditLoggerConfig, logFilePath
}

func (al *AuditLogger) shouldLog(id AuditID, ctx context.Context) bool {
if !auditLogger.FileLogger.shouldLog(LevelNone) {
if al == nil {
return false
} else if !al.FileLogger.shouldLog(LevelNone) {
return false
}

Expand Down
8 changes: 5 additions & 3 deletions base/logger_audit_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -136,9 +136,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
Expand Down Expand Up @@ -296,7 +298,7 @@ func BenchmarkAuditFieldwork(b *testing.B) {
},
}, b.TempDir(), auditMinage, nil, map[string]any{"foo": "bar", "buzz": 1234})
require.NoError(b, err)
auditLogger = al
auditLogger.Store(al)

ctx := TestCtx(b)
ctx = DatabaseLogCtx(ctx, "db", nil)
Expand Down
8 changes: 5 additions & 3 deletions base/logger_external.go
Original file line number Diff line number Diff line change
Expand Up @@ -47,7 +47,8 @@ func initExternalLoggers() {

func updateExternalLoggers() {
// use context.Background() since this is called from init or to reset test logging
if consoleLogger != nil && consoleLogger.shouldLog(context.Background(), LevelDebug, KeyWalrus) {
logger := consoleLogger.Load()
if logger.shouldLog(context.Background(), LevelDebug, KeyWalrus) {
rosmar.SetLogLevel(rosmar.LevelDebug)
} else {
rosmar.SetLogLevel(rosmar.LevelInfo)
Expand Down Expand Up @@ -170,10 +171,11 @@ func (CBGoUtilsLogger) SetLevel(l logging.Level) {
// CBGoUtilsLogger.Level returns a compatible go-couchbase/golog Log Level for
// the given logging config LogLevel
func (CBGoUtilsLogger) Level() logging.Level {
if consoleLogger == nil || consoleLogger.LogLevel == nil {
logger := consoleLogger.Load()
if logger == nil || logger.LogLevel == nil {
return logging.INFO
}
switch *consoleLogger.LogLevel {
switch *logger.LogLevel {
case LevelTrace:
return logging.TRACE
case LevelDebug:
Expand Down
7 changes: 7 additions & 0 deletions base/logger_file.go
Original file line number Diff line number Diff line change
Expand Up @@ -192,6 +192,13 @@ 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...)
}
}

// shouldLog returns true if we can log.
func (l *FileLogger) shouldLog(logLevel LogLevel) bool {
return l != nil && l.logger != nil &&
Expand Down
Loading

0 comments on commit 643494e

Please sign in to comment.