Golang Go语言中 有日志(stdout or file) qps 4k,没日志 qps 10w. why?

发布于 1周前 作者 yuanlaile 来自 Go语言

很简单的一个 echo 的 hello world 小 demo 。

wrk -c2000 -d10s -t6 http://localhost:8000/

use(logger)就 4k 的 qps (默认是 stdout ),不 use 就 10w 的 qps ??

因为同步输出到 stdout 需要时间嘛?那正式线上服务还需要考虑异步写日志咯?

搞个有 buffer 的 writer ?那 panic 的时候没来得及刷盘的日志咋弄。


Golang Go语言中 有日志(stdout or file) qps 4k,没日志 qps 10w. why?

更多关于Golang Go语言中 有日志(stdout or file) qps 4k,没日志 qps 10w. why?的实战系列教程也可以访问 https://www.itying.com/category-94-b0.html

34 回复

writer 本来也有 buffer 吧。你可以搞个写日志的 benchmark 试下,在你的机器上到底什么性能。另外 writer 可能还有锁,这个也有性能消耗。

更多关于Golang Go语言中 有日志(stdout or file) qps 4k,没日志 qps 10w. why?的实战系列教程也可以访问 https://www.itying.com/category-94-b0.html


不至于这么慢吧,你把 log 输出到 io.Discard 试试?

>那正式线上服务还需要考虑异步写日志咯?
不要过度优化。

你正式上线如果要跑 10w qps 的话还是单独开一台日志服务器吧。

goos: windows
goarch: amd64
go:1.18.1
cpu: Intel® Core™ i7-6800K CPU @ 3.40GHz

BenchmarkPrintln-12 18981 110532 ns/op 24 B/op 1 allocs/op
BenchmarkStdout-12 15235 84465 ns/op 24 B/op 1 allocs/op
BenchmarkBufio-12 56409 25036 ns/op 163 B/op 0 allocs/op
BenchmarkDiscard-12 348340519 3.703 ns/op 0 B/op 0 allocs/op

简单测试了一下,光打印“hello world\n”,性能相差还是很大的,Stdout 底层有系统调用和锁,访问量大的话还是会影响性能的。java 的 System.out.println 应该也有类似的问题。

可否详细说明 panic 和落盘的关系?网络服务不一般都对 request 逐个做了 recovery 吗?

虽然都会有一个 recovery middleware ,但是 request 处理内部会起 goroutine 就可能整个程序 panic ,不做处理的话这可能导致日志会丢失一些

嗷嗷快。嗯。

相比于 echo HelloWorld ,写日志本身就很重了。在高性能场景下,除了 debug 日志都要关掉的



goos: darwin
goarch: amd64
cpu: Intel® Core™ i7-7820HQ CPU 2.90GHz
BenchmarkStdout-8 10000 261816 ns/op

1.go 语言的输出队列是 1k 还是多大来着,当高并发写日志的时候把输出队列占满了,其他输出就会等待,因此你 qps 就下去了

2.你应该把日志改成写文件再试试

3.线上服务写日志难道还有人不是异步的?



2. 好像更满了…
3. 这块儿有好用的包吗

开源的不知道,我呆过的公司日志框架都是内部实现的。写日志都是异步操作

估计是你这个日志库里有锁,或者队列长度比较短导致大量调用被 block 住了

写日志到磁盘肯定慢啊,磁盘和网络内存 CPU 比起来实在是太慢了

写日志必须是异步的操作,不然会影响业务性能

Java 那边一般也不会 System.out.println ,一般库都是异步的,go 也一样

io 和 捕捉异常 都很耗时

stdout 输出到控制台的写性能确实不高,stdout 重定向到文件的区别应该不大吧

盲猜一个每次文件都打开关闭,而 stdout 没有用 tmux 之类的,没有缓存真就会碰到阻塞

其实你应该贴 Logger 函数里面的内容,反倒贴了一堆没用的

用 zap 写文件试试

你标题已经说了走的 stdout ,我说的是 stdout 可能在 terminal 这层被阻塞,结果你还是在重复说你走的 stdout ,估计是没听懂

要不这样,你启动的时候结尾加上 >/tmp/log.txt 2>&1 ,再跑一次看有区别没

看你贴的代码,这是你用的 log 库吧,说的是你怎么调的 Logger ,不是问你调的什么 Logger……

你骑共享单车 100 次、每次骑 10 米,跟你一次骑车骑 1000 米,是不一样的。扫码、解锁、停车、关锁的开销这一套下来,可能还没你走着快。这样能理解么

