首页   注册   登录
V2EX = way to explore
V2EX 是一个关于分享和探索的地方
现在注册
已注册用户请  登录
The Go Programming Language
http://golang.org/
Go Playground
Go Projects
Revel Web Framework
beego
拉勾
V2EX  ›  Go

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

  •  
  •   mornlight · 330 天前 · 1576 次点击
    这是一个创建于 330 天前的主题,其中的信息可能已经有所发展或是发生改变。
    用 gin 新写好的一个服务端,正常流量时没有啥问题,做压力测试,对某个高频业务接口调用 15000 次 /秒,go-torch 拿出来 60 秒的火焰图,发现一半消耗在业务逻辑上(主要是读写 Redis 和 JSON 序列化),另一半消耗在 Go 自己的 runtime 里。
    机器环境:32 核物理 CPU,Docker 限制 1200% CPU 使用,被占满。

    想请教各位这个 runtime.findrunnable 消耗是 goroutine 数量上去后带来的还是 CPU 不够用带来的?是否有办法避免或缓解?
    22 回复  |  直到 2018-02-11 09:18:53 +08:00
        1
    mornlight   330 天前
    这里是火焰图:
        2
    whileFalse   330 天前
    随便猜猜,是不是消耗在内存回收上了
        3
    denghongcai   330 天前   ♥ 1
    goroutine 是不是开多了
        4
    mornlight   330 天前   ♥ 1
    @denghongcai #3 每个 request 进来后都会创建一个新的 goroutine,所以肯定是有大量 goroutine 需要管理的。但我不确定这样程度的 runtime 开销是否正常。
        5
    mornlight   330 天前
    @whileFalse #2 schedule 看着不太像干垃圾回收的事情啊。
        6
    PureWhite   330 天前
    go 的版本,什么系统,以及是高 IO 还是高 CPU 还是如何,是否有大量 goroutine ?
        7
    mornlight   330 天前
    @PureWhite #6 Go 版本 1.9.2,Ubuntu 16.04 ,从 pprof 里看到的 goroutine 在 10000 个左右。没有硬盘 IO,只有 Redis 读写和内存操作,CPU 密集。我的疑问在于这样的压力下 runtime 接近一半的 CPU 时间占用是否是正常的。
        8
    PureWhite   330 天前
    Redis 读写量大么? Redis 是在本地还是远程服务器?
        9
    PureWhite   330 天前
        10
    mornlight   330 天前
    @PureWhite #8 每一个请求有一次 Redis 写操作一次读操作,我打码的那部分业务代码最后大多都耗在 Redis 的库里。
        11
    PureWhite   329 天前   ♥ 1
    @mornlight 我的猜测是正常的,因为你进行 redis 操作的时候 goroutine 会挂起等待结果返回,是用的 non-block+epoll 模型,于是这个时候调度器就需要去寻找下一个 goroutine 来运行,这样你并发大的时候,又是 CPU 密集,有 10000 个 goroutine 的时候,就会有大量的时间花在了调度上。
    这个问题的出现和你是 CPU 密集以及 goroutine 数量多都有关,所以你的两个猜测都应该是对的。
    没有看到代码,自己也没有调试,只能是猜测,可能有误。
        12
    zts1993   329 天前   ♥ 1
    上一个 go pprof -> web 的节点调用时间看看吧
        13
    mornlight   329 天前
    @PureWhite #11 感谢!我觉得这个想法可以验证,我把接口的 Redis 操作去掉,然后再压上去看看会不会有缓解。
    自身业务代码占用的 CPU 时间并不多,Redis 连接和 session 反序列化带来的性能开销暂时也不太能做改动,我觉得我已经尽力了......
        14
    mornlight   329 天前
    @zts1993 #12 这个可以看出什么信息?还没试过,明天试试看。
        15
    PureWhite   329 天前
    @mornlight 嗯,这个验证方法好,赞!
    如果验证完确实是这个问题的话,我觉得到这一步已经差不多可以了,下一步看看有没有 ConnectionPool 之类的东西可以来优化一下,剩下的优化空间就不大了。
    基本上我认为一半的 CPU 花在调度上已经不是不能接受得了,毕竟你想想如果用的是 thread。。。。
        16
    mornlight   329 天前   ♥ 1
    @PureWhite #15 这接口之前有个 Python 版本,现在用 Go 重写之后并发上限提升十几倍,内存占用是十分之一
        17
    PureWhite   329 天前
    @mornlight 23333 我觉得已经足够了,这么一比的话。。。
        18
    mornlight   327 天前
    @PureWhite #15 试了下去掉所有 Redis 操作,runtime 占用比例下降了一小截,不够明显,但是能跑到 60000 请求 /秒了。基本可以确认是 IO 等待带来的 goroutine 调度开销。
        19
    PureWhite   327 天前
    @mornlight 你试着还是跑 15000/s,看看下降多少。。。。
    你不能拿 60000/s 和 15000/s 比呀。。。
    另外,如果你是拿 15000/s 和 15000/s 比的话,你要看的是绝对时间,而不是相对时间,因为你 runtime 降低的同时 redis 操作也降低了,所以相对的时间肯定都少了,在这种情况下绝对时间比较有意义。
        20
    mornlight   327 天前
    @PureWhite #19 我的压测代码没有写控制并发量的逻辑,能跑到多少跑多少,等会儿再试试看
        21
    admirez   312 天前 via iPhone
    @mornlight 楼主还等着你的结果呢……
        22
    mornlight   311 天前
    @admirez #21 我在服务器上拿来跑测试的 docker 不知道被谁删了,还没有做更多的测试。你想要啥结果呢?
    关于   ·   FAQ   ·   API   ·   我们的愿景   ·   广告投放   ·   感谢   ·   实用小工具   ·   1573 人在线   最高记录 4019   ·  
    创意工作者们的社区
    World is powered by solitude
    VERSION: 3.9.8.1 · 24ms · UTC 16:46 · PVG 00:46 · LAX 08:46 · JFK 11:46
    ♥ Do have faith in what you're doing.
    沪ICP备16043287号-1