add InfoSDepth and ErrorSDepth

This is needed for wrappers like klogr which need to skip additional
levels in the call stack.

klog.go

@@ -772,32 +772,32 @@ func (l *loggingT) printWithFileLine(s severity, logr logr.Logger, filter LogFil
 }
 
 // if loggr is specified, will call loggr.Error, otherwise output with logging module.
-func (l *loggingT) errorS(err error, loggr logr.Logger, filter LogFilter, msg string, keysAndValues ...interface{}) {
+func (l *loggingT) errorS(err error, loggr logr.Logger, filter LogFilter, depth int, msg string, keysAndValues ...interface{}) {
 	if filter != nil {
 		msg, keysAndValues = filter.FilterS(msg, keysAndValues)
 	}
 	if loggr != nil {
 		loggr.Error(err, msg, keysAndValues...)
 		return
 	}
-	l.printS(err, msg, keysAndValues...)
+	l.printS(err, depth+1, msg, keysAndValues...)
 }
 
 // if loggr is specified, will call loggr.Info, otherwise output with logging module.
-func (l *loggingT) infoS(loggr logr.Logger, filter LogFilter, msg string, keysAndValues ...interface{}) {
+func (l *loggingT) infoS(loggr logr.Logger, filter LogFilter, depth int, msg string, keysAndValues ...interface{}) {
 	if filter != nil {
 		msg, keysAndValues = filter.FilterS(msg, keysAndValues)
 	}
 	if loggr != nil {
 		loggr.Info(msg, keysAndValues...)
 		return
 	}
-	l.printS(nil, msg, keysAndValues...)
+	l.printS(nil, depth+1, msg, keysAndValues...)
 }
 
 // printS is called from infoS and errorS if loggr is not specified.
 // if err arguments is specified, will output to errorLog severity
-func (l *loggingT) printS(err error, msg string, keysAndValues ...interface{}) {
+func (l *loggingT) printS(err error, depth int, msg string, keysAndValues ...interface{}) {
 	b := &bytes.Buffer{}
 	b.WriteString(fmt.Sprintf("%q", msg))
 	if err != nil {
@@ -811,7 +811,7 @@ func (l *loggingT) printS(err error, msg string, keysAndValues ...interface{}) {
 	} else {
 		s = errorLog
 	}
-	l.printDepth(s, logging.logr, nil, 2, b)
+	l.printDepth(s, logging.logr, nil, depth+1, b)
 }
 
 const missingValue = "(MISSING)"
@@ -1359,22 +1359,28 @@ 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, v.filter, msg, keysAndValues...)
+		logging.infoS(v.logr, v.filter, 0, msg, keysAndValues...)
 	}
 }
 
+// InfoSDepth acts as InfoS but uses depth to determine which call frame to log.
+// InfoSDepth(0, "msg") is the same as InfoS("msg").
+func InfoSDepth(depth int, msg string, keysAndValues ...interface{}) {
+	logging.infoS(logging.logr, 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, v.filter, msg, args...)
+		logging.errorS(err, v.logr, v.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, v.filter, msg, keysAndValues...)
+		logging.errorS(err, v.logr, v.filter, 0, msg, keysAndValues...)
 	}
 }
 
@@ -1411,7 +1417,7 @@ 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, logging.filter, msg, keysAndValues...)
+	logging.infoS(logging.logr, logging.filter, 0, msg, keysAndValues...)
 }
 
 // Warning logs to the WARNING and INFO logs.
@@ -1472,7 +1478,13 @@ 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, logging.filter, msg, keysAndValues...)
+	logging.errorS(err, logging.logr, logging.filter, 0, msg, keysAndValues...)
+}
+
+// ErrorSDepth acts as ErrorS but uses depth to determine which call frame to log.
+// ErrorSDepth(0, "msg") is the same as ErrorS("msg").
+func ErrorSDepth(depth int, err error, msg string, keysAndValues ...interface{}) {
+	logging.errorS(err, logging.logr, logging.filter, depth, msg, keysAndValues...)
 }
 
 // Fatal logs to the FATAL, ERROR, WARNING, and INFO logs,

klog_test.go

@@ -822,7 +822,7 @@ func TestKRef(t *testing.T) {
 	}
 }
 
