Zap Concepts

From NovaOrdis Knowledge Base
Jump to navigation Jump to search

External

Internal

Overview

Zap is a logging framework for Go. It provides fast, structured, contextual and leveled logging.

The programming model involves creating a Logger object and invoking its API, for example logger.Info(...). Creation of Logger instances can be done in a number of way that are explored in the Logger Instance Creation section. There are actually two logging APIs, zap.Logger and zap.SugaredLogger. The former is appropriate for high-performance scenarios, but only supports a structured logging method signatures, while the latter has a more friendlier, and just slightly less performant syntax which is similar to that of fmt.Sprintf(). The difference is discussed in Two Logging APIs section.

Each logging invocation creates a log event with key/value pairs, as explained in Structured Logging. The rendering of the log events can be changed through configuration. These aspects are discussed in the Log Rendering section.

There is no global logger that can be used right away, though one can be configured as shown in Global Logger Instance. Use of global loggers should be avoided, though.

Zap supports the standard DEBUG, INFO, WARN and ERROR logging levels. It comes with a few new ones: PANIC, DPANIC and FATAL. The ERROR level requires special attention. There is no TRACE. More details are available in the Logging Levels section.

By default, loggers are unbuffered. This aspect is discussed in the Buffering section.

Implementation aspects are discussed in Implementation Details.

Best Practices

Encapsulate the logic that configures and creates loggers into a logging package. The package should create the loggers, and should manage the number of loggers used by the application.

If the application needs a logger, it should request it via logging.Get(...) *zap.Logger kind of exported method. The Get() methods could use the singleton initialization pattern based on sync.Once synchronization primitive.

Zap documentation seems to recommend passing logger instances as function parameters. Why is this a good idea?

Can I use a single instance? Is it thread safe? Sharing or not sharing logger instances?

Understand how I can get a logger instance “out of the blue” and how I can build a set of predefined loggers. Must figure out logging situation in tests. I must be able to start a test in debug mode and see the log.

Use a typical usage section?

import "go.uber.org/zap"

...

var config zap.Config
var logger *zap.Logger
var sugaredLogger *zap.SugaredLogger
outputPath := "stderr" // ... or a local path
config = zap.NewDevelopmentConfig()
config.OutputPaths = []string{outputPath}
config.ErrorOutputPaths = []string{outputPath}
logger, err := config.Build()
if err != nil {
  panic(err)
}
sugaredLogger = logger.Sugar()
sugaredLogger.Infof("somehting")
...
logger = sugaredLogger.Desugar()

Logger Instance Creation and Configuration

Pre-configured loggers are available. Custom-configured instances can be created via two other methods: building a configuration first and using the configuration to instantiate a logger, or programmatically creating and configuring a zapcore.Core.

Pre-configured Loggers

The framework comes with three preset constructors: zap.NewExample(), zap.NewProduction(...) and zap.NewDevelopment(...). Each of these constructors internally create a logging core and set its encoder, output and level. These components are configured according to the type of logger. In case of the example logger, the encoder produces JSON structures that contain only two keys "level" and "msg", the default log level is DEBUG and the logs are send to stdout. In case of a production logger, the encoder produces JSON structures that contain "level", "ts", "msg" and "caller", the default log level is INFO, the "normal" logging is sent to stdout and error logging is sent to stderr and sampling is enabled. In case of a development logger, the encoder produces "console" encoding, which are human readable messages, the default log level is DEBUG, the "normal" logging is sent to stdout and error logging is sent to stderr and sampling is disabled.

logger := zap.NewExample()
logger, err := zap.NewProduction(...)

// To turn the error into a panic if it occurs, and simplify the code: 
logger := zap.Must(zap.NewProduction(...))
logger, err := zap.NewDevelopment(...)

These instances are OK if their configuration matches the use case.

Configuration-Driven Logger Creation

An alternative to the prepackaged configuration constructors zap.NewDevelopmentConfig() and zap.NewProductionConfig() is creating the logger by instantiating a zap.Config struct, and then invoking Build() on it to create the logger. Note that zap.Config intentionally supports only the most common options. More unusual logging setups, such as logging to network connections or message queues, splitting output between multiple files, etc. are possible, but require direct use of the zapcore package, as shown in the Low-Level Logger Creation section.

