给 Web Server 加压力， CPU 火焰图显示 50% 消耗在 runtime 上，是什么原因？
mornlight · bynil · 2018-01-23 13:07:37 +08:00 · 2555 次点击这是一个创建于 2277 天前的主题，其中的信息可能已经有所发展或是发生改变。
用 gin 新写好的一个服务端，正常流量时没有啥问题，做压力测试，对某个高频业务接口调用 15000 次 /秒，go-torch 拿出来 60 秒的火焰图，发现一半消耗在业务逻辑上（主要是读写 Redis 和 JSON 序列化）,另一半消耗在 Go 自己的 runtime 里。
机器环境：32 核物理 CPU，Docker 限制 1200% CPU 使用，被占满。
想请教各位这个 runtime.findrunnable 消耗是 goroutine 数量上去后带来的还是 CPU 不够用带来的？是否有办法避免或缓解？
机器环境：32 核物理 CPU，Docker 限制 1200% CPU 使用，被占满。
想请教各位这个 runtime.findrunnable 消耗是 goroutine 数量上去后带来的还是 CPU 不够用带来的？是否有办法避免或缓解？
 |
1
mornlight OP 这里是火焰图：
 |
 |
2
whileFalse 2018-01-23 14:25:09 +08:00
随便猜猜，是不是消耗在内存回收上了
|
 |
3
denghongcai 2018-01-23 16:20:07 +08:00  1
goroutine 是不是开多了
|
|
4
mornlight OP 1
@denghongcai #3 每个 request 进来后都会创建一个新的 goroutine，所以肯定是有大量 goroutine 需要管理的。但我不确定这样程度的 runtime 开销是否正常。
|
|
5
mornlight OP @whileFalse #2 schedule 看着不太像干垃圾回收的事情啊。
|
 |
6
PureWhite 2018-01-24 00:22:11 +08:00
go 的版本，什么系统，以及是高 IO 还是高 CPU 还是如何，是否有大量 goroutine ？
|
|
7
mornlight OP @PureWhite #6 Go 版本 1.9.2，Ubuntu 16.04 ，从 pprof 里看到的 goroutine 在 10000 个左右。没有硬盘 IO，只有 Redis 读写和内存操作，CPU 密集。我的疑问在于这样的压力下 runtime 接近一半的 CPU 时间占用是否是正常的。
|
|
8
PureWhite 2018-01-24 00:39:28 +08:00
Redis 读写量大么？ Redis 是在本地还是远程服务器？
|
|
10
mornlight OP @PureWhite #8 每一个请求有一次 Redis 写操作一次读操作，我打码的那部分业务代码最后大多都耗在 Redis 的库里。
|
|
11
PureWhite 2018-01-24 00:49:55 +08:00 1
@mornlight 我的猜测是正常的，因为你进行 redis 操作的时候 goroutine 会挂起等待结果返回，是用的 non-block+epoll 模型，于是这个时候调度器就需要去寻找下一个 goroutine 来运行，这样你并发大的时候，又是 CPU 密集，有 10000 个 goroutine 的时候，就会有大量的时间花在了调度上。
这个问题的出现和你是 CPU 密集以及 goroutine 数量多都有关，所以你的两个猜测都应该是对的。 没有看到代码，自己也没有调试，只能是猜测，可能有误。 |
 |
12
zts1993 2018-01-24 00:58:02 +08:00 1
上一个 go pprof -> web 的节点调用时间看看吧
|
|
13
mornlight OP @PureWhite #11 感谢！我觉得这个想法可以验证，我把接口的 Redis 操作去掉，然后再压上去看看会不会有缓解。
自身业务代码占用的 CPU 时间并不多，Redis 连接和 session 反序列化带来的性能开销暂时也不太能做改动，我觉得我已经尽力了...... |
|
15
PureWhite 2018-01-24 01:02:47 +08:00
@mornlight 嗯，这个验证方法好，赞！
如果验证完确实是这个问题的话，我觉得到这一步已经差不多可以了，下一步看看有没有 ConnectionPool 之类的东西可以来优化一下，剩下的优化空间就不大了。 基本上我认为一半的 CPU 花在调度上已经不是不能接受得了，毕竟你想想如果用的是 thread。。。。 |
|
16
mornlight OP 1
@PureWhite #15 这接口之前有个 Python 版本，现在用 Go 重写之后并发上限提升十几倍，内存占用是十分之一
 |
|
18
mornlight OP @PureWhite #15 试了下去掉所有 Redis 操作，runtime 占用比例下降了一小截，不够明显，但是能跑到 60000 请求 /秒了。基本可以确认是 IO 等待带来的 goroutine 调度开销。
|
Select Language