logr.go raw

   1  /*
   2  Copyright 2019 The logr Authors.
   3  
   4  Licensed under the Apache License, Version 2.0 (the "License");
   5  you may not use this file except in compliance with the License.
   6  You may obtain a copy of the License at
   7  
   8      http://www.apache.org/licenses/LICENSE-2.0
   9  
  10  Unless required by applicable law or agreed to in writing, software
  11  distributed under the License is distributed on an "AS IS" BASIS,
  12  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  See the License for the specific language governing permissions and
  14  limitations under the License.
  15  */
  16  
  17  // This design derives from Dave Cheney's blog:
  18  //     http://dave.cheney.net/2015/11/05/lets-talk-about-logging
  19  
  20  // Package logr defines a general-purpose logging API and abstract interfaces
  21  // to back that API.  Packages in the Go ecosystem can depend on this package,
  22  // while callers can implement logging with whatever backend is appropriate.
  23  //
  24  // # Usage
  25  //
  26  // Logging is done using a Logger instance.  Logger is a concrete type with
  27  // methods, which defers the actual logging to a LogSink interface.  The main
  28  // methods of Logger are Info() and Error().  Arguments to Info() and Error()
  29  // are key/value pairs rather than printf-style formatted strings, emphasizing
  30  // "structured logging".
  31  //
  32  // With Go's standard log package, we might write:
  33  //
  34  //	log.Printf("setting target value %s", targetValue)
  35  //
  36  // With logr's structured logging, we'd write:
  37  //
  38  //	logger.Info("setting target", "value", targetValue)
  39  //
  40  // Errors are much the same.  Instead of:
  41  //
  42  //	log.Printf("failed to open the pod bay door for user %s: %v", user, err)
  43  //
  44  // We'd write:
  45  //
  46  //	logger.Error(err, "failed to open the pod bay door", "user", user)
  47  //
  48  // Info() and Error() are very similar, but they are separate methods so that
  49  // LogSink implementations can choose to do things like attach additional
  50  // information (such as stack traces) on calls to Error(). Error() messages are
  51  // always logged, regardless of the current verbosity.  If there is no error
  52  // instance available, passing nil is valid.
  53  //
  54  // # Verbosity
  55  //
  56  // Often we want to log information only when the application in "verbose
  57  // mode".  To write log lines that are more verbose, Logger has a V() method.
  58  // The higher the V-level of a log line, the less critical it is considered.
  59  // Log-lines with V-levels that are not enabled (as per the LogSink) will not
  60  // be written.  Level V(0) is the default, and logger.V(0).Info() has the same
  61  // meaning as logger.Info().  Negative V-levels have the same meaning as V(0).
  62  // Error messages do not have a verbosity level and are always logged.
  63  //
  64  // Where we might have written:
  65  //
  66  //	if flVerbose >= 2 {
  67  //	    log.Printf("an unusual thing happened")
  68  //	}
  69  //
  70  // We can write:
  71  //
  72  //	logger.V(2).Info("an unusual thing happened")
  73  //
  74  // # Logger Names
  75  //
  76  // Logger instances can have name strings so that all messages logged through
  77  // that instance have additional context.  For example, you might want to add
  78  // a subsystem name:
  79  //
  80  //	logger.WithName("compactor").Info("started", "time", time.Now())
  81  //
  82  // The WithName() method returns a new Logger, which can be passed to
  83  // constructors or other functions for further use.  Repeated use of WithName()
  84  // will accumulate name "segments".  These name segments will be joined in some
  85  // way by the LogSink implementation.  It is strongly recommended that name
  86  // segments contain simple identifiers (letters, digits, and hyphen), and do
  87  // not contain characters that could muddle the log output or confuse the
  88  // joining operation (e.g. whitespace, commas, periods, slashes, brackets,
  89  // quotes, etc).
  90  //
  91  // # Saved Values
  92  //
  93  // Logger instances can store any number of key/value pairs, which will be
  94  // logged alongside all messages logged through that instance.  For example,
  95  // you might want to create a Logger instance per managed object:
  96  //
  97  // With the standard log package, we might write:
  98  //
  99  //	log.Printf("decided to set field foo to value %q for object %s/%s",
 100  //	    targetValue, object.Namespace, object.Name)
 101  //
 102  // With logr we'd write:
 103  //
 104  //	// Elsewhere: set up the logger to log the object name.
 105  //	obj.logger = mainLogger.WithValues(
 106  //	    "name", obj.name, "namespace", obj.namespace)
 107  //
 108  //	// later on...
 109  //	obj.logger.Info("setting foo", "value", targetValue)
 110  //
 111  // # Best Practices
 112  //
 113  // Logger has very few hard rules, with the goal that LogSink implementations
 114  // might have a lot of freedom to differentiate.  There are, however, some
 115  // things to consider.
 116  //
 117  // The log message consists of a constant message attached to the log line.
 118  // This should generally be a simple description of what's occurring, and should
 119  // never be a format string.  Variable information can then be attached using
 120  // named values.
 121  //
 122  // Keys are arbitrary strings, but should generally be constant values.  Values
 123  // may be any Go value, but how the value is formatted is determined by the
 124  // LogSink implementation.
 125  //
 126  // Logger instances are meant to be passed around by value. Code that receives
 127  // such a value can call its methods without having to check whether the
 128  // instance is ready for use.
 129  //
 130  // The zero logger (= Logger{}) is identical to Discard() and discards all log
 131  // entries. Code that receives a Logger by value can simply call it, the methods
 132  // will never crash. For cases where passing a logger is optional, a pointer to Logger
 133  // should be used.
 134  //
 135  // # Key Naming Conventions
 136  //
 137  // Keys are not strictly required to conform to any specification or regex, but
 138  // it is recommended that they:
 139  //   - be human-readable and meaningful (not auto-generated or simple ordinals)
 140  //   - be constant (not dependent on input data)
 141  //   - contain only printable characters
 142  //   - not contain whitespace or punctuation
 143  //   - use lower case for simple keys and lowerCamelCase for more complex ones
 144  //
 145  // These guidelines help ensure that log data is processed properly regardless
 146  // of the log implementation.  For example, log implementations will try to
 147  // output JSON data or will store data for later database (e.g. SQL) queries.
 148  //
 149  // While users are generally free to use key names of their choice, it's
 150  // generally best to avoid using the following keys, as they're frequently used
 151  // by implementations:
 152  //   - "caller": the calling information (file/line) of a particular log line
 153  //   - "error": the underlying error value in the `Error` method
 154  //   - "level": the log level
 155  //   - "logger": the name of the associated logger
 156  //   - "msg": the log message
 157  //   - "stacktrace": the stack trace associated with a particular log line or
 158  //     error (often from the `Error` message)
 159  //   - "ts": the timestamp for a log line
 160  //
 161  // Implementations are encouraged to make use of these keys to represent the
 162  // above concepts, when necessary (for example, in a pure-JSON output form, it
 163  // would be necessary to represent at least message and timestamp as ordinary
 164  // named values).
 165  //
 166  // # Break Glass
 167  //
 168  // Implementations may choose to give callers access to the underlying
 169  // logging implementation.  The recommended pattern for this is:
 170  //
 171  //	// Underlier exposes access to the underlying logging implementation.
 172  //	// Since callers only have a logr.Logger, they have to know which
 173  //	// implementation is in use, so this interface is less of an abstraction
 174  //	// and more of way to test type conversion.
 175  //	type Underlier interface {
 176  //	    GetUnderlying() <underlying-type>
 177  //	}
 178  //
 179  // Logger grants access to the sink to enable type assertions like this:
 180  //
 181  //	func DoSomethingWithImpl(log logr.Logger) {
 182  //	    if underlier, ok := log.GetSink().(impl.Underlier); ok {
 183  //	       implLogger := underlier.GetUnderlying()
 184  //	       ...
 185  //	    }
 186  //	}
 187  //
 188  // Custom `With*` functions can be implemented by copying the complete
 189  // Logger struct and replacing the sink in the copy:
 190  //
 191  //	// WithFooBar changes the foobar parameter in the log sink and returns a
 192  //	// new logger with that modified sink.  It does nothing for loggers where
 193  //	// the sink doesn't support that parameter.
 194  //	func WithFoobar(log logr.Logger, foobar int) logr.Logger {
 195  //	   if foobarLogSink, ok := log.GetSink().(FoobarSink); ok {
 196  //	      log = log.WithSink(foobarLogSink.WithFooBar(foobar))
 197  //	   }
 198  //	   return log
 199  //	}
 200  //
 201  // Don't use New to construct a new Logger with a LogSink retrieved from an
 202  // existing Logger. Source code attribution might not work correctly and
 203  // unexported fields in Logger get lost.
 204  //
 205  // Beware that the same LogSink instance may be shared by different logger
 206  // instances. Calling functions that modify the LogSink will affect all of
 207  // those.
 208  package logr
 209  
 210  // New returns a new Logger instance.  This is primarily used by libraries
 211  // implementing LogSink, rather than end users.  Passing a nil sink will create
 212  // a Logger which discards all log lines.
 213  func New(sink LogSink) Logger {
 214  	logger := Logger{}
 215  	logger.setSink(sink)
 216  	if sink != nil {
 217  		sink.Init(runtimeInfo)
 218  	}
 219  	return logger
 220  }
 221  
 222  // setSink stores the sink and updates any related fields. It mutates the
 223  // logger and thus is only safe to use for loggers that are not currently being
 224  // used concurrently.
 225  func (l *Logger) setSink(sink LogSink) {
 226  	l.sink = sink
 227  }
 228  
 229  // GetSink returns the stored sink.
 230  func (l Logger) GetSink() LogSink {
 231  	return l.sink
 232  }
 233  
 234  // WithSink returns a copy of the logger with the new sink.
 235  func (l Logger) WithSink(sink LogSink) Logger {
 236  	l.setSink(sink)
 237  	return l
 238  }
 239  
 240  // Logger is an interface to an abstract logging implementation.  This is a
 241  // concrete type for performance reasons, but all the real work is passed on to
 242  // a LogSink.  Implementations of LogSink should provide their own constructors
 243  // that return Logger, not LogSink.
 244  //
 245  // The underlying sink can be accessed through GetSink and be modified through
 246  // WithSink. This enables the implementation of custom extensions (see "Break
 247  // Glass" in the package documentation). Normally the sink should be used only
 248  // indirectly.
 249  type Logger struct {
 250  	sink  LogSink
 251  	level int
 252  }
 253  
 254  // Enabled tests whether this Logger is enabled.  For example, commandline
 255  // flags might be used to set the logging verbosity and disable some info logs.
 256  func (l Logger) Enabled() bool {
 257  	// Some implementations of LogSink look at the caller in Enabled (e.g.
 258  	// different verbosity levels per package or file), but we only pass one
 259  	// CallDepth in (via Init).  This means that all calls from Logger to the
 260  	// LogSink's Enabled, Info, and Error methods must have the same number of
 261  	// frames.  In other words, Logger methods can't call other Logger methods
 262  	// which call these LogSink methods unless we do it the same in all paths.
 263  	return l.sink != nil && l.sink.Enabled(l.level)
 264  }
 265  
 266  // Info logs a non-error message with the given key/value pairs as context.
 267  //
 268  // The msg argument should be used to add some constant description to the log
 269  // line.  The key/value pairs can then be used to add additional variable
 270  // information.  The key/value pairs must alternate string keys and arbitrary
 271  // values.
 272  func (l Logger) Info(msg string, keysAndValues ...any) {
 273  	if l.sink == nil {
 274  		return
 275  	}
 276  	if l.sink.Enabled(l.level) { // see comment in Enabled
 277  		if withHelper, ok := l.sink.(CallStackHelperLogSink); ok {
 278  			withHelper.GetCallStackHelper()()
 279  		}
 280  		l.sink.Info(l.level, msg, keysAndValues...)
 281  	}
 282  }
 283  
 284  // Error logs an error, with the given message and key/value pairs as context.
 285  // It functions similarly to Info, but may have unique behavior, and should be
 286  // preferred for logging errors (see the package documentations for more
 287  // information). The log message will always be emitted, regardless of
 288  // verbosity level.
 289  //
 290  // The msg argument should be used to add context to any underlying error,
 291  // while the err argument should be used to attach the actual error that
 292  // triggered this log line, if present. The err parameter is optional
 293  // and nil may be passed instead of an error instance.
 294  func (l Logger) Error(err error, msg string, keysAndValues ...any) {
 295  	if l.sink == nil {
 296  		return
 297  	}
 298  	if withHelper, ok := l.sink.(CallStackHelperLogSink); ok {
 299  		withHelper.GetCallStackHelper()()
 300  	}
 301  	l.sink.Error(err, msg, keysAndValues...)
 302  }
 303  
 304  // V returns a new Logger instance for a specific verbosity level, relative to
 305  // this Logger.  In other words, V-levels are additive.  A higher verbosity
 306  // level means a log message is less important.  Negative V-levels are treated
 307  // as 0.
 308  func (l Logger) V(level int) Logger {
 309  	if l.sink == nil {
 310  		return l
 311  	}
 312  	if level < 0 {
 313  		level = 0
 314  	}
 315  	l.level += level
 316  	return l
 317  }
 318  
 319  // GetV returns the verbosity level of the logger. If the logger's LogSink is
 320  // nil as in the Discard logger, this will always return 0.
 321  func (l Logger) GetV() int {
 322  	// 0 if l.sink nil because of the if check in V above.
 323  	return l.level
 324  }
 325  
 326  // WithValues returns a new Logger instance with additional key/value pairs.
 327  // See Info for documentation on how key/value pairs work.
 328  func (l Logger) WithValues(keysAndValues ...any) Logger {
 329  	if l.sink == nil {
 330  		return l
 331  	}
 332  	l.setSink(l.sink.WithValues(keysAndValues...))
 333  	return l
 334  }
 335  
 336  // WithName returns a new Logger instance with the specified name element added
 337  // to the Logger's name.  Successive calls with WithName append additional
 338  // suffixes to the Logger's name.  It's strongly recommended that name segments
 339  // contain only letters, digits, and hyphens (see the package documentation for
 340  // more information).
 341  func (l Logger) WithName(name string) Logger {
 342  	if l.sink == nil {
 343  		return l
 344  	}
 345  	l.setSink(l.sink.WithName(name))
 346  	return l
 347  }
 348  
 349  // WithCallDepth returns a Logger instance that offsets the call stack by the
 350  // specified number of frames when logging call site information, if possible.
 351  // This is useful for users who have helper functions between the "real" call
 352  // site and the actual calls to Logger methods.  If depth is 0 the attribution
 353  // should be to the direct caller of this function.  If depth is 1 the
 354  // attribution should skip 1 call frame, and so on.  Successive calls to this
 355  // are additive.
 356  //
 357  // If the underlying log implementation supports a WithCallDepth(int) method,
 358  // it will be called and the result returned.  If the implementation does not
 359  // support CallDepthLogSink, the original Logger will be returned.
 360  //
 361  // To skip one level, WithCallStackHelper() should be used instead of
 362  // WithCallDepth(1) because it works with implementions that support the
 363  // CallDepthLogSink and/or CallStackHelperLogSink interfaces.
 364  func (l Logger) WithCallDepth(depth int) Logger {
 365  	if l.sink == nil {
 366  		return l
 367  	}
 368  	if withCallDepth, ok := l.sink.(CallDepthLogSink); ok {
 369  		l.setSink(withCallDepth.WithCallDepth(depth))
 370  	}
 371  	return l
 372  }
 373  
 374  // WithCallStackHelper returns a new Logger instance that skips the direct
 375  // caller when logging call site information, if possible.  This is useful for
 376  // users who have helper functions between the "real" call site and the actual
 377  // calls to Logger methods and want to support loggers which depend on marking
 378  // each individual helper function, like loggers based on testing.T.
 379  //
 380  // In addition to using that new logger instance, callers also must call the
 381  // returned function.
 382  //
 383  // If the underlying log implementation supports a WithCallDepth(int) method,
 384  // WithCallDepth(1) will be called to produce a new logger. If it supports a
 385  // WithCallStackHelper() method, that will be also called. If the
 386  // implementation does not support either of these, the original Logger will be
 387  // returned.
 388  func (l Logger) WithCallStackHelper() (func(), Logger) {
 389  	if l.sink == nil {
 390  		return func() {}, l
 391  	}
 392  	var helper func()
 393  	if withCallDepth, ok := l.sink.(CallDepthLogSink); ok {
 394  		l.setSink(withCallDepth.WithCallDepth(1))
 395  	}
 396  	if withHelper, ok := l.sink.(CallStackHelperLogSink); ok {
 397  		helper = withHelper.GetCallStackHelper()
 398  	} else {
 399  		helper = func() {}
 400  	}
 401  	return helper, l
 402  }
 403  
 404  // IsZero returns true if this logger is an uninitialized zero value
 405  func (l Logger) IsZero() bool {
 406  	return l.sink == nil
 407  }
 408  
 409  // RuntimeInfo holds information that the logr "core" library knows which
 410  // LogSinks might want to know.
 411  type RuntimeInfo struct {
 412  	// CallDepth is the number of call frames the logr library adds between the
 413  	// end-user and the LogSink.  LogSink implementations which choose to print
 414  	// the original logging site (e.g. file & line) should climb this many
 415  	// additional frames to find it.
 416  	CallDepth int
 417  }
 418  
 419  // runtimeInfo is a static global.  It must not be changed at run time.
 420  var runtimeInfo = RuntimeInfo{
 421  	CallDepth: 1,
 422  }
 423  
 424  // LogSink represents a logging implementation.  End-users will generally not
 425  // interact with this type.
 426  type LogSink interface {
 427  	// Init receives optional information about the logr library for LogSink
 428  	// implementations that need it.
 429  	Init(info RuntimeInfo)
 430  
 431  	// Enabled tests whether this LogSink is enabled at the specified V-level.
 432  	// For example, commandline flags might be used to set the logging
 433  	// verbosity and disable some info logs.
 434  	Enabled(level int) bool
 435  
 436  	// Info logs a non-error message with the given key/value pairs as context.
 437  	// The level argument is provided for optional logging.  This method will
 438  	// only be called when Enabled(level) is true. See Logger.Info for more
 439  	// details.
 440  	Info(level int, msg string, keysAndValues ...any)
 441  
 442  	// Error logs an error, with the given message and key/value pairs as
 443  	// context.  See Logger.Error for more details.
 444  	Error(err error, msg string, keysAndValues ...any)
 445  
 446  	// WithValues returns a new LogSink with additional key/value pairs.  See
 447  	// Logger.WithValues for more details.
 448  	WithValues(keysAndValues ...any) LogSink
 449  
 450  	// WithName returns a new LogSink with the specified name appended.  See
 451  	// Logger.WithName for more details.
 452  	WithName(name string) LogSink
 453  }
 454  
 455  // CallDepthLogSink represents a LogSink that knows how to climb the call stack
 456  // to identify the original call site and can offset the depth by a specified
 457  // number of frames.  This is useful for users who have helper functions
 458  // between the "real" call site and the actual calls to Logger methods.
 459  // Implementations that log information about the call site (such as file,
 460  // function, or line) would otherwise log information about the intermediate
 461  // helper functions.
 462  //
 463  // This is an optional interface and implementations are not required to
 464  // support it.
 465  type CallDepthLogSink interface {
 466  	// WithCallDepth returns a LogSink that will offset the call
 467  	// stack by the specified number of frames when logging call
 468  	// site information.
 469  	//
 470  	// If depth is 0, the LogSink should skip exactly the number
 471  	// of call frames defined in RuntimeInfo.CallDepth when Info
 472  	// or Error are called, i.e. the attribution should be to the
 473  	// direct caller of Logger.Info or Logger.Error.
 474  	//
 475  	// If depth is 1 the attribution should skip 1 call frame, and so on.
 476  	// Successive calls to this are additive.
 477  	WithCallDepth(depth int) LogSink
 478  }
 479  
 480  // CallStackHelperLogSink represents a LogSink that knows how to climb
 481  // the call stack to identify the original call site and can skip
 482  // intermediate helper functions if they mark themselves as
 483  // helper. Go's testing package uses that approach.
 484  //
 485  // This is useful for users who have helper functions between the
 486  // "real" call site and the actual calls to Logger methods.
 487  // Implementations that log information about the call site (such as
 488  // file, function, or line) would otherwise log information about the
 489  // intermediate helper functions.
 490  //
 491  // This is an optional interface and implementations are not required
 492  // to support it. Implementations that choose to support this must not
 493  // simply implement it as WithCallDepth(1), because
 494  // Logger.WithCallStackHelper will call both methods if they are
 495  // present. This should only be implemented for LogSinks that actually
 496  // need it, as with testing.T.
 497  type CallStackHelperLogSink interface {
 498  	// GetCallStackHelper returns a function that must be called
 499  	// to mark the direct caller as helper function when logging
 500  	// call site information.
 501  	GetCallStackHelper() func()
 502  }
 503  
 504  // Marshaler is an optional interface that logged values may choose to
 505  // implement. Loggers with structured output, such as JSON, should
 506  // log the object return by the MarshalLog method instead of the
 507  // original value.
 508  type Marshaler interface {
 509  	// MarshalLog can be used to:
 510  	//   - ensure that structs are not logged as strings when the original
 511  	//     value has a String method: return a different type without a
 512  	//     String method
 513  	//   - select which fields of a complex type should get logged:
 514  	//     return a simpler struct with fewer fields
 515  	//   - log unexported fields: return a different struct
 516  	//     with exported fields
 517  	//
 518  	// It may return any value of any type.
 519  	MarshalLog() any
 520  }
 521