72

记一次golang程序CPU高的排查过程

 4 years ago
source link: https://www.tuicool.com/articles/YBvAb2v
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.

事情的起因是某天CTO突然和我说,生产环境的程序CPU有点高,关键是现在也没什么负载,同样的代码在开发环境上CPU就低的多了。

不用细说,那一定是有什么地方出问题了。

CTO还说,他pprof过了,占用CPU最高的 runtime.futex ,还发了一篇相关的文章 谁占了该CPU核的30% - 一个较意外的Go性能问题 ,打趣说没准系统负载高了,这个问题就没了。因为原谅中写到:

必须指出,本问题是因为系统空闲没有goroutine可以调度造成的。显然的,系统繁忙的时候,即CPU资源真正体现价值时,上述30%的%CPU的overhead并不存在,因为大概率下会有goroutine可供调度,无需去做让M去sleep这个很重的操作。

然后就把这个锅就“甩”给我了,让我研究一下。毕竟开发环境的负载也没有那么高,但是CPU却蛮正常的。

分析

一开始我是没什么头绪,顺着CTO提供的线索,搜索了一些 runtime.futex 的文章,几乎所有文章都会提到以下可能会使CPU占用率高的示例代码:

var ticker = time.NewTicker(100 * time.Millisecond)
    defer ticker.Stop()
    var counter = 0
    for {
        select {
        case <-serverDone:
            return
        case <-ticker.C:
            counter += 1
        }
    }
复制代码

这段代码给我指明了一些方向,我开始全局搜索一些time.NewTicker的代码。

巧的是,还真让我搜到了一些,其中一个ticker的时间设置的很有问题。

options = append(options, metrics.BatchInterval(time.Duration(conf.BatchInterval)))
复制代码

这里的 time.Duration ( conf.BatchInterval )没有指定单位,那可就是nano second(纳秒)级别的,这ticker的协程跑起来,没造成死锁,只能说linux服务器的性能好。

后来,顺藤摸瓜,发现了这个interval其实是promethus的采样interval,promethus只在生产打开了,也可以解释了为什么同样的代码只在生产上出问题。

解决方法

初步的解决方法很简单,就是给这个interval加上单位,再略微调大一些就好,而且目前我们并没有太重视promethus的性能数据,所以也不是很确定50ms的采样间隔是不是有些过大。


About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK