logr

package module
Version: v1.1.0 Latest Latest
Warning

This package is not in the latest version of its module.

Go to latest
Published: Aug 23, 2021 License: Apache-2.0 Imports: 1 Imported by: 4,075

README

A minimal logging API for Go

logr offers an(other) opinion on how Go programs and libraries can do logging without becoming coupled to a particular logging implementation. This is not an implementation of logging - it is an API. In fact it is two APIs with two different sets of users.

The Logger type is intended for application and library authors. It provides a relatively small API which can be used everywhere you want to emit logs. It defers the actual act of writing logs (to files, to stdout, or whatever) to the LogSink interface.

The LogSink interface is intended for logging library implementers. It is a pure interface which can be implemented by logging frameworks to provide the actual logging functionality.

This decoupling allows application and library developers to write code in terms of logr.Logger (which has very low dependency fan-out) while the implementation of logging is managed "up stack" (e.g. in or near main().) Application developers can then switch out implementations as necessary.

Many people assert that libraries should not be logging, and as such efforts like this are pointless. Those people are welcome to convince the authors of the tens-of-thousands of libraries that DO write logs that they are all wrong. In the meantime, logr takes a more practical approach.

Typical usage

Somewhere, early in an application's life, it will make a decision about which logging library (implementation) it actually wants to use. Something like:

    func main() {
        // ... other setup code ...

        // Create the "root" logger.  We have chosen the "logimpl" implementation,
        // which takes some initial parameters and returns a logr.Logger.
        logger := logimpl.New(param1, param2)

        // ... other setup code ...

Most apps will call into other libraries, create structures to govern the flow, etc. The logr.Logger object can be passed to these other libraries, stored in structs, or even used as a package-global variable, if needed. For example:

    app := createTheAppObject(logger)
    app.Run()

Outside of this early setup, no other packages need to know about the choice of implementation. They write logs in terms of the logr.Logger that they received:

    type appObject struct {
        // ... other fields ...
        logger logr.Logger
        // ... other fields ...
    }

    func (app *appObject) Run() {
        app.logger.Info("starting up", "timestamp", time.Now())

        // ... app code ...

Background

If the Go standard library had defined an interface for logging, this project probably would not be needed. Alas, here we are.

Inspiration

Before you consider this package, please read this blog post by the inimitable Dave Cheney. We really appreciate what he has to say, and it largely aligns with our own experiences.

Differences from Dave's ideas

The main differences are:

  1. Dave basically proposes doing away with the notion of a logging API in favor of fmt.Printf(). We disagree, especially when you consider things like output locations, timestamps, file and line decorations, and structured logging. This package restricts the logging API to just 2 types of logs: info and error.

Info logs are things you want to tell the user which are not errors. Error logs are, well, errors. If your code receives an error from a subordinate function call and is logging that error and not returning it, use error logs.

  1. Verbosity-levels on info logs. This gives developers a chance to indicate arbitrary grades of importance for info logs, without assigning names with semantic meaning such as "warning", "trace", and "debug." Superficially this may feel very similar, but the primary difference is the lack of semantics. Because verbosity is a numerical value, it's safe to assume that an app running with higher verbosity means more (and less important) logs will be generated.

Implementations (non-exhaustive)

There are implementations for the following logging libraries:

  • a function: funcr
  • github.com/google/glog: glogr
  • k8s.io/klog: klogr
  • go.uber.org/zap: zapr
  • log (the Go standard library logger): stdr
  • github.com/sirupsen/logrus: logrusr
  • github.com/wojas/genericr: genericr (makes it easy to implement your own backend)
  • logfmt (Heroku style logging): logfmtr

FAQ

Conceptual
Why structured logging?
  • Structured logs are more easily queryable: Since you've got key-value pairs, it's much easier to query your structured logs for particular values by filtering on the contents of a particular key -- think searching request logs for error codes, Kubernetes reconcilers for the name and namespace of the reconciled object, etc.

  • Structured logging makes it easier to have cross-referenceable logs: 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 to log certain keys but not others, only log lines where a certain key matches a certain value, etc., instead of just having v-levels and names to key off of.

  • Structured logs better represent structured data: sometimes, the data that you want to log is inherently structured (think tuple-link objects.) Structured logs allow you to preserve that structure when outputting.

Why V-levels?

V-levels give operators an easy way to control the chattiness of log operations. V-levels provide a way for a given package to distinguish the relative importance or verbosity of a given log message. Then, if a particular logger or package is logging too many messages, the user of the package can simply change the v-levels for that library.

Why not named levels, like Info/Warning/Error?

Read Dave Cheney's post. Then read Differences from Dave's ideas.

Why not allow format strings, too?

Format strings negate many of the benefits of structured logs:

  • They're not easily searchable without resorting to fuzzy searching, regular expressions, etc.

  • They don't store structured data well, since contents are flattened into a string.

  • They're not cross-referenceable.

  • They don't compress easily, since the message is not constant.

(Unless you turn positional parameters into key-value pairs with numerical keys, at which point you've gotten key-value logging with meaningless keys.)

Practical
Why key-value pairs, and not a map?

Key-value pairs are much easier to optimize, especially around allocations. Zap (a structured logger that inspired logr's interface) has performance measurements that show this quite nicely.

While the interface ends up being a little less obvious, you get potentially better performance, plus avoid making users type map[string]string{} every time they want to log.

What if my V-levels differ between libraries?

That's fine. Control your V-levels on a per-logger basis, and use the WithName method to pass different loggers to different libraries.

Generally, you should take care to ensure that you have relatively consistent V-levels within a given logger, however, as this makes deciding on what verbosity of logs to request easier.

But I really want to use a format string!

That's not actually a question. Assuming your question is "how do I convert my mental model of logging with format strings to logging with constant messages":

  1. Figure out what the error actually is, as you'd write in a TL;DR style, and use that as a message.

  2. For every place you'd write a format specifier, look to the word before it, and add that as a key value pair.

For instance, consider the following examples (all taken from spots in the Kubernetes codebase):

  • klog.V(4).Infof("Client is returning errors: code %v, error %v", responseCode, err) becomes logger.Error(err, "client returned an error", "code", responseCode)

  • klog.V(4).Infof("Got a Retry-After %ds response for attempt %d to %v", seconds, retries, url) becomes logger.V(4).Info("got a retry-after response when requesting url", "attempt", retries, "after seconds", seconds, "url", url)

If you really must use a format string, use it in a key's value, and call fmt.Sprintf yourself. For instance: log.Printf("unable to reflect over type %T") becomes logger.Info("unable to reflect over type", "type", fmt.Sprintf("%T")). In general though, the cases where this is necessary should be few and far between.

How do I choose my V-levels?

This is basically the only hard constraint: increase V-levels to denote more verbose or more debug-y logs.

Otherwise, you can start out with 0 as "you always want to see this", 1 as "common logging that you might possibly want to turn off", and 10 as "I would like to performance-test your log collection stack."

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?

Keys are fairly flexible, and can hold more or less any string value. For best compatibility with implementations and consistency with existing code in other projects, there are a few conventions you should consider.

  • Make your keys human-readable.
  • Constant keys are generally a good idea.
  • Be consistent across your codebase.
  • Keys should naturally match parts of the message string.
  • Use lower case for simple keys and lowerCamelCase for more complex ones. Kubernetes is one example of a project that has adopted that convention.

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.

Documentation

Overview

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 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".

With Go's standard log package, we might write:

log.Printf("setting target value %s", targetValue)

With logr's structured logging, we'd write:

logger.Info("setting target", "value", targetValue)

Errors are much the same. Instead of:

log.Printf("failed to open the pod bay door for user %s: %v", user, err)

We'd write:

logger.Error(err, "failed to open the pod bay door", "user", user)

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")

# Logger Names

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:

logger.WithName("compactor").Info("started", "time", time.Now())

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).

# Saved Values

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:

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 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)

# Best Practices

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. Variable information can then be attached using named values.

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:

* be human-readable and meaningful (not auto-generated or simple ordinals)
* be constant (not dependent on input data)
* contain only printable characters
* not contain whitespace or punctuation
* use lower case for simple keys and lowerCamelCase for more complex ones

These guidelines help ensure that log data is processed properly regardless of the log implementation. For example, log implementations will try to output JSON data or will store data for later database (e.g. SQL) queries.

While users are generally free to use key names of their choice, it's generally best to avoid using the following keys, as they're frequently used by implementations:

* "caller": the calling information (file/line) of a particular log line.
* "error": the underlying error value in the `Error` method.
* "level": the log level.
* "logger": the name of the associated logger.
* "msg": the log message.
* "stacktrace": the stack trace associated with a particular log line or
                error (often from the `Error` message).
* "ts": the timestamp for a log line.

Implementations are encouraged to make use of these keys to represent the above concepts, when necessary (for example, in a pure-JSON output form, it 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.
// Since callers only have a logr.Logger, they have to know which
// implementation is in use, so this interface is less of an abstraction
// and more of way to test type conversion.
type Underlier interface {
    GetUnderlying() <underlying-type>
}

Logger grants access to the sink to enable type assertions like this:

func DoSomethingWithImpl(log logr.Logger) {
    if underlier, ok := log.GetSink()(impl.Underlier) {
       implLogger := underlier.GetUnderlying()
       ...
    }
}

Custom `With*` functions can be implemented by copying the complete Logger struct and replacing the sink in the copy:

// WithFooBar changes the foobar parameter in the log sink and returns a
// new logger with that modified sink.  It does nothing for loggers where
// the sink doesn't support that parameter.
func WithFoobar(log logr.Logger, foobar int) logr.Logger {
   if foobarLogSink, ok := log.GetSink()(FoobarSink); ok {
      log = log.WithSink(foobarLogSink.WithFooBar(foobar))
   }
   return log
}

Don't use New to construct a new Logger with a LogSink retrieved from an existing Logger. Source code attribution might not work correctly and unexported fields in Logger get lost.

Beware that the same LogSink instance may be shared by different logger instances. Calling functions that modify the LogSink will affect all of those.

Index

Constants

This section is empty.

Variables

This section is empty.

Functions

func NewContext added in v0.3.0

func NewContext(ctx context.Context, logger Logger) context.Context

NewContext returns a new Context, derived from ctx, which carries the provided Logger.

Types

type CallDepthLogSink added in v1.0.0

type CallDepthLogSink interface {
	// WithCallDepth returns a LogSink that will offset the call
	// stack by the specified number of frames when logging call
	// site information.
	//
	// If depth is 0, the LogSink should skip exactly the number
	// of call frames defined in RuntimeInfo.CallDepth when Info
	// or Error are called, i.e. the attribution should be to the
	// direct caller of Logger.Info or Logger.Error.
	//
	// If depth is 1 the attribution should skip 1 call frame, and so on.
	// Successive calls to this are additive.
	WithCallDepth(depth int) LogSink
}

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. Implementations that log information about the call site (such as file, function, or line) would otherwise log information about the intermediate helper functions.

This is an optional interface and implementations are not required to support it.

type CallStackHelperLogSink added in v1.1.0

type CallStackHelperLogSink interface {
	// GetCallStackHelper returns a function that must be called
	// to mark the direct caller as helper function when logging
	// call site information.
	GetCallStackHelper() func()
}

CallStackHelperLogSink represents a Logger that knows how to climb the call stack to identify the original call site and can skip intermediate helper functions if they mark themselves as helper. Go's testing package uses that approach.

This is useful for users who have helper functions between the "real" call site and the actual calls to Logger methods. Implementations that log information about the call site (such as file, function, or line) would otherwise log information about the intermediate helper functions.

This is an optional interface and implementations are not required to support it. Implementations that choose to support this must not simply implement it as WithCallDepth(1), because Logger.WithCallStackHelper will call both methods if they are present. This should only be implemented for LogSinks that actually need it, as with testing.T.

type LogSink added in v1.0.0

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
}

LogSink represents a logging implementation. End-users will generally not interact with this type.

type Logger

type Logger struct {
	// contains filtered or unexported fields
}

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.

The underlying sink can be accessed through GetSink and be modified through WithSink. This enables the implementation of custom extensions (see "Break Glass" in the package documentation). Normally the sink should be used only indirectly.

func Discard added in v0.3.0

func Discard() Logger

Discard returns a Logger that discards all messages logged to it. It can be used whenever the caller is not interested in the logs. Logger instances produced by this function always compare as equal.

func FromContext added in v0.3.0

func FromContext(ctx context.Context) (Logger, error)

FromContext returns a Logger from ctx or an error if no Logger is found.

func FromContextOrDiscard added in v0.3.0

func FromContextOrDiscard(ctx context.Context) Logger

FromContextOrDiscard returns a Logger from ctx. If no Logger is found, this returns a Logger that discards all log messages.

func New added in v1.0.0

func New(sink LogSink) Logger

New returns a new Logger instance. This is primarily used by libraries implementing LogSink, rather than end users.

func (Logger) Enabled added in v0.2.0

func (l Logger) Enabled() bool

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 (Logger) Error

func (l Logger) Error(err error, msg string, keysAndValues ...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).

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 (Logger) GetSink added in v1.1.0

func (l Logger) GetSink() LogSink

GetSink returns the stored sink.

func (Logger) Info added in v0.2.0

func (l Logger) Info(msg string, keysAndValues ...interface{})

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 (Logger) V

func (l Logger) V(level int) Logger

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 (Logger) WithCallDepth added in v1.0.0

func (l Logger) WithCallDepth(depth int) Logger

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.

To skip one level, WithCallStackHelper() should be used instead of WithCallDepth(1) because it works with implementions that support the CallDepthLogSink and/or CallStackHelperLogSink interfaces.

func (Logger) WithCallStackHelper added in v1.1.0

func (l Logger) WithCallStackHelper() (func(), Logger)

WithCallStackHelper returns a new Logger instance that skips the direct caller 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 and want to support loggers which depend on marking each individual helper function, like loggers based on testing.T.

In addition to using that new logger instance, callers also must call the returned function.

If the underlying log implementation supports a WithCallDepth(int) method, WithCallDepth(1) will be called to produce a new logger. If it supports a WithCallStackHelper() method, that will be also called. If the implementation does not support either of these, the original Logger will be returned.

func (Logger) WithName

func (l Logger) WithName(name string) Logger

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 (Logger) WithSink added in v1.1.0

func (l Logger) WithSink(sink LogSink) Logger

WithSink returns a copy of the logger with the new sink.

func (Logger) WithValues

func (l Logger) WithValues(keysAndValues ...interface{}) Logger

WithValues returns a new Logger instance with additional key/value pairs. See Info for documentation on how key/value pairs work.

type RuntimeInfo added in v1.0.0

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 holds information that the logr "core" library knows which LogSinks might want to know.

Source Files

Directories

Path Synopsis
Package funcr implements formatting of structured log messages and optionally captures the call site.
Package funcr implements formatting of structured log messages and optionally captures the call site.

Jump to

Keyboard shortcuts

? : This menu
/ : Search site
f or F : Jump to
t or T : Toggle theme light dark auto
y or Y : Canonical URL