golang uber zap

Logging has an important place in the back-end system. Not only can logs visualize the current running state of the program, but more importantly they can provide clues to developers when something goes wrong with the program.

In the Go ecosystem, logrus is probably the most used Go logging library, which not only provides structured logs, but more importantly is compatible with the standard library log package at the api level. In performance-insensitive domains, logrus is really the way to go.

But in performance-sensitive areas and scenarios, logrus will be less fragrant, and more appearances are made by the big factory uber open source log library called zap. The reason why zap is more fragrant in these scenarios is that although it is known for its high performance, the backing of uber is also extremely important. uber has too many performance and latency-sensitive scenarios, and its production environment now has thousands of microservices developed in Go, most of which are estimated to use zap, a log library that has been tested in performance-sensitive scenarios by uber. There is a guarantee that someone will continue to maintain it, and it is naturally favored by everyone.

The main optimization points of zap include

  • avoiding the overhead of using interface{} (unboxing, object escape to the heap)
  • Firmly refrain from using reflection, and carry type information for each field to be output (this reduces the developer’s experience with zap, but this reduction in experience seems to be nothing compared to the performance gains it achieves).
1
2
3
4
5
6
logger.Info("failed to fetch URL",
    // Structured context as strongly typed Field values.
    zap.String("url", `http://foo.com`),
    zap.Int("attempt", 3),
    zap.Duration("backoff", time.Second),
)
  • Use sync.Pool to reduce heap memory allocation (for zapcore.Entry representing a full log message) and reduce pressure on GC.

Here is a simple zap vs logrus performance benchmark benchmark comparison.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/benchmark/log_lib_test.go
package main

import (
    "io"
    "testing"
    "time"

    "github.com/sirupsen/logrus"
    "go.uber.org/zap"
    "go.uber.org/zap/zapcore"
)

func BenchmarkLogrus(b *testing.B) {
    b.ReportAllocs()
    b.StopTimer()
    logger := logrus.New()
    logger.SetOutput(io.Discard)
    b.StartTimer()
    for i := 0; i < b.N; i++ {
        logger.WithFields(logrus.Fields{
            "url":     "http://foo.com",
            "attempt": 3,
            "backoff": time.Second,
        }).Info("failed to fetch URL")
    }
}

func BenchmarkZap(b *testing.B) {
    b.ReportAllocs()
    b.StopTimer()
    cfg := zap.NewProductionConfig()
    core := zapcore.NewCore(
        zapcore.NewJSONEncoder(cfg.EncoderConfig),
        zapcore.AddSync(io.Discard),
        zapcore.InfoLevel,
    )
    logger := zap.New(core)
    b.StartTimer()
    for i := 0; i < b.N; i++ {
        logger.Info("failed to fetch URL",
            zap.String("url", `http://foo.com`),
            zap.Int("attempt", 3),
            zap.Duration("backoff", time.Second),
        )
    }
}

In the benchmark test above, we used logrus and zap to write the same content to io.Discard respectively, and the benchmark ran as follows.

1
2
3
4
5
6
7
8
9
$go test -bench .
goos: darwin
goarch: amd64
pkg: github.com/bigwhite/zap-usage
cpu: Intel(R) Core(TM) i5-8257U CPU @ 1.40GHz
BenchmarkLogrus-8         281667          4001 ns/op        1365 B/op         25 allocs/op
BenchmarkZap-8           1319922           901.1 ns/op       192 B/op          1 allocs/op
PASS
ok      github.com/bigwhite/zap-usage   3.296s

We see that zap’s write logging performance is four times that of logrus, and with only one memory allocation per op, logrus is indeed inferior in terms of performance and memory allocation.

There are strengths and weaknesses. As mentioned earlier, while zap is a top performer, it leaves a “shadow” on developers’ experience. For example, in the performance benchmark above, instead of writing to stdout or stderr, which is the default, we set output to io.Discard. Such a change requires only one line in logrus.

