给 Web Server 加压力， CPU 火焰图显示 50% 消耗在 runtime 上，是什么原因？

[mornlight]

用 gin 新写好的一个服务端，正常流量时没有啥问题，做压力测试，对某个高频业务接口调用 15000 次 /秒，go-torch 拿出来 60 秒的火焰图，发现一半消耗在业务逻辑上（主要是读写 Redis 和 JSON 序列化）,另一半消耗在 Go 自己的 runtime 里。
机器环境：32 核物理 CPU，Docker 限制 1200% CPU 使用，被占满。

想请教各位这个 runtime.findrunnable 消耗是 goroutine 数量上去后带来的还是 CPU 不够用带来的？是否有办法避免或缓解？

[mornlight]

这里是火焰图：

[whileFalse]

随便猜猜，是不是消耗在内存回收上了

[denghongcai]

goroutine 是不是开多了

[mornlight]

@denghongcai #3 每个 request 进来后都会创建一个新的 goroutine，所以肯定是有大量 goroutine 需要管理的。但我不确定这样程度的 runtime 开销是否正常。

[mornlight]

@whileFalse #2 schedule 看着不太像干垃圾回收的事情啊。

[PureWhite]

go 的版本，什么系统，以及是高 IO 还是高 CPU 还是如何，是否有大量 goroutine ？

[mornlight]

@PureWhite #6 Go 版本 1.9.2，Ubuntu 16.04 ，从 pprof 里看到的 goroutine 在 10000 个左右。没有硬盘 IO，只有 Redis 读写和内存操作，CPU 密集。我的疑问在于这样的压力下 runtime 接近一半的 CPU 时间占用是否是正常的。

[PureWhite]

Redis 读写量大么？ Redis 是在本地还是远程服务器？

[PureWhite]

@mornlight

[mornlight]

@PureWhite #8 每一个请求有一次 Redis 写操作一次读操作，我打码的那部分业务代码最后大多都耗在 Redis 的库里。

[PureWhite]

@mornlight 我的猜测是正常的，因为你进行 redis 操作的时候 goroutine 会挂起等待结果返回，是用的 non-block+epoll 模型，于是这个时候调度器就需要去寻找下一个 goroutine 来运行，这样你并发大的时候，又是 CPU 密集，有 10000 个 goroutine 的时候，就会有大量的时间花在了调度上。
这个问题的出现和你是 CPU 密集以及 goroutine 数量多都有关，所以你的两个猜测都应该是对的。
没有看到代码，自己也没有调试，只能是猜测，可能有误。

[zts1993]

上一个 go pprof -> web 的节点调用时间看看吧

[mornlight]

@PureWhite #11 感谢！我觉得这个想法可以验证，我把接口的 Redis 操作去掉，然后再压上去看看会不会有缓解。
自身业务代码占用的 CPU 时间并不多，Redis 连接和 session 反序列化带来的性能开销暂时也不太能做改动，我觉得我已经尽力了......

[mornlight]

@zts1993 #12 这个可以看出什么信息？还没试过，明天试试看。

[PureWhite]

@mornlight 嗯，这个验证方法好，赞！
如果验证完确实是这个问题的话，我觉得到这一步已经差不多可以了，下一步看看有没有 ConnectionPool 之类的东西可以来优化一下，剩下的优化空间就不大了。
基本上我认为一半的 CPU 花在调度上已经不是不能接受得了，毕竟你想想如果用的是 thread。。。。

[mornlight]

@PureWhite #15 这接口之前有个 Python 版本，现在用 Go 重写之后并发上限提升十几倍，内存占用是十分之一

[PureWhite]

@mornlight 23333 我觉得已经足够了，这么一比的话。。。

[mornlight]

@PureWhite #15 试了下去掉所有 Redis 操作，runtime 占用比例下降了一小截，不够明显，但是能跑到 60000 请求 /秒了。基本可以确认是 IO 等待带来的 goroutine 调度开销。

[PureWhite]

@mornlight 你试着还是跑 15000/s，看看下降多少。。。。
你不能拿 60000/s 和 15000/s 比呀。。。
另外，如果你是拿 15000/s 和 15000/s 比的话，你要看的是绝对时间，而不是相对时间，因为你 runtime 降低的同时 redis 操作也降低了，所以相对的时间肯定都少了，在这种情况下绝对时间比较有意义。

[mornlight]

@PureWhite #19 我的压测代码没有写控制并发量的逻辑，能跑到多少跑多少，等会儿再试试看