An example of creating a logger by creating configuration instance first is:

config := zap.NewDevelopmentConfig()
// update configuration as you like ...
logger, err := config.Build()

zap.Config contains many of the most common configuration options desired when creating a new Logger. The configuration can also be created from scratch:

// The 'loggingLevel' instance can be used to dynamically update the level of the active logger.
loggingLevel, err = zap.ParseAtomicLevel("info")
if err != nil {
  ...
}
encoderConfig := zapcore.EncoderConfig{
	TimeKey:        "timestamp",
	LevelKey:       "level",
	NameKey:        "logger",
	CallerKey:      "caller",
	FunctionKey:    zapcore.OmitKey,
	MessageKey:     "msg",
	StacktraceKey:  "stacktrace",
	LineEnding:     zapcore.DefaultLineEnding,
	EncodeLevel:    zapcore.LowercaseLevelEncoder,
	EncodeTime:     zapcore.ISO8601TimeEncoder,
	EncodeDuration: zapcore.SecondsDurationEncoder,
	EncodeCaller:   zapcore.ShortCallerEncoder,
}
loggerConfig := zap.Config{
	Level:             loggingLevel,
	Development:       false,
	DisableCaller:     false,
	DisableStacktrace: true,
	Sampling:          nil,
	Encoding:          "console",
	EncoderConfig:     encoderConfig,
	OutputPaths:       []string{"stdout"},
	ErrorOutputPaths:  []string{"stdout"},
	InitialFields: map[string]interface{}{
		"pid": os.Getpid(),
	},
}

logger, err := loggerConfig.Build()
if err != nil {
  ...
}

Configuration Options

  • level The minimum enabled logging level. The level can be dynamically changed at runtime with Config.Level.SetLevel() for all logger descended from the Config instance the function was called on.
  • development This field puts the logger in development mode, which changes the behavior of DPanic logging level.
  • disableCaller Setting this field to true stops annotating logs with the calling function's file name and line number. By default, all logs are annotated.
  • disableStacktrace Setting this field to true completely disables automatic stack trace capturing. By stack traces are captured for Warn level and above logs in development and Error level and above in production.
  • sampling Set a sampling| policy. A nil SamplingConfig disables sampling.
  • encoding Sets the logger's encoding. Valid values are "json", "console" and any third-party encoders registered via RegisterEncoder. Also see Log Rendering below.
  • encoderConfig Sets options for the chosen encoder.
  • outputPaths A list of URLs or file paths to write logging output to.
  • errorOutputPaths A list of URLs to write internal logger errors to. The default is standard error. Note that this setting only affects internal errors. For sample code that sends error-level logs to a different location from info- and debug-level logs, see the package-level AdvancedConfiguration example.
  • initialFields Specifies global contextual fields that should be included in every long entry produced by each logger that was built from this Config object.

Low-Level Logger-Creation

An example of creating a logger by programmatically creating and configuring a zapcore.Core instance is:

encoderCfg := zapcore.EncoderConfig{
	MessageKey:     "msg",
	LevelKey:       "level",
	NameKey:        "logger",
	EncodeLevel:    zapcore.LowercaseLevelEncoder,
	EncodeTime:     zapcore.ISO8601TimeEncoder,
	EncodeDuration: zapcore.StringDurationEncoder,
}
core := zapcore.NewCore(zapcore.NewJSONEncoder(encoderCfg), os.Stdout, DebugLevel)
logger := zap.New(core)

Cores may form a tree hierarchy:

core := zapcore.NewTee(zapcore.NewCore(...), zapcore.NewCore(...))

Global Logger Instance

Unlike most other logging packages for Go, Zap does not provide a pre-configured global logger for use. It does provide the API for it, so if you prefer to use a global logger, you could use zap.ReplaceGlobals(), perhaps in your package's init() function, as shown below. However, use of global loggers should be avoided.

