Skip to content

Add SetLogger function to intercept klog output with logr #20

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
k8s-ci-robot merged 8 commits into from
Aug 14, 2019
Merged

Add SetLogger function to intercept klog output with logr #20

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
8627f7d
Add SetLogger function to intercept glog output
munnerz Nov 15, 2018
038c227
Fix unit tests
munnerz Nov 15, 2018
1d02385
Call Error instead of Info when the severity is 'errorLog'
munnerz Feb 25, 2019
6068135
Don't include header if logr is being used
munnerz Feb 25, 2019
1e2e475
Include file and line no as logr values
munnerz Feb 25, 2019
82efb68
Add and update comments
munnerz Feb 25, 2019
c96b964
Remove casting and fix nil check
munnerz Feb 28, 2019
eae9d56
Don't set extra structured log arguments
munnerz Apr 12, 2019
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
158 changes: 112 additions & 46 deletions klog.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -87,6 +87,8 @@ import (
"sync"
"sync/atomic"
"time"

"github.com/go-logr/logr"
Comment thread
thockin marked this conversation as resolved.
)

// severity identifies the sort of log: info, warning etc. It also implements
Expand Down Expand Up @@ -505,6 +507,9 @@ type loggingT struct {

// If true, add the file directory to the header
addDirHeader bool

// If set, all output will be redirected unconditionally to the provided logr.Logger
logr logr.Logger
}

// buffer holds a byte Buffer for reuse. The zero value is ready for use.
Expand Down Expand Up @@ -687,44 +692,68 @@ func (buf *buffer) someDigits(i, d int) int {
return copy(buf.tmp[i:], buf.tmp[j:])
}

