biuaxia

title: 【Reprint】Using the Zap Logging Library in Go Language Projects
date: 2021-08-09 16:37:33
comment: false
toc: true
category:

• Golang
  tags:
• Reprint
• Go
• zap
• Logging

This article is reprinted from: Using the Zap Logging Library in Go Language Projects | Li Wenzhou's Blog

This article first introduces the use of Go's native logging library, then details the very popular open-source Zap logging library from Uber, while also explaining how to use Lumberjack for log rotation and archiving.

Using the Zap Logging Library in Go Language Projects#

Introduction#

In many Go language projects, we need a good logger that can provide the following features:

• Ability to log events to a file instead of the application console.
• Log rotation - the ability to rotate log files based on file size, time, or interval.
• Support for different log levels, such as INFO, DEBUG, ERROR, etc.
• Ability to print basic information, such as calling file/function names and line numbers, log timestamps, etc.

Default Go Logger#

Before introducing the Uber-go zap package, let's first look at the basic logging functionality provided by Go. The default logging package provided by Go is https://golang.org/pkg/log/.

Implementing a Go Logger#

Implementing a logger in Go is very simple - create a new log file and set it as the output location for logging.

Setting Up the Logger#

We can set up the logger as shown in the code below:

func SetupLogger() {
	logFileLocation, _ := os.OpenFile("/Users/q1mi/test.log", os.O_CREATE|os.O_APPEND|os.O_RDWR, 0744)
	log.SetOutput(logFileLocation)
}

Using the Logger#

Let's write some dummy code to use this logger.

In the current example, we will establish an HTTP connection to a URL and log the status code/error to the log file.

func simpleHttpGet(url string) {
	resp, err := http.Get(url)
	if err != nil {
		log.Printf("Error fetching url %s : %s", url, err.Error())
	} else {
		log.Printf("Status Code for %s : %s", url, resp.Status)
		resp.Body.Close()
	}
}

Running the Logger#

Now let's execute the above code and see how the logger performs.

func main() {
	SetupLogger()
	simpleHttpGet("www.google.com")
	simpleHttpGet("http://www.google.com")
}

When we execute the above code, we can see a test.log file created, and the following content will be added to this log file.

2019/05/24 01:14:13 Error fetching url www.google.com : Get www.google.com: unsupported protocol scheme ""
2019/05/24 01:14:14 Status Code for http://www.google.com : 200 OK

Advantages and Disadvantages of the Go Logger#

Advantages#

Its biggest advantage is that it is very easy to use. We can set any io.Writer as the logging output and send logs to it.

Disadvantages#

• Limited basic log levels
  • There is only one Print option. It does not support multiple levels like INFO/DEBUG, etc.
• For error logs, it has Fatal and Panic
  • Fatal logs terminate the program by calling os.Exit(1)
  • Panic logs throw a panic after writing the log message
  • However, it lacks an ERROR log level that can log errors without throwing a panic or exiting the program
• Lack of log formatting capabilities - for example, logging the caller's function name and line number, formatting date and time, etc.
• Does not provide log rotation capabilities.

Uber-go Zap#

Zap is a very fast, structured, leveled logging library for Go.

Why Choose Uber-go Zap#

• It provides both structured logging and printf-style logging
• It is extremely fast

According to the documentation of Uber-go Zap, its performance is better than similar structured logging packages - and faster than the standard library. Here is the benchmark information released by Zap:

Logging a message with 10 fields:

Logging a static string with no context or printf-style template:

Installation#

Run the command below to install zap:

go get -u go.uber.org/zap

Configuring the Zap Logger#

Zap provides two types of loggers - Sugared Logger and Logger.

Use SugaredLogger in contexts where performance is good but not critical. It is 4-10 times faster than other structured logging packages and supports both structured and printf-style logging.

Use Logger in contexts where every microsecond and every memory allocation is important. It is even faster than SugaredLogger and allocates less memory, but it only supports strongly typed structured logging.

Logger#