1
logger.SetOutput(io.Discard)

In the official home page of the zap project, I couldn’t find a way to make this change, and only after a while of searching and reading did I find the correct method (note: the method is not unique).

1
2
3
4
5
6
7
cfg := zap.NewProductionConfig()
core := zapcore.NewCore(
        zapcore.NewJSONEncoder(cfg.EncoderConfig),
        zapcore.AddSync(io.Discard),
        zapcore.InfoLevel,
)
logger := zap.New(core)

The above comparison of logrus and zap’s approach to creating loggers written to io.

So after choosing zap, how can we use zap better to try to bridge the gap with logrus and other logging libraries in terms of experience? That’s what I want to share with you in this article.

1. Wrapping zap to make it more usable

When you enter the Go world, the first log library you use will be the log package that comes with the Go standard library, which is “out of the box”.

1
2
3
4
5
6
7
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/stdlog/demo1.go 

import "log"

func main() {
    log.Println("this is go standard log package")
}

The sample code above outputs a line of log content directly to the standard error (stderr), and we didn’t even create a logger variable. Even writing the log to a file seems to be a very easy thing to do in the log package, see the following code snippet.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/stdlog/demo2.go 

package main

import (
    "log"
    "os"
)

func main() {
    file, err := os.OpenFile("./demo2.log", os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644)
    if err != nil {
        panic(err)
    }
    log.SetOutput(file)
    log.Println("this is go standard log package")
}

File, which implements io.Writer, to the SetOutput function of the log package. This way of writing logs without creating logger variables but directly using the package name + function reduces the complexity of passing and managing logger variables, and this user experience is the goal of our encapsulation of zap. However, we also need to have in mind that zap is a generic logging library, and after we package it, we only need to provide the features we need, there is no need to package it as a generic library like zap. In addition, users only need to rely on our packaged logging package, not explicitly on zap/zapcore.

Let’s build demo1.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/demo1
$tree demo1
demo1
├── go.mod
├── go.sum
├── main.go
└── pkg
    ├── log
       └── log.go
    └── pkg1
        └── pkg1.go

Our wrapper for zap is in pkg/log/log.go:.

  1
  2
  3
  4
  5
  6
  7
  8
  9
 10
 11
 12
 13
 14
 15
 16
 17
 18
 19
 20
 21
 22
 23
 24
 25
 26
 27
 28
 29
 30
 31
 32
 33
 34
 35
 36
 37
 38
 39
 40
 41
 42
 43
 44
 45
 46
 47
 48
 49
 50
 51
 52
 53
 54
 55
 56
 57
 58
 59
 60
 61
 62
 63
 64
 65
 66
 67
 68
 69
 70
 71
 72
 73
 74
 75
 76
 77
 78
 79
 80
 81
 82
 83
 84
 85
 86
 87
 88
 89
 90
 91
 92
 93
 94
 95
 96
 97
 98
 99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/demo1/pkg/log/log.go
package log

import (
    "io"
    "os"

    "go.uber.org/zap"
    "go.uber.org/zap/zapcore"
)

type Level = zapcore.Level

const (
    InfoLevel   Level = zap.InfoLevel   // 0, default level
    WarnLevel   Level = zap.WarnLevel   // 1
    ErrorLevel  Level = zap.ErrorLevel  // 2
    DPanicLevel Level = zap.DPanicLevel // 3, used in development log
    // PanicLevel logs a message, then panics
    PanicLevel Level = zap.PanicLevel // 4
    // FatalLevel logs a message, then calls os.Exit(1).
    FatalLevel Level = zap.FatalLevel // 5
    DebugLevel Level = zap.DebugLevel // -1
)

type Field = zap.Field

func (l *Logger) Debug(msg string, fields ...Field) {
    l.l.Debug(msg, fields...)
}

