日志在后端系统的地位举足轻重。它可以在程序出现问题时,为开发人员提供线索。
对性能敏感的领域和场景,由 Uber 开源的日志库 zap 将是首选。zap 的主要优点包括:

  • 避免使用 Interface{}
  • 避免使用反射,每个要输出到日志的字段,都需要携带类型信息。这减少了开发人员对 zap 的体验,但是与它实现的性能提升相比,这似乎算不上什么
logger.Info("Access URL Success",
    zap.String("url", `https://weizicoding.com`),
    zap.Int("status", 200),
    zap.Duration("second", time.Second),
)
  • 使用 sync.Pool 减少堆内存分配,并且还减少了 GC 的压力

这是一个简单的 zap 与 logrus 性能基准测试。logrus 也是 Go 生态中的开源日志库,它提供了结构化日志,并且在 api 级别兼容 Go 标准库中的 log 包,在对性能不敏感的领域和场景,logrus 也是一个不错的选择。

package zap_log

import (
    "github.com/sirupsen/logrus"
    "go.uber.org/zap"
    "go.uber.org/zap/zapcore"
    "io"
    "testing"
    "time"
)

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":     "https://weizicoding.com",
            "status":  "500",
            "backoff": time.Second,
        }).Info("Access URL Fail")
    }
}

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("Access URL Fail",
            zap.String("url", "https://weizicoding.com"),
            zap.Int("status", 500),
            zap.Duration("backoff", time.Second))
    }
}

在上面的基准测试中,将相同的内容使用 logrus 和 zap 写入 io 后再丢弃,在终端执行 $ go test -bench .结果如下。

goos: darwin
goarch: amd64
pkg: weizicoding.com/zap-log
cpu: Intel(R) Core(TM) i7-9750H CPU @ 2.60GHz
BenchmarkLogrus-12        330294              3616 ns/op            1373 B/op         25 allocs/op
BenchmarkZap-12          1264275               933.8 ns/op           192 B/op          1 allocs/op
PASS
ok      weizicoding.com/zap-log 4.781s

zap 写入日志的性能约是 logrus 的 3.87 倍,并且每个操作只有一次内存分配,每次操作分配的内存也是 logruse 的五分之一。

虽然 zap 性能更好,但是它的开发体验却不怎么样。例如,在上面的基准测试中,将输出设置为 io.Discard,这样的设置在 logrus 中只需要一行。

logger.SetOutput(io.Discard)

但是在 zap 中,我找不到这样的方法,而是经过一段时间的源码阅读和文档查询,才找到了能达到我目的的方法。

cfg := zap.NewProductionConfig()
core := zapcore.NewCore(
        zapcore.NewJSONEncoder(cfg.EncoderConfig),
        zapcore.AddSync(io.Discard),
        zapcore.InfoLevel,
)
logger := zap.New(core)

那么在选择了 zap 之后,如何才能在使用 zap 的同时,保持以前使用其他日志库的经验呢?这就需要自己去封装 zap 了,这也是为什么,很多时候使用框架时,不直接使用 zap,而是使用基于 zap 去封装的日志库的原因!

基于 zap 自定义日志组件

当你刚使用 Go 时,你使用的第一个日志库是什么呢?我想大多数 Gopher 都是 Go 标准库中的日志库,因为它是“开箱即用”的。

package stdlog

import "log"

func main() {
    log.Println("这是 Go 标准库中的日志包")
}

上面的代码将一行日志内容直接输出到终端,我们甚至没有创建 logger 变量。在标准库中,将日志写入文件也是一件简单的事,代码如下。

import (
    "log"
    "os"
)

func main() {
    f, err := os.OpenFile("./demo2.log", os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644)
    if err != nil {
        panic(err)
    }
    log.SetOutput(f)
    log.Println("Go 标准库中将日志内容写入文件")
}

os.OpenFile()的返回值 f 是 *File 类型,该类型实现了 io.Writer,标准库 log.SetOutput() 函数的入参就是 io.Writer 类型,因此 f 可以直接传入 log.SetOutput()。这种不创建 logger 变量的情况下,通过包名+函数的方法,直接写入日志到文件的方式,降低了函数调用传入参数和管理 logger 变量的复杂性,这就是我们封装 zap 要达到的目标。另外,我们要知道,zap 是一个通用的日志库,我们自定义自己的组件,我们只需要提供我们需要的功能。此外,用户只需要依赖我们自定义的日志包,不需要显式依赖 zap/zapcore。

让我们开始写代码吧!把自定义的日志库放在 pkg/log/log.go 中。

$ tree demo1
demo1
├── main.go
└── 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
    WarnLevel   Level = zap.WarnLevel
    ErrorLevel  Level = zap.ErrorLevel
    DPanicLevel Level = zap.DPanicLevel
    PanicLevel  Level = zap.PanicLevel
    FatalLevel  Level = zap.FatalLevel
    DebugLevel  Level = zap.DebugLevel
)

// 由于 zap 在输出日志时,必须告诉特定类型,并且为了不向调用者暴露 zap,我们使用类型别名的方式,来定义
// zap.Field 的等价物

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

// 函数是一等公民, 向调用者公开部分 zap 的函数

var (
    String = zap.String
    Int    = zap.Int
)

// 将每个方法作为包级函数公开给调用者, 简化调用者对 logger 实例的访问

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

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
    level Level
}

var std = New(os.Stderr, InfoLevel)

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

下面的示例,说明我们如何使用刚才封装的日志库,它直接输出到 std,并且像 Go 标准库中的日志包一样,直接使用包级函数,不需要管理和传递 Logger 变量实例。

package main

import "weizicoding.com/zap-log/demo1/pkg/log"

func main() {
    defer log.Sync()
    log.Info("demo1", log.String("hello", "world"))
}

如果你不想使用默认的输出到 std,而是希望写入到指定文件中,可以这样处理。

package main

import (
    "os"
    "weizicoding.com/zap-log/demo1/pkg/log"
)

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

    logger := log.New(f, log.InfoLevel)

    log.ResetDefault(logger)

    defer log.Sync()

    log.Info("demo1:", log.String("hello", "world"), log.Int("status", 200))
}

我们先创建了日志记录文件,再创建新的 logger 实例,通过 log.ResetDefault() 将默认的输出到 std 的 logger 替换,这是为了方便后续包级函数调用,它们都可以使用新创建的 logger 实例。
自定义编码器
运行上面 demo1/main.go,我们可以获得类似一下内容的格式的日志内容。

{"level":"info","ts":1692174669.31306,"msg":"demo1:","hello":"world","status":200}

我们可以自定义 zap 输出的内容格式。在这之前,先了解一下 zap 的内部结构。

日志包通常由两个关键过程组成,创建 Logger 和写入日志,zap 也不例外。zap 围绕 core 日志接口,提供了创建 Logger 和写入日志的方法。开发者也可以基于这个 core 接口定制自己的日志包,例如之前我们实现的 New 函数。

我们可以通过 zapcore.NewCore ,创建一个 zapcore 的实例,该方法接收三个参数:Encoder 日志消息编码器、WriteSyncer 日志输出、LevelEnabler 日志级别。

由此可以看到,要自定义日志的输出格式,重点是 Encoder 。

就广泛的类别而言,zap 有两种内置类型的编码器,一个 ConsoleEncoder 和一个JSONEncoder。ConsoleEncoder 更适合人工阅读,而 JSONEncoder 更适合机器处理。zap 提供了两个最常用的创建记录器函数:NewProduction 和 NewDevelopment 分别使用 JSONEncoder 和 ConsoleEncoder。两个编码器的默认输出如下。

/ ConsoleEncoder(NewDevelopment创建)
2023-08-22 T16:10:12.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}

我们的日志包并不打算成为通用的日志包,不需要支持这两种类型的编码器,所以我们在上面的例子中选择使用 JSONEncoder。

    core := zapcore.NewCore(
        zapcore.NewJSONEncoder(cfg.EncoderConfig),
        zapcore.AddSync(writer),
        zapcore.Level(level),
    )

基于 Encoder,我们可以自定义很多东西,例如自定义日期格式、日志级别打印时是否大写等。

zap 库本身还提供了基于功能选项模型的选项接口。

// zap options.go
type Option interface {
    apply(*Logger)
}

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

如果我们的日志库要提供一些编码器自定义功能,我们还需要公开 zap。选项通过类型别名语法向用户提供,并将 zap 的部分选项以函数类型变量的形式导出给调用者。

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

type Option = zap.Option

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

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
}

自定义后,日志包的输出如下。

{"level":"info","ts":"2023-08-22T16:11:38.858+0800","caller":"log/log.go:33","msg":"demo1:","app":"start ok"}