-// Test that InfoS works as advertised.
+// Test that InfoS and InfoSDepth work as advertised.
 func TestInfoS(t *testing.T) {
 	setFlags()
 	defer logging.swap(logging.newBuffers())
@@ -857,17 +857,23 @@ func TestInfoS(t *testing.T) {
 		},
 	}
 
-	for _, data := range testDataInfo {
-		logging.file[infoLog] = &flushBuffer{}
-		InfoS(data.msg, data.keysValues...)
-		var line int
-		n, err := fmt.Sscanf(contents(infoLog), data.format, &line)
-		if n != 1 || err != nil {
-			t.Errorf("log format error: %d elements, error %s:\n%s", n, err, contents(infoLog))
-		}
-		want := fmt.Sprintf(data.format, line)
-		if contents(infoLog) != want {
-			t.Errorf("InfoS has wrong format: \n got:\t%s\nwant:\t%s", contents(infoLog), want)
+	functions := []func(msg string, keyAndValues ...interface{}){
+		InfoS,
+		myInfoS,
+	}
+	for _, f := range functions {
+		for _, data := range testDataInfo {
+			logging.file[infoLog] = &flushBuffer{}
+			f(data.msg, data.keysValues...)
+			var line int
+			n, err := fmt.Sscanf(contents(infoLog), data.format, &line)
+			if n != 1 || err != nil {
+				t.Errorf("log format error: %d elements, error %s:\n%s", n, err, contents(infoLog))
+			}
+			want := fmt.Sprintf(data.format, line)
+			if contents(infoLog) != want {
+				t.Errorf("InfoS has wrong format: \n got:\t%s\nwant:\t%s", contents(infoLog), want)
+			}
 		}
 	}
 }
@@ -930,7 +936,7 @@ func TestVInfoS(t *testing.T) {
 	}
 }
 
-// Test that ErrorS works as advertised.
+// Test that ErrorS and ErrorSDepth work as advertised.
 func TestErrorS(t *testing.T) {
 	setFlags()
 	defer logging.swap(logging.newBuffers())
@@ -939,16 +945,24 @@ func TestErrorS(t *testing.T) {
 	}
 	logging.logFile = ""
 	pid = 1234
-	ErrorS(fmt.Errorf("update status failed"), "Failed to update pod status", "pod", "kubedns")
-	var line int
-	format := "E0102 15:04:05.067890    1234 klog_test.go:%d] \"Failed to update pod status\" err=\"update status failed\" pod=\"kubedns\"\n"
-	n, err := fmt.Sscanf(contents(errorLog), format, &line)
-	if n != 1 || err != nil {
-		t.Errorf("log format error: %d elements, error %s:\n%s", n, err, contents(errorLog))
+
+	functions := []func(err error, msg string, keyAndValues ...interface{}){
+		ErrorS,
+		myErrorS,
 	}
-	want := fmt.Sprintf(format, line)
-	if contents(errorLog) != want {
-		t.Errorf("ErrorS has wrong format: \n got:\t%s\nwant:\t%s", contents(errorLog), want)
+	for _, f := range functions {
+		logging.file[errorLog] = &flushBuffer{}
+		f(fmt.Errorf("update status failed"), "Failed to update pod status", "pod", "kubedns")
+		var line int
+		format := "E0102 15:04:05.067890    1234 klog_test.go:%d] \"Failed to update pod status\" err=\"update status failed\" pod=\"kubedns\"\n"
+		n, err := fmt.Sscanf(contents(errorLog), format, &line)
+		if n != 1 || err != nil {
+			t.Errorf("log format error: %d elements, error %s:\n%s", n, err, contents(errorLog))
+		}
+		want := fmt.Sprintf(format, line)
+		if contents(errorLog) != want {
+			t.Errorf("ErrorS has wrong format: \n got:\t%s\nwant:\t%s", contents(errorLog), want)
+		}
 	}
 }
 

klog_wrappers_test.go

@@ -0,0 +1,27 @@
+// Copyright 2020 The Kubernetes Authors.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package klog
+
+// These helper functions must be in a separate source file because the
+// tests in klog_test.go compare the logged source code file name against
+// "klog_test.go". "klog_wrappers_test.go" must *not* be logged.
+
+func myInfoS(msg string, keyAndValues ...interface{}) {
+	InfoSDepth(1, msg, keyAndValues...)
+}
+
+func myErrorS(err error, msg string, keyAndValues ...interface{}) {
+	ErrorSDepth(1, err, msg, keyAndValues...)
+}