diff --git a/README.md b/README.md index 2f9f6f0d8..64d29622e 100644 --- a/README.md +++ b/README.md @@ -27,7 +27,7 @@ Historical context is available here: How to use klog =============== -- Replace imports for `github.com/golang/glog` with `k8s.io/klog` +- Replace imports for `"github.com/golang/glog"` with `"k8s.io/klog/v2"` - Use `klog.InitFlags(nil)` explicitly for initializing global flags as we no longer use `init()` method to register the flags - You can now use `log_file` instead of `log_dir` for logging to a single file (See `examples/log_file/usage_log_file.go`) - If you want to redirect everything logged using klog somewhere else (say syslog!), you can use `klog.SetOutput()` method and supply a `io.Writer`. (See `examples/set_output/usage_set_output.go`) @@ -35,6 +35,10 @@ How to use klog **NOTE**: please use the newer go versions that support semantic import versioning in modules, ideally go 1.11.4 or greater. +### Coexisting with klog/v2 + +See [this example](examples/coexist_klog_v1_and_v2/) to see how to coexist with both klog/v1 and klog/v2. + ### Coexisting with glog This package can be used side by side with glog. [This example](examples/coexist_glog/coexist_glog.go) shows how to initialize and synchronize flags from the global `flag.CommandLine` FlagSet. In addition, the example makes use of stderr as combined output by setting `alsologtostderr` (or `logtostderr`) to `true`. diff --git a/klog.go b/klog.go index 767a18c9b..23cced625 100644 --- a/klog.go +++ b/klog.go @@ -510,6 +510,9 @@ type loggingT struct { // If true, messages will not be propagated to lower severity log levels oneOutput bool + + // If set, all output will be filtered through the filter. + filter LogFilter } // buffer holds a byte Buffer for reuse. The zero value is ready for use. @@ -692,7 +695,7 @@ func (buf *buffer) someDigits(i, d int) int { return copy(buf.tmp[i:], buf.tmp[j:]) } -func (l *loggingT) println(s severity, logr logr.Logger, args ...interface{}) { +func (l *loggingT) println(s severity, logr logr.Logger, filter LogFilter, args ...interface{}) { buf, file, line := l.header(s, 0) // if logr is set, we clear the generated header as we rely on the backing // logr implementation to print headers @@ -700,15 +703,18 @@ func (l *loggingT) println(s severity, logr logr.Logger, args ...interface{}) { l.putBuffer(buf) buf = l.getBuffer() } + if filter != nil { + args = filter.Filter(args) + } fmt.Fprintln(buf, args...) l.output(s, logr, buf, file, line, false) } -func (l *loggingT) print(s severity, logr logr.Logger, args ...interface{}) { - l.printDepth(s, logr, 1, args...) +func (l *loggingT) print(s severity, logr logr.Logger, filter LogFilter, args ...interface{}) { + l.printDepth(s, logr, filter, 1, args...) } -func (l *loggingT) printDepth(s severity, logr logr.Logger, depth int, args ...interface{}) { +func (l *loggingT) printDepth(s severity, logr logr.Logger, 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 @@ -716,6 +722,9 @@ func (l *loggingT) printDepth(s severity, logr logr.Logger, depth int, args ...i l.putBuffer(buf) buf = l.getBuffer() } + if filter != nil { + args = filter.Filter(args) + } fmt.Fprint(buf, args...) if buf.Bytes()[buf.Len()-1] != '\n' { buf.WriteByte('\n') @@ -723,7 +732,7 @@ func (l *loggingT) printDepth(s severity, logr logr.Logger, depth int, args ...i l.output(s, logr, buf, file, line, false) } -func (l *loggingT) printf(s severity, logr logr.Logger, format string, args ...interface{}) { +func (l *loggingT) printf(s severity, logr logr.Logger, filter LogFilter, format string, args ...interface{}) { buf, file, line := l.header(s, 0) // if logr is set, we clear the generated header as we rely on the backing // logr implementation to print headers @@ -731,6 +740,9 @@ func (l *loggingT) printf(s severity, logr logr.Logger, format string, args ...i l.putBuffer(buf) buf = l.getBuffer() } + if filter != nil { + format, args = filter.FilterF(format, args) + } fmt.Fprintf(buf, format, args...) if buf.Bytes()[buf.Len()-1] != '\n' { buf.WriteByte('\n') @@ -741,7 +753,7 @@ func (l *loggingT) printf(s severity, logr logr.Logger, format string, args ...i // 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, logr logr.Logger, file string, line int, alsoToStderr bool, args ...interface{}) { +func (l *loggingT) printWithFileLine(s severity, logr logr.Logger, 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 @@ -749,6 +761,9 @@ func (l *loggingT) printWithFileLine(s severity, logr logr.Logger, file string, l.putBuffer(buf) buf = l.getBuffer() } + if filter != nil { + args = filter.Filter(args) + } fmt.Fprint(buf, args...) if buf.Bytes()[buf.Len()-1] != '\n' { buf.WriteByte('\n') @@ -757,7 +772,10 @@ func (l *loggingT) printWithFileLine(s severity, logr logr.Logger, file string, } // if loggr is specified, will call loggr.Error, otherwise output with logging module. -func (l *loggingT) errorS(err error, loggr logr.Logger, msg string, keysAndValues ...interface{}) { +func (l *loggingT) errorS(err error, loggr logr.Logger, filter LogFilter, msg string, keysAndValues ...interface{}) { + if filter != nil { + msg, keysAndValues = filter.FilterS(msg, keysAndValues) + } if loggr != nil { loggr.Error(err, msg, keysAndValues...) return @@ -766,7 +784,10 @@ func (l *loggingT) errorS(err error, loggr logr.Logger, msg string, keysAndValue } // if loggr is specified, will call loggr.Info, otherwise output with logging module. -func (l *loggingT) infoS(loggr logr.Logger, msg string, keysAndValues ...interface{}) { +func (l *loggingT) infoS(loggr logr.Logger, filter LogFilter, msg string, keysAndValues ...interface{}) { + if filter != nil { + msg, keysAndValues = filter.FilterS(msg, keysAndValues) + } if loggr != nil { loggr.Info(msg, keysAndValues...) return @@ -790,7 +811,7 @@ func (l *loggingT) printS(err error, msg string, keysAndValues ...interface{}) { } else { s = errorLog } - l.printDepth(s, logging.logr, 2, b) + l.printDepth(s, logging.logr, nil, 2, b) } const missingValue = "(MISSING)" @@ -1214,7 +1235,7 @@ func (lb logBridge) Write(b []byte) (n int, err error) { } // printWithFileLine with alsoToStderr=true, so standard log messages // always appear on standard error. - logging.printWithFileLine(severity(lb), logging.logr, file, line, true, text) + logging.printWithFileLine(severity(lb), logging.logr, logging.filter, file, line, true, text) return len(b), nil } @@ -1249,13 +1270,14 @@ func (l *loggingT) setV(pc uintptr) Level { type Verbose struct { enabled bool logr logr.Logger + filter LogFilter } func newVerbose(level Level, b bool) Verbose { if logging.logr == nil { - return Verbose{b, nil} + return Verbose{b, nil, logging.filter} } - return Verbose{b, logging.logr.V(int(level))} + return Verbose{b, logging.logr.V(int(level)), logging.filter} } // V reports whether verbosity at the call site is at least the requested level. @@ -1313,7 +1335,7 @@ func (v Verbose) Enabled() bool { // See the documentation of V for usage. func (v Verbose) Info(args ...interface{}) { if v.enabled { - logging.print(infoLog, v.logr, args...) + logging.print(infoLog, v.logr, v.filter, args...) } } @@ -1321,7 +1343,7 @@ func (v Verbose) Info(args ...interface{}) { // See the documentation of V for usage. func (v Verbose) Infoln(args ...interface{}) { if v.enabled { - logging.println(infoLog, v.logr, args...) + logging.println(infoLog, v.logr, v.filter, args...) } } @@ -1329,7 +1351,7 @@ func (v Verbose) Infoln(args ...interface{}) { // See the documentation of V for usage. func (v Verbose) Infof(format string, args ...interface{}) { if v.enabled { - logging.printf(infoLog, v.logr, format, args...) + logging.printf(infoLog, v.logr, v.filter, format, args...) } } @@ -1337,14 +1359,14 @@ func (v Verbose) Infof(format string, args ...interface{}) { // See the documentation of V for usage. func (v Verbose) InfoS(msg string, keysAndValues ...interface{}) { if v.enabled { - logging.infoS(v.logr, msg, keysAndValues...) + logging.infoS(v.logr, v.filter, msg, keysAndValues...) } } // Deprecated: Use ErrorS instead. func (v Verbose) Error(err error, msg string, args ...interface{}) { if v.enabled { - logging.errorS(err, v.logr, msg, args...) + logging.errorS(err, v.logr, v.filter, msg, args...) } } @@ -1352,32 +1374,32 @@ func (v Verbose) Error(err error, msg string, args ...interface{}) { // 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, msg, keysAndValues...) + logging.errorS(err, v.logr, v.filter, msg, keysAndValues...) } } // Info logs to the INFO log. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing. func Info(args ...interface{}) { - logging.print(infoLog, logging.logr, args...) + logging.print(infoLog, logging.logr, logging.filter, args...) } // InfoDepth acts as Info but uses depth to determine which call frame to log. // InfoDepth(0, "msg") is the same as Info("msg"). func InfoDepth(depth int, args ...interface{}) { - logging.printDepth(infoLog, logging.logr, depth, args...) + logging.printDepth(infoLog, logging.logr, logging.filter, depth, args...) } // Infoln logs to the INFO log. // Arguments are handled in the manner of fmt.Println; a newline is always appended. func Infoln(args ...interface{}) { - logging.println(infoLog, logging.logr, args...) + logging.println(infoLog, logging.logr, logging.filter, args...) } // Infof logs to the INFO log. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing. func Infof(format string, args ...interface{}) { - logging.printf(infoLog, logging.logr, format, args...) + logging.printf(infoLog, logging.logr, logging.filter, format, args...) } // InfoS structured logs to the INFO log. @@ -1389,55 +1411,55 @@ func Infof(format string, args ...interface{}) { // output: // >> I1025 00:15:15.525108 1 controller_utils.go:116] "Pod status updated" pod="kubedns" status="ready" func InfoS(msg string, keysAndValues ...interface{}) { - logging.infoS(logging.logr, msg, keysAndValues...) + logging.infoS(logging.logr, logging.filter, msg, keysAndValues...) } // Warning logs to the WARNING and INFO logs. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing. func Warning(args ...interface{}) { - logging.print(warningLog, logging.logr, args...) + logging.print(warningLog, logging.logr, logging.filter, args...) } // WarningDepth acts as Warning but uses depth to determine which call frame to log. // WarningDepth(0, "msg") is the same as Warning("msg"). func WarningDepth(depth int, args ...interface{}) { - logging.printDepth(warningLog, logging.logr, depth, args...) + logging.printDepth(warningLog, logging.logr, logging.filter, depth, args...) } // Warningln logs to the WARNING and INFO logs. // Arguments are handled in the manner of fmt.Println; a newline is always appended. func Warningln(args ...interface{}) { - logging.println(warningLog, logging.logr, args...) + logging.println(warningLog, logging.logr, logging.filter, args...) } // Warningf logs to the WARNING and INFO logs. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing. func Warningf(format string, args ...interface{}) { - logging.printf(warningLog, logging.logr, format, args...) + logging.printf(warningLog, logging.logr, logging.filter, format, args...) } // Error logs to the ERROR, WARNING, and INFO logs. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing. func Error(args ...interface{}) { - logging.print(errorLog, logging.logr, args...) + logging.print(errorLog, logging.logr, logging.filter, args...) } // ErrorDepth acts as Error but uses depth to determine which call frame to log. // ErrorDepth(0, "msg") is the same as Error("msg"). func ErrorDepth(depth int, args ...interface{}) { - logging.printDepth(errorLog, logging.logr, depth, args...) + logging.printDepth(errorLog, logging.logr, logging.filter, depth, args...) } // Errorln logs to the ERROR, WARNING, and INFO logs. // Arguments are handled in the manner of fmt.Println; a newline is always appended. func Errorln(args ...interface{}) { - logging.println(errorLog, logging.logr, args...) + logging.println(errorLog, logging.logr, logging.filter, args...) } // Errorf logs to the ERROR, WARNING, and INFO logs. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing. func Errorf(format string, args ...interface{}) { - logging.printf(errorLog, logging.logr, format, args...) + logging.printf(errorLog, logging.logr, logging.filter, format, args...) } // ErrorS structured logs to the ERROR, WARNING, and INFO logs. @@ -1450,34 +1472,34 @@ func Errorf(format string, args ...interface{}) { // output: // >> E1025 00:15:15.525108 1 controller_utils.go:114] "Failed to update pod status" err="timeout" func ErrorS(err error, msg string, keysAndValues ...interface{}) { - logging.errorS(err, logging.logr, msg, keysAndValues...) + logging.errorS(err, logging.logr, logging.filter, msg, keysAndValues...) } // Fatal logs to the FATAL, ERROR, WARNING, and INFO logs, // including a stack trace of all running goroutines, then calls os.Exit(255). // Arguments are handled in the manner of fmt.Print; a newline is appended if missing. func Fatal(args ...interface{}) { - logging.print(fatalLog, logging.logr, args...) + logging.print(fatalLog, logging.logr, logging.filter, args...) } // FatalDepth acts as Fatal but uses depth to determine which call frame to log. // FatalDepth(0, "msg") is the same as Fatal("msg"). func FatalDepth(depth int, args ...interface{}) { - logging.printDepth(fatalLog, logging.logr, depth, args...) + logging.printDepth(fatalLog, logging.logr, logging.filter, depth, args...) } // Fatalln logs to the FATAL, ERROR, WARNING, and INFO logs, // including a stack trace of all running goroutines, then calls os.Exit(255). // Arguments are handled in the manner of fmt.Println; a newline is always appended. func Fatalln(args ...interface{}) { - logging.println(fatalLog, logging.logr, args...) + logging.println(fatalLog, logging.logr, logging.filter, args...) } // Fatalf logs to the FATAL, ERROR, WARNING, and INFO logs, // including a stack trace of all running goroutines, then calls os.Exit(255). // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing. func Fatalf(format string, args ...interface{}) { - logging.printf(fatalLog, logging.logr, format, args...) + logging.printf(fatalLog, logging.logr, logging.filter, format, args...) } // fatalNoStacks is non-zero if we are to exit without dumping goroutine stacks. @@ -1488,27 +1510,42 @@ var fatalNoStacks uint32 // Arguments are handled in the manner of fmt.Print; a newline is appended if missing. func Exit(args ...interface{}) { atomic.StoreUint32(&fatalNoStacks, 1) - logging.print(fatalLog, logging.logr, args...) + logging.print(fatalLog, logging.logr, logging.filter, args...) } // ExitDepth acts as Exit but uses depth to determine which call frame to log. // ExitDepth(0, "msg") is the same as Exit("msg"). func ExitDepth(depth int, args ...interface{}) { atomic.StoreUint32(&fatalNoStacks, 1) - logging.printDepth(fatalLog, logging.logr, depth, args...) + logging.printDepth(fatalLog, logging.logr, logging.filter, depth, args...) } // Exitln logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1). func Exitln(args ...interface{}) { atomic.StoreUint32(&fatalNoStacks, 1) - logging.println(fatalLog, logging.logr, args...) + logging.println(fatalLog, logging.logr, logging.filter, args...) } // Exitf logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1). // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing. func Exitf(format string, args ...interface{}) { atomic.StoreUint32(&fatalNoStacks, 1) - logging.printf(fatalLog, logging.logr, format, args...) + logging.printf(fatalLog, logging.logr, logging.filter, format, args...) +} + +// LogFilter is a collection of functions that can filter all logging calls, +// e.g. for sanitization of arguments and prevent accidental leaking of secrets. +type LogFilter interface { + Filter(args []interface{}) []interface{} + FilterF(format string, args []interface{}) (string, []interface{}) + FilterS(msg string, keysAndValues []interface{}) (string, []interface{}) +} + +func SetLogFilter(filter LogFilter) { + logging.mu.Lock() + defer logging.mu.Unlock() + + logging.filter = filter } // ObjectRef references a kubernetes object diff --git a/klog_test.go b/klog_test.go index 8c8fa67dd..d71cc9648 100644 --- a/klog_test.go +++ b/klog_test.go @@ -1077,6 +1077,173 @@ func TestSetVState(t *testing.T) { } } +type sampleLogFilter struct{} + +func (f *sampleLogFilter) Filter(args []interface{}) []interface{} { + for i, arg := range args { + v, ok := arg.(string) + if ok && strings.Contains(v, "filter me") { + args[i] = "[FILTERED]" + } + } + return args +} + +func (f *sampleLogFilter) FilterF(format string, args []interface{}) (string, []interface{}) { + return strings.Replace(format, "filter me", "[FILTERED]", 1), f.Filter(args) +} + +func (f *sampleLogFilter) FilterS(msg string, keysAndValues []interface{}) (string, []interface{}) { + return strings.Replace(msg, "filter me", "[FILTERED]", 1), f.Filter(keysAndValues) +} + +func TestLogFilter(t *testing.T) { + setFlags() + defer logging.swap(logging.newBuffers()) + SetLogFilter(&sampleLogFilter{}) + defer SetLogFilter(nil) + funcs := []struct { + name string + logFunc func(args ...interface{}) + severity severity + }{{ + name: "Info", + logFunc: Info, + severity: infoLog, + }, { + name: "InfoDepth", + logFunc: func(args ...interface{}) { + InfoDepth(1, args...) + }, + severity: infoLog, + }, { + name: "Infoln", + logFunc: Infoln, + severity: infoLog, + }, { + name: "Infof", + logFunc: func(args ...interface{}) { + + Infof(args[0].(string), args[1:]...) + }, + severity: infoLog, + }, { + name: "InfoS", + logFunc: func(args ...interface{}) { + InfoS(args[0].(string), args[1:]...) + }, + severity: infoLog, + }, { + name: "Warning", + logFunc: Warning, + severity: warningLog, + }, { + name: "WarningDepth", + logFunc: func(args ...interface{}) { + WarningDepth(1, args...) + }, + severity: warningLog, + }, { + name: "Warningln", + logFunc: Warningln, + severity: warningLog, + }, { + name: "Warningf", + logFunc: func(args ...interface{}) { + Warningf(args[0].(string), args[1:]...) + }, + severity: warningLog, + }, { + name: "Error", + logFunc: Error, + severity: errorLog, + }, { + name: "ErrorDepth", + logFunc: func(args ...interface{}) { + ErrorDepth(1, args...) + }, + severity: errorLog, + }, { + name: "Errorln", + logFunc: Errorln, + severity: errorLog, + }, { + name: "Errorf", + logFunc: func(args ...interface{}) { + Errorf(args[0].(string), args[1:]...) + }, + severity: errorLog, + }, { + name: "ErrorS", + logFunc: func(args ...interface{}) { + ErrorS(errors.New("testerror"), args[0].(string), args[1:]...) + }, + severity: errorLog, + }, { + name: "V().Info", + logFunc: func(args ...interface{}) { + V(0).Info(args...) + }, + severity: infoLog, + }, { + name: "V().Infoln", + logFunc: func(args ...interface{}) { + V(0).Infoln(args...) + }, + severity: infoLog, + }, { + name: "V().Infof", + logFunc: func(args ...interface{}) { + V(0).Infof(args[0].(string), args[1:]...) + }, + severity: infoLog, + }, { + name: "V().InfoS", + logFunc: func(args ...interface{}) { + V(0).InfoS(args[0].(string), args[1:]...) + }, + severity: infoLog, + }, { + name: "V().Error", + logFunc: func(args ...interface{}) { + V(0).Error(errors.New("test error"), args[0].(string), args[1:]...) + }, + severity: errorLog, + }, { + name: "V().ErrorS", + logFunc: func(args ...interface{}) { + V(0).ErrorS(errors.New("test error"), args[0].(string), args[1:]...) + }, + severity: errorLog, + }} + + testcases := []struct { + name string + args []interface{} + expectFiltered bool + }{{ + args: []interface{}{"%s:%s", "foo", "bar"}, + expectFiltered: false, + }, { + args: []interface{}{"%s:%s", "foo", "filter me"}, + expectFiltered: true, + }, { + args: []interface{}{"filter me %s:%s", "foo", "bar"}, + expectFiltered: true, + }} + + for _, f := range funcs { + for _, tc := range testcases { + logging.newBuffers() + f.logFunc(tc.args...) + got := contains(f.severity, "[FILTERED]", t) + if got != tc.expectFiltered { + t.Errorf("%s filter application failed, got %v, want %v", f.name, got, tc.expectFiltered) + } + } + } +} + func TestInfoSWithLogr(t *testing.T) { logger := new(testLogr)