Zap log base practice

2.1 why Uber go zap

For technical selection, see: https://www.yuque.com/jinsesihuanian/gpwou5/aduc5c
​

2.2 installation

Run the following command to install zap

go get -u go.uber.org/zap

2.3 configuring Zap Logger

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

In a context where performance is good but not critical, use sugarlogger. It is 4-10 times faster than other structured logging packages, and supports structured and printf style logging.
In the context where every microsecond and every memory allocation are important, use the Logger. It is even faster than sugarlogger and has fewer memory allocations, but it only supports strongly typed structured logging.

2.3.1 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 that it will record different information. For example, production logger records the calling function information, date and time by default.
• Call Info/Error through Logger.
• By default, logs are printed to the application's console interface.

var logger *zap.Logger func main() { InitLogger() defer logger.Sync() simpleHttpGet("www.baidu.com") simpleHttpGet("http://www.baidu.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, and then use the Logger methods such as Info/ Error to record messages.

The syntax of the logger method is as follows:

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

MethodXXX is a variable parameter function, which can be Info / Error/ Debug / Panic, etc. Each method accepts a message string and any number of zapcore.Field field field parameters.

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

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

{"level":"error","ts":1572159218.912792,"caller":"zap_demo/temp.go:25","msg":"Error fetching url..","url":"www.baidu.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.baidu.com"}

2.3.2 Sugared Logger

Now let's use sugar logger to achieve the same function.

• Most implementations are basically the same.
• The only difference is that we get a SugaredLogger by calling the. Sugar() method of the main logger.
• Then use sugarlogger to record the statement in printf format

The following is the modified code to use sugarlogger instead of Logger:

var sugarLogger *zap.SugaredLogger func main() { InitLogger() defer sugarLogger.Sync() simpleHttpGet("www.baidu.com") simpleHttpGet("http://www.baidu.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.baidu.com : Error = Get www.baidu.com: unsupported protocol scheme \"\"","stacktrace":"main.simpleHttpGet\n\t/Users/zap_demo/logic/temp2.go:27\nmain.main\n\t/Users/zap_demo/logic/temp2.go:14\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:203"} {"level":"info","ts":1572159150.192585,"caller":"logic/temp2.go:29","msg":"Success! statusCode = 200 OK for URL http://www.baidu.com"}

You should notice that so far, both logger s print out JSON structure format.
Later in this blog, we will discuss sugarlogger in more detail and learn how to further configure it.

2.4 customized logger

2.4.1 write log to file instead of terminal

The first change we need to make is to write the log to a file instead of printing to the application console.
​

• Instead of using a preset method like zap.NewProduction() to create a logger, we will use the zap.New(...) method to manually pass all the configurations.

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

zapcore.Core requires three configurations - Encoder, writesynchronizer, and LogLevel.

1.Encoder: encoder (write log format). We'll use NewJSONEncoder() out of the box and the preset productionencoder config ().

zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig())

2.WriterSyncer: specifies where the log is written. We use the zapcore.AddSync() function and pass in the open 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 override the InitLogger() method. The remaining 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 the main() function of the above section is called with these modified logger configurations, the following output will be printed in the file test.log.

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

2.4.2 change JSON Encoder to normal Log Encoder

Now, we want to change the Encoder from JSON Encoder to normal Encoder. To do this, we need to change newjsoneencoder () to NewConsoleEncoder().

return zapcore.NewConsoleEncoder(zap.NewProductionEncoderConfig())

When the main() function of the above section is called with these modified logger configurations, the following output will be printed in the file test.log.

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

2.4.3 change time code and add caller details

In view of the changes we made to the configuration, there are two problems:

• Time is displayed in a non-human readable manner, such as 1.572161051846623e+09
• The details of the caller function are not displayed in the log

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

• Modify time encoder
• Use uppercase letters to record 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 function of logging the calling function information. To do this, we will add an Option to the zap.New(..) function.

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

When the main() function of the above section is called with these modified logger configurations, the following output will be printed in the file test.log.

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

_ Zap itself does not support cutting archive log files_ In order to add log cutting and archiving, we will use a third-party library Lumberjack To achieve.

3.1 installation

Execute the following command to install Lumberjack

go get -u github.com/natefinch/lumberjack

3.2 add Lumberjack to zap logger

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

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

Lumberjack Logger takes the following attributes as input:

• Filename: location of log file
• MaxSize: the maximum size (in MB) of the log file before cutting
• MaxBackups: the maximum number of old files to keep
• MaxAges: maximum number of days to keep old files
• Compress: compress / archive old files

3.3 testing

Finally, the complete example code of 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() } }