func (l *loggingT) println(s severity, args ...interface{}) {
func (l *loggingT) println(s severity, logr logr.InfoLogger, args ...interface{}) {
Comment thread
thockin marked this conversation as resolved.
buf, file, line := l.header(s, 0)
Copy link
Copy Markdown
Member

@thockin thockin Aug 8, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hard to know for sure but this seems like a waste to generate and discard the buffer- should we do something like:

var buf bytes.Buffer
var file string
var line int
if logr == nil {
    buf, file, line := l.header(s, 0)
} else {
    file, line := l.location(s)
    l.putBuffer(buf)
    buf  = l.getBuffer()
}
fmt.Fprintln(buf, args...)

??

// if logr is set, we clear the generated header as we rely on the backing
// logr implementation to print headers
if logr != nil {
l.putBuffer(buf)
buf = l.getBuffer()
}
fmt.Fprintln(buf, args...)
l.output(s, buf, file, line, false)
l.output(s, logr, buf, file, line, false)
}

func (l *loggingT) print(s severity, args ...interface{}) {
l.printDepth(s, 1, args...)
func (l *loggingT) print(s severity, logr logr.InfoLogger, args ...interface{}) {
l.printDepth(s, logr, 1, args...)
}

func (l *loggingT) printDepth(s severity, depth int, args ...interface{}) {
func (l *loggingT) printDepth(s severity, logr logr.InfoLogger, 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 logr != nil {
Copy link
Copy Markdown
Member

@thockin thockin Aug 8, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

same as above

l.putBuffer(buf)
buf = l.getBuffer()
}
fmt.Fprint(buf, args...)
if buf.Bytes()[buf.Len()-1] != '\n' {
buf.WriteByte('\n')
}
l.output(s, buf, file, line, false)
l.output(s, logr, buf, file, line, false)
}

func (l *loggingT) printf(s severity, format string, args ...interface{}) {
func (l *loggingT) printf(s severity, logr logr.InfoLogger, 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
if logr != nil {
Copy link
Copy Markdown
Member

@thockin thockin Aug 8, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

same

l.putBuffer(buf)
buf = l.getBuffer()
}
fmt.Fprintf(buf, format, args...)
if buf.Bytes()[buf.Len()-1] != '\n' {
buf.WriteByte('\n')
}
l.output(s, buf, file, line, false)
l.output(s, logr, buf, file, line, false)
}

// 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, file string, line int, alsoToStderr bool, args ...interface{}) {
func (l *loggingT) printWithFileLine(s severity, logr logr.InfoLogger, 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 logr != nil {
Copy link
Copy Markdown
Member

@thockin thockin Aug 8, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

same

l.putBuffer(buf)
buf = l.getBuffer()
}
fmt.Fprint(buf, args...)
if buf.Bytes()[buf.Len()-1] != '\n' {
buf.WriteByte('\n')
}
l.output(s, buf, file, line, alsoToStderr)
l.output(s, logr, buf, file, line, alsoToStderr)
}

// redirectBuffer is used to set an alternate destination for the logs
Expand All @@ -744,6 +773,18 @@ func (rb *redirectBuffer) Write(bytes []byte) (n int, err error) {
return rb.w.Write(bytes)
}

// SetLogger will set the backing logr implementation for klog.
// If set, all log lines will be supressed from the regular Output, and
// redirected to the logr implementation.
// All log lines include the 'severity', 'file' and 'line' values attached as
// structured logging values.
// Use as:
// ...
// klog.SetLogger(zapr.NewLogger(zapLog))
func SetLogger(logr logr.Logger) {
logging.logr = logr
}

// SetOutput sets the output destination for all severities
func SetOutput(w io.Writer) {
for s := fatalLog; s >= infoLog; s-- {
Expand All @@ -767,15 +808,23 @@ func SetOutputBySeverity(name string, w io.Writer) {
}

// output writes the data to the log files and releases the buffer.
func (l *loggingT) output(s severity, buf *buffer, file string, line int, alsoToStderr bool) {
func (l *loggingT) output(s severity, log logr.InfoLogger, buf *buffer, file string, line int, alsoToStderr bool) {
l.mu.Lock()
if l.traceLocation.isSet() {
if l.traceLocation.match(file, line) {
buf.Write(stacks(false))
}
}
data := buf.Bytes()
if l.toStderr {
if log != nil {
// TODO: set 'severity' and caller information as structured log info
// keysAndValues := []interface{}{"severity", severityName[s], "file", file, "line", line}
if s == errorLog {
l.logr.Error(nil, string(data))
} else {
log.Info(string(data))
}
} else if l.toStderr {
os.Stderr.Write(data)
} else {
if alsoToStderr || l.alsoToStderr || s >= l.stderrThreshold.get() {
Expand Down Expand Up @@ -1066,7 +1115,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), file, line, true, text)
logging.printWithFileLine(severity(lb), logging.logr, file, line, true, text)
return len(b), nil
}

Expand Down Expand Up @@ -1098,13 +1147,23 @@ func (l *loggingT) setV(pc uintptr) Level {

// Verbose is a boolean type that implements Infof (like Printf) etc.
// See the documentation of V for more information.
Copy link
Copy Markdown

@detiber detiber Jul 19, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't this comment be updated for the type change?

type Verbose bool
type Verbose struct {
Copy link
Copy Markdown
Member

@liggitt liggitt Aug 15, 2019 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

note that this broke consumers of client-go. xref https://github.com/kubernetes/client-go/issues/654 https://github.com/kubernetes/client-go/issues/656 https://github.com/kubernetes/client-go/issues/652

Copy link
Copy Markdown

@lavalamp lavalamp Nov 7, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

IMO klog needs to follow real semver rules. It's not in our staging/ directory, there is no reason not to.

enabled bool
logr logr.InfoLogger
}

func newVerbose(level Level, b bool) Verbose {
if logging.logr == nil {
return Verbose{b, nil}
}
return Verbose{b, logging.logr.V(int(level))}
}

// V reports whether verbosity at the call site is at least the requested level.
// The returned value is a boolean of type Verbose, which implements Info, Infoln
// The returned value is a struct of type Verbose, which implements Info, Infoln
// and Infof. These methods will write to the Info log if called.
// Thus, one may write either
// if klog.V(2) { klog.Info("log this") }
// if glog.V(2).Enabled() { klog.Info("log this") }
Copy link
Copy Markdown

@detiber detiber Jul 19, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is the use of glog here intentional?

// or
// klog.V(2).Info("log this")
// The second form is shorter but the first is cheaper if logging is off because it does
Expand All @@ -1120,7 +1179,7 @@ func V(level Level) Verbose {

// Here is a cheap but safe test to see if V logging is enabled globally.
if logging.verbosity.get() >= level {
return Verbose(true)
return newVerbose(level, true)
}

// It's off globally but it vmodule may still be set.
Expand All @@ -1132,138 +1191,145 @@ func V(level Level) Verbose {
logging.mu.Lock()
defer logging.mu.Unlock()
if runtime.Callers(2, logging.pcs[:]) == 0 {
return Verbose(false)
return newVerbose(level, false)
}
v, ok := logging.vmap[logging.pcs[0]]
if !ok {
v = logging.setV(logging.pcs[0])
}
return Verbose(v >= level)
return newVerbose(level, v >= level)
}
return Verbose(false)
return newVerbose(level, false)
}

// Enabled will return true if this log level is enabled, guarded by the value
// of v.
// See the documentation of V for usage.
func (v Verbose) Enabled() bool {
return v.enabled
}

// Info is equivalent to the global Info function, guarded by the value of v.
// See the documentation of V for usage.
func (v Verbose) Info(args ...interface{}) {
if v {
logging.print(infoLog, args...)
if v.enabled {
logging.print(infoLog, v.logr, 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 {
logging.println(infoLog, args...)
if v.enabled {
logging.println(infoLog, v.logr, 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 {
logging.printf(infoLog, format, args...)
if v.enabled {
logging.printf(infoLog, v.logr, format, args...)
}
}

// 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, args...)
logging.print(infoLog, logging.logr, 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, depth, args...)
logging.printDepth(infoLog, logging.logr, 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, args...)
logging.println(infoLog, logging.logr, 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, format, args...)
logging.printf(infoLog, logging.logr, format, args...)
}

// 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, args...)
logging.print(warningLog, logging.logr, 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, depth, args...)
logging.printDepth(warningLog, logging.logr, 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, args...)
logging.println(warningLog, logging.logr, 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, format, args...)
logging.printf(warningLog, logging.logr, 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, args...)
logging.print(errorLog, logging.logr, 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, depth, args...)
logging.printDepth(errorLog, logging.logr, 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, args...)
logging.println(errorLog, logging.logr, 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, format, args...)
logging.printf(errorLog, logging.logr, format, args...)
}

// 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, args...)
logging.print(fatalLog, logging.logr, 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, depth, args...)
logging.printDepth(fatalLog, logging.logr, 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, args...)
logging.println(fatalLog, logging.logr, 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, format, args...)
logging.printf(fatalLog, logging.logr, format, args...)
}

// fatalNoStacks is non-zero if we are to exit without dumping goroutine stacks.
Expand All @@ -1274,25 +1340,25 @@ 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, args...)
logging.print(fatalLog, logging.logr, 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, depth, args...)
logging.printDepth(fatalLog, logging.logr, 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, args...)
logging.println(fatalLog, logging.logr, 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, format, args...)
logging.printf(fatalLog, logging.logr, format, args...)
}
Loading