我是 LEE,老李,一个在 IT 职业摸爬滚打 17 年的技能老兵。
工作背景
春节在家正好闲得没有太多工作,想起年前一个研制项目担任人反应的问题:“老李啊,咱们组一向在运用你这边的 gin 封装的 webservice 结构开发,咱们需求一套规范的异步日志输出模块。现在组内和其他运用 gin 的小伙伴完成的‘各有千秋’不统一,没有一个组或许部门对这部分的代码担任和长期保护。你能不能想想办法。”
这一看便是掉头发的工作,虽然 gin 封装的 webservice 结构是我开发底层服务包,现已推行到公司所有 golang 开发组运用,现在需求一个统一异步日志输出的模块是否真的有意义,要仔细的考虑和研讨下,毕竟有中心事务团队有这样的需求。
干脆打开了 uber-go/zap 日志结构的源代码,看看到底是什么原因推进咱们都要手写异步日志模块。不看不知道,一看吓一跳,项目中 issue#988 就有讨论,我看了下 issue 留言,觉得咱们的说法都挺正确,而项目作者一向无动于衷,并且深信 bufio + 守时 flush 的办法 才是正道,怪不得咱们都要自己手写一个异步日志输出模块。
心智担负
在要写 uber-go/zap 异步日志模块之前,首先要了解异步日志模块的优点、缺点以及适用的场景,这样代码才写的有意义,是真实的处理问题和能帮助到小伙伴的。
关于同步和异步模型的差异,这边就不展开了,估量再写几千字也纷歧定能说清楚,有需求深入了解的小伙伴,能够自行 baidu,那里有许多相关的文章,并且讲解得十分明晰。这儿我就不需求过多解析,而我需求讲的是同步和异步日志模块。
- 同步日志:日志信息投递后,必须要等到日志信息写到对应的 io.Writer 中(os.Stdout, 文件等等)并回来,这个调用进程结束。适宜 Warning 级别以上日志输出,强记载或许落盘需求的日志信息,不能丢掉。
- 异步日志:日志信息投递后,调用进程结束。而日志信息是否能够正确写到对应的 io.Writer 中(os.Stdout, 文件等等)是由异步日志模块确保,不等候调用进程。适宜 Warning 级别以下日志输出,尽量存储日志,假如没有存储,丢掉也没有联系。
那么我就用一句话说了解这两种日志模型的差别。
- 同步日志:慢,安全,日志不丢
- 异步日志:快,不安全,日志极力记载
已然这儿提到是心智担负,可是真实担负在哪里? 实践上面现已提到了心智担负的中心内容:便是怎么正确的挑选一个日志模型。
而咱们这边需求是清晰知道有部分日志能够丢掉,追求接口响应速度,期望有统一的完成,有人保护代码和与整个 gin 封装的 webservice 结构交融的品质。
前置常识
清晰了开发的需求,开发的目标。承认了开发有意义,确实能处理问题。那么:便是干!!!
在动之前仍是要预备些常识,还要做好结构设计,这样才干回答:一套合理的异步输出模型应该是什么样的?
分享下我了解的一个异步日志模型是什么样的(欢迎咱们来“锤”,可是锤我的时分,费事轻点哈)
有的小伙伴看到这个图觉得有点眼熟?Kafka?不对,不对,不对,还少了一个 Broker。由于这儿不需求对 Producer 完成一个独立的缓冲器和分类器,那么 Broker 这样的人物就不存在了。
简略的介绍下成员人物:
- MessageProducer: 音讯和数据生成者
- CriticalSurface: 并发临界面,所有 MessageProducer 都到这边竞赛操控权,往 RingBuffer 中写入数据
- RingBuffer: 音讯和数据的缓冲(记得缓冲和缓存差异,这边用缓冲便是为了处理 Producer 和 Consumer 和速度差)
- MessageConsumer: 音讯和数据顾客
为什么挑选上面的模型:
- 期望在现有的 uber-go/zap 的结构上扩展,完成一部分能力,满意功用扩展。
- 不期望重复做轮子,由于轮子做出来,需求有严格的代码测验和压力测验,才干交付出产体系。
- 模型简略,好了解,也好完成。
- 功能比较高,并且架构全体比较合理。
为了完成这个模型,还需求考虑如下几个问题:
- CriticalSurface 怎么完成?由于要满意多个 MessageProducer 并发运用,那么这个临界面就必须要做,要不然就出现争抢资源失控的状况。
- 为什么要挑选 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 的完成,效率十分不错,并且假如 channel 满了,数据投递动作就会卡住,假如 channel 空了,数据提取动作也会被卡住,这个机制十分棒。
- channel 天然生成便是一个 FIFO 的模型,十分适宜做数据缓冲,处理 Producer 和 Consumer 和速度差这样问题。
有了上面的思路,我的代码架构也根本出来了,结构图如下:
这儿我贴出一个完成代码(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, 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 团队为什么不愿意完成这样的异步日志输出模型,可能有他们的想法吧。可是我想,不管那种异步日志模型,都存在着程序异常会丢日志的状况。这儿再次提醒小伙伴,要慎重挑选日志体系模型,切不能够一味追求速度而疏忽日志,由于服务日志也是重要的事务数据。