zap.ReplaceGlobal(zap.Must(zap.NewProduction()) // or use any other custom configuration you desire
...
zap.L().Info("test")

Two Logging APIs

Zap provides to APIs for logging: zap.Logger and zap.SugaredLogger.

Choosing between Logger and SugaredLogger does not need to be an application-wide decision, the instances implementing these APIs can be converted into each other with negligible performance penalty as shown below. A typical pattern is to use the SugaredLogger API throughout the code, for convenience, then convert it to a Logger at the boundaries of performance-sensitive code.

logger := ...
sugaredLogger := logger.Sugar()
plainLogger := sugar.Desugar()

zap.Logger

zap.Logger is a low-level API aimed for performance-sensitive scenarios. It only supports a structured logging method signatures, with strongly typed fields. It strives to avoid serialization overhead and allocations whenever possible. The logger has a single method fore each supported log levels (Debug(), Info(), Warn(), etc.), and each method accept a message parameter, which will surface as the "msg" key/value pair in the structured log entry, and zero or more zap.Fields, which are strongly typed key/value pairs and will surface as key/value pairs in the structured log entry.

log.Info("this is the message", zap.String("someString", "blue"), zap.Int("someInt", 15))

will generate:

{"level":"info","msg":"this is the message","someString":"blue","someInt":15}

zap.SugaredLogger

zap.SugaredLogger has a friendlier, loosely typed, more convenient API that just slightly less performant. The syntax which is similar to that of fmt.Sprintf(). Internally, zap.SugaredLogger delegates to a zap.Logger instance. The logger exposes a series of methods for each logging level:

  • Info(): all arguments are loosely typed. The method uses fmt.Sprint() to concatenate the arguments into the msg log entry field.
  • Infoln(): Same as above, except that it adds a new line to the message with fmt.Sprintln().
  • Infof(): the first argument is a format string, followed by arguments for conversion characters, in the fmt.Sprintf() style. The format string and the arguments are rendered into the content of the msg log entry field.
  • Infow(): the first argument is the message, followed by a variable number of key/value pairs, as zap.String(), etc. The method allows you to add a mix of strongly and loosely typed key/value pairs. The log message is the first argument. Subsequent arguments are expected to be key/value pairs. Note that for the loosely typed key/value pairs, the keys are always expected to be strings, while the values can be of any type. If you use a non-string key, the program will panic in development and a separate error will logged, and the key/value pair will be ignored in production. Passing an orphaned key behaves similarly. Due to all these caveats, we recommend using strongly-typed contextual fields at all times.

Structured Logging

Structured logging is a technique that generates log events rendered in a well-defined format, typically JSON or key-value pairs. This approach allows efficient searching and filtering, making the log entires machine-readable.

Each logging invocation creates a log event. Zap calls these events log entries. The log entries are implemented as zapcore.Entry struct instances, so each carry by default the structure's fields, also known as logging fields: logging level, timestamp, logger name, message, caller and stack. The caller is a string containing the source code location where the log invocation was done, in form of <package>/<file-name>.go:<line>.

Zap API consistently allows specifying a message in addition to key-value pairs. Subjectively, we find it helpful to accompany structured context with a brief description. This is not critical during development, but it makes debugging and operating unfamiliar system much easier.

Also see:

Structured Logging

Contextual Logging

Contextual logging with Zap is done by passing strongly typed key/value pairs alongside the log message.

Child loggers can be used to add contextual properties to all the logs produced in a specific scope. This helps avoiding unnecessary repetition at log point. A child logger is created calling With() on a parent logger:

log := ...
childLog := log.With(zap.String("color", "red"))
childLog.Info(...)

A similar mechanism can be applied to zapcore.Core.

Also see:

Logging

Log Rendering

The external representation of a log entry is produced by an encoder. The default encoder generates JSON structures, where the log entry's fields are represented as JSON map elements.

zapcore.NewConsoleEncoder()
zapcore.NewJSONEncoder()

The encoder constructors take EncoderConfig instances. The encoder for a logger is configured with the encoding field of the configuration.

Logging Levels

Internally, the logging level are implemented as constants (zap.DebugLevel, zap.InfoLevel, zap.WarnLevel, zap.ErrorLevel, zap.DPanicLevel, zap.PanicLevel, zap.FatalLevel).

DebugLevel

Debugging messages. Debug logs are typically voluminous, and are usually disabled in production.

InfoLevel

Messages describing normal application operations. This is the default logging priority.

WarnLevel

Messages indicating that something unusual happened that may need attention before it escalates to a more severe issue. Warning log entries are more important than info log entries, but don't need individual human review..

ErrorLevel

An unexpected error condition in the program. Error log entries are high-priority. If an application is running smoothly, it shouldn't generate any error-level logs.

zap.Error*() methods issue log events configured by default with ErrorLevel. A stacktrace field is automatically added to the log entry by the Error*() methods.

DPanicLevel

A severe error condition. It behaves like PanicLevel in development and ErrorLevel in production. The behavior of the logger can be changed by configuring the development field of the configuration the logger was created from.

PanicLevel

Calls panic() after logging an error condition.

FatalLevel

The zap.Fatal*() methods issue FatalLevel log entries. After logging such an event, the method calls os.Exit(1).

Buffering

By default, loggers are unbuffered. However, since Zap's low-level API allows buffering, it's a good practice to call Sync() before the process exits:

logger := zap.Must(zap.NewDevelopment(...))
defer logger.Sync()

Loggers and context.Context

https://betterstack.com/community/guides/logging/go/zap/#logging-with-zap-in-a-go-application

Also see:

The context Package

Implementation Details

Each zap.Logger wraps around a core, which is configured with an encoder, an output and a logging level:

Zap.png

An encoder is the component that renders the external representation of the log entry instances. The default encoder is a JSON encoder, which renders entries as JSON structures. The encoder instance can be configured with a zapcore.EncoderConfig structure.

Advanced Use

Disable Stack Trace Rendering

Stack trace on Warning is probably not necessary. However, this disable stack trace rendering altogether:

var config zap.Config
config = zap.NewDevelopmentConfig()
config.DisableStacktrace = true

Change Log Level Dynamically

Create the logger instance with an external zap.AtomicLevel instance. Updating the level on that instance updates it dynamically for the logger:

atomicLevel := zap.NewAtomicLevelAt(zap.DebugLevel)
var config zap.Config
config = zap.NewDevelopmentConfig()
config.Level = atomicLevel // use the instance, updating the level on that instance will dynamically update the logging level
logger, err := config.Build()
...

// this changes the logging level dynamically
atomicLevel.SetLevel(zap.InfoLevel)

Multi-Output Logging

Custom Logging Levels

https://blog.stackademic.com/elevating-your-application-monitoring-golangs-logging-best-practices-7107d57c1fc5#b1ae

Log Rotation

https://github.com/uber-go/zap/blob/master/FAQ.md#does-zap-support-log-rotation

The Lumberjack package https://pkg.go.dev/gopkg.in/natefinch/lumberjack.v2 may be used to rotate log files. However, the recommended practice is to rely on external tools like logrotate instead of doing it in the application itself.

Log Sampling

https://betterstack.com/community/guides/logging/go/zap/#log-sampling-with-zap
https://github.com/uber-go/zap/blob/master/FAQ.md#why-sample-application-logs

Log sampling is a technique used to reduce application log volume by selectively capturing and recording only a subset of log events. Its purpose is to strike a balance between the need for comprehensive logging and the potential performance impact of logging too much data. Rather than capturing every single log event, log sampling selects a representative subset based on specific criterial. This way, the amount of generated log data is greatly reduced, which can be beneficial in high-throughput systems. Zap sampling algorithm uses the log message to identify duplicate entries. This is a practical middle ground between random sampling, which may drop the exact entry that you need while debugging, and hashing the complete entry, which is prohibitively expensive. The sampling policy is configured with the sampling field of the configuration.

Hiding Sensitive Data in Logs

https://betterstack.com/community/guides/logging/go/zap/#hiding-sensitive-details-in-your-logs

Custom Encoders

https://betterstack.com/community/guides/logging/go/zap/#some-caveats-with-custom-encoders

Using Zap as Backend for Slog

https://betterstack.com/community/guides/logging/go/zap/#using-zap-as-a-backend-for-slog