func (l *Logger) Info(msg string, fields ...Field) {
    l.l.Info(msg, fields...)
}

func (l *Logger) Warn(msg string, fields ...Field) {
    l.l.Warn(msg, fields...)
}

func (l *Logger) Error(msg string, fields ...Field) {
    l.l.Error(msg, fields...)
}
func (l *Logger) DPanic(msg string, fields ...Field) {
    l.l.DPanic(msg, fields...)
}
func (l *Logger) Panic(msg string, fields ...Field) {
    l.l.Panic(msg, fields...)
}
func (l *Logger) Fatal(msg string, fields ...Field) {
    l.l.Fatal(msg, fields...)
}

// function variables for all field types
// in github.com/uber-go/zap/field.go

var (
    Skip        = zap.Skip
    Binary      = zap.Binary
    Bool        = zap.Bool
    Boolp       = zap.Boolp
    ByteString  = zap.ByteString
    ... ...
    Float64     = zap.Float64
    Float64p    = zap.Float64p
    Float32     = zap.Float32
    Float32p    = zap.Float32p
    Durationp   = zap.Durationp
    ... ...
    Any         = zap.Any

    Info   = std.Info
    Warn   = std.Warn
    Error  = std.Error
    DPanic = std.DPanic
    Panic  = std.Panic
    Fatal  = std.Fatal
    Debug  = std.Debug
)

// not safe for concurrent use
func ResetDefault(l *Logger) {
    std = l
    Info = std.Info
    Warn = std.Warn
    Error = std.Error
    DPanic = std.DPanic
    Panic = std.Panic
    Fatal = std.Fatal
    Debug = std.Debug
}

type Logger struct {
    l     *zap.Logger // zap ensure that zap.Logger is safe for concurrent use
    level Level
}

var std = New(os.Stderr, int8(InfoLevel))

func Default() *Logger {
    return std
}

// New create a new logger (not support log rotating).
func New(writer io.Writer, level Level) *Logger {
    if writer == nil {
        panic("the writer is nil")
    }
    cfg := zap.NewProductionConfig()
    core := zapcore.NewCore(
        zapcore.NewJSONEncoder(cfg.EncoderConfig),
        zapcore.AddSync(writer),
        zapcore.Level(level),
    )
    logger := &Logger{
        l:     zap.New(core),
        level: level,
    }
    return logger
}

func (l *Logger) Sync() error {
    return l.l.Sync()
}

func Sync() error {
    if std != nil {
        return std.Sync()
    }
    return nil
}

In this package, we have the following notes.

  • Referring to the standard library log package, we provide the package level function interface, the bottom is the default Logger created: std.
  • You can use the New function to create your own Logger variable, but at this time can only use the methods of the instance to achieve log output, if you expect to use the package level function interface to output log, you need to call ResetDefault to replace the value of the updated std instance, so that subsequent calls to package level functions (Info, Debug), etc. will be output to the new instance of the target io. Writer. However, it is best to call ResetDefault to replace std before outputting any logs.
  • Since zap has to tell the specific type when outputting logs, zap wraps out Field and some sugar functions (Int, String, etc.). Here, in order not to expose zap to the user, we use type alias syntax to define our own equivalent to zap.Field for the type log.
1
type Field = zap.Field
  • We expose some of zap’s sugar functions (Int, String, etc.) to the user based on the “functions are first-class citizens” feature (this is also a method often used by Go unit tests in export_test.go).
1
2
3
4
5
6
7
8
var (
    Skip        = zap.Skip
    Binary      = zap.Binary
    Bool        = zap.Bool
    Boolp       = zap.Boolp
    ByteString  = zap.ByteString
    ... ...
)
  • We use method value syntax to expose each method of the std instance to the user as a package-level function, simplifying the user’s access to the logger instance.
1
2
3
4
5
6
7
8
9
var (
    Info   = std.Info
    Warn   = std.Warn
    Error  = std.Error
    DPanic = std.DPanic
    Panic  = std.Panic
    Fatal  = std.Fatal
    Debug  = std.Debug
)

