Merge pull request #363 from pohly/textlogger-backend

textlogger write through

contextual.go

@@ -70,11 +70,14 @@ func SetLogger(logger logr.Logger) {
 // routing log entries through klogr into klog and then into the actual Logger
 // backend.
 func SetLoggerWithOptions(logger logr.Logger, opts ...LoggerOption) {
-	logging.logger = &logger
 	logging.loggerOptions = loggerOptions{}
 	for _, opt := range opts {
 		opt(&logging.loggerOptions)
 	}
+	logging.logger = &logWriter{
+		Logger:          logger,
+		writeKlogBuffer: logging.loggerOptions.writeKlogBuffer,
+	}
 }
 
 // ContextualLogger determines whether the logger passed to
@@ -93,13 +96,36 @@ func FlushLogger(flush func()) LoggerOption {
 	}
 }
 
+// WriteKlogBuffer sets a callback that will be invoked by klog to write output
+// produced by non-structured log calls like Infof.
+//
+// The buffer will contain exactly the same data that klog normally would write
+// into its own output stream(s). In particular this includes the header, if
+// klog is configured to write one. The callback then can divert that data into
+// its own output streams. The buffer may or may not end in a line break.
+//
+// Without such a callback, klog will call the logger's Info or Error method
+// with just the message string (i.e. no header).
+func WriteKlogBuffer(write func([]byte)) LoggerOption {
+	return func(o *loggerOptions) {
+		o.writeKlogBuffer = write
+	}
+}
+
 // LoggerOption implements the functional parameter paradigm for
 // SetLoggerWithOptions.
 type LoggerOption func(o *loggerOptions)
 
 type loggerOptions struct {
 	contextualLogger bool
 	flush            func()
+	writeKlogBuffer  func([]byte)
+}
+
+// logWriter combines a logger (always set) with a write callback (optional).
+type logWriter struct {
+	Logger
+	writeKlogBuffer func([]byte)
 }
 
 // ClearLogger removes a backing Logger implementation if one was set earlier
