uber go zap 日志框架支持異步日志輸出
事件背景
過年在家正好閑得沒有太多事情,想起年前一個(gè)研發(fā)項(xiàng)目負(fù)責(zé)人反饋的問題:“老李啊,我們組一直在使用你這邊的 gin 封裝的 webservice 框架開發(fā),我們需要一套標(biāo)準(zhǔn)的異步日志輸出模塊。現(xiàn)在組內(nèi)和其他使用 gin 的小伙伴實(shí)現(xiàn)的‘各有千秋’不統(tǒng)一,沒有一個(gè)組或者部門對(duì)這部分的代碼負(fù)責(zé)和長(zhǎng)期維護(hù)。你能不能想想辦法。”
這一看就是掉頭發(fā)的事情,雖然 gin 封裝的 webservice 框架是我開發(fā)底層服務(wù)包,已經(jīng)推廣到公司所有 golang 開發(fā)組使用,現(xiàn)在需要一個(gè)統(tǒng)一異步日志輸出的模塊是否真的有意義,要認(rèn)真的考慮和研究下,畢竟有核心業(yè)務(wù)團(tuán)隊(duì)有這樣的需求。
索性打開了 uber-go/zap 日志框架的源代碼,看看到底是什么原因推動(dòng)大家都要手寫異步日志模塊。不看不知道,一看嚇一跳,項(xiàng)目中 issue#998 就有討論,我看了下 issue 留言,覺得大家的說法都挺正確,而項(xiàng)目作者一直無動(dòng)無衷,而且堅(jiān)信 bufio + 定時(shí) flush 的方式 才是正道,怪不得大家都要自己手寫一個(gè)異步日志輸出模塊。
心智負(fù)擔(dān)
在要寫 uber-go/zap 異步日志模塊之前,首先要明白異步日志模塊的優(yōu)點(diǎn)、缺點(diǎn)以及適用的場(chǎng)景,這樣代碼才寫的有意義,是真正的解決問題和能幫助到小伙伴的。
關(guān)于同步和異步模型的差異,這邊就不展開了,估計(jì)再寫幾千字也不一定能說清楚,有需要深入了解的小伙伴,可以自行 baidu,那里有很多相關(guān)的文章,而且講解得非常清晰。這里我就不需要過多解析,而我需要講的是同步和異步日志模塊。
- 同步日志:日志信息投遞后,必須要等到日志信息寫到對(duì)應(yīng)的 io.Writer 中(os.Stdout, 文件等等)并返回,這個(gè)調(diào)用過程結(jié)束。適合 Warning 級(jí)別以上日志輸出,強(qiáng)記錄或者落盤需求的日志信息,不能丟失。
- 異步日志:日志信息投遞后,調(diào)用過程結(jié)束。而日志信息是否能夠正確寫到對(duì)應(yīng)的 io.Writer 中(os.Stdout, 文件等等)是由異步日志模塊保證,不等待調(diào)用過程。適合 Warning 級(jí)別以下日志輸出,盡量存儲(chǔ)日志,如果沒有存儲(chǔ),丟失也沒有關(guān)系。
那么我就用一句話說明白這兩種日志模型的差別。
- 同步日志:慢,安全,日志不丟
- 異步日志:快,不安全,日志盡力記錄
既然這里說到是心智負(fù)擔(dān),但是真正負(fù)擔(dān)在哪里? 實(shí)際上面已經(jīng)提到了心智負(fù)擔(dān)的核心內(nèi)容:就是如何正確的選擇一個(gè)日志模型。
而我們這邊需求是明確知道有部分日志可以丟失,追求接口響應(yīng)速度,希望有統(tǒng)一的實(shí)現(xiàn),有人維護(hù)代碼和與整個(gè) gin 封裝的 webservice 框架融合的品質(zhì)。
前置知識(shí)
明確了開發(fā)的需求,開發(fā)的目標(biāo)。確認(rèn)了開發(fā)有意義,確實(shí)能解決問題。那么:就是干!!!
在動(dòng)之前還是要準(zhǔn)備些知識(shí),還要做好結(jié)構(gòu)設(shè)計(jì),這樣才能解答:一套合理的異步輸出模型應(yīng)該是什么樣的?
分享下我理解的一個(gè)異步日志模型是什么樣的(歡迎大家來“錘”,但是錘我的時(shí)候,麻煩輕點(diǎn)哈)
有的小伙伴看到這個(gè)圖覺得有點(diǎn)眼熟?Kafka?不對(duì),不對(duì),不對(duì),還少了一個(gè) Broker。因?yàn)檫@里不需要對(duì) Producer 實(shí)現(xiàn)一個(gè)獨(dú)立的緩沖器和分類器,那么 Broker 這樣的角色就不存在了。
簡(jiǎn)單的介紹下成員角色:
- MessageProducer: 消息和數(shù)據(jù)生成者
- CriticalSurface: 并發(fā)臨界面,所有 MessageProducer 都到這邊競(jìng)爭(zhēng)控制權(quán),往 RingBuffer 中寫入數(shù)據(jù)
- RingBuffer: 消息和數(shù)據(jù)的緩沖(記得緩沖和緩存區(qū)別,這邊用緩沖就是為了解決 Producer 和 Consumer 和速度差)
- MessageConsumer: 消息和數(shù)據(jù)消費(fèi)者
為什么選擇上面的模型:
- 希望在現(xiàn)有的 uber-go/zap 的結(jié)構(gòu)上擴(kuò)展,實(shí)現(xiàn)一部分能力,滿足功能擴(kuò)展。
- 不希望重復(fù)做輪子,因?yàn)檩喿幼龀鰜恚枰袊?yán)格的代碼測(cè)試和壓力測(cè)試,才能交付生產(chǎn)系統(tǒng)。
- 模型簡(jiǎn)單,好理解,也好實(shí)現(xiàn)。
- 性能比較高,而且架構(gòu)整體比較合理。
為了實(shí)現(xiàn)這個(gè)模型,還需要思考如下幾個(gè)問題:
- CriticalSurface 如何實(shí)現(xiàn)?因?yàn)橐獫M足多個(gè) MessageBroker 并發(fā)使用,那么這個(gè)臨界面就必須要做,要不然就出現(xiàn)爭(zhēng)搶資源失控的情況。
- 為什么要選擇 RingBuffer?RingBuffer 是目前速度和效率最好的一種緩沖模型,Linux/Unix 系統(tǒng)中廣泛使用。
- 選擇 RingBuffer 需要注意些什么?RingBuffer 有快慢指針的問題,如果控制不好,快指針就回覆寫慢指針的數(shù)據(jù),地址數(shù)據(jù)丟失的情況。
- MessageConsumer 數(shù)量如何限制?如何平衡信息的創(chuàng)建與消費(fèi)之間的速度差異。
- 如何支持多種日志方式輸出類型。(golang 多種 io.Writer 模型)
如果看到這里,估計(jì)已經(jīng)勸退了很多的小伙伴,我想這就是為什么那個(gè)研發(fā)項(xiàng)目負(fù)責(zé)人帶著團(tuán)隊(duì)問題來找我,希望能夠得到解決的原因吧。確實(shí)不容易。
解決思路
uber-go/zap 代碼分析
在認(rèn)真看看完了 uber-go/zap 的代碼以后,發(fā)現(xiàn) uber 就是 uber,代碼質(zhì)量還是非常不錯(cuò)的,很多模塊抽象的非常不錯(cuò)。通過一段時(shí)間的思考后,確認(rèn)我們要實(shí)現(xiàn)一個(gè)獨(dú)立的 WriteSyncer, 跟 uber-go/zap 中的 BufferedWriteSyncer 扮演相同的角色。
既然要實(shí)現(xiàn),我們先看看 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 是一個(gè) interface,也就是我們只要引用 io.Writer 和實(shí)現(xiàn) Sync() error 這樣的一個(gè)方法就可以對(duì)接 uber-go/zap 系統(tǒng)中。那么 Sync() 這個(gè)函數(shù)到底是干嘛的? 顧名思義就是讓 zap 觸發(fā)數(shù)據(jù)同步動(dòng)作時(shí)需要執(zhí)行的一個(gè)方法。但是我們是異步日志,明顯 uber-go/zap 處理完日志相關(guān)的數(shù)據(jù),丟給我實(shí)現(xiàn)的 WriteSyncer 以后,就不應(yīng)該在干預(yù)異步日志模塊的后期動(dòng)作了,所以 Sync() 給他一個(gè)空殼函數(shù)就行了。
當(dāng)然 uber-go/zap 早考慮到這樣的情況,就給一個(gè)非常棒的包裝函數(shù) 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 已經(jīng)把我們希望要做的事情都給做好了,我們只要實(shí)現(xiàn)一個(gè)標(biāo)準(zhǔn)的 io.Writer 就行了,那繼續(xù)看 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) }
哇,好簡(jiǎn)單。要實(shí)現(xiàn) io.Writer 僅僅只要實(shí)現(xiàn)一個(gè) Write(p []byte) (n int, err error) 方法就行了,So Easy !!!!
上手開發(fā)
還是回到上一章中的 5 個(gè)核心問題,我想到這里應(yīng)該有答案了:
- MessageProducer:用一個(gè)函數(shù)實(shí)現(xiàn),實(shí)際上就是 Write(p []byte),接收 uber-go/zap 投遞來的消息內(nèi)容。
- CriticalSurface 和 RingBuffer: 是最核心的部件,既然要考慮到性能、安全、兼容各種數(shù)據(jù)類型,同時(shí)要有一個(gè) Locker 保證臨界面,也要滿足 FIFO 模型。思來想去,當(dāng)然自己也實(shí)現(xiàn)了幾版,最后還是用 golang 自身的 channel 來完成。
- MessageConsumer:用一個(gè) go 協(xié)程來執(zhí)行從 RingBuffer 循環(huán)讀取,然后往真正的 os.Stdout/os.StdErr/os.File 中輸出。(為什么是一個(gè)而不是多個(gè)?一個(gè)速度就足夠快了,同時(shí)系統(tǒng)底層 io.Writer 自身也帶鎖,所以一個(gè)能減少鎖沖撞。)
TIPS: 這里說說為什么我要選擇 golang 自身的 channel 作為 CriticalSurface 和 RingBuffer 的實(shí)現(xiàn)體:
- channel 是 golang 官方的代碼包,有專門的團(tuán)隊(duì)對(duì)這個(gè)代碼質(zhì)量負(fù)責(zé)。channel 很早就出來了,Bugs 修復(fù)的差不多了,非常的穩(wěn)定可靠。(也有自己懶了,不想自己寫 RingBuffer,然后要考慮各種場(chǎng)景的代碼測(cè)試。)
- channel 的 “<-” 動(dòng)作天生就有一個(gè) Locker,有非常好的臨界面控制。
- channel 底層是就是一個(gè) RingBuffer 的實(shí)現(xiàn),效率非常不錯(cuò),而且如果 channel 滿了,數(shù)據(jù)投遞動(dòng)作就會(huì)卡住,如果 channel 空了,數(shù)據(jù)提取動(dòng)作也會(huì)被卡住,這個(gè)機(jī)制非常棒。
- channel 天生就是一個(gè) FIFO 的模型,非常合適做數(shù)據(jù)緩沖,解決 Producer 和 Consumer 和速度差這樣問題。
有了上面的思路,我的代碼架構(gòu)也基本出來了,結(jié)構(gòu)圖如下:
這里我貼出一個(gè)實(shí)現(xiàn)代碼(DEMO 測(cè)試用,生產(chǎn)要謹(jǐn)慎重新實(shí)現(xiàn)):
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 內(nèi)部傳遞的是 buffer 的指針,速度比傳遞對(duì)象快。 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) // 這里要稍微等待下,因?yàn)槭钱惒降妮敵?,log.Info() 執(zhí)行完畢,日志并沒有完全輸出到 console }
Console 輸出:
$ go run asynclog.go {"level":"info","ts":1674808100.0148869,"msg":"demo log"}
輸出結(jié)果符合逾期
測(cè)試代碼
為了驗(yàn)證架構(gòu)和代碼質(zhì)量,這里做了異步輸出日志、同步輸出日志和不輸出日志 3 種情況下,對(duì) gin 封裝的 webservice 框架吞吐力的影響。
# | 測(cè)試內(nèi)容 | 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
總結(jié)
通過對(duì)上面的工程代碼測(cè)試,基本實(shí)現(xiàn)了 gin + zap 的異步日志輸出功能的實(shí)現(xiàn)。當(dāng)然上面的代碼僅供小伙伴學(xué)習(xí)研究用,并不能作為生產(chǎn)代碼使用。
從結(jié)果來看,golang 的 channel 整體性能還是非常不錯(cuò)。基于 channel 實(shí)現(xiàn)的異步日志輸出基本于不輸出日志的吞吐力和性能相當(dāng)。
在實(shí)際工作中,我們能用 golang 原生庫的時(shí)候就盡量用,因?yàn)?golang 團(tuán)隊(duì)在寫庫的時(shí)候,大多數(shù)的情況和場(chǎng)景都考慮過,所以沒有必自己做一個(gè)輪子。安全!安全!安全!
至于 uber-go/zap 團(tuán)隊(duì)為什么不愿意實(shí)現(xiàn)這樣的異步日志輸出模型,可能有他們的想法吧。但是我想,不論那種異步日志模型,都存在著程序異常會(huì)丟日志的情況。這里再次提醒小伙伴,要慎重選擇日志系統(tǒng)模型,切不可以一味追求速度而忽略日志,因?yàn)榉?wù)日志也是重要的業(yè)務(wù)數(shù)據(jù)。
以上就是uber go zap 日志框架支持異步日志輸出的詳細(xì)內(nèi)容,更多關(guān)于uber go zap日志異步輸出的資料請(qǐng)關(guān)注腳本之家其它相關(guān)文章!
相關(guān)文章
golang 網(wǎng)絡(luò)框架之gin的使用方法
這篇文章主要介紹了golang 網(wǎng)絡(luò)框架之gin的使用方法,文中通過示例代碼介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值,需要的朋友們下面隨著小編來一起學(xué)習(xí)學(xué)習(xí)吧2019-11-11Golang反射獲取結(jié)構(gòu)體的值和修改值的代碼示例
這篇文章主要給大家介紹了golang反射獲取結(jié)構(gòu)體的值和修改值的代碼示例及演示效果,對(duì)我們的學(xué)習(xí)或工作有一定的幫助,感興趣的同學(xué)可以參考閱讀本文2023-08-08golang如何實(shí)現(xiàn)三元運(yùn)算符功能
這篇文章主要介紹了在其他一些編程語言中,如?C?語言,三元運(yùn)算符是一種可以用一行代碼實(shí)現(xiàn)條件選擇的簡(jiǎn)便方法,那么在Go語言中如何實(shí)現(xiàn)類似功能呢,下面就跟隨小編一起學(xué)習(xí)一下吧2024-02-02golang多次讀取http request body的問題分析
這篇文章主要給大家分析了golang多次讀取http request body的問題,文中通過代碼示例和圖文介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或工作有一定的幫助,需要的朋友可以參考下2024-01-01Golang中crypto/rand庫的使用技巧與最佳實(shí)踐
在Golang的眾多隨機(jī)數(shù)生成庫中,crypto/rand?是一個(gè)專為加密安全設(shè)計(jì)的庫,本文主要介紹了Golang中crypto/rand庫的使用技巧與最佳實(shí)踐,感興趣的可以了解一下2024-02-02Go?實(shí)現(xiàn)?WebSockets之創(chuàng)建?WebSockets
這篇文章主要介紹了Go?實(shí)現(xiàn)?WebSockets之創(chuàng)建?WebSockets,文章主要探索?WebSockets,并簡(jiǎn)要介紹了它們的工作原理,并仔細(xì)研究了全雙工通信,想了解更多相關(guān)內(nèi)容的小伙伴可以參考一下2022-04-04