• Create a Logger by calling zap.NewProduction()/zap.NewDevelopment() or zap.Example().
• Each of the above functions will create a logger. The only difference is the information it will log. For example, the production logger logs calling function information, date, and time by default.
• Call Info/Error, etc., through the Logger.
• By default, logs will be printed to the application's console interface.

var logger *zap.Logger

func main() {
	InitLogger()
	defer logger.Sync()
	simpleHttpGet("www.google.com")
	simpleHttpGet("http://www.google.com")
}

func InitLogger() {
	logger, _ = zap.NewProduction()
}

func simpleHttpGet(url string) {
	resp, err := http.Get(url)
	if err != nil {
		logger.Error(
			"Error fetching url..",
			zap.String("url", url),
			zap.Error(err))
	} else {
		logger.Info("Success..",
			zap.String("statusCode", resp.Status),
			zap.String("url", url))
		resp.Body.Close()
	}
}

In the above code, we first create a Logger, then use Info/Error and other Logger methods to log messages.

The syntax for the logger methods is as follows:

func (log *Logger) MethodXXX(msg string, fields ...Field)

Where MethodXXX is a variadic function that can be Info/Error/Debug/Panic, etc. Each method accepts a message string and any number of zapcore.Field parameters.

Each zapcore.Field is essentially a set of key-value pair parameters.

When we execute the above code, we will get the following output:

{"level":"error","ts":1572159218.912792,"caller":"zap_demo/temp.go:25","msg":"Error fetching url..","url":"www.sogo.com","error":"Get www.sogo.com: unsupported protocol scheme \"\"","stacktrace":"main.simpleHttpGet\n\t/Users/q1mi/zap_demo/temp.go:25\nmain.main\n\t/Users/q1mi/zap_demo/temp.go:14\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:203"}
{"level":"info","ts":1572159219.1227388,"caller":"zap_demo/temp.go:30","msg":"Success..","statusCode":"200 OK","url":"http://www.sogo.com"}

Sugared Logger#

Now let's use the Sugared Logger to achieve the same functionality.

• Most of the implementation is basically the same.
• The only difference is that we obtain a SugaredLogger by calling the .Sugar() method on the main logger.
• Then use the SugaredLogger to log statements in printf format.

Here is the modified code using SugaredLogger instead of Logger:

var sugarLogger *zap.SugaredLogger

func main() {
	InitLogger()
	defer sugarLogger.Sync()
	simpleHttpGet("www.google.com")
	simpleHttpGet("http://www.google.com")
}

func InitLogger() {
	logger, _ := zap.NewProduction()
	sugarLogger = logger.Sugar()
}

func simpleHttpGet(url string) {
	sugarLogger.Debugf("Trying to hit GET request for %s", url)
	resp, err := http.Get(url)
	if err != nil {
		sugarLogger.Errorf("Error fetching URL %s : Error = %s", url, err)
	} else {
		sugarLogger.Infof("Success! statusCode = %s for URL %s", resp.Status, url)
		resp.Body.Close()
	}
}

When you execute the above code, you will get the following output:

{"level":"error","ts":1572159149.923002,"caller":"logic/temp2.go:27","msg":"Error fetching URL www.sogo.com : Error = Get www.sogo.com: unsupported protocol scheme \"\"","stacktrace":"main.simpleHttpGet\n\t/Users/q1mi/zap_demo/logic/temp2.go:27\nmain.main\n\t/Users/q1mi/zap_demo/logic/temp2.go:14\nruntime.main\n\t/Users/q1mi/zap_demo/logic/temp2.go:203"}
{"level":"info","ts":1572159150.192585,"caller":"logic/temp2.go:29","msg":"Success! statusCode = 200 OK for URL http://www.sogo.com"}

You should notice that so far both loggers print output in JSON structure format.

In the later part of this blog, we will discuss SugaredLogger in more detail and learn how to further configure it.

Customizing the Logger#

Writing Logs to a File Instead of the Terminal#

The first change we want to make is to write logs to a file instead of printing them to the application console.