@@ -152,7 +178,7 @@ func Background() Logger {
 	if logging.loggerOptions.contextualLogger {
 		// Is non-nil because logging.loggerOptions.contextualLogger is
 		// only true if a logger was set.
-		return *logging.logger
+		return logging.logger.Logger
 	}
 
 	return klogLogger

klog.go

@@ -91,8 +91,6 @@ import (
 	"sync/atomic"
 	"time"
 
-	"github.com/go-logr/logr"
-
 	"k8s.io/klog/v2/internal/buffer"
 	"k8s.io/klog/v2/internal/clock"
 	"k8s.io/klog/v2/internal/dbg"
@@ -453,7 +451,7 @@ type settings struct {
 
 	// logger is the global Logger chosen by users of klog, nil if
 	// none is available.
-	logger *Logger
+	logger *logWriter
 
 	// loggerOptions contains the options that were supplied for
 	// globalLogger.
@@ -525,6 +523,11 @@ func (s settings) deepCopy() settings {
 	}
 	s.vmodule.filter = filter
 
+	if s.logger != nil {
+		logger := *s.logger
+		s.logger = &logger
+	}
+
 	return s
 }
 
@@ -668,15 +671,16 @@ func (l *loggingT) formatHeader(s severity.Severity, file string, line int) *buf
 	return buf
 }
 
-func (l *loggingT) println(s severity.Severity, logger *logr.Logger, filter LogFilter, args ...interface{}) {
+func (l *loggingT) println(s severity.Severity, logger *logWriter, filter LogFilter, args ...interface{}) {
 	l.printlnDepth(s, logger, filter, 1, args...)
 }
 
-func (l *loggingT) printlnDepth(s severity.Severity, logger *logr.Logger, filter LogFilter, depth int, args ...interface{}) {
+func (l *loggingT) printlnDepth(s severity.Severity, logger *logWriter, filter LogFilter, depth int, args ...interface{}) {
 	buf, file, line := l.header(s, depth)
-	// if logger is set, we clear the generated header as we rely on the backing
-	// logger implementation to print headers
-	if logger != nil {
+	// If a logger is set and doesn't support writing a formatted buffer,
+	// we clear the generated header as we rely on the backing
+	// logger implementation to print headers.
+	if logger != nil && logger.writeKlogBuffer == nil {
 		buffer.PutBuffer(buf)
 		buf = buffer.GetBuffer()
 	}
@@ -687,15 +691,16 @@ func (l *loggingT) printlnDepth(s severity.Severity, logger *logr.Logger, filter
 	l.output(s, logger, buf, depth, file, line, false)
 }
 
-func (l *loggingT) print(s severity.Severity, logger *logr.Logger, filter LogFilter, args ...interface{}) {
+func (l *loggingT) print(s severity.Severity, logger *logWriter, filter LogFilter, args ...interface{}) {
 	l.printDepth(s, logger, filter, 1, args...)
 }
 
-func (l *loggingT) printDepth(s severity.Severity, logger *logr.Logger, filter LogFilter, depth int, args ...interface{}) {
+func (l *loggingT) printDepth(s severity.Severity, logger *logWriter, filter LogFilter, depth int, args ...interface{}) {
 	buf, file, line := l.header(s, depth)
-	// if logr is set, we clear the generated header as we rely on the backing
-	// logr implementation to print headers
-	if logger != nil {
+	// If a logger is set and doesn't support writing a formatted buffer,
+	// we clear the generated header as we rely on the backing
+	// logger implementation to print headers.
+	if logger != nil && logger.writeKlogBuffer == nil {
 		buffer.PutBuffer(buf)
 		buf = buffer.GetBuffer()
 	}
@@ -709,15 +714,16 @@ func (l *loggingT) printDepth(s severity.Severity, logger *logr.Logger, filter L
 	l.output(s, logger, buf, depth, file, line, false)
 }
 
-func (l *loggingT) printf(s severity.Severity, logger *logr.Logger, filter LogFilter, format string, args ...interface{}) {
+func (l *loggingT) printf(s severity.Severity, logger *logWriter, filter LogFilter, format string, args ...interface{}) {
 	l.printfDepth(s, logger, filter, 1, format, args...)
 }
 
-func (l *loggingT) printfDepth(s severity.Severity, logger *logr.Logger, filter LogFilter, depth int, format string, args ...interface{}) {
+func (l *loggingT) printfDepth(s severity.Severity, logger *logWriter, filter LogFilter, depth int, format string, args ...interface{}) {
 	buf, file, line := l.header(s, depth)
-	// if logr is set, we clear the generated header as we rely on the backing
-	// logr implementation to print headers
-	if logger != nil {
+	// If a logger is set and doesn't support writing a formatted buffer,
+	// we clear the generated header as we rely on the backing
+	// logger implementation to print headers.
+	if logger != nil && logger.writeKlogBuffer == nil {
 		buffer.PutBuffer(buf)
 		buf = buffer.GetBuffer()
 	}
@@ -734,11 +740,12 @@ func (l *loggingT) printfDepth(s severity.Severity, logger *logr.Logger, filter
 // printWithFileLine behaves like print but uses the provided file and line number.  If
 // alsoLogToStderr is true, the log message always appears on standard error; it
 // will also appear in the log file unless --logtostderr is set.
-func (l *loggingT) printWithFileLine(s severity.Severity, logger *logr.Logger, filter LogFilter, file string, line int, alsoToStderr bool, args ...interface{}) {
+func (l *loggingT) printWithFileLine(s severity.Severity, logger *logWriter, filter LogFilter, file string, line int, alsoToStderr bool, args ...interface{}) {
 	buf := l.formatHeader(s, file, line)
-	// if logr is set, we clear the generated header as we rely on the backing
-	// logr implementation to print headers
-	if logger != nil {
+	// If a logger is set and doesn't support writing a formatted buffer,
+	// we clear the generated header as we rely on the backing
+	// logger implementation to print headers.
+	if logger != nil && logger.writeKlogBuffer == nil {
 		buffer.PutBuffer(buf)
 		buf = buffer.GetBuffer()
 	}
@@ -753,7 +760,7 @@ func (l *loggingT) printWithFileLine(s severity.Severity, logger *logr.Logger, f
 }
 
 // if loggr is specified, will call loggr.Error, otherwise output with logging module.
-func (l *loggingT) errorS(err error, logger *logr.Logger, filter LogFilter, depth int, msg string, keysAndValues ...interface{}) {
+func (l *loggingT) errorS(err error, logger *logWriter, filter LogFilter, depth int, msg string, keysAndValues ...interface{}) {
 	if filter != nil {
 		msg, keysAndValues = filter.FilterS(msg, keysAndValues)
 	}
@@ -765,7 +772,7 @@ func (l *loggingT) errorS(err error, logger *logr.Logger, filter LogFilter, dept
 }
 
 // if loggr is specified, will call loggr.Info, otherwise output with logging module.
-func (l *loggingT) infoS(logger *logr.Logger, filter LogFilter, depth int, msg string, keysAndValues ...interface{}) {
+func (l *loggingT) infoS(logger *logWriter, filter LogFilter, depth int, msg string, keysAndValues ...interface{}) {
 	if filter != nil {
 		msg, keysAndValues = filter.FilterS(msg, keysAndValues)
 	}
@@ -846,7 +853,7 @@ func LogToStderr(stderr bool) {
 }
 
 // output writes the data to the log files and releases the buffer.
-func (l *loggingT) output(s severity.Severity, log *logr.Logger, buf *buffer.Buffer, depth int, file string, line int, alsoToStderr bool) {
+func (l *loggingT) output(s severity.Severity, logger *logWriter, buf *buffer.Buffer, depth int, file string, line int, alsoToStderr bool) {
 	var isLocked = true
 	l.mu.Lock()
 	defer func() {
@@ -862,13 +869,17 @@ func (l *loggingT) output(s severity.Severity, log *logr.Logger, buf *buffer.Buf
 		}
 	}
 	data := buf.Bytes()
-	if log != nil {
-		// TODO: set 'severity' and caller information as structured log info
-		// keysAndValues := []interface{}{"severity", severityName[s], "file", file, "line", line}
-		if s == severity.ErrorLog {
-			logging.logger.WithCallDepth(depth+3).Error(nil, string(data))
+	if logger != nil {
+		if logger.writeKlogBuffer != nil {
+			logger.writeKlogBuffer(data)
 		} else {
-			log.WithCallDepth(depth + 3).Info(string(data))
+			// TODO: set 'severity' and caller information as structured log info
+			// keysAndValues := []interface{}{"severity", severityName[s], "file", file, "line", line}
+			if s == severity.ErrorLog {
+				logger.WithCallDepth(depth+3).Error(nil, string(data))
+			} else {
+				logger.WithCallDepth(depth + 3).Info(string(data))
+			}
 		}
 	} else if l.toStderr {
 		os.Stderr.Write(data)
@@ -1277,15 +1288,15 @@ func (l *loggingT) setV(pc uintptr) Level {
 // See the documentation of V for more information.
 type Verbose struct {
 	enabled bool
-	logr    *logr.Logger
+	logger  *logWriter
 }
 
 func newVerbose(level Level, b bool) Verbose {
 	if logging.logger == nil {
 		return Verbose{b, nil}
 	}
 	v := logging.logger.V(int(level))
-	return Verbose{b, &v}
+	return Verbose{b, &logWriter{Logger: v, writeKlogBuffer: logging.loggerOptions.writeKlogBuffer}}
 }
 
 // V reports whether verbosity at the call site is at least the requested level.
@@ -1359,55 +1370,55 @@ func (v Verbose) Enabled() bool {
 // See the documentation of V for usage.
 func (v Verbose) Info(args ...interface{}) {
 	if v.enabled {
-		logging.print(severity.InfoLog, v.logr, logging.filter, args...)
+		logging.print(severity.InfoLog, v.logger, logging.filter, args...)
 	}
 }
 
 // InfoDepth is equivalent to the global InfoDepth function, guarded by the value of v.
 // See the documentation of V for usage.
 func (v Verbose) InfoDepth(depth int, args ...interface{}) {
 	if v.enabled {
-		logging.printDepth(severity.InfoLog, v.logr, logging.filter, depth, args...)
+		logging.printDepth(severity.InfoLog, v.logger, logging.filter, depth, args...)
 	}
 }
 
 // Infoln is equivalent to the global Infoln function, guarded by the value of v.
 // See the documentation of V for usage.
 func (v Verbose) Infoln(args ...interface{}) {
 	if v.enabled {
-		logging.println(severity.InfoLog, v.logr, logging.filter, args...)
+		logging.println(severity.InfoLog, v.logger, logging.filter, args...)
 	}
 }
 
 // InfolnDepth is equivalent to the global InfolnDepth function, guarded by the value of v.
 // See the documentation of V for usage.
 func (v Verbose) InfolnDepth(depth int, args ...interface{}) {
 	if v.enabled {
-		logging.printlnDepth(severity.InfoLog, v.logr, logging.filter, depth, args...)
+		logging.printlnDepth(severity.InfoLog, v.logger, logging.filter, depth, args...)
 	}
 }
 
 // Infof is equivalent to the global Infof function, guarded by the value of v.
 // See the documentation of V for usage.
 func (v Verbose) Infof(format string, args ...interface{}) {
 	if v.enabled {
-		logging.printf(severity.InfoLog, v.logr, logging.filter, format, args...)
+		logging.printf(severity.InfoLog, v.logger, logging.filter, format, args...)
 	}
 }
 
 // InfofDepth is equivalent to the global InfofDepth function, guarded by the value of v.
 // See the documentation of V for usage.
 func (v Verbose) InfofDepth(depth int, format string, args ...interface{}) {
 	if v.enabled {
-		logging.printfDepth(severity.InfoLog, v.logr, logging.filter, depth, format, args...)
+		logging.printfDepth(severity.InfoLog, v.logger, logging.filter, depth, format, args...)
 	}
 }
 
 // InfoS is equivalent to the global InfoS function, guarded by the value of v.
 // See the documentation of V for usage.
 func (v Verbose) InfoS(msg string, keysAndValues ...interface{}) {
 	if v.enabled {
-		logging.infoS(v.logr, logging.filter, 0, msg, keysAndValues...)
+		logging.infoS(v.logger, logging.filter, 0, msg, keysAndValues...)
 	}
 }
 
@@ -1421,22 +1432,22 @@ func InfoSDepth(depth int, msg string, keysAndValues ...interface{}) {
 // See the documentation of V for usage.
 func (v Verbose) InfoSDepth(depth int, msg string, keysAndValues ...interface{}) {
 	if v.enabled {
-		logging.infoS(v.logr, logging.filter, depth, msg, keysAndValues...)
+		logging.infoS(v.logger, logging.filter, depth, msg, keysAndValues...)
 	}
 }
 
 // Deprecated: Use ErrorS instead.
 func (v Verbose) Error(err error, msg string, args ...interface{}) {
 	if v.enabled {
-		logging.errorS(err, v.logr, logging.filter, 0, msg, args...)
+		logging.errorS(err, v.logger, logging.filter, 0, msg, args...)
 	}
 }
 
 // ErrorS is equivalent to the global Error function, guarded by the value of v.
 // See the documentation of V for usage.
 func (v Verbose) ErrorS(err error, msg string, keysAndValues ...interface{}) {
 	if v.enabled {
-		logging.errorS(err, v.logr, logging.filter, 0, msg, keysAndValues...)
+		logging.errorS(err, v.logger, logging.filter, 0, msg, keysAndValues...)
 	}
 }
 

klog_test.go

@@ -2196,7 +2196,7 @@ func TestSettingsDeepCopy(t *testing.T) {
 	logger := logr.Discard()
 
 	settings := settings{
-		logger: &logger,
+		logger: &logWriter{Logger: logger},
 		vmodule: moduleSpec{
 			filter: []modulePat{
 				{pattern: "a"},