Introduction to Golang Zap
Zap was birthed from Uber's need for a high-speed logger that could keep pace with its voluminous, high-throughput applications without being the system's bottleneck. Traditional loggers often produce a significant overhead, slowing down applications and, in high-velocity contexts, can even drop logs. Furthermore, in distributed systems and microservices architectures – like those employed at Uber – the ability to produce structured logs becomes paramount for tracing, monitoring, and debugging.
Zap's design principles centered around performance and safety. With its unique design, Zap claims to be one of the fastest loggers in Go. But speed isn't its only forte; Zap also provides human-friendly and machine-readable log formats, catering to both developers and log aggregation systems.
Comparison with Other Logging Packages in Go:
- Standard Library's
logPackage: The built-inlogpackage in Go is straightforward and suitable for basic logging needs. However, it lacks the flexibility and performance optimizations that Zap offers. Zap provides structured logging, which the standard library does not support. - Logrus: Before Zap's emergence, Logrus was one of the most popular logging libraries in Go. It offers a more feature-rich interface compared to the standard library. Logrus provides structured logging and a pluggable architecture. However, in terms of raw performance, Zap has the edge due to its design optimizations.
- Go-kit's log: Go-kit is a toolkit for building microservices in Go, and it includes its own logging interface. While it offers structured logging, its primary focus is on compatibility and interoperability, making it somewhat slower than Zap.
- Zerolog and Go-logr: Both of these libraries, like Zap, emphasize performance and zero memory allocation in their design. They offer similar speed and structure, but their APIs and additional features may vary.
Installation and Setup of Zap in Go
When it comes to Go, adding external dependencies is straightforward with the help of Go Modules. Introduced in Go 1.11, modules have since become the de-facto package management solution, making dependency management a breeze.
To integrate Zap into your project, you'll need to fetch the Zap package:
go get -u go.uber.org/zap
This command instructs the Go toolchain to fetch the latest version of Zap and update your project's go.mod and go.sum files accordingly.
Alternatively if you already have initialized a module (go mod init <your-module-name>, in such case you can just execute go mod tidy and that should download zap and any dependent packages.
Understanding the Logger and SugaredLogger from ZAP
Zap provides two primary types of loggers: Logger and SugaredLogger.
Logger
The core Logger in Zap provides ultra-fast, leveled, structured logging. Every log message emitted by a core Logger is strongly typed. This ensures a high performance but at the cost of slightly less user-friendly syntax.
package main
import (
"go.uber.org/zap"
)
func main() {
logger, _ := zap.NewProduction()
defer logger.Sync()
logger.Info("This is an info log with fields", zap.String("key", "value"))
}
Output:
{"level":"info","ts":1257894000,"caller":"sandbox2337442541/prog.go:10","msg":"This is an info log with fields","key":"value"}
SugaredLogger
The SugaredLogger, on the other hand, trades some performance for a more developer-friendly API. It's slightly slower than the core Logger, but it's still faster than many other logging packages. The sugaring is essentially syntactic sugar, making logging more convenient and flexible.
package main
import (
"go.uber.org/zap"
)
func main() {
logger, _ := zap.NewProduction()
defer logger.Sync()
sugar := logger.Sugar()
sugar.Infof("This is a sugared %s log with fields", "info", "key", "value")
}
Output:
{"level":"info","ts":1257894000,"caller":"sandbox2549994747/prog.go:11","msg":"This is a sugared info log with fields%!(EXTRA string=key, string=value)"}
Performance comparison (Logger Vs SugaredLogger)
Let us run some benchmark tests to compare the performance of Logger Vs SugaredLogger, here is my main_test.go:
package main
import (
"testing"
"go.uber.org/zap"
)
func getFileLogger(filename string) *zap.Logger {
cfg := zap.NewProductionConfig()
cfg.OutputPaths = []string{filename}
cfg.ErrorOutputPaths = []string{filename}
logger, _ := cfg.Build()
return logger
}
func BenchmarkLogger(b *testing.B) {
logger := getFileLogger("logger_output.log")
defer logger.Sync()
b.ResetTimer()
for i := 0; i < b.N; i++ {
logger.Info("This is a structured log.",
zap.String("key", "value"),
zap.Int("count", i),
)
}
}
func BenchmarkSugaredLogger(b *testing.B) {
logger := getFileLogger("sugaredlogger_output.log")
sugar := logger.Sugar()
defer sugar.Sync()
b.ResetTimer()
for i := 0; i < b.N; i++ {
sugar.Infof("This is a sugared log with key %s and count %d.", "value", i)
}
}
When we execute this:
# go test -bench . goos: linux goarch: amd64 pkg: project cpu: Intel(R) Core(TM) i5-10310U CPU @ 1.70GHz BenchmarkLogger 4005057 252.8 ns/op BenchmarkSugaredLogger 214629 5648 ns/op PASS ok project 2.550s
Let's break down the output:
- BenchmarkLogger:
-
4005057: This means theLoggerbenchmark ran a total of 4,005,057 iterations.252.8 ns/op: On average, it took approximately 252.8 nanoseconds for each logging operation using theLogger.
- BenchmarkSugaredLogger:
-
214629: This means theSugaredLoggerbenchmark ran a total of 214,629 iterations.5648 ns/op: On average, it took approximately 5,648 nanoseconds (or 5.648 microseconds) for each logging operation using theSugaredLogger.
From this, we can conclude:
- The
Loggeris significantly faster than theSugaredLoggerfor the benchmarked operations. This is evidenced by both the higher number of iterations forLoggerand the much lower average time per operation (ns/op). - There's a trade-off between the two. While
Loggeroffers better performance,SugaredLoggerprovides more developer-friendly sugar syntax, which might be more comfortable for some developers to use.
Configuring different Log Levels
In Zap, logging levels are controlled using the zapcore.Level type. The different log levels available are:
- DebugLevel
- InfoLevel
- WarnLevel
- ErrorLevel
- DPanicLevel
- PanicLevel
- FatalLevel
Configuring a logger to use a specific log level is important when you want to filter out logs based on their severity. For instance, in a production environment, you might only want to log messages of InfoLevel and above, skipping DebugLevel messages.
Here's a brief overview of how to configure and use different log levels in Zap:
1. Configuring a Logger with a Specific Level
Here's how you can set a logger's level:
package main
import (
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
func main() {
config := zap.Config{
Level: zap.NewAtomicLevelAt(zapcore.DebugLevel),
Development: true,
Encoding: "json",
EncoderConfig: zap.NewProductionEncoderConfig(),
OutputPaths: []string{"stdout"},
ErrorOutputPaths: []string{"stderr"},
}
logger, _ := config.Build()
defer logger.Sync()
// Example logs
logger.Debug("This is a debug message.")
logger.Info("This is an info message.")
logger.Warn("This is a warning message.")
logger.Error("This is an error message.")
}
In the code above, the logger is set to the DebugLevel, so it will log messages of all levels from Debug and above.
Output:
{"level":"debug","ts":1257894000,"caller":"sandbox1385456267/prog.go:22","msg":"This is a debug message."}
{"level":"info","ts":1257894000,"caller":"sandbox1385456267/prog.go:23","msg":"This is an info message."}
{"level":"warn","ts":1257894000,"caller":"sandbox1385456267/prog.go:24","msg":"This is a warning message.","stacktrace":"main.main\n\t/tmp/sandbox1385456267/prog.go:24\nruntime.main\n\t/usr/local/go-faketime/src/runtime/proc.go:267"}
{"level":"error","ts":1257894000,"caller":"sandbox1385456267/prog.go:25","msg":"This is an error message.","stacktrace":"main.main\n\t/tmp/sandbox1385456267/prog.go:25\nruntime.main\n\t/usr/local/go-faketime/src/runtime/proc.go:267"}
2. Changing the Log Level Dynamically (AtomicLevel)
In Zap, the concept of an "atomic level" refers to the ability to safely change a logger's level at runtime in a concurrent environment without causing data races. This capability is particularly useful when building applications that might require dynamic log level adjustments, like during debugging or when a specific event triggers a need for more detailed logging.
An AtomicLevel encapsulates a safely-changeable logging level. It's called "atomic" because the underlying operations to set and get the level are atomic operations. This means that they're automatically synchronized, ensuring that even if multiple goroutines are attempting to read or write the level concurrently, they won't interfere with each other or cause race conditions.
Basic AtomicLevel Setup:
package main
import (
"fmt"
"go.uber.org/zap"
)
func main() {
// Create an AtomicLevel, initially set to InfoLevel
atomicLevel := zap.NewAtomicLevelAt(zap.InfoLevel)
// Create a logger configuration that uses the AtomicLevel
config := zap.Config{
Level: atomicLevel,
Development: true,
Encoding: "console",
EncoderConfig: zap.NewProductionEncoderConfig(),
OutputPaths: []string{"stdout"},
ErrorOutputPaths: []string{"stderr"},
}
// Check for errors when building the logger
logger, err := config.Build()
if err != nil {
fmt.Printf("Failed to create logger: %v\n", err)
return
}
defer logger.Sync()
if logger == nil {
fmt.Println("Logger is nil!")
return
}
logger.Info("This message will be logged because the level is set to Info.")
atomicLevel.SetLevel(zap.DebugLevel)
logger.Debug("This message will be logged because the level is now set to Debug.")
}
Output:
1.257894e+09 info sandbox2825592330/prog.go:36 This message will be logged because the level is set to Info. 1.257894e+09 debug sandbox2825592330/prog.go:38 This message will be logged because the level is now set to Debug.
2. Dynamically Changing Log Level:
Imagine a web service where you can adjust the log level dynamically through an endpoint:
package main
import (
"net/http"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
var atomicLevel = zap.NewAtomicLevelAt(zap.InfoLevel)
var logger *zap.Logger
func main() {
config := zap.Config{
Level: atomicLevel,
Development: true,
Encoding: "json",
EncoderConfig: zap.NewProductionEncoderConfig(),
OutputPaths: []string{"stdout"},
ErrorOutputPaths: []string{"stderr"},
}
var err error
logger, err = config.Build()
if err != nil {
panic(err)
}
defer logger.Sync()
http.HandleFunc("/set-level/", setLogLevel)
http.ListenAndServe(":8080", nil)
}
func setLogLevel(w http.ResponseWriter, r *http.Request) {
level := r.URL.Query().Get("level")
switch level {
case "debug":
atomicLevel.SetLevel(zapcore.DebugLevel)
case "info":
atomicLevel.SetLevel(zapcore.InfoLevel)
case "warn":
atomicLevel.SetLevel(zapcore.WarnLevel)
case "error":
atomicLevel.SetLevel(zapcore.ErrorLevel)
default:
w.WriteHeader(http.StatusBadRequest)
w.Write([]byte("Invalid level."))
return
}
w.Write([]byte("Log level set successfully."))
}
With the above setup, you can dynamically change the log level by visiting, for example, http://localhost:8080/set-level/?level=debug.
Formatting Options with Golang ZAP
Zap is a structured logger, and it prioritizes structured logging over printf-style formatting. This is one of the aspects that sets Zap apart from some other logging libraries. However, Zap does offer ways to format your logs, especially through its encoder configurations.
Here's an overview of the formatting and customization available in Zap:
- Encoding: Zap supports two primary types of encoding for log outputs:
- JSON: This is a common format, especially useful when your logs are ingested by tools that can parse and search through JSON formatted logs (like the ELK stack or other log management systems).
- Console: This format outputs logs in a human-readable format which is more suitable for local development or reading logs directly from the console.The encoding type can be set using the
Encodingfield in thezap.Configstruct.
- EncoderConfig: This allows customization of the encoding, offering fields like:
TimeKey,LevelKey,NameKey,CallerKey: Define the key names for the respective fields in the log output.FunctionKey: If you want to log the name of the function, this defines its key name.MessageKey: Defines the key name for the log message.StacktraceKey: Defines the key name for the stack trace, if any.LineEnding: Defines the line ending format, e.g.,zap.DefaultLineEndingis\n.EncodeLevel: Determines how the log level is encoded (e.g.,zapcore.CapitalLevelEncoderwill encodeinfoasINFO).EncodeTime: Determines how the timestamp is encoded. You can set tozapcore.ISO8601TimeEncoderfor an ISO8601 formatted timestamp, among other options.EncodeDuration: Determines how durations are encoded, e.g., turning a duration into a human-readable string.EncodeCaller: Determines how the caller information (<a title="Print Function, File Name, Line Number in GO [SOLVED]" href="https://www.golinuxcloud.com/logrus-print-function-file-name-line-number/" target="_blank" rel="noopener noreferrer">file and line number</a>) is encoded.
- Field Formatting: When adding fields to logs, you can use different types which will be formatted appropriately:
zap.String(key, val): Adds a string field.zap.Int(key, val): Adds an integer field.zap.Duration(key, val): Adds a duration field which will be formatted using the encoder's duration formatter.- ... and many more field types.
Here's a comprehensive example that showcases various formatting options available in Zap, for both the core Logger and SugaredLogger.
package main
import (
"os"
"time"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
func main() {
// Define custom encoder configuration
encoderConfig := zapcore.EncoderConfig{
TimeKey: "timestamp",
LevelKey: "level",
NameKey: "logger",
CallerKey: "caller",
MessageKey: "message",
StacktraceKey: "stacktrace",
LineEnding: zapcore.DefaultLineEnding,
EncodeLevel: zapcore.CapitalLevelEncoder, // Capitalize the log level names
EncodeTime: zapcore.ISO8601TimeEncoder, // ISO8601 UTC timestamp format
EncodeDuration: zapcore.SecondsDurationEncoder, // Duration in seconds
EncodeCaller: zapcore.ShortCallerEncoder, // Short caller (file and line)
}
// Create a core logger with JSON encoding
core := zapcore.NewCore(
zapcore.NewJSONEncoder(encoderConfig), // Using JSON encoder
zapcore.NewMultiWriteSyncer(zapcore.AddSync(os.Stdout)),
zap.InfoLevel,
)
logger := zap.New(core)
defer logger.Sync() // Sync writes logs to the writers (in this case, stdout)
// Basic structured logging with Logger
logger.Info("Structured logging with Logger",
zap.String("stringField", "stringValue"),
zap.Int("intField", 42),
zap.Duration("durationField", time.Second*3), // This will use the SecondsDurationEncoder format
)
// Using SugaredLogger for printf-style logging
sugar := logger.Sugar()
sugar.Infof("Printf-style logging with SugaredLogger: %s = %d", "intField", 42)
// SugaredLogger supports adding structured context
sugar.With(
zap.String("contextField", "contextValue"),
).Infof("Printf-style logging with context: %s", "additional info")
// Demonstrating other field types with Logger
logger.Info("Demonstrating other field types",
zap.Bool("boolField", true),
zap.Float64("floatField", 3.14),
zap.Time("timeField", time.Now()),
zap.Any("anyField", map[string]int{"key": 1}), // Use zap.Any for any supported type
)
}
Output:
{"level":"INFO","timestamp":"2009-11-10T23:00:00.000Z","message":"Structured logging with Logger","stringField":"stringValue","intField":42,"durationField":3}
{"level":"INFO","timestamp":"2009-11-10T23:00:00.000Z","message":"Printf-style logging with SugaredLogger: intField = 42"}
{"level":"INFO","timestamp":"2009-11-10T23:00:00.000Z","message":"Printf-style logging with context: additional info","contextField":"contextValue"}
{"level":"INFO","timestamp":"2009-11-10T23:00:00.000Z","message":"Demonstrating other field types","boolField":true,"floatField":3.14,"timeField":"2009-11-10T23:00:00.000Z","anyField":{"key":1}}
Setting custom Time Format
In zap, the time format is determined by the EncodeTime function within the EncoderConfig structure. By default, zap provides a few time encoders like ISO8601TimeEncoder, EpochTimeEncoder, etc. However, if you want a specific format, you need to define a custom function.
encoderConfig.EncodeTime = func(t time.Time, enc zapcore.PrimitiveArrayEncoder) {
enc.AppendString(t.Format("2006-01-02 15:04:05"))
}
Adding and Customizing Log Fields
With zap, you can add fields to your logs that provide more context about the event being logged. Let's take a look at how you can add and customize these fields.
With the Logger, you add fields by chaining them with the log message. Here's an example:
logger.Info("A log message",
zap.String("key1", "value1"),
zap.Int("key2", 42),
)
With the SugaredLogger, you can use structured context:
sugar.With(
zap.String("key1", "value1"),
).Infof("A log message with key2=%d", 42)
Here's a comprehensive example that integrates both custom time formats and adding/customizing log fields:
package main
import (
"os"
"time"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
func main() {
// Custom time format for encoder
customTimeEncoder := func(t time.Time, enc zapcore.PrimitiveArrayEncoder) {
enc.AppendString(t.Format("02 Jan 2006 15:04:05"))
}
encoderConfig := zapcore.EncoderConfig{
TimeKey: "timestamp",
LevelKey: "level",
NameKey: "logger",
CallerKey: "caller",
MessageKey: "message",
StacktraceKey: "stacktrace",
LineEnding: zapcore.DefaultLineEnding,
EncodeLevel: zapcore.CapitalLevelEncoder,
EncodeTime: customTimeEncoder, // Using custom time format
EncodeDuration: zapcore.SecondsDurationEncoder,
EncodeCaller: zapcore.ShortCallerEncoder,
}
core := zapcore.NewCore(
zapcore.NewJSONEncoder(encoderConfig),
zapcore.NewMultiWriteSyncer(zapcore.AddSync(os.Stdout)),
zap.InfoLevel,
)
logger := zap.New(core)
defer logger.Sync()
// Adding custom fields with Logger
logger.Info("Logging with custom fields using Logger",
zap.String("user", "alice"),
zap.Duration("latency", time.Second*5),
)
sugar := logger.Sugar()
// Adding custom fields with SugaredLogger
sugar.With(
zap.String("user", "bob"),
).Infof("Logging with custom fields using SugaredLogger with latency=%s", time.Second*3)
}
Output:
{"level":"INFO","timestamp":"10 Nov 2009 23:00:00","message":"Logging with custom fields using Logger","user":"alice","latency":5}
{"level":"INFO","timestamp":"10 Nov 2009 23:00:00","message":"Logging with custom fields using SugaredLogger with latency=3s","user":"bob"}
Setting Output in Zap: Console, Log File, or Both
Zap provides the capability to set the output destination for logs. This can be set to the console (stdout or stderr), a file, or both. Below are examples of how to configure each.
Logging to Console
package main
import "go.uber.org/zap"
func main() {
logger, _ := zap.NewProduction()
logger.Info("INFO log level message")
logger.Warn("Warn log level message")
logger.Error("Error log level message")
}Output:
{"level":"info","ts":1257894000,"caller":"sandbox1581238468/prog.go:8","msg":"INFO log level message"}
{"level":"warn","ts":1257894000,"caller":"sandbox1581238468/prog.go:9","msg":"Warn log level message"}
{"level":"error","ts":1257894000,"caller":"sandbox1581238468/prog.go:10","msg":"Error log level message","stacktrace":"main.main\n\t/tmp/sandbox1581238468/prog.go:10\nruntime.main\n\t/usr/local/go-faketime/src/runtime/proc.go:267"}
Logging to a File
To log into a file, you can use the zapcore.AddSync function along with os.Create or os.OpenFile.
package main
import (
"os"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
func main() {
filename := "logs.log"
logger := fileLogger(filename)
logger.Info("INFO log level message")
logger.Warn("Warn log level message")
logger.Error("Error log level message")
}
func fileLogger(filename string) *zap.Logger {
config := zap.NewProductionEncoderConfig()
config.EncodeTime = zapcore.ISO8601TimeEncoder
fileEncoder := zapcore.NewJSONEncoder(config)
logFile, _ := os.OpenFile(filename, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
writer := zapcore.AddSync(logFile)
defaultLogLevel := zapcore.DebugLevel
core := zapcore.NewTee(
zapcore.NewCore(fileEncoder, writer, defaultLogLevel),
)
logger := zap.New(core, zap.AddCaller(), zap.AddStacktrace(zapcore.ErrorLevel))
return logger
}
Output in the logfile:
{"level":"info","ts":"2022-10-15T11:41:22.310+0300","caller":"zapLogger/main.go:14","msg":"INFO log level message"}
{"level":"warn","ts":"2022-10-15T11:41:22.310+0300","caller":"zapLogger/main.go:15","msg":"Warn log level message"}
{"level":"error","ts":"2022-10-15T11:41:22.310+0300","caller":"zapLogger/main.go:16","msg":"Error log level message","stacktrace":"main.main\n\t/Golinuxcloud/Go Zap/zapLogger/main.go:16\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:250"}
Logging to Both Console and File
To log to both the console and a file, use zapcore.NewTee.
package main
import (
"fmt"
"os"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
func main() {
filename := "logs.log"
logger, err := fileLogger(filename)
if err != nil {
fmt.Printf("Failed to initialize logger: %v\n", err)
return
}
defer logger.Sync() // Ensure logs are flushed
logger.Info("INFO log level message")
logger.Warn("Warn log level message")
logger.Error("Error log level message")
}
// fileLogger initializes a zap.Logger that writes to both the console and a specified file.
func fileLogger(filename string) (*zap.Logger, error) {
// Configure the time format
config := zap.NewProductionEncoderConfig()
config.EncodeTime = zapcore.ISO8601TimeEncoder
// Create file and console encoders
fileEncoder := zapcore.NewJSONEncoder(config)
consoleEncoder := zapcore.NewConsoleEncoder(config)
// Open the log file
logFile, err := os.OpenFile(filename, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
if err != nil {
return nil, fmt.Errorf("failed to open log file: %v", err)
}
// Create writers for file and console
fileWriter := zapcore.AddSync(logFile)
consoleWriter := zapcore.AddSync(os.Stdout)
// Set the log level
defaultLogLevel := zapcore.DebugLevel
// Create cores for writing to the file and console
fileCore := zapcore.NewCore(fileEncoder, fileWriter, defaultLogLevel)
consoleCore := zapcore.NewCore(consoleEncoder, consoleWriter, defaultLogLevel)
// Combine cores
core := zapcore.NewTee(fileCore, consoleCore)
// Create the logger with additional context information (caller, stack trace)
logger := zap.New(core, zap.AddCaller(), zap.AddStacktrace(zapcore.ErrorLevel))
return logger, nil
}
Output:
# go run main.go 2023-08-21T10:22:16.937+0530 info project/main.go:20 INFO log level message 2023-08-21T10:22:16.938+0530 warn project/main.go:21 Warn log level message 2023-08-21T10:22:16.939+0530 error project/main.go:22 Error log level message main.main /root/project/main.go:22 runtime.main /usr/lib/go-1.18/src/runtime/proc.go:250
Here,
- The first three lines are the expected log messages: one at the "info" level, one at the "warn" level, and one at the "error" level.
- The last lines, which begin with
main.main, are a stack trace. You're seeing this because the logger configuration includes thezap.AddStacktrace(zapcore.ErrorLevel)option. This means that for any log at the "error" level (or more severe), Zap will include a stack trace to show where in the code the log message originated.
Configuring log rotation and retention policies
Log rotation and retention are crucial for production environments, especially when logs can grow and occupy large amounts of storage space. While zap itself doesn't provide built-in log rotation and retention, it integrates well with third-party tools or libraries that offer this functionality.
One popular choice for this in the Go ecosystem is lumberjack. The lumberjack package is a rolling logger, which means it can automatically handle log rotation based on parameters like maximum log file size, maximum age of a log file, etc.
Here's a step-by-step guide to configuring log rotation and retention policies with zap and lumberjack:
Install the lumberjack package:
go get -u gopkg.in/natefinch/lumberjack.v2
Integrate lumberjack with zap:
package main
import (
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"gopkg.in/natefinch/lumberjack.v2"
)
func main() {
// Set up lumberjack as a logger:
logger := &lumberjack.Logger{
Filename: "/var/log/myapp.log", // Or any other path
MaxSize: 500, // MB; after this size, a new log file is created
MaxBackups: 3, // Number of backups to keep
MaxAge: 28, // Days
Compress: true, // Compress the backups using gzip
}
writeSyncer := zapcore.AddSync(logger)
// Set up zap logger configuration:
core := zapcore.NewCore(
zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()), // Using JSON encoder, but you can choose another
writeSyncer,
zapcore.InfoLevel,
)
loggerZap := zap.New(core)
defer loggerZap.Sync()
// Log messages:
loggerZap.Info("This is a test message for our logger!")
}
In the above example:
MaxSize: Once the log file grows beyond this size (in MB), a new log file is created.MaxBackups: Specifies the number of old log files to keep.MaxAge: Specifies the maximum number of days to keep a log file. Older logs get deleted.Compress: Iftrue, the rotated log files will be compressed using gzip.
This setup ensures your logs rotate based on the conditions set in the lumberjack configuration. It also retains the logs per the retention policies you've defined, ensuring that older logs are cleaned up automatically.
Structured Logging Examples
Structured logging is a method of logging where log messages are structured in key-value pairs or as objects, rather than just plain text messages. This allows for easier querying, filtering, and analytics on logs, making them more actionable and insightful.
Zap is designed around structured logging. Here are examples using both the base Logger and the SugaredLogger:
Using Logger (Structured Logger)
Basic Logging
logger, _ := zap.NewProduction()
defer logger.Sync()
logger.Info("User registration successful",
zap.String("username", "john_doe"),
zap.Int("id", 12345)
)
This will generate a log like:
{"level":"info","ts":...,"msg":"User registration successful","username":"john_doe","id":12345}
Logging With Error
Suppose a user registration failed due to a database error:
err := errors.New("database connection failed")
logger.Error("User registration failed",
zap.Error(err),
zap.String("username", "john_doe")
)
This will generate:
{"level":"error","ts":...,"msg":"User registration failed","username":"john_doe","error":"database connection failed"}
Using SugaredLogger
Basic Logging
logger, _ := zap.NewProduction()
sugar := logger.Sugar()
defer sugar.Sync()
sugar.Infow("User registration successful",
"username", "john_doe",
"id", 12345
)
This will generate the same log as the previous example:
{"level":"info","ts":...,"msg":"User registration successful","username":"john_doe","id":12345}
Logging With Error
Suppose a user registration failed due to a database error:
err := errors.New("database connection failed")
sugar.Errorw("User registration failed",
"error", err,
"username", "john_doe"
)
Formatted Logging
The SugaredLogger allows for printf-style formatting, which is a mix between structured and unstructured logging:
sugar.Infof("User %s with ID %d registered successfully.", "john_doe", 12345)
This will generate:
{"level":"info","ts":...,"msg":"User john_doe with ID 12345 registered successfully."}
Error Handling with Golang ZAP
Zap is designed to be both fast and reliable. It takes a "fail-fast" approach and will panic rather than silently swallowing errors in many scenarios. While this behavior is great for catching misconfigurations during development and testing, it can be a bit surprising if you're not prepared for it.
Here are some ways to handle errors with zap and best practices to follow:
1. Logger Creation
When creating a logger, always check for errors.
logger, err := zap.NewProduction()
if err != nil {
// Handle error
fmt.Printf("Can't initialize zap logger: %v", err)
os.Exit(1)
}
defer logger.Sync()
The logger's Sync method should be deferred immediately after creating the logger to flush any buffered log entries.
2. Logger Sync
While we use defer logger.Sync() to ensure all log entries are written before the program exits, remember that Sync can also return an error. In critical applications, you might want to handle this error explicitly:
defer func() {
if err := logger.Sync(); err != nil {
// Handle error, perhaps with another logger or stdlib
fmt.Printf("Logger Sync failed: %v", err)
}
}()
3. Logger Levels
When using an atomic level (dynamically adjustable log level), ensure it's always set to a valid level. An invalid level can lead to panics.
atomicLevel := zap.NewAtomicLevel()
if err := atomicLevel.UnmarshalText([]byte("debug")); err != nil {
// Handle error
}
4. Field Types
Always use the correct type for fields. Using a mismatched type can lead to panics. For instance, don't use zap.String for an integer value.
5. Recover from Panics
Zap uses panics to propagate certain kinds of errors. You can recover from these panics using Go's built-in recovery mechanisms if you really want to. But, keep in mind that a panic from Zap usually means a configuration mistake.
func safeLog() {
defer func() {
if r := recover(); r != nil {
fmt.Println("Recovered in safeLog", r)
}
}()
// logging logic that might cause panic
}
Summary
The Go programming language, while efficient and powerful, lacked a flexible logging solution. Enter zap, a blazing fast, structured logger for Go. This article delved deep into zap, showcasing its two logging paradigms: the Logger and SugaredLogger. While the former offers faster performance and is suited for structured logging, the latter provides a more user-friendly API at a slight cost to performance.
Key configurations such as setting dynamic log levels and custom formatting were explored, shedding light on zap's versatility. The article also tackled error handling, demonstrating best practices for capturing and logging errors effectively. Finally, readers were guided on setting up output configurations, ensuring that logs are directed appropriately, be it the console, log files, or both.
With its unmatched speed and extensive customization options, zap proves to be an indispensable tool for any Go developer prioritizing efficient and informative logging.
References
https://pkg.go.dev/go.uber.org/zap/zapcore
https://pkg.go.dev/go.uber.org/zap#hdr-Configuring_Zap
