-
Notifications
You must be signed in to change notification settings - Fork 218
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.
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
Add missing Depth logging functions. #280
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -699,7 +699,11 @@ func (buf *buffer) someDigits(i, d int) int { | |
} | ||
|
||
func (l *loggingT) println(s severity, logger *logr.Logger, filter LogFilter, args ...interface{}) { | ||
buf, file, line := l.header(s, 0) | ||
l.printlnDepth(s, logger, filter, 1, args...) | ||
} | ||
|
||
func (l *loggingT) printlnDepth(s severity, logger *logr.Logger, filter LogFilter, depth int, args ...interface{}) { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. What is suspicious here is that depth is not passed through to There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I assume it should be something like depth+1 There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Pasing depth through fixed it for me -> #287 There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Whether it is "1" or "depth + 1" depends a lot on the actual semantic, which isn't well defined. This is almost impossible to get right without tests 😢 In this case one can reason like this: 0 was correct before, now we add one layer and pass depth=1 -> passing depth is right, depth+1 would be one level too many. Testing with the JSON tests in Kubernetes confirms that. |
||
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 { | ||
|
@@ -736,7 +740,11 @@ func (l *loggingT) printDepth(s severity, logger *logr.Logger, filter LogFilter, | |
} | ||
|
||
func (l *loggingT) printf(s severity, logger *logr.Logger, filter LogFilter, format string, args ...interface{}) { | ||
buf, file, line := l.header(s, 0) | ||
l.printfDepth(s, logger, filter, 1, format, args...) | ||
} | ||
|
||
func (l *loggingT) printfDepth(s severity, logger *logr.Logger, 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 { | ||
|
@@ -1459,6 +1467,14 @@ func (v Verbose) Info(args ...interface{}) { | |
} | ||
} | ||
|
||
// 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(infoLog, v.logr, v.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{}) { | ||
|
@@ -1467,6 +1483,14 @@ func (v Verbose) Infoln(args ...interface{}) { | |
} | ||
} | ||
|
||
// 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(infoLog, v.logr, v.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{}) { | ||
|
@@ -1475,6 +1499,14 @@ func (v Verbose) Infof(format string, args ...interface{}) { | |
} | ||
} | ||
|
||
// 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(infoLog, v.logr, v.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{}) { | ||
|
@@ -1530,12 +1562,24 @@ func Infoln(args ...interface{}) { | |
logging.println(infoLog, logging.logr, logging.filter, args...) | ||
} | ||
|
||
// InfolnDepth acts as Infoln but uses depth to determine which call frame to log. | ||
// InfolnDepth(0, "msg") is the same as Infoln("msg"). | ||
func InfolnDepth(depth int, args ...interface{}) { | ||
logging.printlnDepth(infoLog, logging.logr, logging.filter, depth, 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, logging.filter, format, args...) | ||
} | ||
|
||
// InfofDepth acts as Infof but uses depth to determine which call frame to log. | ||
// InfofDepth(0, "msg", args...) is the same as Infof("msg", args...). | ||
func InfofDepth(depth int, format string, args ...interface{}) { | ||
logging.printfDepth(infoLog, logging.logr, logging.filter, depth, format, args...) | ||
} | ||
|
||
// InfoS structured logs to the INFO log. | ||
// The msg argument used to add constant description to the log line. | ||
// The key/value pairs would be join by "=" ; a newline is always appended. | ||
|
@@ -1566,12 +1610,24 @@ func Warningln(args ...interface{}) { | |
logging.println(warningLog, logging.logr, logging.filter, args...) | ||
} | ||
|
||
// WarninglnDepth acts as Warningln but uses depth to determine which call frame to log. | ||
// WarninglnDepth(0, "msg") is the same as Warningln("msg"). | ||
func WarninglnDepth(depth int, args ...interface{}) { | ||
logging.printDepth(warningLog, logging.logr, logging.filter, depth, args...) | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Also should be There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Should I do a PR fix for that? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. There is also FatallnDepth( with similar issue |
||
} | ||
|
||
// 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, logging.filter, format, args...) | ||
} | ||
|
||
// WarningfDepth acts as Warningf but uses depth to determine which call frame to log. | ||
// WarningfDepth(0, "msg", args...) is the same as Warningf("msg", args...). | ||
func WarningfDepth(depth int, format string, args ...interface{}) { | ||
logging.printfDepth(warningLog, logging.logr, logging.filter, depth, 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{}) { | ||
|
@@ -1590,12 +1646,24 @@ func Errorln(args ...interface{}) { | |
logging.println(errorLog, logging.logr, logging.filter, args...) | ||
} | ||
|
||
// ErrorlnDepth acts as Errorln but uses depth to determine which call frame to log. | ||
// ErrorlnDepth(0, "msg") is the same as Errorln("msg"). | ||
func ErrorlnDepth(depth int, args ...interface{}) { | ||
logging.printDepth(errorLog, logging.logr, logging.filter, depth, args...) | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Shouldn't this be There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. hmm, yea |
||
} | ||
|
||
// 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, logging.filter, format, args...) | ||
} | ||
|
||
// ErrorfDepth acts as Errorf but uses depth to determine which call frame to log. | ||
// ErrorfDepth(0, "msg", args...) is the same as Errorf("msg", args...). | ||
func ErrorfDepth(depth int, format string, args ...interface{}) { | ||
logging.printfDepth(errorLog, logging.logr, logging.filter, depth, format, args...) | ||
} | ||
|
||
// ErrorS structured logs to the ERROR, WARNING, and INFO logs. | ||
// the err argument used as "err" field of log line. | ||
// The msg argument used to add constant description to the log line. | ||
|
@@ -1635,13 +1703,25 @@ func Fatalln(args ...interface{}) { | |
logging.println(fatalLog, logging.logr, logging.filter, args...) | ||
} | ||
|
||
// FatallnDepth acts as Fatalln but uses depth to determine which call frame to log. | ||
// FatallnDepth(0, "msg") is the same as Fatalln("msg"). | ||
func FatallnDepth(depth int, args ...interface{}) { | ||
logging.printDepth(fatalLog, logging.logr, logging.filter, depth, 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, logging.filter, format, args...) | ||
} | ||
|
||
// FatalfDepth acts as Fatalf but uses depth to determine which call frame to log. | ||
// FatalfDepth(0, "msg", args...) is the same as Fatalf("msg", args...). | ||
func FatalfDepth(depth int, format string, args ...interface{}) { | ||
logging.printfDepth(fatalLog, logging.logr, logging.filter, depth, format, args...) | ||
} | ||
|
||
// fatalNoStacks is non-zero if we are to exit without dumping goroutine stacks. | ||
// It allows Exit and relatives to use the Fatal logs. | ||
var fatalNoStacks uint32 | ||
|
@@ -1666,13 +1746,27 @@ func Exitln(args ...interface{}) { | |
logging.println(fatalLog, logging.logr, logging.filter, args...) | ||
} | ||
|
||
// ExitlnDepth acts as Exitln but uses depth to determine which call frame to log. | ||
// ExitlnDepth(0, "msg") is the same as Exitln("msg"). | ||
func ExitlnDepth(depth int, args ...interface{}) { | ||
atomic.StoreUint32(&fatalNoStacks, 1) | ||
logging.printDepth(fatalLog, logging.logr, logging.filter, depth, 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, logging.filter, format, args...) | ||
} | ||
|
||
// ExitfDepth acts as Exitf but uses depth to determine which call frame to log. | ||
// ExitfDepth(0, "msg", args...) is the same as Exitf("msg", args...). | ||
func ExitfDepth(depth int, format string, args ...interface{}) { | ||
atomic.StoreUint32(&fatalNoStacks, 1) | ||
logging.printfDepth(fatalLog, logging.logr, logging.filter, depth, 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 { | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm seeing off-by-one errors during stack unwinding after updating to a klog with this change.
Why is this 1 and not something else? Was that tested?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I can change that to 2 without any test failing. Looks like we don't have any test for this in klog itself.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
sorry, I assumed that 1 for stack unwinding is correct value due to
func Exitf(format string, args ...interface{}) { atomic.StoreUint32(&fatalNoStacks, 1) logging.printf(fatalLog, logging.logr, logging.filter, format, args...) }
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
and also by this: https://github.com/s3rj1k/klog/blame/868bc68c8b1236129dd305d801e01e076a033e39/klog.go#L721
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
It breaks in Kubernetes when testing the JSON logger, i.e. when SetLogger is used with a Logger implementation that itself does stack unwinding. We can't test that in klog with just a unit test because we must not depend on such a logger.