标签 Golang 下的文章

一文搞懂Go语言的plugin

本文永久链接 – https://tonybai.com/2021/07/19/understand-go-plugin

要历数Go语言中还有哪些我还没用过的特性,在Go 1.8版本中引入的go plugin算一个。近期想给一个网关类平台设计一个插件系统,于是想起了go plugin^_^。

Go plugin支持将Go包编译为共享库(.so)的形式单独发布,主程序可以在运行时动态加载这些编译为动态共享库文件的go plugin,从中提取导出(exported)变量或函数的符号并在主程序的包中使用。Go plugin的这种特性为Go开发人员提供更多的灵活性,我们可以用之实现支持热插拔的插件系统。

但不得不提到的一个事实是:go plugin自诞生以来已有4年多了,但它依旧没有被广泛地应用起来。究其原因,(我猜)一方面Go自身支持静态编译,可以将应用编译为一个完全不需要依赖操作系统运行时库(一般为libc)的可执行文件,这是Go的优势,而支持go plugin则意味着你只能对主程序进行动态编译,与静态编译的优势相悖;而另外一方面原因占比更大,那就是Go plugin自身有太多的对使用者的约束,这让很多Go开发人员望而却步。

只有亲历,才能体会到其中的滋味。在这篇文章中,我们就一起来看看go plugin究竟是何许东东,它对使用者究竟有着怎样的约束,我们究竟要不要使用它。

1. go plugin的基本使用方法

截至Go 1.16版本,Go官方文档明确说明go plugin只支持Linux, FreeBSD和macOS,这算是go plugin的第一个约束。在处理器层面,go plugin以支持amd64(x86-64)为主,对arm系列芯片的支持似乎没有明确说明(我翻看各个Go版本release notes也没看到,也许是我漏掉了),但我在华为的泰山服务器(鲲鹏arm64芯片)上使用Go 1.16.2(for arm64)版本构建plugin包以及加载动态共享库.so文件的主程序都顺利通过编译,运行也一切正常。

主程序通过plugin包加载.so并提取.so文件中的符号的过程与C语言应用运行时加载动态链接库并调用库中函数的过程如出一辙。下面我们就来看一个直观的例子。

下面是这个例子的结构布局:

// github.com/bigwhite/experiments/tree/master/go-plugin

├── demo1
│   ├── go.mod
│   ├── main.go
│   └── pkg
│       └── pkg1
│           └── pkg1.go
└── demo1-plugins
    ├── Makefile
    ├── go.mod
    └── plugin1.go

其中demo1代表主程序工程,demo1-plugins是主程序的plugins工程。下面是插件工程的代码:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo1-plugins/plugin1.go

package main

import (
    "fmt"
    "log"
)

func init() {
    log.Println("plugin1 init")
}

var V int

func F() {
    fmt.Printf("plugin1: public integer variable V=%d\n", V)
}

type foo struct{}

func (foo) M1() {
    fmt.Println("plugin1: invoke foo.M1")
}

var Foo foo

plugin包和普通的Go包没太多区别,只是plugin包有一个约束:其包名必须为main,我们使用下面命令编译该plugin:

$go build -buildmode=plugin -o plugin1.so plugin1.go

如果plugin源代码没有放置在main包下面,我们在编译plugin时会遭遇如下编译器错误:

-buildmode=plugin requires exactly one main package

接下来,我们来看主程序(demo1):

package main

import (
    "fmt"

    "github.com/bigwhite/demo1/pkg/pkg1"
)

func main() {
    err := pkg1.LoadAndInvokeSomethingFromPlugin("../demo1-plugins/plugin1.so")
    if err != nil {
        fmt.Println("LoadAndInvokeSomethingFromPlugin error:", err)
        return
    }
    fmt.Println("LoadAndInvokeSomethingFromPlugin ok")
}

下面是主程序demo1工程中的关键代码:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo1/main.go
package main

import (
    "fmt"

    "github.com/bigwhite/demo1/pkg/pkg1"
)

func main() {
    err := pkg1.LoadAndInvokeSomethingFromPlugin("../demo1-plugins/plugin1.so")
    if err != nil {
        fmt.Println("LoadAndInvokeSomethingFromPlugin error:", err)
        return
    }
    fmt.Println("LoadAndInvokeSomethingFromPlugin ok")
}

我们在main函数中调用pkg1包的LoadAndInvokeSomethingFromPlugin函数,该函数会加载main函数传入的go plugin、查找plugin中相应符号并通过这些符号使用plugin中的导出变量、函数等。下面是LoadAndInvokeSomethingFromPlugin函数的实现:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo1/pkg/pkg1/pkg1.go

package pkg1

import (
    "errors"
    "plugin"
    "log"
)

func init() {
    log.Println("pkg1 init")
}

type MyInterface interface {
    M1()
}

func LoadAndInvokeSomethingFromPlugin(pluginPath string) error {
    p, err := plugin.Open(pluginPath)
    if err != nil {
        return err
    }

    // 导出整型变量
    v, err := p.Lookup("V")
    if err != nil {
        return err
    }
    *v.(*int) = 15

    // 导出函数变量
    f, err := p.Lookup("F")
    if err != nil {
        return err
    }
    f.(func())()

    // 导出自定义类型变量
    f1, err := p.Lookup("Foo")
    if err != nil {
        return err
    }
    i, ok := f1.(MyInterface)
    if !ok {
        return errors.New("f1 does not implement MyInterface")
    }
    i.M1()

    return nil
}

在LoadAndInvokeSomethingFromPlugin函数中,我们通过plugin包提供的Plugin类型提供的Lookup方法在加载的.so中查找相应的导出符号,比如上面的V、F和Foo等。Lookup方法返回plugin.Symbol类型,而Symbol类型定义如下:

// $GOROOT/src/plugin/plugin.go
type Symbol interface{}

我们看到Symbol的底层类型(underlying type)是interface{},因此它可以承载从plugin中找到的任何类型的变量、函数(得益于函数是一等公民)的符号。而plugin中定义的类型则是不能被主程序查找的,通常主程序也不会依赖plugin中定义的类型。