The following is an example of how we can output logs directly to stderr using the default std using package level functions.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/demo1/main.go
package main

import (
    "github.com/bigwhite/zap-usage/pkg/log"
    "github.com/bigwhite/zap-usage/pkg/pkg1"
)

func main() {
    defer log.Sync()
    log.Info("demo1:", log.String("app", "start ok"),
        log.Int("major version", 2))
    pkg1.Foo()
}

In this main.go, we use package level functions directly to achieve log output like the standard library log package, and we don’t need to create logger instances, and we don’t need to manage and pass logger instances, in the log package another user pkg1 package, we can also use package level functions directly to output log.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/demo1/pkg/pkg1/pkg1.go

package pkg1

import "github.com/bigwhite/zap-usage/pkg/log"

func Foo() {
    log.Info("call foo", log.String("url", "https://tonybai.com"),
        log.Int("attempt", 3))
}

If you don’t want to use the default std, but want to create a logger that writes to a filesystem file, we can handle it like this.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/demo1/main_new_logger.go
package main

import (
    "os"

    "github.com/bigwhite/zap-usage/pkg/log"
    "github.com/bigwhite/zap-usage/pkg/pkg1"
)

func main() {
    file, err := os.OpenFile("./demo1.log", os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644)
    if err != nil {
        panic(err)
    }
    logger := log.New(file, log.InfoLevel)
    log.ResetDefault(logger)
    defer log.Sync()
    log.Info("demo1:", log.String("app", "start ok"),
        log.Int("major version", 2))
    pkg1.Foo()
}

We use log.New to create a new instance of Logger and then replace std with it via log.ResetDefault so that subsequent package level function calls (log.Info) will use the newly created Logger instance.

2. Customizing encoder

Running demo1 above, we will get the log content in a format similar to the following.

1
2
{"level":"info","ts":1625954037.630399,"msg":"demo1:","app":"start ok","major version":2}
{"level":"info","ts":1625954037.630462,"msg":"call foo","url":"https://tonybai.com","attempt":3}

We can customize the output content format of zap.

Before customizing, let’s take a look at the internal structure of zap.

zap

Similar to other log libraries, zap is composed of two key processes: creating loggers and writing logs. Core is a logging interface defined by zap, and as the name suggests, around this Core, zap provides upper-level logging objects and corresponding methods (zap.Logger combines zapcore.Core), and developers can also customize their own logging packages based on this interface ( For example: the previous implementation of our New function).

We generally create an instance that implements zapcore.Core through the zapcore.NewCore function. NewCore receives three parameters, which are also the main components of Core, and they are shown below.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
                                ┌───────────────┐
                                 │               │
                                 │               │
                      ┌─────────►│     Encoder   │
                      │          │               │
                      │          │               │
                      │          └───────────────┘
┌────────────────┐    │
│                ├────┘
│                │               ┌───────────────┐
│                │               │               │
│      Core      ├──────────────►│  WriteSyncer  │
│                │               │               │
│                ├─────┐         │               │
└────────────────┘     │         └───────────────┘
                       │         ┌───────────────┐
                       │         │               │
                       └────────►│  LevelEnabler │
                                 │               │
                                 │               │
                                 └───────────────┘
  • Encoder is the encoder for log messages.
  • WriteSyncer is an io.Writer that supports the Sync method, meaning the log output, and we can easily convert an io.Writer to a WriteSyncer that supports the Sync method via zap.AddSync.
  • LevelEnabler, on the other hand, is a log level related parameter.

From this we see that to customize the output format of the log, our focus is on the Encoder.

In terms of broad categories, zap has two built-in types of encoders, a ConsoleEncoder and a JSONEncoder. consoleEncoder is more suitable for human reading, while JSONEncoder is more suitable for machine processing. zap provides the two most commonly used functions for creating Loggers. NewProduction and NewDevelopment use JSONEncoder and ConsoleEncoder, respectively. a comparison of the default output of the two encoders is as follows.

