diff --git a/README.md b/README.md index e9b5520..304163d 100644 --- a/README.md +++ b/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 diff --git a/benchmark/benchmark_test.go b/benchmark/benchmark_test.go index e16bd07..0c0d0fa 100644 --- a/benchmark/benchmark_test.go +++ b/benchmark/benchmark_test.go @@ -27,17 +27,15 @@ 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, @@ -45,9 +43,8 @@ func BenchmarkInfoSeveralArgs(b *testing.B) { } } -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, @@ -55,9 +52,8 @@ func BenchmarkV0Info(b *testing.B) { } } -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, @@ -65,9 +61,8 @@ func BenchmarkV9Info(b *testing.B) { } } -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) +} diff --git a/discard.go b/discard.go index 2bafb13..ec02a78 100644 --- a/discard.go +++ b/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{} diff --git a/discard_test.go b/discard_test.go index e2a01cb..c1a6177 100644 --- a/discard_test.go +++ b/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. diff --git a/examples/tab_logger.go b/examples/tab_logger.go index 445c6d6..84892ae 100644 --- a/examples/tab_logger.go +++ b/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,28 +53,20 @@ 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 @@ -76,7 +74,7 @@ func (l *TabLogger) WithValues(kvs ...interface{}) logr.Logger { 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, @@ -84,7 +82,8 @@ func (l *TabLogger) WithValues(kvs ...interface{}) logr.Logger { } func NewTabLogger() logr.Logger { - return &TabLogger{ + sink := tabLogSink{ writer: tabwriter.NewWriter(os.Stderr, 40, 8, 2, '\t', 0), } + return logr.New(sink) } diff --git a/funcr/funcr.go b/funcr/funcr.go index 613a66d..4262969 100644 --- a/funcr/funcr.go +++ b/funcr/funcr.go @@ -33,14 +33,15 @@ import ( // New returns a logr.Logger which is implemented by a function. func New(fn func(prefix, args string), opts Options) logr.Logger { - return fnlogger{ - level: 0, + fnl := &fnlogger{ prefix: "", values: nil, + depth: 0, write: fn, logCaller: opts.LogCaller, verbosity: opts.Verbosity, } + return logr.New(fnl) } type Options struct { @@ -63,9 +64,9 @@ const ( ) type fnlogger struct { - level int prefix string values []interface{} + depth int write func(prefix, args string) logCaller MessageClass verbosity int @@ -266,32 +267,32 @@ type callerID struct { } func (l fnlogger) caller() callerID { - // +1 for this frame, +1 for logr itself. - // FIXME: Maybe logr should offer a clue as to how many frames are - // needed here? Or is it part of the contract to LogSinks? - _, file, line, ok := runtime.Caller(framesToCaller() + 2) + // +1 for this frame. + _, file, line, ok := runtime.Caller(framesToCaller() + l.depth + 1) if !ok { return callerID{"", 0} } return callerID{filepath.Base(file), line} } -func (l fnlogger) Enabled() bool { - return l.level <= l.verbosity +func (l *fnlogger) Init(info logr.RuntimeInfo) { + l.depth += info.CallDepth } -func (l fnlogger) Info(msg string, kvList ...interface{}) { - if l.Enabled() { - args := make([]interface{}, 0, 64) // using a constant here impacts perf - if l.logCaller == All || l.logCaller == Info { - args = append(args, "caller", l.caller()) - } - args = append(args, "level", l.level, "msg", msg) - args = append(args, l.values...) - args = append(args, kvList...) - argsStr := flatten(args...) - l.write(l.prefix, argsStr) +func (l fnlogger) Enabled(level int) bool { + return level <= l.verbosity +} + +func (l fnlogger) Info(level int, msg string, kvList ...interface{}) { + args := make([]interface{}, 0, 64) // using a constant here impacts perf + if l.logCaller == All || l.logCaller == Info { + args = append(args, "caller", l.caller()) } + args = append(args, "level", level, "msg", msg) + args = append(args, l.values...) + args = append(args, kvList...) + argsStr := flatten(args...) + l.write(l.prefix, argsStr) } func (l fnlogger) Error(err error, msg string, kvList ...interface{}) { @@ -311,27 +312,34 @@ func (l fnlogger) Error(err error, msg string, kvList ...interface{}) { l.write(l.prefix, argsStr) } -func (l fnlogger) V(level int) logr.Logger { - l.level += level - return l -} - // WithName returns a new Logger with the specified name appended. funcr // uses '/' characters to separate name elements. Callers should not pass '/' // in the provided name string, but this library does not actually enforce that. -func (l fnlogger) WithName(name string) logr.Logger { - if len(l.prefix) > 0 { - l.prefix = l.prefix + "/" +func (l *fnlogger) WithName(name string) logr.LogSink { + l2 := &fnlogger{} + *l2 = *l + if len(l2.prefix) > 0 { + l.prefix = l2.prefix + "/" } - l.prefix += name + l2.prefix += name return l } -func (l fnlogger) WithValues(kvList ...interface{}) logr.Logger { +func (l *fnlogger) WithValues(kvList ...interface{}) logr.LogSink { + l2 := &fnlogger{} + *l2 = *l // Three slice args forces a copy. n := len(l.values) - l.values = append(l.values[:n:n], kvList...) - return l + l2.values = append(l2.values[:n:n], kvList...) + return l2 +} + +func (l *fnlogger) WithCallDepth(depth int) logr.LogSink { + l2 := &fnlogger{} + *l2 = *l + l2.depth += depth + return l2 } -var _ logr.Logger = fnlogger{} +var _ logr.LogSink = &fnlogger{} +var _ logr.CallDepthLogSink = &fnlogger{} diff --git a/funcr/funcr_test.go b/funcr/funcr_test.go index 2971e20..c38e0fc 100644 --- a/funcr/funcr_test.go +++ b/funcr/funcr_test.go @@ -1,3 +1,19 @@ +/* +Copyright 2021 The logr 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 funcr import ( diff --git a/logr.go b/logr.go index 842428b..9ea027b 100644 --- a/logr.go +++ b/logr.go @@ -17,84 +17,110 @@ limitations under the License. // This design derives from Dave Cheney's blog: // http://dave.cheney.net/2015/11/05/lets-talk-about-logging // -// This is a BETA grade API. Until there is a significant 2nd implementation, -// I don't really know how it will change. +// This is a BETA grade API. -// Package logr defines abstract interfaces for logging. Packages can depend on -// these interfaces and callers can implement logging in whatever way is -// appropriate. +// Package logr defines a general-purpose logging API and abstract interfaces +// to back that API. Packages in the Go ecosystem can depend on this package, +// while callers can implement logging with whatever backend is appropriate. // // Usage +// ----- // -// Logging is done using a Logger. Loggers can have name prefixes and named -// values attached, so that all log messages logged with that Logger have some -// base context associated. +// Logging is done using a Logger instance. Logger is a concrete type with +// methods, which defers the actual logging to a LogSink interface. The main +// methods of Logger are Info() and Error(). Arguments to Info() and Error() +// are key/value pairs rather than printf-style formatted strings, emphasizing +// "structured logging". // -// The term "key" is used to refer to the name associated with a particular -// value, to disambiguate it from the general Logger name. +// With Go's standard log package, we might write: +// log.Printf("setting target value %s", targetValue) // -// For instance, suppose we're trying to reconcile the state of an object, and -// we want to log that we've made some decision. +// With logr's structured logging, we'd write: +// logger.Info("setting target", "value", targetValue) // -// With the traditional log package, we might write: -// log.Printf("decided to set field foo to value %q for object %s/%s", -// targetValue, object.Namespace, object.Name) +// Errors are much the same. Instead of: +// log.Printf("failed to open the pod bay door for user %s: %v", user, err) // -// With logr's structured logging, we'd write: -// // elsewhere in the file, set up the logger to log with the prefix of -// // "reconcilers", and the named value target-type=Foo, for extra context. -// log := mainLogger.WithName("reconcilers").WithValues("target-type", "Foo") +// We'd write: +// logger.Error(err, "failed to open the pod bay door", "user", user) // -// // later on... -// log.Info("setting foo on object", "value", targetValue, "object", object) +// Info() and Error() are very similar, but they are separate methods so that +// LogSink implementations can choose to do things like attach additional +// information (such as stack traces) on calls to Error(). +// +// Verbosity +// --------- +// +// Often we want to log information only when the application in "verbose +// mode". To write log-lines that are more verbose, Logger has a V() method. +// The higher the V-level of a log-line, the less critical it is considered. +// Log-lines with V-levels that are not enabled (as per the LogSink) will not +// be written. Level V(0) is the default, and logger.V(0).Info() has the same +// meaning as logger.Info(). Negative V-levels have the same meaning as V(0). +// +// Where we might have written: +// if flVerbose >= 2 { +// log.Printf("an unusual thing happened") +// } +// +// We can write: +// logger.V(2).Info("an unusual thing happened") // -// Depending on our logging implementation, we could then make logging decisions -// based on field values (like only logging such events for objects in a certain -// namespace), or copy the structured information into a structured log store. +// Logger Names +// ------------ // -// For logging errors, Logger has a method called Error. Suppose we wanted to -// log an error while reconciling. With the traditional log package, we might -// write: -// log.Errorf("unable to reconcile object %s/%s: %v", object.Namespace, object.Name, err) +// Logger instances can have name strings so that all messages logged through +// that instance have additional context. For example, you might want to add +// a subsystem name: // -// With logr, we'd instead write: -// // assuming the above setup for log -// log.Error(err, "unable to reconcile object", "object", object) +// logger.WithName("compactor").Info("started", "time", time.Now()) // -// This functions similarly to: -// log.Info("unable to reconcile object", "error", err, "object", object) +// The WithName() method returns a new Logger, which can be passed to +// constructors or other functions for further use. Repeated use of WithName() +// will accumulate name "segments". These name segments will be joined in some +// way by the LogSink implementation. It is strongly recommended that name +// segments contain simple identifiers (letters, digits, and hyphen), and do +// not contain characters that could muddle the log output or confuse the +// joining operation (e.g. whitespace, commas, periods, slashes, brackets, +// quotes, etc). // -// However, it ensures that a standard key for the error value ("error") is used -// across all error logging. Furthermore, certain implementations may choose to -// attach additional information (such as stack traces) on calls to Error, so -// it's preferred to use Error to log errors. +// Saved Values +// ------------ // -// Parts of a log line +// Logger instances can store any number of key/value pairs, which will be +// logged alongside all messages logged through that instance. For example, +// you might want to create a Logger instance per managed object: // -// Each log message from a Logger has four types of context: -// logger name, log verbosity, log message, and the named values. +// With the standard log package, we might write: +// log.Printf("decided to set field foo to value %q for object %s/%s", +// targetValue, object.Namespace, object.Name) +// +// With logr's we'd write: +// // Elsewhere: set up the logger to log the object name. +// obj.logger = mainLogger.WithValues( +// "name", obj.name, "namespace", obj.namespace) +// +// // later on... +// obj.logger.Info("setting foo", "value", targetValue) // -// The Logger name consists of a series of name "segments" added by successive -// calls to WithName. These name segments will be joined in some way by the -// underlying implementation. It is strongly recommended that name segments -// contain simple identifiers (letters, digits, and hyphen), and do not contain -// characters that could muddle the log output or confuse the joining operation -// (e.g. whitespace, commas, periods, slashes, brackets, quotes, etc). +// Best Practices +// -------------- // -// Log verbosity represents how little a log matters. Level zero, the default, -// matters most. Increasing levels matter less and less. Try to avoid lots of -// different verbosity levels, and instead provide useful keys, logger names, -// and log messages for users to filter on. It's illegal to pass a log level -// below zero. +// Logger has very few hard rules, with the goal that LogSink implementations +// might have a lot of freedom to differentiate. There are, however, some +// things to consider. // // The log message consists of a constant message attached to the log line. // This should generally be a simple description of what's occurring, and should -// never be a format string. +// never be a format string. Variable information can then be attached using +// named values. // -// Variable information can then be attached using named values (key/value -// pairs). Keys are arbitrary strings, while values may be any Go value. +// Keys are arbitrary strings, but should generally be constant values. Values +// may be any Go value, but how the value is formatted is determined by the +// LogSink implementation. // // Key Naming Conventions +// ---------------------- // // Keys are not strictly required to conform to any specification or regex, but // it is recommended that they: @@ -125,6 +151,9 @@ limitations under the License. // would be necessary to represent at least message and timestamp as ordinary // named values). // +// Break Glass +// ----------- +// // Implementations may choose to give callers access to the underlying // logging implementation. The recommended pattern for this is: // // Underlier exposes access to the underlying logging implementation. @@ -140,75 +169,135 @@ import ( "context" ) -// TODO: consider adding back in format strings if they're really needed -// TODO: consider other bits of zap/zapcore functionality like ObjectMarshaller (for arbitrary objects) -// TODO: consider other bits of glog functionality like Flush, OutputStats +// New returns a new Logger instance. This is primarily used by libraries +// implementing LogSink, rather than end users. +func New(sink LogSink) Logger { + logger := Logger{ + sink: sink, + } + if withCallDepth, ok := sink.(CallDepthLogSink); ok { + logger.withCallDepth = withCallDepth + } + sink.Init(runtimeInfo) + return logger +} -// Logger represents the ability to log messages, both errors and not. -type Logger interface { - // Enabled tests whether this Logger is enabled. For example, commandline - // flags might be used to set the logging verbosity and disable some info - // logs. - Enabled() bool +// Logger is an interface to an abstract logging implementation. This is a +// concrete type for performance reasons, but all the real work is passed on +// to a LogSink. Implementations of LogSink should provide their own +// constructors that return Logger, not LogSink. +type Logger struct { + level int + sink LogSink + withCallDepth CallDepthLogSink +} - // Info logs a non-error message with the given key/value pairs as context. - // - // The msg argument should be used to add some constant description to - // the log line. The key/value pairs can then be used to add additional - // variable information. The key/value pairs should alternate string - // keys and arbitrary values. - Info(msg string, keysAndValues ...interface{}) - - // Error logs an error, with the given message and key/value pairs as context. - // It functions similarly to calling Info with the "error" named value, but may - // have unique behavior, and should be preferred for logging errors (see the - // package documentations for more information). - // - // The msg field should be used to add context to any underlying error, - // while the err field should be used to attach the actual error that - // triggered this log line, if present. - Error(err error, msg string, keysAndValues ...interface{}) +// Enabled tests whether this Logger is enabled. For example, commandline +// flags might be used to set the logging verbosity and disable some info +// logs. +func (l Logger) Enabled() bool { + return l.sink.Enabled(l.level) +} - // V returns an Logger value for a specific verbosity level, relative to - // this Logger. In other words, V values are additive. V higher verbosity - // level means a log message is less important. It's illegal to pass a log - // level less than zero. - V(level int) Logger - - // WithValues adds some key-value pairs of context to a logger. - // See Info for documentation on how key/value pairs work. - WithValues(keysAndValues ...interface{}) Logger - - // WithName adds a new element to the logger's name. - // Successive calls with WithName continue to append - // suffixes to the logger's name. It's strongly recommended - // that name segments contain only letters, digits, and hyphens - // (see the package documentation for more information). - WithName(name string) Logger +// Info logs a non-error message with the given key/value pairs as context. +// +// The msg argument should be used to add some constant description to +// the log line. The key/value pairs can then be used to add additional +// variable information. The key/value pairs must alternate string +// keys and arbitrary values. +func (l Logger) Info(msg string, keysAndValues ...interface{}) { + if l.Enabled() { + l.sink.Info(l.level, msg, keysAndValues...) + } } -// InfoLogger provides compatibility with code that relies on the v0.1.0 -// interface. +// Error logs an error, with the given message and key/value pairs as context. +// It functions similarly to Info, but may have unique behavior, and should be +// preferred for logging errors (see the package documentations for more +// information). // -// Deprecated: InfoLogger is an artifact of early versions of this API. New -// users should never use it and existing users should use Logger instead. This -// will be removed in a future release. -type InfoLogger = Logger +// The msg argument should be used to add context to any underlying error, +// while the err argument should be used to attach the actual error that +// triggered this log line, if present. +func (l Logger) Error(err error, msg string, keysAndValues ...interface{}) { + if l.Enabled() { + l.sink.Error(err, msg, keysAndValues...) + } +} +// V returns a new Logger instance for a specific verbosity level, relative to +// this Logger. In other words, V-levels are additive. A higher verbosity +// level means a log message is less important. Negative V-levels are treated +// as 0. +func (l Logger) V(level int) Logger { + if level < 0 { + level = 0 + } + l.level += level + return l +} + +// WithValues returns a new Logger instance with additional key/value pairs. +// See Info for documentation on how key/value pairs work. +func (l Logger) WithValues(keysAndValues ...interface{}) Logger { + l.sink = l.sink.WithValues(keysAndValues...) + return l +} + +// WithName returns a new Logger instance with the specified name element added +// to the Logger's name. Successive calls with WithName append additional +// suffixes to the Logger's name. It's strongly recommended that name segments +// contain only letters, digits, and hyphens (see the package documentation for +// more information). +func (l Logger) WithName(name string) Logger { + l.sink = l.sink.WithName(name) + return l +} + +// WithCallDepth returns a Logger instance that offsets the call stack by the +// specified number of frames when logging call site information, if possible. +// This is useful for users who have helper functions between the "real" call +// site and the actual calls to Logger methods. If depth is 0 the attribution +// should be to the direct caller of this function. If depth is 1 the +// attribution should skip 1 call frame, and so on. Successive calls to this +// are additive. +// +// If the underlying log implementation supports a WithCallDepth(int) method, +// it will be called and the result returned. If the implementation does not +// support CallDepthLogSink, the original Logger will be returned. +func (l Logger) WithCallDepth(depth int) Logger { + if l.withCallDepth == nil { + return l + } + l.sink = l.withCallDepth.WithCallDepth(depth) + return l +} + +// contextKey is how we find Loggers in a context.Context. type contextKey struct{} -// FromContext returns a Logger constructed from ctx or nil if no -// logger details are found. -func FromContext(ctx context.Context) Logger { +// FromContext returns a Logger from ctx or an error if no Logger is found. +func FromContext(ctx context.Context) (Logger, error) { if v, ok := ctx.Value(contextKey{}).(Logger); ok { - return v + return v, nil } - return nil + return Logger{}, notFoundError{} +} + +// notFoundError exists to carry an IsNotFound method. +type notFoundError struct{} + +func (notFoundError) Error() string { + return "no logr.Logger was present" } -// FromContextOrDiscard returns a Logger constructed from ctx or a Logger -// that discards all messages if no logger details are found. +func (notFoundError) IsNotFound() bool { + return true +} + +// FromContextOrDiscard returns a Logger from ctx. If no Logger is found, this +// returns a Logger that discards all log messages. func FromContextOrDiscard(ctx context.Context) Logger { if v, ok := ctx.Value(contextKey{}).(Logger); ok { return v @@ -217,12 +306,59 @@ func FromContextOrDiscard(ctx context.Context) Logger { return Discard() } -// NewContext returns a new context derived from ctx that embeds the Logger. -func NewContext(ctx context.Context, l Logger) context.Context { - return context.WithValue(ctx, contextKey{}, l) +// NewContext returns a new Context, derived from ctx, which carries the +// provided Logger. +func NewContext(ctx context.Context, logger Logger) context.Context { + return context.WithValue(ctx, contextKey{}, logger) +} + +// RuntimeInfo holds information that the logr "core" library knows which +// LogSinks might want to know. +type RuntimeInfo struct { + // CallDepth is the number of call frames the logr library adds between the + // end-user and the LogSink. LogSink implementations which choose to print + // the original logging site (e.g. file & line) should climb this many + // additional frames to find it. + CallDepth int +} + +// runtimeInfo is a static global. It must not be changed at run time. +var runtimeInfo = RuntimeInfo{ + CallDepth: 1, +} + +// LogSink represents a logging implementation. End-users will generally not +// interact with this type. +type LogSink interface { + // Init receives optional information about the logr library for LogSink + // implementations that need it. + Init(info RuntimeInfo) + + // Enabled tests whether this LogSink is enabled at the specified V-level. + // For example, commandline flags might be used to set the logging + // verbosity and disable some info logs. + Enabled(level int) bool + + // Info logs a non-error message with the given key/value pairs as context. + // The level argument is provided for optional logging. This method will + // only be called when Enabled(level) is true. See Logger.Info for more + // details. + Info(level int, msg string, keysAndValues ...interface{}) + + // Error logs an error, with the given message and key/value pairs as + // context. See Logger.Error for more details. + Error(err error, msg string, keysAndValues ...interface{}) + + // WithValues returns a new LogSink with additional key/value pairs. See + // Logger.WithValues for more details. + WithValues(keysAndValues ...interface{}) LogSink + + // WithName returns a new LogSink with the specified name appended. See + // Logger.WithName for more details. + WithName(name string) LogSink } -// CallDepthLogger represents a Logger that knows how to climb the call stack +// CallDepthLogSink represents a Logger that knows how to climb the call stack // to identify the original call site and can offset the depth by a specified // number of frames. This is useful for users who have helper functions // between the "real" call site and the actual calls to Logger methods. @@ -232,35 +368,11 @@ func NewContext(ctx context.Context, l Logger) context.Context { // // This is an optional interface and implementations are not required to // support it. -type CallDepthLogger interface { - Logger - +type CallDepthLogSink interface { // WithCallDepth returns a Logger that will offset the call stack by the // specified number of frames when logging call site information. If depth // is 0 the attribution should be to the direct caller of this method. If // depth is 1 the attribution should skip 1 call frame, and so on. // Successive calls to this are additive. - WithCallDepth(depth int) Logger -} - -// WithCallDepth returns a Logger that will offset the call stack by the -// specified number of frames when logging call site information, if possible. -// This is useful for users who have helper functions between the "real" call -// site and the actual calls to Logger methods. If depth is 0 the attribution -// should be to the direct caller of this function. If depth is 1 the -// attribution should skip 1 call frame, and so on. Successive calls to this -// are additive. -// -// If the underlying log implementation supports the CallDepthLogger interface, -// the WithCallDepth method will be called and the result returned. If the -// implementation does not support CallDepthLogger, the original Logger will be -// returned. -// -// Callers which care about whether this was supported or not should test for -// CallDepthLogger support themselves. -func WithCallDepth(logger Logger, depth int) Logger { - if decorator, ok := logger.(CallDepthLogger); ok { - return decorator.WithCallDepth(depth) - } - return logger + WithCallDepth(depth int) LogSink } diff --git a/logr_test.go b/logr_test.go index e88f888..cb79a1b 100644 --- a/logr_test.go +++ b/logr_test.go @@ -21,91 +21,91 @@ import ( "testing" ) -// testLogger is a Logger just for testing that does nothing. -type testLogger struct{} +// testLogSink is a Logger just for testing that does nothing. +type testLogSink struct{} -func (l *testLogger) Enabled() bool { - return false +func (l *testLogSink) Init(RuntimeInfo) { } -func (l *testLogger) Info(msg string, keysAndValues ...interface{}) { +func (l *testLogSink) Enabled(int) bool { + return false } -func (l *testLogger) Error(err error, msg string, keysAndValues ...interface{}) { +func (l *testLogSink) Info(level int, msg string, keysAndValues ...interface{}) { } -func (l *testLogger) V(level int) Logger { - return l +func (l *testLogSink) Error(err error, msg string, keysAndValues ...interface{}) { } -func (l *testLogger) WithValues(keysAndValues ...interface{}) Logger { +func (l *testLogSink) WithValues(keysAndValues ...interface{}) LogSink { return l } -func (l *testLogger) WithName(name string) Logger { +func (l *testLogSink) WithName(name string) LogSink { return l } // Verify that it actually implements the interface -var _ Logger = &testLogger{} +var _ LogSink = &testLogSink{} func TestContext(t *testing.T) { ctx := context.TODO() - if out := FromContext(ctx); out != nil { - t.Errorf("expected nil logger, got %#v", out) + if out, err := FromContext(ctx); err == nil { + t.Errorf("expected error, got %#v", out) } - if out := FromContextOrDiscard(ctx); out == nil { - t.Errorf("expected non-nil logger") - } else if _, ok := out.(DiscardLogger); !ok { - t.Errorf("expected a DiscardLogger, got %#v", out) + out := FromContextOrDiscard(ctx) + if _, ok := out.sink.(discardLogger); !ok { + t.Errorf("expected a discardLogger, got %#v", out) } - logger := &testLogger{} + sink := &testLogSink{} + logger := New(sink) lctx := NewContext(ctx, logger) - if out := FromContext(lctx); out == nil { - t.Errorf("expected non-nil logger") - } else if out.(*testLogger) != logger { - t.Errorf("expected output to be the same as input: got in=%p, out=%p", logger, out) + if out, err := FromContext(lctx); err != nil { + t.Errorf("unexpected error: %v", err) + } else if p := out.sink.(*testLogSink); p != sink { + t.Errorf("expected output to be the same as input: got in=%p, out=%p", sink, p) } - if out := FromContextOrDiscard(lctx); out == nil { - t.Errorf("expected non-nil logger") - } else if out.(*testLogger) != logger { - t.Errorf("expected output to be the same as input: got in=%p, out=%p", logger, out) + out = FromContextOrDiscard(lctx) + if p := out.sink.(*testLogSink); p != sink { + t.Errorf("expected output to be the same as input: got in=%p, out=%p", sink, p) } } -// testCallDepthLogger is a Logger just for testing that does nothing. -type testCallDepthLogger struct { - *testLogger +// testCallDepthLogSink is a Logger just for testing that does nothing. +type testCallDepthLogSink struct { + *testLogSink depth int } -func (l *testCallDepthLogger) WithCallDepth(depth int) Logger { - return &testCallDepthLogger{l.testLogger, l.depth + depth} +func (l *testCallDepthLogSink) WithCallDepth(depth int) LogSink { + return &testCallDepthLogSink{l.testLogSink, l.depth + depth} } // Verify that it actually implements the interface -var _ CallDepthLogger = &testCallDepthLogger{} +var _ CallDepthLogSink = &testCallDepthLogSink{} func TestWithCallDepth(t *testing.T) { // Test an impl that does not support it. t.Run("not supported", func(t *testing.T) { - in := &testLogger{} - out := WithCallDepth(in, 42) - if out.(*testLogger) != in { - t.Errorf("expected output to be the same as input: got in=%p, out=%p", in, out) + in := &testLogSink{} + l := New(in) + out := l.WithCallDepth(42) + if p := out.sink.(*testLogSink); p != in { + t.Errorf("expected output to be the same as input: got in=%p, out=%p", in, p) } }) // Test an impl that does support it. t.Run("supported", func(t *testing.T) { - in := &testCallDepthLogger{&testLogger{}, 0} - out := WithCallDepth(in, 42) - if out.(*testCallDepthLogger) == in { + in := &testCallDepthLogSink{&testLogSink{}, 0} + l := New(in) + out := l.WithCallDepth(42) + if out.sink.(*testCallDepthLogSink) == in { t.Errorf("expected output to be different than input: got in=out=%p", in) } - if cdl := out.(*testCallDepthLogger); cdl.depth != 42 { + if cdl := out.sink.(*testCallDepthLogSink); cdl.depth != 42 { t.Errorf("expected depth=42, got %d", cdl.depth) } }) diff --git a/testing/test.go b/testing/test.go index 1222fae..98f7f78 100644 --- a/testing/test.go +++ b/testing/test.go @@ -20,36 +20,14 @@ import ( "testing" "github.com/go-logr/logr" + "github.com/go-logr/logr/funcr" ) -// TestLogger is a logr.Logger that prints through a testing.T object. -// Only error logs will have any effect. -type TestLogger struct { - T *testing.T -} - -var _ logr.Logger = TestLogger{} - -func (_ TestLogger) Info(_ string, _ ...interface{}) { - // Do nothing. -} - -func (_ TestLogger) Enabled() bool { - return false -} - -func (log TestLogger) Error(err error, msg string, args ...interface{}) { - log.T.Logf("%s: %v -- %v", msg, err, args) -} - -func (log TestLogger) V(v int) logr.Logger { - return log -} - -func (log TestLogger) WithName(_ string) logr.Logger { - return log -} - -func (log TestLogger) WithValues(_ ...interface{}) logr.Logger { - return log +// NewTestLogger returns a logr.Logger that prints through a testing.T object. +// Info logs are only enabled at V(0). +func NewTestLogger(t *testing.T) logr.Logger { + fn := func(prefix, args string) { + t.Logf("%s: %s", prefix, args) + } + return funcr.New(fn, funcr.Options{}) } diff --git a/testing/null.go b/testing/test_test.go similarity index 63% rename from testing/null.go rename to testing/test_test.go index f5444b1..467518d 100644 --- a/testing/null.go +++ b/testing/test_test.go @@ -1,5 +1,5 @@ /* -Copyright 2019 The logr Authors. +Copyright 2021 The logr Authors. Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with the License. @@ -16,11 +16,15 @@ limitations under the License. package testing -import "github.com/go-logr/logr" +import ( + "fmt" + "testing" +) -// NullLogger is a logr.Logger that does nothing. -// -// Deprecated: NullLogger is idenitcal to logr.DiscardLogger. It is retained -// for backwards compatibility, but new users should use logr.DiscardLogger -// instead. -type NullLogger = logr.DiscardLogger +func TestTestLogger(t *testing.T) { + logger := NewTestLogger(t) + logger.Info("info") + logger.V(0).Info("V(0).info") + logger.V(1).Info("v(1).info") + logger.Error(fmt.Errorf("error"), "error") +}