一旦Lookup成功,我们便可以将符号通过类型断言(type assert)获取到其真实类型的实例,通过这些实例(变量或函数),我们可以调用plugin中实现的逻辑。编译plugin后,运行上述主程序,我们可以看到如下结果:

$go run main.go
2021/06/15 10:05:22 pkg1 init
try to LoadAndInvokeSomethingFromPlugin...
2021/06/15 10:05:22 plugin1 init
plugin1: public integer variable V=15
plugin1: invoke foo.M1
LoadAndInvokeSomethingFromPlugin ok

那么,主程序是如何知道导出的符号究竟是函数还是变量呢?这取决于主程序插件系统的设计,因为主程序与plugin间必然要有着某种“契约”或“约定”。就像上面主程序定义的MyInterface接口类型,它就是一个主程序与plugin之间的约定,plugin中只要暴露实现了该接口的类型实例,主程序便可以通过MyInterface接口类型实例与其建立关联并调用plugin中的实现 。

2. plugin中包的初始化

在上面的例子中我们看到,插件的初始化(plugin1 init)发生在主程序open .so文件时。按照官方文档的说法:“当一个插件第一次被open时,plugin中所有不属于主程序的包的init函数将被调用,但一个插件只被初始化一次,而且不能被关闭”。

我们来验证一下在主程序中多次加载同一个plugin的情况,这次我们将程序升级为demo2和demo2-plugins:

主程序代码如下:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo2/main.go

package main

import (
    "fmt"

    "github.com/bigwhite/demo2/pkg/pkg1"
)

func main() {
    fmt.Println("try to LoadPlugin...")
    err := pkg1.LoadPlugin("../demo2-plugins/plugin1.so")
    if err != nil {
        fmt.Println("LoadPlugin error:", err)
        return
    }
    fmt.Println("LoadPlugin ok")
    err = pkg1.LoadPlugin("../demo2-plugins/plugin1.so")
    if err != nil {
        fmt.Println("Re-LoadPlugin error:", err)
        return
    }
    fmt.Println("Re-LoadPlugin ok")
}

package pkg1

import (
    "log"
    "plugin"
)

func init() {
    log.Println("pkg1 init")
}

func LoadPlugin(pluginPath string) error {
    _, err := plugin.Open(pluginPath)
    if err != nil {
        return err
    }
    return nil
}

由于仅是验证初始化,我们去掉了查找符号和调用的环节。plugin的代码如下:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo2-plugins/plugin1.go
package main

import (
    "log"

    _ "github.com/bigwhite/common"
)

func init() {
    log.Println("plugin1 init")
}

在demo2的plugin中,我们同样仅保留初始化相关的代码,这里我们在demo2的plugin1中还增加了一个外部依赖:github.com/bigwhite/common。

运行上述代码:

$go run main.go
2021/06/15 10:50:47 pkg1 init
try to LoadPlugin...
2021/06/15 10:50:47 common init
2021/06/15 10:50:47 plugin1 init
LoadPlugin ok
Re-LoadPlugin ok

通过这个输出结果,我们验证了两点说法:

  • 重复加载同一个plugin,不会触发多次plugin包的初始化,上述结果中仅输出一次:“plugin1 init”;
  • plugin中依赖的包,但主程序中没有的包,在加载plugin时,这些包会被初始化,如:“commin init”。

如果主程序也依赖github.com/bigwhite/common包,我们在主程序的main包中增加一行:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo2/main.go
import (
    "fmt"   

    _ "github.com/bigwhite/common"    // 增加这一行
    "github.com/bigwhite/demo2/pkg/pkg1"
)

那么我们再执行demo2,输出如下结果:

2021/06/15 11:00:00 common init
2021/06/15 11:00:00 pkg1 init
try to LoadPlugin...
2021/06/15 11:00:00 plugin1 init
LoadPlugin ok
Re-LoadPlugin ok

我们看到common包在demo2主程序中已经做了初始化,这样当加载plugin时,common包不会再进行初始化了。

3. go plugin的使用约束

开篇我们就提到了,go plugin应用不甚广泛的一个主因是其约束较多,这里我们来看一下究竟go plugin都有哪些约束:

1) 主程序与plugin的共同依赖包的版本必须一致

在上面demo2中,主程序和plugin依赖的github.com/bigwhite/common包是一个本地module,我们在go.mod中使用replace指向本地路径:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo2/go.mod

module github.com/bigwhite/demo2

replace github.com/bigwhite/common => /Users/tonybai/go/src/github.com/bigwhite/experiments/go-plugin/common

require github.com/bigwhite/common v0.0.0-20180202201655-eb2c6b5be1b6 // 这个版本号是自行“伪造”的

go 1.16

如果我clone一份common包,将其放在common1目录下,并在plugin的go.mod中将replace github.com/bigwhite/common语句指向common1目录,我们重新编译主程序和plugin后,运行主程序,我们将得到如下结果:

$go run main.go
2021/06/15 14:09:07 common init
2021/06/15 14:09:07 pkg1 init
try to LoadPlugin...
LoadPlugin error: plugin.Open("../demo2-plugins/plugin1"): plugin was built with a different version of package github.com/bigwhite/common

我们看到因common的版本不同,plugin加载失败,这是plugin使用的一个约束:主程序与plugin的共同依赖包的版本必须一致

我们再来看一个主程序与plugin有共同以来包的例子。我们建立demo3,在这个版本中,主程序和plugin都依赖了logrus日志包,但主程序使用的是logrus 1.8.1版本,而plugin使用的是logrus 1.8.0版本,分别编译后,我们运行主程序:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo3

2021/06/15 14:18:35 pkg1 init
try to LoadPlugin...
LoadPlugin error: plugin.Open("../demo3-plugins/plugin1"): plugin was built with a different version of package github.com/sirupsen/logrus

我们看到主程序运行报错,和前面的例子提示一样,都是因为使用了版本不一致的第三方包。要想解决这个问题,我们只需让两者使用的logrus包版本保持一致即可,比如将主程序的logrus从v1.8.1降级为v1.8.0:

$go get github.com/sirupsen/logrus@v1.8.0
go get: downgraded github.com/sirupsen/logrus v1.8.1 => v1.8.0
$go run main.go
2021/06/15 14:19:09 pkg1 init
try to LoadPlugin...
2021/06/15 14:19:09 plugin1 init
LoadPlugin ok

我们看到降级logrus版本后,主程序便可以正常加载plugin了。

还有一种情况,那就是主程序与plugin使用了同一个module的不同major版本的包,由于major版本不同,虽然是同一module,但实则是两个不同的包,这不会影响主程序对plugin的加载。但问题在于这个被共同依赖的module也会有自己的依赖包,当其不同major版本所依赖的某个包的版本不同时,同样会导致主程序加载plugin出现问题。 比如:主程序依赖go-redis/redis的v6.15.9+incompatible版本,而plugin依赖的是go-redis/redis/v8版本,当我们使用这样的主程序去加载plugin时,我们会遇到如下错误:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo3

$go run main.go
2021/06/15 14:32:11 pkg1 init
try to LoadPlugin...
LoadPlugin error: plugin.Open("../demo3-plugins/plugin1"): plugin was built with a different version of package golang.org/x/sys/unix

我们看到redis版本并未出错,但问题出在redis与redis/v8所依赖的golang.org/x/sys的版本不同,这种间接依赖的module的版本的不一致同样会导致go plugin加载失败,这同样是go plugin的使用约束之一。

2) 如果采用mod=vendor构建,那么主程序和plugin必须基于同一个vendor目录构建

基于vendor构建是go 1.5版本引入的特性,go 1.11版本引入go module构建模式后,vendor构建的方式得以保留。那么问题来了,如果主程序或plugin采用vendor构建或同时采用vendor构建,那么主程序是否可以正常加载plugin呢?我们来用示例demo4验证一下。(demo4和demo3大同小异,这里就不列出具体代码了)。

首先我们分别为主程序(demo4)和plugin(demo4-plugins)生成vendor目录:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4
$go mod vendor

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4-plugins
$go mod vendor

我们测试如下三种情况(go 1.16版本默认在有vendor的情况下,优先使用vendor构建。所以要基于mod构建需要显式的传入-mod=mod):

  • 主程序基于mod构建,插件基于vendor构建
// github.com/bigwhite/experiments/tree/master/go-plugin/demo4-plugins
$go build -mod=vendor -buildmode=plugin -o plugin1.so plugin1.go

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4
$go build -mod=mod -o main.mod main.go

$main.mod
2021/06/15 15:41:21 pkg1 init
try to LoadPlugin...
LoadPlugin error: plugin.Open("../demo4-plugins/plugin1"): plugin was built with a different version of package golang.org/x/sys/unix
  • 主程序基于vendor构建,插件基于mod构建
// github.com/bigwhite/experiments/tree/master/go-plugin/demo4-plugins
$go build -mod=mod -buildmode=plugin -o plugin1.so plugin1.go

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4
$go build -mod=vendor -o main.vendor main.go

$./main.vendor
2021/06/15 15:44:15 pkg1 init
try to LoadPlugin...
LoadPlugin error: plugin.Open("../demo4-plugins/plugin1"): plugin was built with a different version of package golang.org/x/sys/unix
  • 主程序和插件分别基于各自的vendor构建
// github.com/bigwhite/experiments/tree/master/go-plugin/demo4-plugins
$go build -mod=vendor -buildmode=plugin -o plugin1.so plugin1.go

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4
$go build -mod=vendor -o main.vendor main.go

$./main.vendor
2021/06/15 15:45:11 pkg1 init
try to LoadPlugin...
LoadPlugin error: plugin.Open("../demo4-plugins/plugin1"): plugin was built with a different version of package golang.org/x/sys/unix

从上面的测试,我们看到无论是哪一方采用vendor构建,或者双方都基于各自vendor构建,主程序加载plugin都会失败。如何解决这一问题呢?让主程序和plugin基于同一个vendor构建!

我们将plugin1.go拷贝到demo4中,然后分别用vendor构建构建主程序和plugin1.go:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4
$go build -mod=vendor -o main.vendor main.go

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4
$go build -mod=vendor -buildmode=plugin -o plugin1.so plugin1.go

将编译生成的plugin1.so拷贝到demo4-plugins中,然后运行main.vendor:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4
$cp plugin1.so ../demo4-plugins
$main.vendor
2021/06/15 15:48:56 pkg1 init
try to LoadPlugin...
2021/06/15 15:48:56 plugin1 init
LoadPlugin ok

我们看到基于同一vendor的主程序与plugin是可以相容的。下面的表格总结了主程序与plugin采用不同构建模式时是否相容:

插件构建方式\主程序构建方式 基于mod 基于自己的vendor
基于mod 加载成功 加载失败
基于基于自己的vendor 加载失败 加载失败

在vendor构建模式下,只有基于同一个vendor目录构建时,plugin才能被主程序加载成功

3) 主程序与plugin使用的编译器版本必须一致

如果我们使用不同版本的Go编译器分别编译主程序以及plugin,那么这两者是否能相容呢?我们还拿demo4来验证一下。我在主机上准备了go 1.16.5和go 1.16两个版本的Go编译器,go 1.16.5是go 1.16的patch维护版本,其区别与go 1.16与go 1.15相比则不是一个量级的,我们用go 1.16编译主程序,用go 1.16.5编译plugin:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4-plugins
$go version
go version go1.16.5 darwin/amd64
$go build -buildmode=plugin -o plugin1.so plugin1.go

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4
$go version
go version go1.16 darwin/amd64

$go run main.go
2021/06/15 15:58:44 pkg1 init
try to LoadPlugin...
LoadPlugin error: plugin.Open("../demo4-plugins/plugin1"): plugin was built with a different version of package runtime/internal/sys

我们看到即便用patch版本编译,plugin与主程序也是不兼容的。我们将demo4升级到用go 1.16.5版本编译:

$go version
go version go1.16.5 darwin/amd64
$go run main.go
2021/06/15 15:59:05 pkg1 init
try to LoadPlugin...
2021/06/15 15:59:05 plugin1 init
LoadPlugin ok

我们看到只有主程序与plugin采用完全相同的版本(patch版本也要相同)编译时,它们才是相容的,主程序才能正常加载plugin。

那么操作系统版本是否影响主程序和plugin的相容性呢?这个没有官方说明,我亲测了一下。我在centos 7.6(amd64, go 1.16.5)上构建了demo4-plugin(基于mod=mod),然后将其拷贝到一台ubuntu 18.04(amd64, go1.16.5)的主机上,ubuntu主机上的demo4主程序可以与centos上编译出来的plugin相容。

4) 使用plugin的主程序仅能使用动态链接

Go以静态编译便于分发和部署著称,但使用plugin的主程序仅能使用动态链接。不信?那我们来挑战一下静态编译demo4中的主程序。

先来看看默认编译的情况:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4
$go build main.go
$ldd main
    linux-vdso.so.1 (0x00007ffc05b73000)
    libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007f6a9fa3f000)
    libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007f6a9f820000)
    libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f6a9f42f000)
    /lib64/ld-linux-x86-64.so.2 (0x00007f6a9fc43000)

我们看到默认编译的情况下,demo4主程序被编译为一个需要在运行时动态链接的可执行文件,它依赖诸多linux系统运行时库,比如:libc等。

这一切的原因都是我们在demo4中使用了一些通过cgo实现的标准库,比如plugin包:

// $GOROOT/src/plugin/plugin_dlopen.go

// +build linux,cgo darwin,cgo freebsd,cgo

package plugin

/*
#cgo linux LDFLAGS: -ldl
#include <dlfcn.h>
#include <limits.h>
#include <stdlib.h>
#include <stdint.h>

#include <stdio.h>

static uintptr_t pluginOpen(const char* path, char** err) {
    void* h = dlopen(path, RTLD_NOW|RTLD_GLOBAL);
    if (h == NULL) {
        *err = (char*)dlerror();
    }
    return (uintptr_t)h;
}
... ...
*/

我们看到plugin_dlopen.go的头部有build指示符,它仅在cgo开启的前提下才会被编译,如果我们去掉cgo,比如利用下面这行命令:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4
$ CGO_ENABLED=0 go build main.go
$ ldd main
    not a dynamic executable

我们确实编译出一个静态链接的可执行文件,但当我们执行该文件时,我们得到如下结果:

$ ./main
2021/06/15 17:01:51 pkg1 init
try to LoadPlugin...
LoadPlugin error: plugin: not implemented

我们看到由于cgo被关闭,plugin包的一些函数并没有被编译到最终可执行文件中,于是报了”not implemented”的错误!

在CGO开启的情况下,我们依旧可以让外部链接器使用静态链接,我们再来试一下:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo4