1
2
3
4
5
// ConsoleEncoder(NewDevelopment创建)
2021-07-11T09:39:04.418+0800    INFO    zap/testzap2.go:12  failed to fetch URL {"url": "localhost:8080", "attempt": 3, "backoff": "1s"}

// JSONEncoder (NewProduction创建)
{"level":"info","ts":1625968332.269727,"caller":"zap/testzap1.go:12","msg":"failed to fetch URL","url":"localhost:8080","attempt":3,"backoff":1}

ConsoleEncoder output is more suitable for reading, while JSONEncoder output is more suitable for machine/program processing. As we said before, our packaged log package is not intended to be a generic log package, we do not need to support both types of Encoder, so we chose to use JSONEncoder in the above example.

1
2
3
4
5
    core := zapcore.NewCore(
        zapcore.NewJSONEncoder(cfg.EncoderConfig),
        zapcore.AddSync(writer),
        zapcore.Level(level),
    )

Based on Encoder, there are many things we can customize, and most developers are probably interested in customizing the date format, whether to display caller information for this log, etc.

The zap library itself also provides an Option interface based on the functional option model.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
// zap options.go
type Option interface {
    apply(*Logger)
}

func WithCaller(enabled bool) Option {
    return optionFunc(func(log *Logger) {
        log.addCaller = enabled
    })
}

If our log library is to provide some Encoder customization capability, we also need to expose zap.Option to the user through the type alias syntax like Field, and export part of zap’s option to the user in the form of a function type variable. As for the timestamp, we can fix it after choosing a format that suits us. The following is the demo2 log package, which is based on the demo1 log with some customizations to the encoder.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/demo2/pkg/log/log.go

var std = New(os.Stderr, InfoLevel, WithCaller(true))

type Option = zap.Option

var (
    WithCaller    = zap.WithCaller
    AddStacktrace = zap.AddStacktrace
)

// New create a new logger (not support log rotating).
func New(writer io.Writer, level Level, opts ...Option) *Logger {
    if writer == nil {
        panic("the writer is nil")
    }
    cfg := zap.NewProductionConfig()
    cfg.EncoderConfig.EncodeTime = func(t time.Time, enc zapcore.PrimitiveArrayEncoder) {
        enc.AppendString(t.Format("2006-01-02T15:04:05.000Z0700"))
    }

    core := zapcore.NewCore(
        zapcore.NewJSONEncoder(cfg.EncoderConfig),
        zapcore.AddSync(writer),
        zapcore.Level(level),
    )
    logger := &Logger{
        l:     zap.New(core, opts...),
        level: level,
    }
    return logger
}

After customization, the output of our log package will look like this.

1
2
3
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/demo2/
$go run main.go
{"level":"info","ts":"2021-07-11T10:45:38.858+0800","caller":"log/log.go:33","msg":"demo1:","app":"start ok"}

3. writing multiple log files

After customizing encoder, let’s take a look at writeSyncer. nginx, which I’m sure no one has ever used, has two important log files: access.log and error.log, the former being the normal access log and the latter being the error report log. If we also want to learn nginx and create two types of log files for the business system, one is similar to access.log, which records the log of normal business blowing, and the other is similar to error.log, which records the error log of the system, how should we design and implement it? Some people may say, then create two loggers. Yes, this is indeed a solution. But what if I just want to use a package level function to write multiple log files without passing logger instances? zap provides NewTee as an export function to write multiple log files.

Let’s do this with demo3, where we also provide an external NewTee function to create a logger that writes multiple log files.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/demo3/pkg/log/log.go
type LevelEnablerFunc func(lvl Level) bool

type TeeOption struct {
    W   io.Writer
    Lef LevelEnablerFunc
}