你这里,如果是个复杂的 log ,还有颜色高亮什么的,可能拼 log 的时间远大于写 log 的时间,但再大再复杂的 log 也不应该每秒 4k

应该着眼于怎么消除 goroutine 里面的代码缺陷带来的 panic 吧。我觉得,欢迎交流

火焰图看看就知道,之前分析过日志,如果日志里有很多 format ,没处理好会涉及到很多反射调用,QPS 一大就非常耗性能,用 uber 的 zap 试试

#4 "你正式上线如果要跑 10w qps 的话还是单独开一台日志服务器吧"
都写到日志服务器难道不比写本机更慢吗。。。


#11 "3.线上服务写日志难道还有人不是异步的?"
比如金融级的业务,资金很重要,如果用异步、刚好宕机日志丢失了,那就不好了
#13 "开源的不知道,我呆过的公司日志框架都是内部实现的。写日志都是异步操作"
这些业务的安全等级不需要那么高,所以可以允许异步日志

#16 同上面的回复

最后, OP 可以按业务需要做日志选型,比如我上面说的。并且安全等级要求高的,比如金融级的,不差这点堆机器的硬件成本。如果是普通业务,异步也可

金融级别的,核心日志肯定得写数据库了,而且还得使用数据库事务提交。

如果要求日志不能丢,那只能控制日志的量了,线上服务使用 warning 以上的日志级别,并且严格控制日志数量

#29
不一样的,写数据库的那叫操作日志之类的,记录的东西不一样,比如 admin 操作之类的,是给管理人员用的。
程序日志主要是用于 debug 日志的,是给程序员用的。


1. 写到日志服务器可以异步
2. 金融级服务如果宕机,应该找硬件或操作系统公司索赔。
再者,如果是金融级服务,可以搞高可用,前端 LB 后端集群,基本不需要考虑宕机的问题。
不管怎么说,一旦量级到了 10w qps ,就不是一个人在一个论坛上问问就能搞定的了,怎么都需要一个团队和专业的有经验的架构师来搞了。


我说的是写日志服务器比写本机更慢,用相同的方式,都同步或者都异步,肯定是本机快。如果不考虑日志安全级别、也即不需要考虑异步的丢日志问题,那当然也能异步写本地了。
另外就是,异步写到日志服务器的硬件、配置耦合更高、还需要考虑短线重连之类的稳定性问题,而且是业务进程内的模块,远不如 ELK 拉日志之类的解耦(当然,也额外增加了运维成本,但是开发和代码相对解脱了一些)

索赔是依赖第三方的正常商业行为,但是在依赖第三方之前,自家的 debug 、故障修复能力也是应该尽量自己提升的。
这个安全级别日志是单节点的稳定性、故障恢复、debug 能力的范畴; LB 是处理扩容问题、分布式范畴。一个是单点内的问题,一个是集群扩容能力的问题,所以 LB 跟这个问题没有直接关系

不是很重要的日志可以加个缓冲

在Go语言中,遇到开启日志(无论是输出到标准输出stdout还是文件file)后QPS(Queries Per Second,即每秒查询率)大幅下降的现象,主要是由于以下几个原因:

  1. I/O性能瓶颈:日志记录涉及磁盘或网络I/O操作,这些操作相对较慢。在高并发环境下,频繁的日志写入会显著影响整体性能,尤其是当日志量较大时,磁盘I/O可能成为瓶颈。

  2. 锁竞争:如果日志库不是并发安全的,或者在高并发写入时存在锁竞争,也会导致性能下降。Go语言的标准库log在并发写入时可能不是最优的,而一些第三方日志库如zaplogrus等提供了更好的并发性能。

  3. 内存消耗:日志记录会增加内存消耗,尤其是在日志量大的情况下。虽然内存消耗本身不一定直接导致QPS下降,但内存不足时可能触发GC(垃圾回收),进而影响性能。

  4. 上下文切换:频繁的日志写入可能导致CPU上下文切换增加,尤其是在多线程/多goroutine环境下,这会降低CPU的利用率,从而影响QPS。

为了优化性能,可以考虑以下措施:

  • 使用高效的日志库,如zap,它提供了高性能的日志记录能力。
  • 异步日志记录,将日志写入操作放入一个单独的goroutine中,减少主业务逻辑的等待时间。
  • 控制日志级别和输出频率,避免生成过多的日志。
  • 优化磁盘I/O性能,如使用SSD替代HDD,或者将日志文件写入到更快的存储设备上。
回到顶部