logger.go raw

   1  // Copyright (c) 2016 Uber Technologies, Inc.
   2  //
   3  // Permission is hereby granted, free of charge, to any person obtaining a copy
   4  // of this software and associated documentation files (the "Software"), to deal
   5  // in the Software without restriction, including without limitation the rights
   6  // to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
   7  // copies of the Software, and to permit persons to whom the Software is
   8  // furnished to do so, subject to the following conditions:
   9  //
  10  // The above copyright notice and this permission notice shall be included in
  11  // all copies or substantial portions of the Software.
  12  //
  13  // THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
  14  // IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
  15  // FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
  16  // AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
  17  // LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
  18  // OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
  19  // THE SOFTWARE.
  20  
  21  package zap
  22  
  23  import (
  24  	"fmt"
  25  	"io"
  26  	"os"
  27  	"strings"
  28  
  29  	"go.uber.org/zap/internal/bufferpool"
  30  	"go.uber.org/zap/internal/stacktrace"
  31  	"go.uber.org/zap/zapcore"
  32  )
  33  
  34  // A Logger provides fast, leveled, structured logging. All methods are safe
  35  // for concurrent use.
  36  //
  37  // The Logger is designed for contexts in which every microsecond and every
  38  // allocation matters, so its API intentionally favors performance and type
  39  // safety over brevity. For most applications, the SugaredLogger strikes a
  40  // better balance between performance and ergonomics.
  41  type Logger struct {
  42  	core zapcore.Core
  43  
  44  	development bool
  45  	addCaller   bool
  46  	onPanic     zapcore.CheckWriteHook // default is WriteThenPanic
  47  	onFatal     zapcore.CheckWriteHook // default is WriteThenFatal
  48  
  49  	name        string
  50  	errorOutput zapcore.WriteSyncer
  51  
  52  	addStack zapcore.LevelEnabler
  53  
  54  	callerSkip int
  55  
  56  	clock zapcore.Clock
  57  }
  58  
  59  // New constructs a new Logger from the provided zapcore.Core and Options. If
  60  // the passed zapcore.Core is nil, it falls back to using a no-op
  61  // implementation.
  62  //
  63  // This is the most flexible way to construct a Logger, but also the most
  64  // verbose. For typical use cases, the highly-opinionated presets
  65  // (NewProduction, NewDevelopment, and NewExample) or the Config struct are
  66  // more convenient.
  67  //
  68  // For sample code, see the package-level AdvancedConfiguration example.
  69  func New(core zapcore.Core, options ...Option) *Logger {
  70  	if core == nil {
  71  		return NewNop()
  72  	}
  73  	log := &Logger{
  74  		core:        core,
  75  		errorOutput: zapcore.Lock(os.Stderr),
  76  		addStack:    zapcore.FatalLevel + 1,
  77  		clock:       zapcore.DefaultClock,
  78  	}
  79  	return log.WithOptions(options...)
  80  }
  81  
  82  // NewNop returns a no-op Logger. It never writes out logs or internal errors,
  83  // and it never runs user-defined hooks.
  84  //
  85  // Using WithOptions to replace the Core or error output of a no-op Logger can
  86  // re-enable logging.
  87  func NewNop() *Logger {
  88  	return &Logger{
  89  		core:        zapcore.NewNopCore(),
  90  		errorOutput: zapcore.AddSync(io.Discard),
  91  		addStack:    zapcore.FatalLevel + 1,
  92  		clock:       zapcore.DefaultClock,
  93  	}
  94  }
  95  
  96  // NewProduction builds a sensible production Logger that writes InfoLevel and
  97  // above logs to standard error as JSON.
  98  //
  99  // It's a shortcut for NewProductionConfig().Build(...Option).
 100  func NewProduction(options ...Option) (*Logger, error) {
 101  	return NewProductionConfig().Build(options...)
 102  }
 103  
 104  // NewDevelopment builds a development Logger that writes DebugLevel and above
 105  // logs to standard error in a human-friendly format.
 106  //
 107  // It's a shortcut for NewDevelopmentConfig().Build(...Option).
 108  func NewDevelopment(options ...Option) (*Logger, error) {
 109  	return NewDevelopmentConfig().Build(options...)
 110  }
 111  
 112  // Must is a helper that wraps a call to a function returning (*Logger, error)
 113  // and panics if the error is non-nil. It is intended for use in variable
 114  // initialization such as:
 115  //
 116  //	var logger = zap.Must(zap.NewProduction())
 117  func Must(logger *Logger, err error) *Logger {
 118  	if err != nil {
 119  		panic(err)
 120  	}
 121  
 122  	return logger
 123  }
 124  
 125  // NewExample builds a Logger that's designed for use in zap's testable
 126  // examples. It writes DebugLevel and above logs to standard out as JSON, but
 127  // omits the timestamp and calling function to keep example output
 128  // short and deterministic.
 129  func NewExample(options ...Option) *Logger {
 130  	encoderCfg := zapcore.EncoderConfig{
 131  		MessageKey:     "msg",
 132  		LevelKey:       "level",
 133  		NameKey:        "logger",
 134  		EncodeLevel:    zapcore.LowercaseLevelEncoder,
 135  		EncodeTime:     zapcore.ISO8601TimeEncoder,
 136  		EncodeDuration: zapcore.StringDurationEncoder,
 137  	}
 138  	core := zapcore.NewCore(zapcore.NewJSONEncoder(encoderCfg), os.Stdout, DebugLevel)
 139  	return New(core).WithOptions(options...)
 140  }
 141  
 142  // Sugar wraps the Logger to provide a more ergonomic, but slightly slower,
 143  // API. Sugaring a Logger is quite inexpensive, so it's reasonable for a
 144  // single application to use both Loggers and SugaredLoggers, converting
 145  // between them on the boundaries of performance-sensitive code.
 146  func (log *Logger) Sugar() *SugaredLogger {
 147  	core := log.clone()
 148  	core.callerSkip += 2
 149  	return &SugaredLogger{core}
 150  }
 151  
 152  // Named adds a new path segment to the logger's name. Segments are joined by
 153  // periods. By default, Loggers are unnamed.
 154  func (log *Logger) Named(s string) *Logger {
 155  	if s == "" {
 156  		return log
 157  	}
 158  	l := log.clone()
 159  	if log.name == "" {
 160  		l.name = s
 161  	} else {
 162  		l.name = strings.Join([]string{l.name, s}, ".")
 163  	}
 164  	return l
 165  }
 166  
 167  // WithOptions clones the current Logger, applies the supplied Options, and
 168  // returns the resulting Logger. It's safe to use concurrently.
 169  func (log *Logger) WithOptions(opts ...Option) *Logger {
 170  	c := log.clone()
 171  	for _, opt := range opts {
 172  		opt.apply(c)
 173  	}
 174  	return c
 175  }
 176  
 177  // With creates a child logger and adds structured context to it. Fields added
 178  // to the child don't affect the parent, and vice versa. Any fields that
 179  // require evaluation (such as Objects) are evaluated upon invocation of With.
 180  func (log *Logger) With(fields ...Field) *Logger {
 181  	if len(fields) == 0 {
 182  		return log
 183  	}
 184  	l := log.clone()
 185  	l.core = l.core.With(fields)
 186  	return l
 187  }
 188  
 189  // WithLazy creates a child logger and adds structured context to it lazily.
 190  //
 191  // The fields are evaluated only if the logger is further chained with [With]
 192  // or is written to with any of the log level methods.
 193  // Until that occurs, the logger may retain references to objects inside the fields,
 194  // and logging will reflect the state of an object at the time of logging,
 195  // not the time of WithLazy().
 196  //
 197  // WithLazy provides a worthwhile performance optimization for contextual loggers
 198  // when the likelihood of using the child logger is low,
 199  // such as error paths and rarely taken branches.
 200  //
 201  // Similar to [With], fields added to the child don't affect the parent, and vice versa.
 202  func (log *Logger) WithLazy(fields ...Field) *Logger {
 203  	if len(fields) == 0 {
 204  		return log
 205  	}
 206  	return log.WithOptions(WrapCore(func(core zapcore.Core) zapcore.Core {
 207  		return zapcore.NewLazyWith(core, fields)
 208  	}))
 209  }
 210  
 211  // Level reports the minimum enabled level for this logger.
 212  //
 213  // For NopLoggers, this is [zapcore.InvalidLevel].
 214  func (log *Logger) Level() zapcore.Level {
 215  	return zapcore.LevelOf(log.core)
 216  }
 217  
 218  // Check returns a CheckedEntry if logging a message at the specified level
 219  // is enabled. It's a completely optional optimization; in high-performance
 220  // applications, Check can help avoid allocating a slice to hold fields.
 221  func (log *Logger) Check(lvl zapcore.Level, msg string) *zapcore.CheckedEntry {
 222  	return log.check(lvl, msg)
 223  }
 224  
 225  // Log logs a message at the specified level. The message includes any fields
 226  // passed at the log site, as well as any fields accumulated on the logger.
 227  // Any Fields that require  evaluation (such as Objects) are evaluated upon
 228  // invocation of Log.
 229  func (log *Logger) Log(lvl zapcore.Level, msg string, fields ...Field) {
 230  	if ce := log.check(lvl, msg); ce != nil {
 231  		ce.Write(fields...)
 232  	}
 233  }
 234  
 235  // Debug logs a message at DebugLevel. The message includes any fields passed
 236  // at the log site, as well as any fields accumulated on the logger.
 237  func (log *Logger) Debug(msg string, fields ...Field) {
 238  	if ce := log.check(DebugLevel, msg); ce != nil {
 239  		ce.Write(fields...)
 240  	}
 241  }
 242  
 243  // Info logs a message at InfoLevel. The message includes any fields passed
 244  // at the log site, as well as any fields accumulated on the logger.
 245  func (log *Logger) Info(msg string, fields ...Field) {
 246  	if ce := log.check(InfoLevel, msg); ce != nil {
 247  		ce.Write(fields...)
 248  	}
 249  }
 250  
 251  // Warn logs a message at WarnLevel. The message includes any fields passed
 252  // at the log site, as well as any fields accumulated on the logger.
 253  func (log *Logger) Warn(msg string, fields ...Field) {
 254  	if ce := log.check(WarnLevel, msg); ce != nil {
 255  		ce.Write(fields...)
 256  	}
 257  }
 258  
 259  // Error logs a message at ErrorLevel. The message includes any fields passed
 260  // at the log site, as well as any fields accumulated on the logger.
 261  func (log *Logger) Error(msg string, fields ...Field) {
 262  	if ce := log.check(ErrorLevel, msg); ce != nil {
 263  		ce.Write(fields...)
 264  	}
 265  }
 266  
 267  // DPanic logs a message at DPanicLevel. The message includes any fields
 268  // passed at the log site, as well as any fields accumulated on the logger.
 269  //
 270  // If the logger is in development mode, it then panics (DPanic means
 271  // "development panic"). This is useful for catching errors that are
 272  // recoverable, but shouldn't ever happen.
 273  func (log *Logger) DPanic(msg string, fields ...Field) {
 274  	if ce := log.check(DPanicLevel, msg); ce != nil {
 275  		ce.Write(fields...)
 276  	}
 277  }
 278  
 279  // Panic logs a message at PanicLevel. The message includes any fields passed
 280  // at the log site, as well as any fields accumulated on the logger.
 281  //
 282  // The logger then panics, even if logging at PanicLevel is disabled.
 283  func (log *Logger) Panic(msg string, fields ...Field) {
 284  	if ce := log.check(PanicLevel, msg); ce != nil {
 285  		ce.Write(fields...)
 286  	}
 287  }
 288  
 289  // Fatal logs a message at FatalLevel. The message includes any fields passed
 290  // at the log site, as well as any fields accumulated on the logger.
 291  //
 292  // The logger then calls os.Exit(1), even if logging at FatalLevel is
 293  // disabled.
 294  func (log *Logger) Fatal(msg string, fields ...Field) {
 295  	if ce := log.check(FatalLevel, msg); ce != nil {
 296  		ce.Write(fields...)
 297  	}
 298  }
 299  
 300  // Sync calls the underlying Core's Sync method, flushing any buffered log
 301  // entries. Applications should take care to call Sync before exiting.
 302  func (log *Logger) Sync() error {
 303  	return log.core.Sync()
 304  }
 305  
 306  // Core returns the Logger's underlying zapcore.Core.
 307  func (log *Logger) Core() zapcore.Core {
 308  	return log.core
 309  }
 310  
 311  // Name returns the Logger's underlying name,
 312  // or an empty string if the logger is unnamed.
 313  func (log *Logger) Name() string {
 314  	return log.name
 315  }
 316  
 317  func (log *Logger) clone() *Logger {
 318  	clone := *log
 319  	return &clone
 320  }
 321  
 322  func (log *Logger) check(lvl zapcore.Level, msg string) *zapcore.CheckedEntry {
 323  	// Logger.check must always be called directly by a method in the
 324  	// Logger interface (e.g., Check, Info, Fatal).
 325  	// This skips Logger.check and the Info/Fatal/Check/etc. method that
 326  	// called it.
 327  	const callerSkipOffset = 2
 328  
 329  	// Check the level first to reduce the cost of disabled log calls.
 330  	// Since Panic and higher may exit, we skip the optimization for those levels.
 331  	if lvl < zapcore.DPanicLevel && !log.core.Enabled(lvl) {
 332  		return nil
 333  	}
 334  
 335  	// Create basic checked entry thru the core; this will be non-nil if the
 336  	// log message will actually be written somewhere.
 337  	ent := zapcore.Entry{
 338  		LoggerName: log.name,
 339  		Time:       log.clock.Now(),
 340  		Level:      lvl,
 341  		Message:    msg,
 342  	}
 343  	ce := log.core.Check(ent, nil)
 344  	willWrite := ce != nil
 345  
 346  	// Set up any required terminal behavior.
 347  	switch ent.Level {
 348  	case zapcore.PanicLevel:
 349  		ce = ce.After(ent, terminalHookOverride(zapcore.WriteThenPanic, log.onPanic))
 350  	case zapcore.FatalLevel:
 351  		ce = ce.After(ent, terminalHookOverride(zapcore.WriteThenFatal, log.onFatal))
 352  	case zapcore.DPanicLevel:
 353  		if log.development {
 354  			ce = ce.After(ent, terminalHookOverride(zapcore.WriteThenPanic, log.onPanic))
 355  		}
 356  	}
 357  
 358  	// Only do further annotation if we're going to write this message; checked
 359  	// entries that exist only for terminal behavior don't benefit from
 360  	// annotation.
 361  	if !willWrite {
 362  		return ce
 363  	}
 364  
 365  	// Thread the error output through to the CheckedEntry.
 366  	ce.ErrorOutput = log.errorOutput
 367  
 368  	addStack := log.addStack.Enabled(ce.Level)
 369  	if !log.addCaller && !addStack {
 370  		return ce
 371  	}
 372  
 373  	// Adding the caller or stack trace requires capturing the callers of
 374  	// this function. We'll share information between these two.
 375  	stackDepth := stacktrace.First
 376  	if addStack {
 377  		stackDepth = stacktrace.Full
 378  	}
 379  	stack := stacktrace.Capture(log.callerSkip+callerSkipOffset, stackDepth)
 380  	defer stack.Free()
 381  
 382  	if stack.Count() == 0 {
 383  		if log.addCaller {
 384  			fmt.Fprintf(log.errorOutput, "%v Logger.check error: failed to get caller\n", ent.Time.UTC())
 385  			_ = log.errorOutput.Sync()
 386  		}
 387  		return ce
 388  	}
 389  
 390  	frame, more := stack.Next()
 391  
 392  	if log.addCaller {
 393  		ce.Caller = zapcore.EntryCaller{
 394  			Defined:  frame.PC != 0,
 395  			PC:       frame.PC,
 396  			File:     frame.File,
 397  			Line:     frame.Line,
 398  			Function: frame.Function,
 399  		}
 400  	}
 401  
 402  	if addStack {
 403  		buffer := bufferpool.Get()
 404  		defer buffer.Free()
 405  
 406  		stackfmt := stacktrace.NewFormatter(buffer)
 407  
 408  		// We've already extracted the first frame, so format that
 409  		// separately and defer to stackfmt for the rest.
 410  		stackfmt.FormatFrame(frame)
 411  		if more {
 412  			stackfmt.FormatStack(stack)
 413  		}
 414  		ce.Stack = buffer.String()
 415  	}
 416  
 417  	return ce
 418  }
 419  
 420  func terminalHookOverride(defaultHook, override zapcore.CheckWriteHook) zapcore.CheckWriteHook {
 421  	// A nil or WriteThenNoop hook will lead to continued execution after
 422  	// a Panic or Fatal log entry, which is unexpected. For example,
 423  	//
 424  	//   f, err := os.Open(..)
 425  	//   if err != nil {
 426  	//     log.Fatal("cannot open", zap.Error(err))
 427  	//   }
 428  	//   fmt.Println(f.Name())
 429  	//
 430  	// The f.Name() will panic if we continue execution after the log.Fatal.
 431  	if override == nil || override == zapcore.WriteThenNoop {
 432  		return defaultHook
 433  	}
 434  	return override
 435  }
 436