在Golang服务里,日志打印看起来只是简单的一行调用,但当QPS上升到几万甚至更高时,每次写文件或网络日志都会触发系统调用和磁盘IO,成为拖慢接口的隐形杀手。要把这部分开销压下去,核心思路是把同步写改成异步输出,再把零散的写操作聚合成批量写入。
为什么同步日志会拖慢性能
大多数初学者使用的标准库log或者直接用fmt.Fprintf写文件,本质都是同步操作。调用方必须等数据真正写到目标(磁盘、管道或者远程)后才返回。在普通后台任务里这没问题,但在HTTP接口或消息消费循环中,每一次日志都会占用本该处理业务的goroutine时间。
我们可以用一段最基础的同步写日志代码来看问题所在:
package main
import (
"log"
"os"
)
func main() {
f, _ := os.OpenFile("app.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
defer f.Close()
logger := log.New(f, "", log.LstdFlags)
// 模拟高并发中频繁打印
for i := 0; i < 100000; i++ {
logger.Printf("handle request id=%d cost=%dms", i, i%10)
}
}
上面代码在循环里同步写十万条日志,程序绝大多数时间耗在write系统调用上。如果这是Web接口的一部分,用户请求就会明显变慢。更糟的是,当磁盘繁忙或日志服务网络抖动,goroutine会被卡住,导致协程堆积、内存上涨。
异步输出:用channel解耦生产者和消费者
异步输出的本质是引入一个中间队列。业务goroutine把日志内容扔进channel就立刻返回,后台只启动一个或少量goroutine负责从channel取出内容并写入文件。这样业务侧几乎不被IO阻塞。
下面是一个最简化的异步日志器示例,用带缓冲的channel接收日志字符串:
package main
import (
"log"
"os"
"sync"
)
type AsyncLogger struct {
ch chan string
wg sync.WaitGroup
done chan struct{}
}
func NewAsyncLogger(bufSize int) *AsyncLogger {
a := &AsyncLogger{
ch: make(chan string, bufSize),
done: make(chan struct{}),
}
a.wg.Add(1)
go a.consume()
return a
}
func (a *AsyncLogger) consume() {
defer a.wg.Done()
f, _ := os.OpenFile("async.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
defer f.Close()
for {
select {
case msg := <-a.ch:
f.WriteString(msg + "n")
case <-a.done:
// 退出前把剩余数据写完
for len(a.ch) > 0 {
msg := <-a.ch
f.WriteString(msg + "n")
}
return
}
}
}
func (a *AsyncLogger) Log(msg string) {
a.ch <- msg
}
func (a *AsyncLogger) Close() {
close(a.done)
a.wg.Wait()
}
func main() {
logger := NewAsyncLogger(1000)
defer logger.Close()
for i := 0; i < 100000; i++ {
logger.Log("handle request id=" + string(rune(i)))
}
}
这个实现里,Log方法只是往channel发送,业务goroutine不会被文件写入拖住。后台consume协程不断从channel读并写文件。不过它仍然是一条一条写,没有发挥批量优势,而且进程退出时如果忘记Close就可能丢日志。
它的优点是结构简单、延迟低;缺点是当channel满时发送方还是会阻塞,并且单条写文件的系统调用次数并没有减少,只是转移到了另一个goroutine。
批量写入:攒一波再落盘
批量写入是在异步基础上增加缓冲:后台协程不急着写,而是把日志先放到内存切片里,当数量达到阈值或者定时时间到了,才一次性调用WriteString写入多行。这样能大幅减少系统调用次数。
下面示例在consume中加入了批量缓冲和定时刷新:
package main
import (
"log"
"os"
"sync"
"time"
)
type BatchLogger struct {
ch chan string
batch []string
maxBatch int
flushInt time.Duration
wg sync.WaitGroup
done chan struct{}
}
func NewBatchLogger(bufSize, maxBatch int, flushInt time.Duration) *BatchLogger {
b := &BatchLogger{
ch: make(chan string, bufSize),
batch: make([]string, 0, maxBatch),
maxBatch: maxBatch,
flushInt: flushInt,
done: make(chan struct{}),
}
b.wg.Add(1)
go b.consume()
return b
}
func (b *BatchLogger) consume() {
defer b.wg.Done()
f, _ := os.OpenFile("batch.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
defer f.Close()
ticker := time.NewTicker(b.flushInt)
defer ticker.Stop()
for {
select {
case msg := <-b.ch:
b.batch = append(b.batch, msg)
if len(b.batch) >= b.maxBatch {
b.flush(f)
}
case <-ticker.C:
if len(b.batch) > 0 {
b.flush(f)
}
case <-b.done:
for len(b.ch) > 0 {
b.batch = append(b.batch, <-b.ch)
}
b.flush(f)
return
}
}
}
func (b *BatchLogger) flush(f *os.File) {
for _, m := range b.batch {
f.WriteString(m + "n")
}
b.batch = b.batch[:0]
}
func (b *BatchLogger) Log(msg string) {
b.ch <- msg
}
func (b *BatchLogger) Close() {
close(b.done)
b.wg.Wait()
}
func main() {
logger := NewBatchLogger(2000, 100, 500*time.Millisecond)
defer logger.Close()
for i := 0; i < 100000; i++ {
logger.Log("batch request id=" + string(rune(i)))
}
}
在这段代码里,我们设定每满100条或每500毫秒强制刷盘一次。系统调用次数从十万次降到约一千次,磁盘写入更友好。batch切片复用也避免了频繁分配内存。
批量写入的代价是:如果程序意外崩溃,内存里没刷的日志会丢。因此实际项目中应把阈值和间隔设小一点,或者接入sigterm信号在退出前Close。对于审计类日志,不建议纯内存批量,可结合本地磁盘队列。
生产环境的一些补充建议
除了自己写,Go生态里像zap配合writeSyncer、logrus的AsyncHook都已经实现了类似机制。如果你的服务对性能极度敏感,推荐直接用zap并开启缓冲:
package main
import (
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"os"
)
func main() {
ws := zapcore.AddSync(os.Stdout)
// 这里可包一层bufio.Writer做批量
encCfg := zap.NewProductionEncoderConfig()
core := zapcore.NewCore(
zapcore.NewJSONEncoder(encCfg),
ws,
zapcore.InfoLevel,
)
logger := zap.New(core)
logger.Info("hello", zap.Int("qps", 1000))
}
使用第三方库时,要注意它们的异步实现是否会在进程退出时丢失日志,以及是否支持按大小切割文件。自己实现的话,上文的BatchLogger已经覆盖核心逻辑,你可以加上文件轮转和错误计数。
总结来说,优化Golang日志性能就是两步:先通过channel把业务和IO解耦,再用内存缓冲把多次写合成一次。只要控制好刷盘频率和退出清理,就能在几乎不丢日志的前提下把性能提升一个量级。