🐛 Fix some more races in the delegating logger

The delegatingLogger had a logger implementation embedded, calling any
method of that would race with FullFill(), which replaces the embedded
logger.

pkg/log/deleg.go

@@ -73,7 +73,7 @@ func (p *loggerPromise) Fulfill(parentLogger logr.Logger) {
 	}
 
 	p.logger.lock.Lock()
-	p.logger.Logger = logger
+	p.logger.logger = logger
 	p.logger.promise = nil
 	p.logger.lock.Unlock()
 
@@ -88,21 +88,64 @@ func (p *loggerPromise) Fulfill(parentLogger logr.Logger) {
 // logger.  It expects to have *some* logr.Logger set at all times (generally
 // a no-op logger before the promises are fulfilled).
 type DelegatingLogger struct {
-	lock sync.Mutex
-	logr.Logger
+	lock    sync.Mutex
+	logger  logr.Logger
 	promise *loggerPromise
 }
 
+// Enabled tests whether this Logger is enabled.  For example, commandline
+// flags might be used to set the logging verbosity and disable some info
+// logs.
+func (l *DelegatingLogger) Enabled() bool {
+	l.lock.Lock()
+	defer l.lock.Unlock()
+	return l.logger.Enabled()
+}
+
+// Info logs a non-error message with the given key/value pairs as context.
+//
+// The msg argument should be used to add some constant description to
+// the log line.  The key/value pairs can then be used to add additional
+// variable information.  The key/value pairs should alternate string
+// keys and arbitrary values.
+func (l *DelegatingLogger) Info(msg string, keysAndValues ...interface{}) {
+	l.lock.Lock()
+	defer l.lock.Unlock()
+	l.logger.Info(msg, keysAndValues...)
+}
+
+// Error logs an error, with the given message and key/value pairs as context.
+// It functions similarly to calling Info with the "error" named value, but may
+// have unique behavior, and should be preferred for logging errors (see the
+// package documentations for more information).
+//
+// The msg field should be used to add context to any underlying error,
+// while the err field should be used to attach the actual error that
+// triggered this log line, if present.
+func (l *DelegatingLogger) Error(err error, msg string, keysAndValues ...interface{}) {
+	l.lock.Lock()
+	defer l.lock.Unlock()
+	l.logger.Error(err, msg, keysAndValues...)
+}
+
+// V returns an Logger value for a specific verbosity level, relative to
+// this Logger.  In other words, V values are additive.  V higher verbosity
+// level means a log message is less important.  It's illegal to pass a log
+// level less than zero.
+func (l *DelegatingLogger) V(level int) logr.Logger {
+	return l.WithValues().V(level)
+}
+
 // WithName provides a new Logger with the name appended
 func (l *DelegatingLogger) WithName(name string) logr.Logger {
 	l.lock.Lock()
 	defer l.lock.Unlock()
 
 	if l.promise == nil {
-		return l.Logger.WithName(name)
+		return l.logger.WithName(name)
 	}
 
-	res := &DelegatingLogger{Logger: l.Logger}
+	res := &DelegatingLogger{logger: l.logger}
 	promise := l.promise.WithName(res, name)
 	res.promise = promise
 
@@ -115,10 +158,10 @@ func (l *DelegatingLogger) WithValues(tags ...interface{}) logr.Logger {
 	defer l.lock.Unlock()
 
 	if l.promise == nil {
-		return l.Logger.WithValues(tags...)
+		return l.logger.WithValues(tags...)
 	}
 
-	res := &DelegatingLogger{Logger: l.Logger}
+	res := &DelegatingLogger{logger: l.logger}
 	promise := l.promise.WithValues(res, tags...)
 	res.promise = promise
 
@@ -138,7 +181,7 @@ func (l *DelegatingLogger) Fulfill(actual logr.Logger) {
 // the given logger before it's promise is fulfilled.
 func NewDelegatingLogger(initial logr.Logger) *DelegatingLogger {
 	l := &DelegatingLogger{
-		Logger:  initial,
+		logger:  initial,
 		promise: &loggerPromise{promisesLock: sync.Mutex{}},
 	}
 	l.promise.logger = l

pkg/log/log_test.go

@@ -18,12 +18,15 @@ package log
 
 import (
 	"context"
+	"errors"
 
 	"github.com/go-logr/logr"
 	. "github.com/onsi/ginkgo"
 	. "github.com/onsi/gomega"
 )
 
+var _ logr.Logger = &DelegatingLogger{}
+
 // logInfo is the information for a particular fakeLogger message
 type logInfo struct {
 	name []string
@@ -169,6 +172,10 @@ var _ = Describe("logging", func() {
 			withNameDone := make(chan struct{})
 			withValuesDone := make(chan struct{})
 			grandChildDone := make(chan struct{})
+			logEnabledDone := make(chan struct{})
+			logInfoDone := make(chan struct{})
+			logErrorDone := make(chan struct{})
+			logVDone := make(chan struct{})
 
 			// Constructing the child in the goroutine does not reliably
 			// trigger the race detector
@@ -193,11 +200,35 @@ var _ = Describe("logging", func() {
 				child.WithValues("grandchild")
 				close(grandChildDone)
 			}()
+			go func() {
+				defer GinkgoRecover()
+				delegLog.Enabled()
+				close(logEnabledDone)
+			}()
+			go func() {
+				defer GinkgoRecover()
+				delegLog.Info("hello world")
+				close(logInfoDone)
+			}()
+			go func() {
+				defer GinkgoRecover()
+				delegLog.Error(errors.New("err"), "hello world")
+				close(logErrorDone)
+			}()
+			go func() {
+				defer GinkgoRecover()
+				delegLog.V(1)
+				close(logVDone)
+			}()
 
 			<-fulfillDone
 			<-withNameDone
 			<-withValuesDone
 			<-grandChildDone
+			<-logEnabledDone
+			<-logInfoDone
+			<-logErrorDone
+			<-logVDone
 		})
 
 		It("should delegate with tags", func() {