Go Study Notes - Zap Journal

Log package

The default log package provided by the Go language: https://golang.org/pkg/log/

Basic usage

The log package defines the Logger type, which provides some methods for formatting output.

 type Logger struct {
    mu     sync.Mutex // ensures atomic writes; protects the following fields
    prefix string     // prefix on each line to identify the logger (but see                            Lmsgprefix)
    flag   int        // properties
    out    io.Writer  // destination for output
    buf    []byte     // for accumulating text to write
}

mu attributes are mainly to ensure atomic operations, prefix set the prefix of each line, flag set various attributes of the output, such as time, line number, file path Wait. out The direction of the output, which is used to store the log in the file.

This package also provides a predefined "standard" logger, which can be used by calling the functions Print series (Print|Printf|Println） , Fatal series （Fatal|Fatalf|Fatalln） , and Panic series （Panic|Panicf|Panicln） , which is easier to use than creating a logger object yourself.

For example, we can call the above-mentioned methods directly through the log package like the following code, and by default they will print log information to the terminal interface:

 log.Println("这是一条优雅的日志。")
v := "优雅的"
log.Printf("这是一个%s日志\n", v)
//fatal系列函数会在写入日志信息后调用os.Exit(1)
log.Fatalln("这是一天会触发fatal的日志") 
//Panic系列函数会在写入日志信息后panic
log.Panicln("这是一个会触发panic的日志。") //执行后会自动触发一个异常

flag attribute

The logger by default only provides the time information of the log, but in many cases we want to get more information, such as the file name and line number of the log. The log standard library provides us with methods to customize these settings.

The Flags function in the log standard library will return the output configuration of the standard logger, and the SetFlags function is used to set the output configuration of the standard logger. The following are the constants corresponding to the flag attribute

 const (
    Ldate    = 1 << iota     // the date in the local time zone: 2009/01/23
    Ltime                    // the time in the local time zone: 01:23:23
    Lmicroseconds           // microsecond resolution: 01:23:23.123123.  assumes Ltime.
    Llongfile               // full file name and line number: /a/b/c/d.go:23
    Lshortfile   // final file name element and line number: d.go:23. overrides Llongfile
    LUTC         // if Ldate or Ltime is set, use UTC rather than the local time zone
    Lmsgprefix  // move the "prefix" from the beginning of the line to before the message
    LstdFlags = Ldate | Ltime // initial values for the standard logger
)

The code to set the output properties is as follows:

 func main() {
    log.SetFlags(log.Llongfile | log.Lmicroseconds | log.Ldate)
    log.Println("这是一条优雅的日志。")
}

Compilation output:

 2020/07/14 22:51:06.079594 D:/xxx/test_log.go:24: 这是一条优雅的日志。

prefix property

The log standard library also provides two methods about the prefix of log information: the Prefix function is used to view the output prefix of the standard logger, and the SetPrefix function is used to set the output prefix.

 func Prefix() string
 func SetPrefix(prefix string)

The code to set the log output prefix is as follows:

 func main() {
    log.SetPrefix("[PS]")
    log.Println("这是一条很普通的日志。")
}

Compilation output:

 [PS]2020/07/14 22:56:15.652555 D:/xxx/test_log.go:26: 这是一个普通的日志

out property

The out property is an io.Writer output stream, which can be used to output the log to a file.

The method that needs to be used is: set the output destination of the standard logger, the default is standard error output.

 func SetOutput(w io.Writer)

For example, the following code will output the log to the xx.log file in the same directory.

 func main() {
    logFile, err := os.OpenFile("./xx.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
    if err != nil {
        fmt.Println("open log file failed, err:", err)
        return
    }
    log.SetOutput(logFile)
    log.SetFlags(log.Llongfile | log.Lmicroseconds | log.Ldate)
    log.Println("这是一条很普通的日志。")
    log.SetPrefix("[PS]")
    log.Println("这是一条很普通的日志。")
}

If you want to use the standard logger, we usually write the above configuration operation in the init function.

 func init() {
    logFile, err := os.OpenFile("./xx.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
    if err != nil {
        fmt.Println("open log file failed, err:", err)
        return
    }
    log.SetOutput(logFile)
    log.SetFlags(log.Llongfile | log.Lmicroseconds | log.Ldate)
}

Create a new Logger

The log standard library also provides a constructor New that creates a new logger object, allowing us to create our own logger examples. The signature of the New function is as follows:

 func New(out io.Writer, prefix string, flag int) *Logger

New creates a Logger object. Among them, the parameter out sets the destination where the log information is written. The parameter prefix will be added to the front of each log generated. The parameter flag defines the properties of the log (time, file, etc.).

for example:

 func main() {
    logger := log.New(os.Stdout, "<PS>", log.Lshortfile|log.Ldate|log.Ltime)
    logger.Println("这是自定义的logger记录的日志。")
}

Compilation output:

 <PS>2020/07/14 23:02:59 test_log.go:43: 这是自定义的logger记录的日志

Custom Go Logger

Can set any io.Writer as logging output and send it the log to write

set up

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

use

 func test(){
   log.Printf("Test log: %s %s", "Hello", "World")
}

run

 func main() {
    SetupLogger()
  test()
}

Zap

Zap is a very fast, structured, log-level logging library for Go.

Install

 go get -u go.uber.org/zap

Configure Zap Logger

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

• Logger is faster, but only supports strongly typed structured logging.
• Sugared Logger supports structured and printf style logging.

Logger

• Create a Logger by calling zap.NewProduction() / zap.NewDevelopment() or zap.Example() .
• Example and Production are output using the json format output, Development use the line output form
• Development from the warning level (Warn) printed up to the stack to trace,
• Production Error , Dpanic level record, will trace the file in the stack, Warn will not
• Call Info/Error etc. via Logger.
• By default, logs are 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 and then log messages using Logger methods like Info/Error.

The syntax of the logger method is this:

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

Where MethodXXX is a variadic function, which can be Info/Error/Debug/Panic etc. Each method accepts a message string and any number of zapcore.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:

 {"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/itxiaoma/zap_demo/temp.go:25\nmain.main\n\t/Users/itxiaoma/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

 slogger := logger.Sugar()

suger logger Reflected type detection based on printf split, providing a simpler syntax to add labels of mixed types.

 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()
    }
}

Results of the:

 {"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/itxiaoma/zap_demo/logic/temp2.go:27\nmain.main\n\t/Users/itxiaoma/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.sogo.com"}

custom logger

1. Write log to file

Use the zap.New(…) method to pass all the configuration manually instead of using the preset method like zap.NewProduction() to create the logger.

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

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

   zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig())

• WriterSyncer : Specifies where the log will be written to. We use the zapcore.AddSync() function and pass in the open file handle.

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

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

 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 in 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.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"}

2. Change JSON Encoder to normal Log Encoder

Change --- NewJSONEncoder() to NewConsoleEncoder() .

 return zapcore.NewConsoleEncoder(zap.NewProductionEncoderConfig())

When calling the main() function in the above section 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.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.572161052068744e+09    info    Success! statusCode = 200 OK for URL http://www.sogo.com

3. Change time code and add caller details

Modify the time encoder:

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

Add caller information: Add a Option to the zap.New(..) function.

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

Final result:

 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

Lumberjack log cutting

Install

 go get -u github.com/natefinch/lumberjack

use

 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 properties as input:

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

Zap receives Gin default logs

When we use gin.Default() , we also use two default middleware in the gin framework Logger() and Recovery() .

• Logger() is to output the log of the gin framework itself to the standard output (the logs output in the terminal during our local development and debugging are its credit)
• Recovery() is to restore the scene and write a 500 response when the program panics.

zap-based middleware

replace gin.Default()

 r := gin.New()
r.Use(GinLogger(), GinRecovery())

Middleware:

 // GinLogger 接收gin框架默认的日志
func GinLogger(logger *zap.Logger) gin.HandlerFunc {
    return func(c *gin.Context) {
        start := time.Now()
        path := c.Request.URL.Path
        query := c.Request.URL.RawQuery
        c.Next()

        cost := time.Since(start)
        logger.Info(path,
            zap.Int("status", c.Writer.Status()),
            zap.String("method", c.Request.Method),
            zap.String("path", path),
            zap.String("query", query),
            zap.String("ip", c.ClientIP()),
            zap.String("user-agent", c.Request.UserAgent()),
            zap.String("errors", c.Errors.ByType(gin.ErrorTypePrivate).String()),
            zap.Duration("cost", cost),
        )
    }
}

// GinRecovery recover掉项目可能出现的panic
func GinRecovery(logger *zap.Logger, stack bool) gin.HandlerFunc {
    return func(c *gin.Context) {
        defer func() {
            if err := recover(); err != nil {
                // Check for a broken connection, as it is not really a
                // condition that warrants a panic stack trace.
                var brokenPipe bool
                if ne, ok := err.(*net.OpError); ok {
                    if se, ok := ne.Err.(*os.SyscallError); ok {
                        if strings.Contains(strings.ToLower(se.Error()), "broken pipe") || strings.Contains(strings.ToLower(se.Error()), "connection reset by peer") {
                            brokenPipe = true
                        }
                    }
                }

                httpRequest, _ := httputil.DumpRequest(c.Request, false)
                if brokenPipe {
                    logger.Error(c.Request.URL.Path,
                        zap.Any("error", err),
                        zap.String("request", string(httpRequest)),
                    )
                    // If the connection is dead, we can't write a status to it.
                    c.Error(err.(error)) // nolint: errcheck
                    c.Abort()
                    return
                }

                if stack {
                    logger.Error("[Recovery from panic]",
                        zap.Any("error", err),
                        zap.String("request", string(httpRequest)),
                        zap.String("stack", string(debug.Stack())),
                    )
                } else {
                    logger.Error("[Recovery from panic]",
                        zap.Any("error", err),
                        zap.String("request", string(httpRequest)),
                    )
                }
                c.AbortWithStatus(http.StatusInternalServerError)
            }
        }()
        c.Next()
    }
}

If you don't want to implement it yourself, you can use https://github.com/gin-contrib/zap packaged by others on github.

In this way, we can use the two middleware we defined above to replace the default gin framework Logger() and Recovery() in the gin framework.

Use zap in the gin project

Finally, we add the log cutting commonly used in our project. The full version logger.go code is as follows:

 package logger

import (
    "gin_zap_demo/config"
    "net"
    "net/http"
    "net/http/httputil"
    "os"
    "runtime/debug"
    "strings"
    "time"

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

var lg *zap.Logger

// InitLogger 初始化Logger
func InitLogger(cfg *config.LogConfig) (err error) {
    writeSyncer := getLogWriter(cfg.Filename, cfg.MaxSize, cfg.MaxBackups, cfg.MaxAge)
    encoder := getEncoder()
    var l = new(zapcore.Level)
    err = l.UnmarshalText([]byte(cfg.Level))
    if err != nil {
        return
    }
    core := zapcore.NewCore(encoder, writeSyncer, l)

    lg = zap.New(core, zap.AddCaller())
    zap.ReplaceGlobals(lg) // 替换zap包中全局的logger实例，后续在其他包中只需使用zap.L()调用即可
    return
}

func getEncoder() zapcore.Encoder {
    encoderConfig := zap.NewProductionEncoderConfig()
    encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
    encoderConfig.TimeKey = "time"
    encoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder
    encoderConfig.EncodeDuration = zapcore.SecondsDurationEncoder
    encoderConfig.EncodeCaller = zapcore.ShortCallerEncoder
    return zapcore.NewJSONEncoder(encoderConfig)
}

func getLogWriter(filename string, maxSize, maxBackup, maxAge int) zapcore.WriteSyncer {
    lumberJackLogger := &lumberjack.Logger{
        Filename:   filename,
        MaxSize:    maxSize,
        MaxBackups: maxBackup,
        MaxAge:     maxAge,
    }
    return zapcore.AddSync(lumberJackLogger)
}

// GinLogger 接收gin框架默认的日志
func GinLogger() gin.HandlerFunc {
    return func(c *gin.Context) {
        start := time.Now()
        path := c.Request.URL.Path
        query := c.Request.URL.RawQuery
        c.Next()

        cost := time.Since(start)
        lg.Info(path,
            zap.Int("status", c.Writer.Status()),
            zap.String("method", c.Request.Method),
            zap.String("path", path),
            zap.String("query", query),
            zap.String("ip", c.ClientIP()),
            zap.String("user-agent", c.Request.UserAgent()),
            zap.String("errors", c.Errors.ByType(gin.ErrorTypePrivate).String()),
            zap.Duration("cost", cost),
        )
    }
}

// GinRecovery recover掉项目可能出现的panic，并使用zap记录相关日志
func GinRecovery(stack bool) gin.HandlerFunc {
    return func(c *gin.Context) {
        defer func() {
            if err := recover(); err != nil {
                // Check for a broken connection, as it is not really a
                // condition that warrants a panic stack trace.
                var brokenPipe bool
                if ne, ok := err.(*net.OpError); ok {
                    if se, ok := ne.Err.(*os.SyscallError); ok {
                        if strings.Contains(strings.ToLower(se.Error()), "broken pipe") || strings.Contains(strings.ToLower(se.Error()), "connection reset by peer") {
                            brokenPipe = true
                        }
                    }
                }

                httpRequest, _ := httputil.DumpRequest(c.Request, false)
                if brokenPipe {
                    lg.Error(c.Request.URL.Path,
                        zap.Any("error", err),
                        zap.String("request", string(httpRequest)),
                    )
                    // If the connection is dead, we can't write a status to it.
                    c.Error(err.(error)) // nolint: errcheck
                    c.Abort()
                    return
                }

                if stack {
                    lg.Error("[Recovery from panic]",
                        zap.Any("error", err),
                        zap.String("request", string(httpRequest)),
                        zap.String("stack", string(debug.Stack())),
                    )
                } else {
                    lg.Error("[Recovery from panic]",
                        zap.Any("error", err),
                        zap.String("request", string(httpRequest)),
                    )
                }
                c.AbortWithStatus(http.StatusInternalServerError)
            }
        }()
        c.Next()
    }
}

Then define the log related configuration:

 type LogConfig struct {
    Level string `json:"level"`
    Filename string `json:"filename"`
    MaxSize int `json:"maxsize"`
    MaxAge int `json:"max_age"`
    MaxBackups int `json:"max_backups"`
}

In the project, first load the configuration information from the configuration file, and then call logger.InitLogger(config.Conf.LogConfig) to complete the initial recognition of the logger instance. Among them, register our middleware by r.Use(logger.GinLogger(), logger.GinRecovery(true)) to use zap to receive the logs of the gin framework itself, and use the zap.L().Xxx() method to record custom log information where needed in the project.

 package main

import (
    "fmt"
    "gin_zap_demo/config"
    "gin_zap_demo/logger"
    "net/http"
    "os"

    "go.uber.org/zap"

    "github.com/gin-gonic/gin"
)

func main() {
    // load config from config.json
    if len(os.Args) < 1 {
        return
    }

    if err := config.Init(os.Args[1]); err != nil {
        panic(err)
    }
    // init logger
    if err := logger.InitLogger(config.Conf.LogConfig); err != nil {
        fmt.Printf("init logger failed, err:%v\n", err)
        return
    }

    gin.SetMode(config.Conf.Mode)

    r := gin.Default()
    // 注册zap相关中间件
    r.Use(logger.GinLogger(), logger.GinRecovery(true))

    r.GET("/hello", func(c *gin.Context) {
        // 假设你有一些数据需要记录到日志中
        var (
            name = "itxiaoma"
            age  = 18
        )
        // 记录日志并使用zap.Xxx(key, val)记录相关字段
        zap.L().Debug("this is hello func", zap.String("user", name), zap.Int("age", age))

        c.String(http.StatusOK, "hello itxiaoma!")
    })

    addr := fmt.Sprintf(":%v", config.Conf.Port)
    r.Run(addr)
}

refer to

Go language log usage

Using the Zap logging library in a Go language project

Use zap to receive the default log of the gin framework and configure log archiving