• We will use the zap.New(...) method to manually pass all configurations instead of using preset methods like zap.NewProduction() to create the logger.

func New(core zapcore.Core, options ...Option) *Logger

zapcore.Core requires three configurations - Encoder, WriteSyncer, LogLevel.

1. Encoder: The encoder (how to write logs). We will use the out-of-the-box NewJSONEncoder() and use the pre-set ProductionEncoderConfig().

zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig())

2. WriterSyncer: Specifies where the logs will be written. We use the zapcore.AddSync() function and pass in the opened file handle.

file, _ := os.Create("./test.log")
   writeSyncer := zapcore.AddSync(file)

3. Log Level: Which level of logs will be written.

We will modify the Logger code in the above section and rewrite the InitLogger() method. The other methods - main() / SimpleHttpGet() remain unchanged.

func InitLogger() {
	writeSyncer := getLogWriter()
	encoder := getEncoder()
	core := zapcore.NewCore(encoder, writeSyncer, zapcore.DebugLevel)

	logger := zap.New(core)
	sugarLogger = logger.Sugar()
}

func getEncoder() zapcore.Encoder {
	return zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig())
}

func getLogWriter() zapcore.WriteSyncer {
	file, _ := os.Create("./test.log")
	return zapcore.AddSync(file)
}

When calling the main() function with these modified logger configurations, the following output will be printed to the file - test.log.

{"level":"debug","ts":1572160754.994731,"msg":"Trying to hit GET request for www.sogo.com"}
{"level":"error","ts":1572160754.994982,"msg":"Error fetching URL www.sogo.com : Error = Get www.sogo.com: unsupported protocol scheme \"\""}
{"level":"debug","ts":1572160754.994996,"msg":"Trying to hit GET request for http://www.sogo.com"}
{"level":"info","ts":1572160757.3755069,"msg":"Success! statusCode = 200 OK for URL http://www.sogo.com"}

Changing the JSON Encoder to a Regular Log Encoder#

Now, we want to change the encoder from JSON Encoder to a regular Encoder. To do this, we need to change NewJSONEncoder() to NewConsoleEncoder().

return zapcore.NewConsoleEncoder(zap.NewProductionEncoderConfig())

When calling the main() function with these modified logger configurations, the following output will be printed to the file - test.log.

1.572161051846623e+09	debug	Trying to hit GET request for www.sogo.com
1.572161051846828e+09	error	Error fetching URL www.sogo.com : Error = Get www.sogo.com: unsupported protocol scheme ""
1.5721610518468401e+09	debug	Trying to hit GET request for http://www.sogo.com
1.5721610518468401e+09	info	Success! statusCode = 200 OK for URL http://www.sogo.com

Changing Time Encoding and Adding Caller Details#

Given the changes we made to the configuration, there are two issues:

• The time is displayed in a non-human-readable way, such as 1.572161051846623e+09
• The caller function details are not displayed in the logs

The first thing we want to do is override the default ProductionConfig() and make the following changes:

• Modify the time encoder
• Use uppercase letters to log the log level in the log file

func getEncoder() zapcore.Encoder {
	encoderConfig := zap.NewProductionEncoderConfig()
	encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
	encoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder
	return zapcore.NewConsoleEncoder(encoderConfig)
}

Next, we will modify the zap logger code to add the functionality of logging the calling function information into the logs. To do this, we will add an Option in the zap.New(..) function.

logger := zap.New(core, zap.AddCaller())

When calling the main() function with these modified logger configurations, the following output will be printed to the file - test.log.

2019-10-27T15:33:29.855+0800	DEBUG	logic/temp2.go:47	Trying to hit GET request for www.sogo.com
2019-10-27T15:33:29.855+0800	ERROR	logic/temp2.go:50	Error fetching URL www.sogo.com : Error = Get www.sogo.com: unsupported protocol scheme ""
2019-10-27T15:33:29.856+0800	DEBUG	logic/temp2.go:47	Trying to hit GET request for http://www.sogo.com
2019-10-27T15:33:30.125+0800	INFO	logic/temp2.go:52	Success! statusCode = 200 OK for URL http://www.sogo.com