Execute the above code, and the following contents 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 record the log circularly in the main function to test whether the log file will be automatically cut and archived (the log file will be cut every 1MB and save up to 5 backups in the current directory).
​

4.1 current problems

We still have two problems:

1. The generated log does not contain a date suffix, which Lumberjack will include when backing up
2. All levels of logs are written in one file, and different files need to be written according to the log level

Here I write a tool class based on zap + "GitHub. COM / lestrrat / go file rotatelogs" tool to automatically append date suffixes and write logs of different log levels to different files. The effects are as follows:

4.2 log tools:

package zaplog import ( rotatelogs "github.com/lestrrat/go-file-rotatelogs" "go.uber.org/zap" "go.uber.org/zap/zapcore" "os" "path/filepath" "sync" "time" ) type Options struct { LogFileDir string //Log path AppName string // Filename is the prefix of the file to be written to the log ErrorFileName string WarnFileName string InfoFileName string DebugFileName string MaxSize int // How many m of a file is greater than this number to start file segmentation MaxBackups int // MaxBackups is the maximum number of old log files to keep MaxAge int // MaxAge is the maximum number of days old log files are retained by date zap.Config } var ( logger *Logger sp = string(filepath.Separator) errWS, warnWS, infoWS, debugWS zapcore.WriteSyncer // IO output debugConsoleWS = zapcore.Lock(os.Stdout) // console output errorConsoleWS = zapcore.Lock(os.Stderr) ) func init() { logger = &Logger{ Opts: &Options{}, } } type Logger struct { *zap.SugaredLogger sync.RWMutex Opts *Options `json:"opts"` zapConfig zap.Config inited bool } func initLogger(cf ...*Options) { logger.Lock() defer logger.Unlock() if logger.inited { logger.Info("[initLogger] logger Inited") return } if len(cf) > 0 { logger.Opts = cf[0] } logger.loadCfg() logger.init() logger.Info("[initLogger] zap plugin initializing completed") logger.inited = true } // GetLogger returns logger func GetLogger() (ret *Logger) { return logger } func (l *Logger) init() { l.setSyncers() var err error mylogger, err := l.zapConfig.Build(l.cores()) if err != nil { panic(err) } l.SugaredLogger = mylogger.Sugar() defer l.SugaredLogger.Sync() } func (l *Logger) loadCfg() { if l.Opts.Development { l.zapConfig = zap.NewDevelopmentConfig() l.zapConfig.EncoderConfig.EncodeTime = timeEncoder } else { l.zapConfig = zap.NewProductionConfig() l.zapConfig.EncoderConfig.EncodeTime = timeUnixNano } if l.Opts.OutputPaths == nil || len(l.Opts.OutputPaths) == 0 { l.zapConfig.OutputPaths = []string{"stdout"} } if l.Opts.ErrorOutputPaths == nil || len(l.Opts.ErrorOutputPaths) == 0 { l.zapConfig.OutputPaths = []string{"stderr"} } // The default output is to the logs subdirectory of the program running directory if l.Opts.LogFileDir == "" { l.Opts.LogFileDir, _ = filepath.Abs(filepath.Dir(filepath.Join("."))) l.Opts.LogFileDir += sp + "logs" + sp } if l.Opts.AppName == "" { l.Opts.AppName = "app" } if l.Opts.ErrorFileName == "" { l.Opts.ErrorFileName = "error.log" } if l.Opts.WarnFileName == "" { l.Opts.WarnFileName = "warn.log" } if l.Opts.InfoFileName == "" { l.Opts.InfoFileName = "info.log" } if l.Opts.DebugFileName == "" { l.Opts.DebugFileName = "debug.log" } if l.Opts.MaxSize == 0 { l.Opts.MaxSize = 100 } if l.Opts.MaxBackups == 0 { l.Opts.MaxBackups = 30 } if l.Opts.MaxAge == 0 { l.Opts.MaxAge = 30 } } func (l *Logger) setSyncers() { f := func(fN string) zapcore.WriteSyncer { //return zapcore.AddSync(&lumberjack.Logger{ // Filename: logger.Opts.LogFileDir + sp + logger.Opts.AppName + "-" + fN, // MaxSize: logger.Opts.MaxSize, // MaxBackups: logger.Opts.MaxBackups, // MaxAge: logger.Opts.MaxAge, // Compress: true, // LocalTime: true, //}) // One file per hour logf, _ := rotatelogs.New(l.Opts.LogFileDir + sp + l.Opts.AppName + "-" + fN +".%Y_%m%d_%H", rotatelogs.WithLinkName(l.Opts.LogFileDir + sp + l.Opts.AppName + "-" + fN), rotatelogs.WithMaxAge(30*24*time.Hour), rotatelogs.WithRotationTime(time.Minute), ) return zapcore.AddSync(logf) } errWS = f(l.Opts.ErrorFileName) warnWS = f(l.Opts.WarnFileName) infoWS = f(l.Opts.InfoFileName) debugWS = f(l.Opts.DebugFileName) return } func (l *Logger) cores() zap.Option { fileEncoder := zapcore.NewJSONEncoder(l.zapConfig.EncoderConfig) //consoleEncoder := zapcore.NewConsoleEncoder(logger.zapConfig.EncoderConfig) encoderConfig := zap.NewDevelopmentEncoderConfig() encoderConfig.EncodeTime = timeEncoder consoleEncoder := zapcore.NewConsoleEncoder(encoderConfig) errPriority := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool { return lvl > zapcore.WarnLevel && zapcore.WarnLevel-l.zapConfig.Level.Level() > -1 }) warnPriority := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool { return lvl == zapcore.WarnLevel && zapcore.WarnLevel-l.zapConfig.Level.Level() > -1 }) infoPriority := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool { return lvl == zapcore.InfoLevel && zapcore.InfoLevel-l.zapConfig.Level.Level() > -1 }) debugPriority := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool { return lvl == zapcore.DebugLevel && zapcore.DebugLevel-l.zapConfig.Level.Level() > -1 }) cores := []zapcore.Core{ zapcore.NewCore(fileEncoder, errWS, errPriority), zapcore.NewCore(fileEncoder, warnWS, warnPriority), zapcore.NewCore(fileEncoder, infoWS, infoPriority), zapcore.NewCore(fileEncoder, debugWS, debugPriority), } if l.Opts.Development { cores = append(cores, []zapcore.Core{ zapcore.NewCore(consoleEncoder, errorConsoleWS, errPriority), zapcore.NewCore(consoleEncoder, debugConsoleWS, warnPriority), zapcore.NewCore(consoleEncoder, debugConsoleWS, infoPriority), zapcore.NewCore(consoleEncoder, debugConsoleWS, debugPriority), }...) } return zap.WrapCore(func(c zapcore.Core) zapcore.Core { return zapcore.NewTee(cores...) }) } func timeEncoder(t time.Time, enc zapcore.PrimitiveArrayEncoder) { enc.AppendString(t.Format("2006-01-02 15:04:05")) } func timeUnixNano(t time.Time, enc zapcore.PrimitiveArrayEncoder) { enc.AppendInt64(t.UnixNano() / 1e6) }

4.3 testing

package zaplog import ( "fmt" "go.uber.org/zap" "testing" "time" ) func TestZapLog(t *testing.T) { data := &Options{ LogFileDir: "/Users/didi/code/golang/learn-go/zap_log/v3/logs", AppName: "logtool", MaxSize: 30, MaxBackups: 7, MaxAge: 7, Config: zap.Config{}, } data.Development = true initLogger(data) for i := 0; i < 2; i++ { time.Sleep(time.Second) logger.Debug(fmt.Sprint("debug log ", i), zap.Int("line", 999)) logger.Info(fmt.Sprint("Info log ", i), zap.Any("level", "1231231231")) logger.Warn(fmt.Sprint("warn log ", i), zap.String("level", `{"a":"4","b":"5"}`)) logger.Error(fmt.Sprint("err log ", i), zap.String("level", `{"a":"7","b":"8"}`)) } }

So far, we have summarized how to integrate the zap logger into the Go application project. Now the whole log system of golang is relatively complete. The only thing missing is that trace is not connected to the log, which can not form a complete log link tracking. Later, I will share this function in the article "using zap combined with gin framework". I'll see you next time, Peace 😘

I am Jian Fan, an inspirational migrant worker in the new era who aims to describe the most complex problems in the simplest language. If you have any doubts about this article, please leave a message in my WeChat official account. What I can do is to help you:

• Help build your own knowledge system
• Real high concurrency scenarios on the Internet
• Occasionally share classic scenarios and practices related to Golang and Java

My blog: https://besthpt.github.io/
My wechat: bestbear666
The official account of WeChat:

Reference documents: https://liwenzhou.com/posts/Go/zap/

Add new comment

0 comments