开发者

uber go zap 日志框架支持异步日志输出

目录
  • 事件背景
  • 心智负担
  • 前置知识
  • 解决思路
    • uber-go/zap 代码分析
    • 上手开发
    • 测试代码
      • 同步输出日志
      • 异步输出日志
      • 不输出日志
  • 总结

    事件背景

    过年在家正好闲得没有太多事情,想起年前一个研发项目负责人反馈的问题:“老李啊,我们组一直在使用你这边的 gin 封装的 webservice 框架开发,我们需要一套标准的异步日志输出模块。现在组内和其他使用 gin 的小伙伴实现的‘各有千秋’不统一,没有一个组或者部门对这部分的代码负责和长期维护。你能不能想想办法。”

    这一看就是掉头发的事情,虽然 gin 封装的 webservice 框架是我开发底层服务包,已经推广到公司所有 golang 开发组使用,现在需要一个统一异步日志输出的模块是否真的有意义,要认真的考虑和研究下,毕竟有核心业务团队有这样的需求。

    索性打开了 uber-go/zap 日志框架的源代码,看看到底是什么原因推动大家都要手写异步日志模块js。不看不知道,一看吓一跳,项目中 issue#998 就有讨论,我看了下 issue 留言,觉得大开发者_Go培训家的说法都挺正确,而项目作者一直无动无衷,而且坚信 bufio + 定时 flush 的方式 才是正道,怪不得大家都要自己手写一个异步日志输出模块。

    uber go zap 日志框架支持异步日志输出

    心智负担

    在要写 uber-go/zap 异步日志模块之前,首先要明白异步日志模块的优点、缺点以及适用的场景,这样代码才写的有意义,是真正的解决问题和能帮助到小伙伴的。

    关于同步和异步模型的差异,这边就不展开了,估计再写几千字也不一定能说清楚,有需要深入了解的小伙伴,可以自行 baidu,那里有很多相关的文章,而且讲解得非常清晰。这里我就不需要过多解析,而我需要讲的是同步和异步日志模块。

    • 同步日志:日志信息投递后,必须要等到日志信息写到对应的 io.Writer 中(os.Stdout, 文件等等)并返回,这个调用过程结束。适合 Warning 级别以上日志输出,强记录或者落盘需求的日志信息,不能丢失。
    • 异步日志:日志信息投递后,调用过程结束。而日志信息是否能够正确写到对应的 io.Writer 中(os.Stdout, 文件等等)是由异步日志模块保证,不等待调用过程。适合 Warning 级别以下日志输出,尽量存储日志,如果没有存储,丢失也没有关系

    那么我就用一句话说明白这两种日志模型的差别。

    • 同步日志:慢,安全,日志不丢
    • 异步日志:快,不安全,日志尽力记录

    既然这里说到是心智负担,但是真正负担在哪里? 实际上面已经提到了心智负担的核心内容:就是如何正确的选择一个日志模型

    而我们这边需求是明确知道有部分日志可以丢失,追求接口响应速度,希望有统一的实现,有人维护代码和与整个 gin 封装的 webservice 框架融合的品质。

    前置知识

    明确了开发的需求,开发的目标。确认了开发有意义,确实能解决问题。那么:就是干!!!

    在动之前还是要准备些知识,还要做好结构设计,这样才能解答:一套合理的异步输出模型应该是什么样的?

    分享下我理解的一个异步日志模型是什么样的(欢迎大家来“锤”,但是锤我的时候,麻烦轻点哈)

    uber go zap 日志框架支持异步日志输出

    有的小伙伴看到这个图觉得有点眼熟?Kafka?不对,不对,不对,还少了一个 Broker。因为这里不需要对 Producer 实现一个独立的缓冲器和分类器,那么 Broker 这样的角色就不存在了。

    简单的介绍下成员角色:

    • MessageProducer: 消息和数据生成者
    • CriticalSurface: 并发临界面,所有 MessageProducer 都到这边竞争控制权,往 RingBuffer 中写入数据
    • RingBuffer: 消息和数据的缓冲(记得缓冲和缓存区别,这边用缓冲就是为了解决 Producer 和 Consumer 和速度差)
    • MessageConsumer: 消息和数据消费者

    为什么选择上面的模型:

    • 希望在现有的 uber-go/zap python的结构上扩展,实现一部分能力,满足功能扩展。
    • 不希望重复做轮子,因为轮子做出来,需要有严格的代码测试和压力测试,才能交付生产系统。
    • 模型简单,好理解,也好实现。
    • 性能比较高,而且架构整体比较合理。

    为了实现这个模型,还需要思考如下几个问题:

    • CriticalSurface 如何实现?因为要满足多个 MessageBroker 并发使用,那么这个临界面就必须要做,要不然就出现争抢资源失控的情况。
    • 为什么要选择 RingBuffer?RingBuffer 是目前速度和效率最好的一种缓冲模型,linux/Unix 系统中广泛使用。
    • 选择 RingBuffer 需要注意些什么?RingBuffer 有快慢指针的问题,如果控制不好,快指针就回覆写慢指针的数据,地址数据丢失的情况。
    • MessageConsumer 数量如何限制?如何平衡信息的创建与消费之间的速度差异。
    • 如何支持多种日志方式输出类型。(golang 多种 io.Writer 模型)

    如果看到这里,估计已经劝退了很多的小伙伴,我想这就是为什么那个研发项目负责人带着团队问题来找我,希望能够得到解决的原因吧。确实不容易。

    解决思路

    uber-go/zap 代码分析

    在认真看看完了 uber-go/zap 的代码以后,发现 uber 就是 uber,代码质量还是非常不错的,很多模块抽象的非常不错。通过一段时间的思考后,确认我们要实现一个独立的 WriteSyncer, 跟 uber-go/zap 中的 BufferedwriteSyncer 扮演相同的角色。

    既然要实现,我们先看看 uber-go/zap 中的源代码怎么定义 WriteSyncer 的。

    go.uber.org/zap@v1.24.0/zapcore/write_syncer.go

    // A WriteSyncer is an io.Writer that can also flush any buffered data. Note
    // that *os.File (and thus, os.Stderr and os.Stdout) implement WriteSyncer.
    type WriteSyncer interface {
    	io.Writer
    	Sync() error
    }
    

    WriteSyncer 是一个 interface,也就是我们只要引用 io.Writer 和实现 Sync() error 这样的一个方法就可以对接 uber-go/zap 系统中。那么 Sync() 这个函数到底是干嘛的? 顾名思义就是让 zap 触发数据同步动作时需要执行的一个方法。但是我们是异步日志,明显 uber-go/zap 处理完日志相关的数据,丢给我实现的 WriteSyncer 以后,就不应该在干预异步日志模块的后期动作了,所以 Sync() 给他一个空壳函数就行了。

    当然 uber-go/zap 早考虑到这样的情况,就给一个非常棒的包装函数 AddSync()

    go.uber.org/zap@v1.24.0/zapcore/write_syncer.go

    // AddSync converts an io.Writer to a WriteSyncer. It attempts to be
    // intelligent: if the concrete type of the io.Writer implements WriteSyncer,
    // we'll use the existing Sync method. If it doesn't, we'll add a no-op Sync.
    func AddSync(w io.Writer) WriteSyncer {
    	switch w := w.(type) {
    	case WriteSyncer:
    		return w
    	default:
    		return writerWrapper{w}
    	}
    }
    type writerWrapper struct {
    	io.Writer
    }
    func (w writerWrapper) Sync() error {
    	return nil
    }
    

    uber-go/zap 已经把我们希望要做的事情都给做好了,我们只要实现一个标准的 io.Writer 就行了,那继续看 io.Writer 的定义方式。

    go/src/io/io.go

    // Writer is the interface that wraps the basic Write method.
    //
    // Write writes len(p) bytes from p to the underlying data stream.
    // It returns the number of bytes written from p (0 <= n <= len(p))
    // and any error encountered that caused the write to stop early.
    // Write must return a non-nil error if it returns n < len(p).
    // Write must not modify the slice data, even temporarily.
    //
    // Implementations must not retain p.
    type Writer interface {
    	Write(p []byte) (n int, err error)
    }
    

    哇,好简单。要实现 io.Writer 仅仅只要实现一个 Write(p []byte) (n int, err error) 方法就行了,So Easy !!!!

    上手开发

    还是回到上一章中的 5 个核心问题,我想到这里应该有答案了:

    • MessageProducer:用一个函数实现,实际上就是 Write(p []byte),接收 uber-go/zap 投递来的消息内容。
    • CriticalSurface 和 RingBuffer: 是最核心的部件,既然要考虑到性能、安全、兼容各种数据类型,同时要有一个 Locker 保证临界面,也要满足 FIFO 模型。思来想去,当然自己也实现了几版,最后还是用 golang 自身的 channel 来完成。
    • MessageConsumer:用一个 go 协程来执行从 RingBuffer 循环读取,然后往真正的 os.Stdout/os.StdErr/os.File 中输出。(为什么是一个而不是多个?一个速度就足够快了,同时系统底层 io.Writer 自身也带锁,所以一个能减少锁冲撞。)

    TIPS: 这里说说为什么我要选择 golang 自身的 channel 作为 CriticalSurface 和 RingBuffer 的实现体:

    • channel 是 golang 官方的代码包,有专门的团队对这个代码质量负责。channel 很早就出来了,Bugs 修复的差不多了,非常的稳定可靠。(也有自己懒了,不想自己写 RingBuffer,然后要考虑各种场景的代码测试。)
    • channel 的 “<-” 动作天生就有一个 Locker,有非常好的临界面控制。
    • channel 底层是就是一个 RingBuffer 的实现,效率非常不错,而且如果 chanphpnel 满了,数据投递动作就会卡住,如果 channel 空了,数据提取动作也会被卡住,这个机制非常棒。
    • channel 天生就是一个 FIFO 的模型,非常合适做数据缓冲,解决 Producer 和 Consumer 和速度差这样问题。

    有了上面的思路,我的代码架构也基本出来了,结构图如下:

    uber go zap 日志框架支持异步日志输出

    这里我贴出一个实现代码(DEMO 测试用,生产要谨慎重新实现):

    const defaultQueueCap = math.MaxUint16 * 8
    var QueueIsFullError = errors.New("queue is full")
    var DropWriteMessageError = errors.New("message writing failure and drop it")
    type Writer struct {
    	name        string
    	bufferPool  *extraBufferPool
    	writer      io.Writer
    	wg          sync.WaitGroup
    	lock        sync.RWMutex
    	channel     chan *extraBuffer
    }
    func NewBufferWriter(name string, w io.Writer, queueCap uint32) *Writer {
    	if len(name) <= 0 {
    		name = "bw_" + utils.GetRandIdString()
    	}
    	if queueCap <= 0 {
    		queueCap = defaultQueueCap
    	}
    	if w == nil {
    		return nil
    	}
    	wr := Writer{
    		name:          name,
    		bufferPool:    newExtraBufferPool(defaultBufferSize),
    		writer:        w,
    		channel:       make(chan *extraBuffer, queueCap),
    	}
    	wr.wg.Add(1)
    	go wr.poller(utils.GetRandIdString())
    	return &wr
    }
    func (w *Writer) Write(p []byte) (int, error) {
    	if w.lock.TryRLock() {
    		defer w.lock.RUnlock()
    		b := w.bufferPool.Get()
    		count, err := b.buff.Write(p)
    		if err != nil {
    			w.bufferPool.Put(b)
    			return count, err
    		}
    		select {
    		case w.channel <- b: // channel 内部传递的是 buffer 的指针,速度比传递对象快。
    			break
    		default:
    			w.bufferPool.Put(b)
    			return count, QueueIsFullError
    		}
    		return len(p), nil
    	} else {
    		return -1, DropWriteMessageError
    	}
    }
    func (w *Writer) Close() {
    	w.lock.Lock()
    	close(w.channel)
    	w.wg.Wait()
    	w.lock.Unlock()
    }
    func (w *Writer) poller(id string) {
    	var (
    		eb  *extraBuffer
    		err error
    	)
    	defer w.wg.Done()
    	for eb = range w.channel {
    		_, err = w.writer.Write(eb.buff.Bytes())
    		if err != nil {
    			log.Printf("writer: %s, id: %s,python error: %s, message: %s", w.name, id,
    				err.Error(), utils.BytesToString(eb.buff.Bytes()))
    		}
    		w.bufferPool.Put(eb)
    	}
    }
    

    然后在 uber-go/zap 中如何使用呢?

    import (
    	"go.uber.org/zap"
    	"go.uber.org/zap/zapcore"
    	"os"
    	"time"
    )
    func main() {
    	wr := NewBufferWriter("lee", os.Stdout, 0)
    	defer wr.Close()
    	c := zapcore.NewCore(
    		zapcore.NewjsONEncoder(zap.NewproductionEncoderConfig()),
    		zapcore.AddSync(wr)编程客栈,
    		zap.NewAtomicLevelAt(zap.DebugLevel),
    	)
    	log := zap.New(c)
    	log.Info("demo log")
    	time.Sleep(3 * time.Second) // 这里要稍微等待下,因为是异步的输出,log.Info() 执行完毕,日志并没有完全输出到 console
    }
    

    Console 输出:

    $ go run asynclog.go
    {"level":"info","ts":1674808100.0148869,"msg":"demo log"}
    

    输出结果符合逾期

    测试代码

    为了验证架构和代码质量,这里做了异步输出日志、同步输出日志和不输出日志 3 种情况下,对 gin 封装的 webservice 框架吞吐力的影响。

    #测试内容Requests/sec
    1同步输出日志20074.24
    2异步输出日志64197.08
    3不输出日志65551.84

    同步输出日志

    $ wrk -t 10 -c 1000 http://127.0.0.1:8080/xx/
    Running 10s test @ http://127.0.0.1:8080/xx/
      10 threads and 1000 connections
      Thread Stats   Avg      Stdev     Max   +/- Stdev
        Latency    12.03ms   14.23ms 202.46ms   89.23%
        Req/Sec     2.03k     1.36k    9.49k    59.28%
      202813 requests in 10.10s, 100.58MB read
      Socket errors: connect 757, read 73, write 0, timeout 0
    Requests/sec:  20074.24
    Transfer/sec:      9.96MB
    

    异步输出日志

    $ wrk -t 10 -c 1000 http://127.0.0.1:8080/xx/
    Running 10s test @ http://127.0.0.1:8080/xx/
      10 threads and 1000 connections
      Thread Stats   Avg      Stdev     Max   +/- Stdev
        Latency     3.75ms    2.43ms  39.94ms   92.68%
        Req/Sec     6.48k     3.86k   14.78k    57.11%
      648554 requests in 10.10s, 321.62MB read
      Socket errors: connect 757, read 79, write 0, timeout 0
    Requests/sec:  64197.08
    Transfer/sec:     31.84MB
    

    不输出日志

    $ wrk -t 10 -c 1000 http://127.0.0.1:8080/xx/
    Running 10s test @ http://127.0.0.1:8080/xx/
      10 threads and 1000 connections
      Thread Stats   Avg      Stdev     Max   +/- Stdev
        Latency     3.69ms  505.13us   9.29ms   77.36%
        Req/Sec     6.60k     4.25k   15.31k    56.45%
      662381 requests in 10.10s, 328.48MB read
      Socket errors: connect 757, read 64, write 0, timeout 0
    Requests/sec:  65551.84
    Transfer/sec:     32.51MB
    

    总结

    通过对上面的工程代码测试,基本实现了 gin + zap 的异步日志输出功能的实现。当然上面的代码仅供小伙伴学习研究用,并不能作为生产代码使用。

    从结果来看,golang 的 channel 整体性能还是非常不错。基于 channel 实现的异步日志输出基本于不输出日志的吞吐力和性能相当。

    在实际工作中,我们能用 golang 原生库的时候就尽量用,因为 golang 团队在写库的时候,大多数的情况和场景都考虑过,所以没有必自己做一个轮子。安全!安全!安全!

    至于 uber-go/zap 团队为什么不愿意实现这样的异步日志输出模型,可能有他们的想法吧。但是我想,不论那种异步日志模型,都存在着程序异常会丢日志的情况。这里再次提醒小伙伴,要慎重选择日志系统模型,切不可以一味追求速度而忽略日志,因为服务日志也是重要的业务数据。

    以上就是uber go zap 日志框架支持异步日志输出的详细内容,更多关于uber go zap日志异步输出的资料请关注我们其它相关文章!

    0

    上一篇:

    下一篇:

    精彩评论

    暂无评论...
    验证码 换一张
    取 消

    最新开发

    开发排行榜