Using Lumberjack for Log Rotation and Archiving#

The only feature missing from this logging program is log rotation and archiving.

Zap itself does not support log rotation and archiving

To add log rotation and archiving functionality, we will use the third-party library Lumberjack.

Installation#

Run the command below to install Lumberjack:

go get -u github.com/natefinch/lumberjack

Adding Lumberjack to the Zap Logger#

To add Lumberjack support in zap, we need to modify the WriteSyncer code. We will modify the getLogWriter() function as follows:

func getLogWriter() zapcore.WriteSyncer {
	lumberJackLogger := &lumberjack.Logger{
		Filename:   "./test.log",
		MaxSize:    10,
		MaxBackups: 5,
		MaxAge:     30,
		Compress:   false,
	}
	return zapcore.AddSync(lumberJackLogger)
}

The Lumberjack Logger takes the following properties as input:

• Filename: The location of the log file
• MaxSize: The maximum size of the log file (in MB) before rotation
• MaxBackups: The maximum number of old files to retain
• MaxAge: The maximum number of days to retain old files
• Compress: Whether to compress/archive old files

Testing All Features#

Finally, the complete example code using the Zap/Lumberjack logger is as follows:

package main

import (
	"net/http"

	"github.com/natefinch/lumberjack"
	"go.uber.org/zap"
	"go.uber.org/zap/zapcore"
)

var sugarLogger *zap.SugaredLogger

func main() {
	InitLogger()
	defer sugarLogger.Sync()
	simpleHttpGet("www.sogo.com")
	simpleHttpGet("http://www.sogo.com")
}

func InitLogger() {
	writeSyncer := getLogWriter()
	encoder := getEncoder()
	core := zapcore.NewCore(encoder, writeSyncer, zapcore.DebugLevel)

	logger := zap.New(core, zap.AddCaller())
	sugarLogger = logger.Sugar()
}

func getEncoder() zapcore.Encoder {
	encoderConfig := zap.NewProductionEncoderConfig()
	encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
	encoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder
	return zapcore.NewConsoleEncoder(encoderConfig)
}

func getLogWriter() zapcore.WriteSyncer {
	lumberJackLogger := &lumberjack.Logger{
		Filename:   "./test.log",
		MaxSize:    1,
		MaxBackups: 5,
		MaxAge:     30,
		Compress:   false,
	}
	return zapcore.AddSync(lumberJackLogger)
}

func simpleHttpGet(url string) {
	sugarLogger.Debugf("Trying to hit GET request for %s", url)
	resp, err := http.Get(url)
	if err != nil {
		sugarLogger.Errorf("Error fetching URL %s : Error = %s", url, err)
	} else {
		sugarLogger.Infof("Success! statusCode = %s for URL %s", resp.Status, url)
		resp.Body.Close()
	}
}

When executing the above code, the following content will be output to the file - test.log.

2019-10-27T15:50:32.944+0800	DEBUG	logic/temp2.go:48	Trying to hit GET request for www.sogo.com
2019-10-27T15:50:32.944+0800	ERROR	logic/temp2.go:51	Error fetching URL www.sogo.com : Error = Get www.sogo.com: unsupported protocol scheme ""
2019-10-27T15:50:32.944+0800	DEBUG	logic/temp2.go:48	Trying to hit GET request for http://www.sogo.com
2019-10-27T15:50:33.165+0800	INFO	logic/temp2.go:53	Success! statusCode = 200 OK for URL http://www.sogo.com

At the same time, you can loop log in the main function to test whether the log file will automatically rotate and archive (the log file will rotate every 1MB and keep a maximum of 5 backups in the current directory).

Thus, we summarize how to integrate the Zap logging library into Go application projects.

Translated from https://dev-journal.in/2019/05/27/adding-uber-go-zap-logger-to-golang-project/, with slight modifications for better understanding of the original content.