$ go build -o main-static -ldflags '-linkmode "external" -extldflags "-static"' main.go
# command-line-arguments
/tmp/go-link-638385712/000001.o: In function `pluginOpen':
/usr/local/go/src/plugin/plugin_dlopen.go:19: warning: Using 'dlopen' in statically linked applications requires at runtime the shared libraries from the glibc version used for linking
$ ldd main-static
    not a dynamic executable

我们的确得到了一个静态编译的二进制文件,但编译器也给出了warning。

执行这个文件:

$ ./main-static
2021/06/15 17:02:35 pkg1 init
try to LoadPlugin...
fatal error: runtime: no plugin module data

goroutine 1 [running]:
runtime.throw(0x5d380a, 0x1e)
    /usr/local/go/src/runtime/panic.go:1117 +0x72 fp=0xc000091b50 sp=0xc000091b20 pc=0x435712
plugin.lastmoduleinit(0xc000076210, 0x1001, 0x1001, 0xc000010040, 0x24db1f0)
    /usr/local/go/src/runtime/plugin.go:20 +0xb50 fp=0xc000091c48 sp=0xc000091b50 pc=0x466750
plugin.open(0x5d284c, 0x18, 0xc0000788f0, 0x0, 0x0)
    /usr/local/go/src/plugin/plugin_dlopen.go:77 +0x4ef fp=0xc000091ec0 sp=0xc000091c48 pc=0x4dad8f
plugin.Open(...)
    /usr/local/go/src/plugin/plugin.go:32
github.com/bigwhite/demo4/pkg/pkg1.LoadPlugin(0x5d284c, 0x1b, 0xc000091f48, 0x1)
    /root/test/go/plugin/demo4/pkg/pkg1/pkg1.go:13 +0x35 fp=0xc000091ef8 sp=0xc000091ec0 pc=0x4dbbb5
main.main()
    /root/test/go/plugin/demo4/main.go:12 +0xa5 fp=0xc000091f88 sp=0xc000091ef8 pc=0x4ee805
runtime.main()
    /usr/local/go/src/runtime/proc.go:225 +0x256 fp=0xc000091fe0 sp=0xc000091f88 pc=0x438196
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:1371 +0x1 fp=0xc000091fe8 sp=0xc000091fe0 pc=0x46a841

warning最终演变为运行时的panic,看来使用plugin的主程序只能编译为动态链接的可执行程序了。目前go项目有多个issue与此有关:

  • https://github.com/golang/go/issues/33072
  • https://github.com/golang/go/issues/17150
  • https://github.com/golang/go/issues/18123

4. plugin版本管理

使用动态链接实现插件系统,一个更大的问题就是插件的版本管理问题。

linux上的动态链接库采用soname的方式进行版本管理。soname的关键功能是它提供了兼容性的标准,当要升级系统中的一个库时,并且新库的soname和老库的soname一样,用旧库链接生成的程序使用新库依然能正常运行。这个特性使得在Linux下,升级使得共享库的程序和定位错误变得十分容易。

什么是soname呢? 在/lib和/usr/lib等集中放置共享库的目录下,你总是会看到诸如下面的情况:

2019-12-10 12:28 libfoo.so -> libfoo.so.0.0.0*
2019-12-10 12:28 libfoo.so.0 -> libfoo.so.0.0.0*
2019-12-10 12:28 libfoo.so.0.0.0*

关于libfoo.so居然有三个文件入口,其中libfoo.so.0.0.0是真正的共享库文件,而其他两个文件入口则是指向libfoo.so.0.0.0的符号链接。为何会出现这个情况呢?这与共享库的命名惯例和版本管理不无关系。

共享库的惯例中每个共享库都有多个名字属性,包括real name、soname和linker name:

  • real name

real name指的是实际包含共享库代码的那个文件的名字(如上面例子中的libfoo.so.0.0.0),也是在共享库编译命令行中-o后面的那个参数;

  • soname

soname则是shared object name的缩写,也是这三个名字中最重要的一个,无论是在编译阶段还是在运行阶段,系统链接器都是通过共享库的soname(如上面例子中的libfoo.so.0)来唯一识别共享库的。即使real name相同但soname不同,也会被链接器认为是两个不同的库。共享库的soname可在编译期间通过传给链接器的参数来指定,如我们可以通过”gcc -shared -Wl,-soname -Wl,libfoo.so.0 -o libfoo.so.0.0.0 libfoo.o”来指定libfoo.so.0.0.0的soname为libfoo.so.0。ldconfig -n directory_with_shared_libraries命令会根据共享库的soname自动生成一个名为soname的符号链接指向real name文件,当然你也可以通过ln命令自己来创建这个符号链接。另外在linux下我们可通过readelf -d查看共享库的soname,ldd输出的ELF文件依赖的共享库列表中显示的也是共享库的soname及所在路径。

  • linker name

linker name是编译阶段提供给编译器的名字(如上面例子中的libfoo.so)。如果你构建的共享库的real name是类似于上例中libfoo.so.0.0.0那样的带有版本号的样子,那么你在编译器命令中直接使用-L path -lfoo是无法让链接器找到对应的共享库文件的,除非你为libfoo.so.0.0.0提供了一个linker name(如libfoo.so,一个指向libfoo.so.0.0.0的符号链接)。linker name一般在共享库安装时手工创建。

那么go plugin是否可以用soname的方式来做版本管理呢?基于demo1我们创建demo5,并来做一下试验。

在demo5-plugins中,我们为构建出的.so增加版本信息:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo5-plugins

$go build -buildmode=plugin -o plugin1.so.1.1 plugin1.go
$ln -s plugin1.so.1.1 plugin1.so.1
$ls -l
lrwxr-xr-x  1 tonybai  staff       14  7 16 05:42 plugin1.so.1@ -> plugin1.so.1.1
-rw-r--r--  1 tonybai  staff  2888408  7 16 05:42 plugin1.so.1.1

我们通过ln命令为构建出的plugin1.so.1.1创建了一个符号链接plugin1.so.1,plugin1.so.1作为我们插件的soname传给demo5:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo5/main.go

func main() {
    fmt.Println("try to LoadAndInvokeSomethingFromPlugin...")
    err := pkg1.LoadAndInvokeSomethingFromPlugin("../demo5-plugins/plugin1.so.1")
    if err != nil {
        fmt.Println("LoadAndInvokeSomethingFromPlugin error:", err)
        return
    }
    fmt.Println("LoadAndInvokeSomethingFromPlugin ok")
}

运行demo5:

// github.com/bigwhite/experiments/tree/master/go-plugin/demo5

$go run main.go
2021/07/16 05:58:33 pkg1 init
try to LoadAndInvokeSomethingFromPlugin...
2021/07/16 05:58:33 plugin1 init
plugin1: public integer variable V=15
plugin1: invoke foo.M1
LoadAndInvokeSomethingFromPlugin ok

我们看到以soname传入的插件被顺利加载并提取符号。

后续如果plugin发生变更,比如打了patch,我们只需要升级plugin为plugin1.so.1.2,然后soname依旧保持不变,主程序也无需变动。

注意:如果插件名相同,内容相同,主程序多次加载不会出现问题;但插件名相同,但内容不同,主程序运行时多次load会导致runtime panic,并且是无法恢复的panic。所以务必做好插件的版本管理

5. 小结

go plugin是go语言原生提供的一种go插件方案(非go插件方案,可以使用c shared library等)。但经过上面的实验和学习,我们我们看到了plugin使用的诸多约束,这的确给go plugin的推广使用造成的很大障碍,导致目前go plugin应用不甚广泛。

根据上面看到的种种约束,如果要应用go plugin,必须要做到:

  • 构建环境一致
  • 对第三方包的版本一致。

因此,业内在使用go plugin时多利用builder container(用来构建程序的容器)来保证主程序和plugin使用相同的构建环境。

在go plugin为数不多的用户中,有三个比较知名的开源项目值得后续认真研究:

  • gosh: https://github.com/vladimirvivien/gosh
  • tyk api gateway: https://github.com/TykTechnologies/tyk
  • tidb : https://github.com/pingcap/tidb

尤其是tidb,还给出了其插件系统使用go plugin的完整设计方案:https://github.com/pingcap/tidb/blob/master/docs/design/2018-12-10-plugin-framework.md,值得大家细致品读。

本文涉及的所有源码可以在这里下载:https://github.com/bigwhite/experiments/tree/master/go-plugin 。

6. 参考资料

  • https://golang.org/pkg/plugin/
  • https://golang.org/cmd/go/#hdr-Build_modes
  • https://golang.org/doc/go1.8
  • https://www.reddit.com/r/golang/comments/b6h8qq/is_anyone_actually_using_go_plugins/
  • https://medium.com/@alperkose/things-to-avoid-while-using-golang-plugins-f34c0a636e8
  • https://medium.com/learning-the-go-programming-language/writing-modular-go-programs-with-plugins-ec46381ee1a9

“Gopher部落”知识星球正式转正(从试运营星球变成了正式星球)!“gopher部落”旨在打造一个精品Go学习和进阶社群!高品质首发Go技术文章,“三天”首发阅读权,每年两期Go语言发展现状分析,每天提前1小时阅读到新鲜的Gopher日报,网课、技术专栏、图书内容前瞻,六小时内必答保证等满足你关于Go语言生态的所有需求!部落目前虽小,但持续力很强。在2021年上半年,部落将策划两个专题系列分享,并且是部落独享哦:

  • Go技术书籍的书摘和读书体会系列
  • Go与eBPF系列

欢迎大家加入!

Go技术专栏“改善Go语⾔编程质量的50个有效实践”正在慕课网火热热销中!本专栏主要满足广大gopher关于Go语言进阶的需求,围绕如何写出地道且高质量Go代码给出50条有效实践建议,上线后收到一致好评!欢迎大家订
阅!

img{512x368}

我的网课“Kubernetes实战:高可用集群搭建、配置、运维与应用”在慕课网热卖中,欢迎小伙伴们订阅学习!

img{512x368}

我爱发短信:企业级短信平台定制开发专家 https://tonybai.com/。smspush : 可部署在企业内部的定制化短信平台,三网覆盖,不惧大并发接入,可定制扩展; 短信内容你来定,不再受约束, 接口丰富,支持长短信,签名可选。2020年4月8日,中国三大电信运营商联合发布《5G消息白皮书》,51短信平台也会全新升级到“51商用消息平台”,全面支持5G RCS消息。

著名云主机服务厂商DigitalOcean发布最新的主机计划,入门级Droplet配置升级为:1 core CPU、1G内存、25G高速SSD,价格5$/月。有使用DigitalOcean需求的朋友,可以打开这个链接地址:https://m.do.co/c/bff6eed92687 开启你的DO主机之路。

Gopher Daily(Gopher每日新闻)归档仓库 – https://github.com/bigwhite/gopherdaily

我的联系方式:

  • 微博:https://weibo.com/bigwhite20xx
  • 微信公众号:iamtonybai
  • 博客:tonybai.com
  • github: https://github.com/bigwhite
  • “Gopher部落”知识星球:https://public.zsxq.com/groups/51284458844544

微信赞赏:
img{512x368}

商务合作方式:撰稿、出书、培训、在线课程、合伙创业、咨询、广告合作。

一文告诉你如何用好uber开源的zap日志库

本文永久链接 – https://tonybai.com/2021/07/14/uber-zap-advanced-usage

1. 引子

日志在后端系统中有着重要的地位,通过日志不仅可以直观看到程序的当前运行状态,更重要的是日志可以在程序发生问题时为开发人员提供线索。

在Go生态中,logrus可能是使用最多的Go日志库,它不仅提供结构化的日志,更重要的是与标准库log包在api层面兼容。在性能不敏感的领域,logrus确实是不二之选。

但在性能敏感的领域和场景下,logrus便不那么香了,出镜更多的是大厂uber开源的名为zap的日志库。之所以在这些场景下zap更香,虽与其以高性能著称不无关系,但其背后的大厂uber背书也是极其重要的。uber大厂有着太多性能和延迟敏感的场景,其生产环境现存数千个Go语言开发的微服务,这些微服务估计大多使用的都是zap,经历过大厂性能敏感场景考验的log库信誉有保障,后续有人持续维护,自然被大家青睐。

关于zap高性能的原理,在网络上已经有不少高质量的资料(参见本文末的参考资料)做过详尽的分析了。zap的主要优化点包括:

  • 避免使用interface{}带来的开销(拆装箱、对象逃逸到堆上
  • 坚决不用反射,每个要输出的字段(field)在传入时都携带类型信息(这虽然降低了开发者使用zap的体验,但相对于其获得的性能提升,这点体验下降似乎也算不得什么):
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),
)
  • 使用sync.Pool减少堆内存分配(针对代表一条完整日志消息的zapcore.Entry),降低对GC压力。

下面是一个简单zap与logrus的性能基准benchmark对比:

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

在上面的基准测试中,我们使用logrus和zap分别向io.Discard写入相同内容的日志,基准测试的运行结果如下:

$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

我们看到zap的写日志性能是logrus的4倍,且每op仅一次内存分配,相比之下,logrus在性能和内存分配方面的确逊色不少。

有优点,就有不足。前面也说过,虽然zap在性能方面一骑绝尘,但是在使用体验方面却给开发者留下“阴影”。就比如在上面的性能基准测试中,考虑测试过程中的日志输出,我们没有采用默认的向stdout或stderr写入,而是将output设置为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)

上面的logrus和zap在创建写向io.Discard的logger时的方法对比很直观地反映出两者在使用体验上的差异。

那么选择了zap后,我们如何能更好地使用zap以尽量弥合与logrus等log库在体验方面的差距呢?这就是本文想要和大家分享的内容。

2. 对zap进行封装,让其更好用

进入Go世界后,大家使用的第一个log库想必是Go标准库自带的log包,log包可谓是“开箱即用”:

// 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")
}

上面的示例代码直接向标准错误(stderr)输出一行日志内容,而我们居然连一个logger变量都没有创建。即便是将日志写入文件,在log包看来也是十分easy的事情,看下面代码段:

// 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")
}

我们仅需要将实现了io.Writer的os.File传给log包的SetOutput函数即可。这种无需创建logger变量而是直接使用包名+函数的方式写日志的方式减少了传递和管理logger变量的复杂性,这种使用者体验是我们对zap进行封装的目标。不过,我们也要做到心里有数:zap是一个通用的log库,我们封装后,只需提供我们所需的特性即可,没有必要再封装成一个像zap一样通用的库。另外用户只需依赖我们封装后的log包,而无需显式依赖zap/zapcore。

下面我们就来建立demo1:

// 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

我们对zap的封装在pkg/log/log.go中:

// 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
}

在这个封装中,我们有如下几点说明:

  • 参考标准库log包,我们提供包级函数接口,底层是创建的默认Logger: std;
  • 你可以使用New函数创建了自己的Logger变量,但此时只能使用该实例的方法实现log输出,如果期望使用包级函数接口输出log,需要调用ResetDefault替换更新std实例的值,这样后续调用包级函数(Info、Debug)等就会输出到新实例的目标io.Writer中了。不过最好在输出任何日志前调用ResetDefault换掉std;
  • 由于zap在输出log时要告知具体类型,zap封装出了Field以及一些sugar函数(Int、String等),这里为了不暴露zap给用户,我们使用type alias语法定义了我们自己的等价于zap.Field的类型log.Field:
type Field = zap.Field

var (
    Skip        = zap.Skip
    Binary      = zap.Binary
    Bool        = zap.Bool
    Boolp       = zap.Boolp
    ByteString  = zap.ByteString
    ... ...
)
  • 我们使用method value语法将std实例的各个方法以包级函数的形式暴露给用户,简化用户对logger实例的获取:
var (
    Info   = std.Info
    Warn   = std.Warn
    Error  = std.Error
    DPanic = std.DPanic
    Panic  = std.Panic
    Fatal  = std.Fatal
    Debug  = std.Debug
)

下面是我们利用默认std使用包级函数直接输出日志到stderr的示例:

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

在这个main.go中,我们像标准库log包那样直接使用包级函数实现日志输出,同时我们无需创建logger实例,也无需管理和传递logger实例,在log包的另外一个用户pkg1包中,我们同样可以直接使用包级函数输出log:

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

如果你不想使用默认的std,而是要创建一个写入文件系统文件的logger,我们可以这样处理:

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

我们使用log.New创建一个新的Logger实例,然后通过log.ResetDefault用其替换掉std,这样后续的包级函数调用(log.Info)就会使用新创建的Logger实例了。

3. 自定义encoder

运行上面的demo1,我们会得到类似于下面格式的日志内容:

{"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}

我们可以定制zap的输出内容格式。

在定制之前,我们先来看看zap的内部结构:


图来自Go: How Zap Package is Optimized(见参考资料)

和其他log库相似,zap也是由创建logger与写log两个关键过程组成。其中zap的核心是名为zapcore.Core抽象,Core是zap定义的一个log接口,正如其名,围绕着这个Core,zap提供上层log对象以及相应的方法(zap.Logger就组合了zapcore.Core),开发者同样可以基于该接口定制自己的log包(比如:前面我们在New函数的实现)。

我们一般通过zapcore.NewCore函数创建一个实现了zapcore.Core的实例,NewCore接收三个参数,也是Core的主要组成部分,它们如下图:

                                 ┌───────────────┐
                                 │               │
                                 │               │
                      ┌─────────►│     Encoder   │
                      │          │               │
                      │          │               │
                      │          └───────────────┘
┌────────────────┐    │
│                ├────┘
│                │               ┌───────────────┐
│                │               │               │
│      Core      ├──────────────►│  WriteSyncer  │
│                │               │               │
│                ├─────┐         │               │
└────────────────┘     │         └───────────────┘
                       │
                       │
                       │         ┌───────────────┐
                       │         │               │
                       └────────►│  LevelEnabler │
                                 │               │
                                 │               │
                                 └───────────────┘
  • Encoder是日志消息的编码器;
  • WriteSyncer是支持Sync方法的io.Writer,含义是日志输出的地方,我们可以很方便的通过zap.AddSync将一个io.Writer转换为支持Sync方法的WriteSyncer;
  • LevelEnabler则是日志级别相关的参数。

由此我们看到要定制日志的输出格式,我们的重点是Encoder。

从大类别上分,zap内置了两类编码器,一个是ConsoleEncoder,另一个是JSONEncoder。ConsoleEncoder更适合人类阅读,而JSONEncoder更适合机器处理。zap提供的两个最常用创建Logger的函数:NewProduction和NewDevelopment则分别使用了JSONEncoder和ConsoleEncoder。两个编码器默认输出的内容对比如下:

// 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输出的内容跟适合我们阅读,而JSONEncoder输出的结构化日志更适合机器/程序处理。前面我们说了,我们封装的log包不是要做通用log包,我们无需同时支持这两大类Encoder,于是我们在上面的示例选择采用的JSONEncoder:

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

基于Encoder,我们可以定制的内容有很多,多数开发人员可能都会对日期格式、是否显示此条日志的caller信息等定制感兴趣。

zap库自身也提供了基于功能选项模式的Option接口:

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

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

我们的log库如果要提供一定的Encoder定制能力,我们也需要像Field那样通过type alias语法将zap.Option暴露给用户,同时以函数类型变量的形式将zap的部分option导出给用户。至于时间戳,我们选择一种适合我们的格式后可固定下来。下面是demo1的log的基础上增加了一些对encoder的定制功能而形成的demo2 log包:

// 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
}

定制后,我们的log包输出的内容就变成了如下这样了:

// 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"}

4. 写入多log文件

定制完encoder,我们再来看看writeSyncer。nginx想必没人没用过,nginx有两个重要的日志文件:access.log和error.log,前者是正常的访问日志,后者则是报错日志。如果我们也要学习nginx,为业务系统建立两类日志文件,一类类似于access.log,记录正常业务吹的日志,另外一类则类似error.log,记录系统的出错日志,我们该如何设计和实现?有人可能会说,那就建立两个logger呗。没错,这的确是一个方案。但如果我就想使用包级函数来写多个log文件,并且无需传递logger实例呢?zap提供了NewTee这个导出函数就是用来写多个日志文件的。

下面我们就来用demo3来实现这个功能,我们也对外提供一个NewTee的函数,用于创建写多个log文件的logger:

// 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
}

我们看到由于多个日志文件可能会根据写入的日志级别选择是否落入文件,于是我们提供了一个TeeOption类型,类型定义中包含一个io.Writer以及一个level enabler func,我们来看一下如何使用这个NewTee函数:

// 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))

}

我们建立两个TeeOption,分别对应access.log和error.log,前者接受level<=info级别的日志,后者接受level>error级别的日志。我们运行一下该程序:

$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}

如我们预期,不同level的日志写入到不同文件中了,而我们只需调用包级函数即可,无需管理和传递不同logger。

5. 让日志文件支持自动rotate(轮转)

如果log写入文件,那么文件迟早会被写满!我们不能坐视不管!业内通用的方案是log rotate(轮转),即当log文件size到达一定大小时,会归档该文件,并重新创建一个新文件继续写入,这个过程对应用是透明无感知的。

而log rotate方案通常有两种,一种是基于logrotate工具的外部方案,一种是log库自身支持轮转。zap库与logrotate工具的兼容性似乎有些问题,zap官方FAQ也推荐第二种方案

不过zap并不是原生支持rotate,而是通过外部包来支持,zap提供了WriteSyncer接口可以方便我们为zap加入rotate功能。目前在支持logrotate方面,natefinch的lumberjack是应用最为官方的包,下面我们来看看如何为demo3的多日志文件增加logrotate:

// 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
}

我们在TeeOption中加入了RotateOptions(当然这种绑定并非必须),并使用lumberjack.Logger作为io.Writer传给zapcore.AddSync,这样创建出来的logger既有写多日志文件的能力,又让每种日志文件具备了自动rotate的功能。

我们在main中使用该log:

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

运行上述main包,我们将看到如下输出:

// 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

我们看到access.log和error.log都在size超过1M后完成了一次自动轮转,归档的日志也按照之前的配置(compress)进行了压缩。

6. 小结

本文对zap日志库的使用方法做了深度说明,包括对zap进行封装的一种方法,使得我们可以像标准库log包那样通过包级函数直接输出log而无需管理和传递logger变量;我们可以自定义zap encoder(时间、是否输出caller等);通过NewTee可以创建一次性写入多个日志文件的logger,并且可以通过log level判断是否接受写入;最后,我们让zap日志支持了自动轮转。

如果说有不足,那就是zap不支持动态设置全局logger的日志级别,不过似乎有第三方方案,这里就不深入了,作为遗留问题留给大家了。

本文涉及到的代码可以在这里下载: https://github.com/bigwhite/experiments/tree/master/uber-zap-advanced-usage

7. 参考资料

  • Go: How Zap Package is Optimized – https://medium.com/@blanchon.vincent/go-how-zap-package-is-optimized-dbf72ef48f2d
  • 深度 | 从Go高性能日志库zap看如何实现高性能Go组件 – https://mp.weixin.qq.com/s/i0bMh_gLLrdnhAEWlF-xDw

“Gopher部落”知识星球正式转正(从试运营星球变成了正式星球)!“gopher部落”旨在打造一个精品Go学习和进阶社群!高品质首发Go技术文章,“三天”首发阅读权,每年两期Go语言发展现状分析,每天提前1小时阅读到新鲜的Gopher日报,网课、技术专栏、图书内容前瞻,六小时内必答保证等满足你关于Go语言生态的所有需求!部落目前虽小,但持续力很强。在2021年上半年,部落将策划两个专题系列分享,并且是部落独享哦:

  • Go技术书籍的书摘和读书体会系列
  • Go与eBPF系列

欢迎大家加入!

Go技术专栏“改善Go语⾔编程质量的50个有效实践”正在慕课网火热热销中!本专栏主要满足广大gopher关于Go语言进阶的需求,围绕如何写出地道且高质量Go代码给出50条有效实践建议,上线后收到一致好评!欢迎大家订
阅!

img{512x368}

我的网课“Kubernetes实战:高可用集群搭建、配置、运维与应用”在慕课网热卖中,欢迎小伙伴们订阅学习!

img{512x368}

我爱发短信:企业级短信平台定制开发专家 https://tonybai.com/。smspush : 可部署在企业内部的定制化短信平台,三网覆盖,不惧大并发接入,可定制扩展; 短信内容你来定,不再受约束, 接口丰富,支持长短信,签名可选。2020年4月8日,中国三大电信运营商联合发布《5G消息白皮书》,51短信平台也会全新升级到“51商用消息平台”,全面支持5G RCS消息。

著名云主机服务厂商DigitalOcean发布最新的主机计划,入门级Droplet配置升级为:1 core CPU、1G内存、25G高速SSD,价格5$/月。有使用DigitalOcean需求的朋友,可以打开这个链接地址:https://m.do.co/c/bff6eed92687 开启你的DO主机之路。

Gopher Daily(Gopher每日新闻)归档仓库 – https://github.com/bigwhite/gopherdaily

我的联系方式:

  • 微博:https://weibo.com/bigwhite20xx
  • 微信公众号:iamtonybai
  • 博客:tonybai.com
  • github: https://github.com/bigwhite
  • “Gopher部落”知识星球:https://public.zsxq.com/groups/51284458844544

微信赞赏:
img{512x368}

商务合作方式:撰稿、出书、培训、在线课程、合伙创业、咨询、广告合作。

如发现本站页面被黑,比如:挂载广告、挖矿等恶意代码,请朋友们及时联系我。十分感谢! Go语言第一课 Go语言精进之路1 Go语言精进之路2 Go语言编程指南
商务合作请联系bigwhite.cn AT aliyun.com

欢迎使用邮件订阅我的博客

输入邮箱订阅本站,只要有新文章发布,就会第一时间发送邮件通知你哦!

这里是 Tony Bai的个人Blog,欢迎访问、订阅和留言! 订阅Feed请点击上面图片

如果您觉得这里的文章对您有帮助,请扫描上方二维码进行捐赠 ,加油后的Tony Bai将会为您呈现更多精彩的文章,谢谢!

如果您希望通过微信捐赠,请用微信客户端扫描下方赞赏码:

如果您希望通过比特币或以太币捐赠,可以扫描下方二维码:

比特币:

以太币:

如果您喜欢通过微信浏览本站内容,可以扫描下方二维码,订阅本站官方微信订阅号“iamtonybai”;点击二维码,可直达本人官方微博主页^_^:
本站Powered by Digital Ocean VPS。
选择Digital Ocean VPS主机,即可获得10美元现金充值,可 免费使用两个月哟! 著名主机提供商Linode 10$优惠码:linode10,在 这里注册即可免费获 得。阿里云推荐码: 1WFZ0V立享9折!


View Tony Bai's profile on LinkedIn
DigitalOcean Referral Badge

文章

评论

  • 正在加载...

分类

标签

归档



View My Stats