写入多个日志文件

自定义编码器后,让我们来看看 writeSyncer 日志输出。Nginx,相信每个人都使用过,它有两个重要的日志文件:access.log 正常访问日志和 error.log 错误报告日志。我们也像 Nginx 一样,为我们的系统简历两种类型的日志文件,应该如何设计和实现呢?

有人可能会说,创建两个 logger。这确实是一种解决方案。但如果我只想使用包级函数来写入多个日志文件,而不传递 logger,该怎么办?zap 提供了 NewTee 函数来将日志写入多个日志文件。代码如下。

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
    c := zap.NewProductionConfig()
    c.EncoderConfig.EncodeTime = func(t time.Time, enc zapcore.PrimitiveArrayEncoder) {
        enc.AppendString(t.Format("2006-01-02T15:04:05.000Z0700"))
    }
    for _, top := range tops {
        if top.W == 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
}

由于多个日志文件可能会根据写入的日志级别选择是否放入文件中,因此我们提供了一个带有 io 的 TeeOption 类型。下面的代码演示如何使用这个 NewTee 函数。

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

    // 创建两个日志级别的文件, 前者接收 level <= info 级别的日志
    // 后者接收 level > error 级别的日志
    var tops = []log.TeeOption{
        {
            W: f1,
            Lef: func(lvl log.Level) bool {
                return lvl <= log.InfoLevel
            },
        },
        {
            W: f2,
            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("status", 200))
    log.Error("demo3:", log.String("app", "faild"),
        log.Int("reason", 404))
}

正如我们所期望的那样,不同级别的日志被写入不同的文件,同时我们可以只调用包级函数,而不必管理和传递不同的记录器。

$ go run main.go
$ cat access.log

{"level":"info","ts":"2023-08-22T16:24:47.736+0800","msg":"demo3:","app":"start ok","status":200}
$cat error.log
{"level":"error","ts":"2023-08-22T12:24:47.737+0800","msg":"demo3:","app":"faild","reason":404}
我曾经做过一个需求,创建每天根据日志多个日志文件,文件名中要有日期和级别,遇见了一个奇怪的问题,构造日志 cores 的时候,级别参数,如果使用实现的方式,无法写入日志,但是直接赋值 zap.Level 的枚举值就可以。

使日志文件支持自动轮转

如果日志写入文件,那么文件迟早会满,这是无法忽视的问题,业界常见的解决方案是日志轮换,这意味着当日志文件大小达到一定大小时,将存档文件创建一个新文件以继续写入。

日志轮换解决方案通常有两种,一种是基于日志轮换工具的外部解决方案,另一种是基于日志轮换工具的日志库。zap 官方推荐后者。但是,zap 不支持日志自动轮换,而是通过外部包。zap 提供了一个 WriteSyncer 接口,使我们能够轻松地向 zap 添加轮转功能。

目前 github.com/natefinch/lumberjack 是常用的轮转日志库工具。

接下来让我们一起通过 lumberjack 为日志添加自动轮转的能力。

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 {

        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
}

我们将 RotateOptions 添加到 TeeOption 中,为每个日志文件提供自动轮转功能。下面的代码演示如何使用。

func main() {
    var tops = []log.TeeOption{
        {
            Filename: "info.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)

    for i := 0; i < 20000; i++ {
        log.Info("demo3:", log.String("app", "start ok"),
            log.Int("status", 200))
        log.Error("demo3:", log.String("app", "faild"),
            log.Int("reason", 404))
    }
}

运行后当前工作区目录输出如下。无论是 info.log 还是 error.log,在大小超过 1M 后完成自动轮换,归档的日志按照之前的配置进行压缩。

$go run main.go
$ls -l
total 3680
drwxr-xr-x  10 gongguowei  staff      320  7 11 16:34 ./
drwxr-xr-x   8 gongguowei  staff      256  7 11 16:34 ../
-rw-r--r--   1 gongguowei  staff     3938  7 11 16:35 info-2023-08-22T16-35-04.697.log.gz
-rw-r--r--   1 gongguowei  staff  1011563  7 11 16:35 info.log
-rw-r--r--   1 gongguowei  staff     3963  7 11 16:35 error-2023-08-22T16-35-04.708.log.gz
-rw-r--r--   1 gongguowei  staff   851580  7 11 16:35 error.log
最后修改:2023 年 09 月 06 日
如果觉得我的文章对你有用,请随意赞赏