Rearch for performance: BREAKING CHANGES

README.md

@@ -35,11 +35,11 @@ This is a BETA grade API.
 
 There are implementations for the following logging libraries:
 
+- **a function**: [funcr](https://github.com/go-logr/logr/funcr)
 - **github.com/google/glog**: [glogr](https://github.com/go-logr/glogr)
 - **k8s.io/klog**: [klogr](https://git.k8s.io/klog/klogr)
 - **go.uber.org/zap**: [zapr](https://github.com/go-logr/zapr)
-- **log** (the Go standard library logger):
-  [stdr](https://github.com/go-logr/stdr)
+- **log** (the Go standard library logger): [stdr](https://github.com/go-logr/stdr)
 - **github.com/sirupsen/logrus**: [logrusr](https://github.com/bombsimon/logrusr)
 - **github.com/wojas/genericr**: [genericr](https://github.com/wojas/genericr) (makes it easy to implement your own backend)
 - **logfmt** (Heroku style [logging](https://www.brandur.org/logfmt)): [logfmtr](https://github.com/iand/logfmtr)
@@ -60,7 +60,7 @@ There are implementations for the following logging libraries:
   Similarly to searchability, if you maintain conventions around your
   keys, it becomes easy to gather all log lines related to a particular
   concept.
- 
+
 - **Structured logs allow better dimensions of filtering**: if you have
   structure to your logs, you've got more precise control over how much
   information is logged -- you might choose in a particular configuration
@@ -169,7 +169,7 @@ Then gradually choose levels in between as you need them, working your way
 down from 10 (for debug and trace style logs) and up from 1 (for chattier
 info-type logs).
 
-## How do I choose my keys
+## How do I choose my keys?
 
 - make your keys human-readable
 - constant keys are generally a good idea
@@ -180,4 +180,19 @@ While key names are mostly unrestricted (and spaces are acceptable),
 it's generally a good idea to stick to printable ascii characters, or at
 least match the general character set of your log lines.
 
+## Why should keys be constant values?
+
+The point of structured logging is to make later log processing easier.  Your
+keys are, effectively, the schema of each log message.  If you use different
+keys across instances of the same log-line, you will make your structured logs
+much harder to use.  `Sprintf()` is for values, not for keys!
+
+## Why is this not a pure interface?
+
+The Logger type is implemented as a struct in order to allow the Go compiler to
+optimize things like high-V Info logs that are not triggered.  Not all of these
+implementations are implemented yet, but this structure was suggested as a way to
+ensure they *can* be implemented.  All of the real work is behind the LogSink
+interface.
+
 [warning-makes-no-sense]: http://dave.cheney.net/2015/11/05/lets-talk-about-logging

benchmark/benchmark_test.go

@@ -27,47 +27,42 @@ import (
 func noop(prefix, args string) {
 }
 
-func BenchmarkInfoOneArg(b *testing.B) {
-	var log logr.Logger = funcr.New(noop, funcr.Options{})
-
+//go:noinline
+func doInfoOneArg(b *testing.B, log logr.Logger) {
 	for i := 0; i < b.N; i++ {
 		log.Info("this is", "a", "string")
 	}
 }
 
-func BenchmarkInfoSeveralArgs(b *testing.B) {
-	var log logr.Logger = funcr.New(noop, funcr.Options{})
-
+//go:noinline
+func doInfoSeveralArgs(b *testing.B, log logr.Logger) {
 	for i := 0; i < b.N; i++ {
 		log.Info("multi",
 			"bool", true, "string", "str", "int", 42,
 			"float", 3.14, "struct", struct{ X, Y int }{93, 76})
 	}
 }
 
-func BenchmarkV0Info(b *testing.B) {
-	var log logr.Logger = funcr.New(noop, funcr.Options{})
-
+//go:noinline
+func doV0Info(b *testing.B, log logr.Logger) {
 	for i := 0; i < b.N; i++ {
 		log.V(0).Info("multi",
 			"bool", true, "string", "str", "int", 42,
 			"float", 3.14, "struct", struct{ X, Y int }{93, 76})
 	}
 }
 
-func BenchmarkV9Info(b *testing.B) {
-	var log logr.Logger = funcr.New(noop, funcr.Options{})
-
+//go:noinline
+func doV9Info(b *testing.B, log logr.Logger) {
 	for i := 0; i < b.N; i++ {
 		log.V(9).Info("multi",
 			"bool", true, "string", "str", "int", 42,
 			"float", 3.14, "struct", struct{ X, Y int }{93, 76})
 	}
 }
 
-func BenchmarkError(b *testing.B) {
-	var log logr.Logger = funcr.New(noop, funcr.Options{})
-
+//go:noinline
+func doError(b *testing.B, log logr.Logger) {
 	err := fmt.Errorf("error message")
 	for i := 0; i < b.N; i++ {
 		log.Error(err, "multi",
@@ -76,20 +71,88 @@ func BenchmarkError(b *testing.B) {
 	}
 }
 
-func BenchmarkWithValues(b *testing.B) {
-	var log logr.Logger = funcr.New(noop, funcr.Options{})
-
+//go:noinline
+func doWithValues(b *testing.B, log logr.Logger) {
 	for i := 0; i < b.N; i++ {
 		l := log.WithValues("k1", "v1", "k2", "v2")
 		_ = l
 	}
 }
 
-func BenchmarkWithName(b *testing.B) {
-	var log logr.Logger = funcr.New(noop, funcr.Options{})
-
+//go:noinline
+func doWithName(b *testing.B, log logr.Logger) {
 	for i := 0; i < b.N; i++ {
 		l := log.WithName("name")
 		_ = l
 	}
 }
+
+func BenchmarkDiscardInfoOneArg(b *testing.B) {
+	var log logr.Logger = logr.Discard()
+	doInfoOneArg(b, log)
+}
+
+func BenchmarkDiscardInfoSeveralArgs(b *testing.B) {
+	var log logr.Logger = logr.Discard()
+	doInfoSeveralArgs(b, log)
+}
+
+func BenchmarkDiscardV0Info(b *testing.B) {
+	var log logr.Logger = logr.Discard()
+	doV0Info(b, log)
+}
+
+func BenchmarkDiscardV9Info(b *testing.B) {
+	var log logr.Logger = logr.Discard()
+	doV9Info(b, log)
+}
+
+func BenchmarkDiscardError(b *testing.B) {
+	var log logr.Logger = logr.Discard()
+	doError(b, log)
+}
+
+func BenchmarkDiscardWithValues(b *testing.B) {
+	var log logr.Logger = logr.Discard()
+	doWithValues(b, log)
+}
+
+func BenchmarkDiscardWithName(b *testing.B) {
+	var log logr.Logger = logr.Discard()
+	doWithName(b, log)
+}
+
+func BenchmarkFuncrInfoOneArg(b *testing.B) {
+	var log logr.Logger = funcr.New(noop, funcr.Options{})
+	doInfoOneArg(b, log)
+}
+
+func BenchmarkFuncrInfoSeveralArgs(b *testing.B) {
+	var log logr.Logger = funcr.New(noop, funcr.Options{})
+	doInfoSeveralArgs(b, log)
+}
+
+func BenchmarkFuncrV0Info(b *testing.B) {
+	var log logr.Logger = funcr.New(noop, funcr.Options{})
+	doV0Info(b, log)
+}
+
+func BenchmarkFuncrV9Info(b *testing.B) {
+	var log logr.Logger = funcr.New(noop, funcr.Options{})
+	doV9Info(b, log)
+}
+
+func BenchmarkFuncrError(b *testing.B) {
+	var log logr.Logger = funcr.New(noop, funcr.Options{})
+	doError(b, log)
+}
+
+func BenchmarkFuncrWithValues(b *testing.B) {
+	var log logr.Logger = funcr.New(noop, funcr.Options{})
+	doWithValues(b, log)
+}
+
+func BenchmarkFuncrWithName(b *testing.B) {
+	var log logr.Logger = funcr.New(noop, funcr.Options{})
+	doWithName(b, log)
+}

discard.go

@@ -16,36 +16,38 @@ limitations under the License.
 
 package logr
 
-// Discard returns a valid Logger that discards all messages logged to it.
-// It can be used whenever the caller is not interested in the logs.
+// Discard returns a Logger that discards all messages logged to it.  It can be
+// used whenever the caller is not interested in the logs.
 func Discard() Logger {
-	return DiscardLogger{}
+	return Logger{
+		level: 0,
+		sink:  discardLogger{},
+	}
 }
 
-// DiscardLogger is a Logger that discards all messages.
-type DiscardLogger struct{}
+// discardLogger is a LogSink that discards all messages.
+type discardLogger struct{}
 
-func (l DiscardLogger) Enabled() bool {
-	return false
+// Verify that it actually implements the interface
+var _ LogSink = discardLogger{}
+
+func (l discardLogger) Init(RuntimeInfo) {
 }
 
-func (l DiscardLogger) Info(msg string, keysAndValues ...interface{}) {
+func (l discardLogger) Enabled(int) bool {
+	return false
 }
 
-func (l DiscardLogger) Error(err error, msg string, keysAndValues ...interface{}) {
+func (l discardLogger) Info(int, string, ...interface{}) {
 }
 
-func (l DiscardLogger) V(level int) Logger {
-	return l
+func (l discardLogger) Error(error, string, ...interface{}) {
 }
 
-func (l DiscardLogger) WithValues(keysAndValues ...interface{}) Logger {
+func (l discardLogger) WithValues(...interface{}) LogSink {
 	return l
 }
 
-func (l DiscardLogger) WithName(name string) Logger {
+func (l discardLogger) WithName(string) LogSink {
 	return l
 }
-
-// Verify that it actually implements the interface
-var _ Logger = DiscardLogger{}

discard_test.go

@@ -23,7 +23,7 @@ import (
 
 func TestDiscard(t *testing.T) {
 	l := Discard()
-	if _, ok := l.(DiscardLogger); !ok {
+	if _, ok := l.sink.(discardLogger); !ok {
 		t.Error("did not return the expected underlying type")
 	}
 	// Verify that none of the methods panic, there is not more we can test.

examples/tab_logger.go

@@ -24,18 +24,24 @@ import (
 	"github.com/go-logr/logr"
 )
 
-// TabLogger is a sample logr.Logger that logs to stderr.
-// It's terribly inefficient, and is *only* a basic example.
-type TabLogger struct {
+// tabLogSink is a sample logr.LogSink that logs to stderr.
+// It's terribly inefficient, and is only a basic example.
+type tabLogSink struct {
 	name      string
 	keyValues map[string]interface{}
+	writer    *tabwriter.Writer
+}
+
+var _ logr.LogSink = tabLogSink{}
 
-	writer *tabwriter.Writer
+func (_ tabLogSink) Init(info logr.RuntimeInfo) {
 }
 
-var _ logr.Logger = &TabLogger{}
+func (_ tabLogSink) Enabled(level int) bool {
+	return true
+}
 
-func (l *TabLogger) Info(msg string, kvs ...interface{}) {
+func (l tabLogSink) Info(level int, msg string, kvs ...interface{}) {
 	fmt.Fprintf(l.writer, "%s\t%s\t", l.name, msg)
 	for k, v := range l.keyValues {
 		fmt.Fprintf(l.writer, "%s: %+v  ", k, v)
@@ -47,44 +53,37 @@ func (l *TabLogger) Info(msg string, kvs ...interface{}) {
 	l.writer.Flush()
 }
 
-func (_ *TabLogger) Enabled() bool {
-	return true
-}
-
-func (l *TabLogger) Error(err error, msg string, kvs ...interface{}) {
+func (l tabLogSink) Error(err error, msg string, kvs ...interface{}) {
 	kvs = append(kvs, "error", err)
-	l.Info(msg, kvs...)
-}
-
-func (l *TabLogger) V(_ int) logr.Logger {
-	return l
+	l.Info(0, msg, kvs...)
 }
 
-func (l *TabLogger) WithName(name string) logr.Logger {
-	return &TabLogger{
+func (l tabLogSink) WithName(name string) logr.LogSink {
+	return tabLogSink{
 		name:      l.name + "." + name,
 		keyValues: l.keyValues,
 		writer:    l.writer,
 	}
 }
 
-func (l *TabLogger) WithValues(kvs ...interface{}) logr.Logger {
+func (l tabLogSink) WithValues(kvs ...interface{}) logr.LogSink {
 	newMap := make(map[string]interface{}, len(l.keyValues)+len(kvs)/2)
 	for k, v := range l.keyValues {
 		newMap[k] = v
 	}
 	for i := 0; i < len(kvs); i += 2 {
 		newMap[kvs[i].(string)] = kvs[i+1]
 	}
-	return &TabLogger{
+	return tabLogSink{
 		name:      l.name,
 		keyValues: newMap,
 		writer:    l.writer,
 	}
 }
 
 func NewTabLogger() logr.Logger {
-	return &TabLogger{
+	sink := tabLogSink{
 		writer: tabwriter.NewWriter(os.Stderr, 40, 8, 2, '\t', 0),
 	}
+	return logr.New(sink)
 }