func NewTee(tops []TeeOption, opts ...Option) *Logger {
    var cores []zapcore.Core
    cfg := zap.NewProductionConfig()
    cfg.EncoderConfig.EncodeTime = func(t time.Time, enc zapcore.PrimitiveArrayEncoder) {
        enc.AppendString(t.Format("2006-01-02T15:04:05.000Z0700"))
    }
    for _, top := range tops {
        top := top
        if top.W == nil {
            panic("the writer is nil")
        }         

        lv := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
            return top.Lef(Level(lvl))
        })        

        core := zapcore.NewCore(
            zapcore.NewJSONEncoder(cfg.EncoderConfig),
            zapcore.AddSync(top.W),
            lv,
        )
        cores = append(cores, core)
    }

    logger := &Logger{
        l: zap.New(zapcore.NewTee(cores...), opts...),
    }
    return logger
}

We see that since multiple log files may choose whether to drop into the file based on the level of the log written, we provide a TeeOption type with a io.Writer and a level enabler func in the type definition, so let’s see how to use this NewTee function.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/demo3/main.go
package main

import (
    "os"

    "github.com/bigwhite/zap-usage/pkg/log"
)

func main() {
    file1, err := os.OpenFile("./access.log", os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644)
    if err != nil {
        panic(err)
    }
    file2, err := os.OpenFile("./error.log", os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644)
    if err != nil {
        panic(err)
    }

    var tops = []log.TeeOption{
        {
            W: file1,
            Lef: func(lvl log.Level) bool {
                return lvl <= log.InfoLevel
            },
        },
        {
            W: file2,
            Lef: func(lvl log.Level) bool {
                return lvl > log.InfoLevel
            },
        },
    }

    logger := log.NewTee(tops)
    log.ResetDefault(logger)

    log.Info("demo3:", log.String("app", "start ok"),
        log.Int("major version", 3))
    log.Error("demo3:", log.String("app", "crash"),
        log.Int("reason", -1))

}

We create two TeeOptions, corresponding to access.log and error.log, the former accepting logs at level<=info and the latter accepting logs at level>error. Let’s run the program.

1
2
3
4
5
$go run main.go
$cat access.log
{"level":"info","ts":"2021-07-11T12:09:47.736+0800","msg":"demo3:","app":"start ok","major version":3}
$cat error.log
{"level":"error","ts":"2021-07-11T12:09:47.737+0800","msg":"demo3:","app":"crash","reason":-1}

As we expected, different levels of logs are written to different files, and we can just call package level functions without having to manage and pass different loggers.

4. Make log files support auto-rotate (rotation)

If logs are written to a file, then sooner or later the file will be full! We can’t just sit back and do nothing! The industry’s common solution is log rotate, which means that when the log file size reaches a certain size, the file is archived and a new file is created to continue writing, a process that is transparent to the application.

There are usually two kinds of log rotate solutions, one is an external solution based on the logrotate tool, and the other is a log library that supports rotation itself. The compatibility of the zap library with the logrotate tool seems to be somewhat problematic, zap the official FAQ also recommends the second option master/FAQ.md#does-zap-support-log-rotation).

However, zap does not support rotate natively, but through an external package. zap provides a WriteSyncer interface that allows us to easily add rotate functionality to zap. Currently, natefinch’s lumberjack is the most official package in terms of logrotate support, so let’s see how to add logrotate to demo3’s multiple log files.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/demo4/pkg/log/log.go

type RotateOptions struct {
    MaxSize    int
    MaxAge     int
    MaxBackups int
    Compress   bool
}

type TeeOption struct {
    Filename string
    Ropt     RotateOptions
    Lef      LevelEnablerFunc
}

func NewTeeWithRotate(tops []TeeOption, opts ...Option) *Logger {
    var cores []zapcore.Core
    cfg := zap.NewProductionConfig()
    cfg.EncoderConfig.EncodeTime = func(t time.Time, enc zapcore.PrimitiveArrayEncoder) {
        enc.AppendString(t.Format("2006-01-02T15:04:05.000Z0700"))
    }

    for _, top := range tops {
        top := top

        lv := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
            return top.Lef(Level(lvl))
        })

        w := zapcore.AddSync(&lumberjack.Logger{
            Filename:   top.Filename,
            MaxSize:    top.Ropt.MaxSize,
            MaxBackups: top.Ropt.MaxBackups,
            MaxAge:     top.Ropt.MaxAge,
            Compress:   top.Ropt.Compress,
        })

        core := zapcore.NewCore(
            zapcore.NewJSONEncoder(cfg.EncoderConfig),
            zapcore.AddSync(w),
            lv,
        )
        cores = append(cores, core)
    }

    logger := &Logger{
        l: zap.New(zapcore.NewTee(cores...), opts...),
    }
    return logger
}

We added RotateOptions to TeeOption (this binding is not necessary, of course) and used lumberjack.Logger as the io.Writer to pass to zapcore.AddSync, thus creating a logger with the ability to write multiple log files and giving each log file the ability to automatically rotate function.

We use this log in main.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
// github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage/main.go
package main

import (
    "github.com/bigwhite/zap-usage/pkg/log"
)

func main() {
    var tops = []log.TeeOption{
        {
            Filename: "access.log",
            Ropt: log.RotateOptions{
                MaxSize:    1,
                MaxAge:     1,
                MaxBackups: 3,
                Compress:   true,
            },
            Lef: func(lvl log.Level) bool {
                return lvl <= log.InfoLevel
            },
        },
        {
            Filename: "error.log",
            Ropt: log.RotateOptions{
                MaxSize:    1,
                MaxAge:     1,
                MaxBackups: 3,
                Compress:   true,
            },
            Lef: func(lvl log.Level) bool {
                return lvl > log.InfoLevel
            },
        },
    }

    logger := log.NewTeeWithRotate(tops)
    log.ResetDefault(logger)

    // 为了演示自动rotate效果,这里多次调用log输出
    for i := 0; i < 20000; i++ {
        log.Info("demo3:", log.String("app", "start ok"),
            log.Int("major version", 3))
        log.Error("demo3:", log.String("app", "crash"),
            log.Int("reason", -1))
    }
}

Running the above main package, we will see the following output.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
// demo4

$go run main.go
$ls -l
total 3680
drwxr-xr-x  10 tonybai  staff      320  7 11 12:54 ./
drwxr-xr-x   8 tonybai  staff      256  7 11 12:23 ../
-rw-r--r--   1 tonybai  staff     3938  7 11 12:54 access-2021-07-11T04-54-04.697.log.gz
-rw-r--r--   1 tonybai  staff  1011563  7 11 12:54 access.log
-rw-r--r--   1 tonybai  staff     3963  7 11 12:54 error-2021-07-11T04-54-04.708.log.gz
-rw-r--r--   1 tonybai  staff   851580  7 11 12:54 error.log

We see that both access.log and error.log complete an automatic rotation after the size exceeds 1M, and the archived logs are compressed according to the previous configuration (compress).

5. Summary

This article provides an in-depth explanation of how to use the zap log library, including a way to encapsulate zap so that we can output logs directly through package-level functions like the standard library log package without having to manage and pass logger variables; we can customize the zap encoder (time, whether to output caller, etc.); with NewTee we can create We can customize the zap encoder (time, whether to output caller, etc.); with NewTee, we can create loggers that write to multiple log files at once, and we can determine whether to accept writes by log level; finally, we make zap logs support automatic rotation.

If there is a shortcoming, it is that zap does not support dynamically setting the log level of the global logger, but there seems to be a third-party solution, so we won’t go deeper here and leave it as a legacy issue.

The code involved in this article can be downloaded at here.