谁偷了1/3个CPU - 诡异Go性能问题追根问底

看到过很多文章介绍本身CPU占用恶高甚至接近100%，其实那到反而清楚无遗漏了，无非哪一个busy loop卡住了。这里为你们描述一个近期遇到的Go程序在空闲时候依旧在top命令里总报告30%左右CPU占用的问题，这样的性能问题更隐蔽更难琢磨。

问题发生在我本身作的高性能多组Raft库Dragonboat里，这是一个Apache2开源的Go实现的多组Raft库，它的主打就是吞吐性能吊打竟品几十倍。由于性能是核心卖点，所以每一个函数的CPU耗费都了如指掌，直到有一天忽然发现系统空载的时候占用一个CPU核的30%的负载，以下图：

服务器程序空闲的时候，top中看到的cpu负载一般应该是个位数低位。深刻分析之后发现是一个较深的Go调度实现的问题。

观察

看到上述top的结果，strace -c 看了一下，不少futex。多启动几个这样的空闲进程，抓个火焰图看，它是这样的：

必须得假设您对Go近期版本(如1.8-1.11)的调度有必定基本了解，了解M、P、G三者的意义和做用。如暂时不了解，可参考本文或者该文的中文翻译。

火焰图中能够观察到几点：

• 让当前M去sleep的操做挺重的，它由tickWorkerMain试图去读一个channel引起
• runtime.futex的数据和上面提到的strace所报告的状况吻合

查看代码，Dragonboat库tickWorkerMain中有一个1khz的ticker，等于每秒读ticker.C这个channel 1000次。当时第一感受是有些疑惑，由于常识告诉我，一个简单的非严格1khz的低频ticker，在3Ghz左右的服务器处理器上，cpu占用应该在1-2%这样极低的占用才合理。只是但愿程序某个函数被一秒调用1000次，怎么就占用掉近30%的cpu？

先无论成因，孤立出这个问题点来看看。为了实现“程序某个函数被一秒调用1000次”这点，在Go中用ticker能够这么作：

package main

import (
    "time"
)

func main() {
    ticker := time.NewTicker(time.Millisecond)
    defer ticker.Stop()
    for range ticker.C {
    }
}

结果上述程序top报告25%的%CPU值。是Go的ticker实现的问题吗？换sleep循环看看：

package main

import (
    "time"
)

func main() {
    for {
        time.Sleep(time.Millisecond)
    }
}

运行上述time.Sleep程序，top报告15%的%CPU。这和一样一个sleep循环的C++在1%的%CPU有天壤之别。因而开始倾向因而Go的调度器的锅。

分析

再回到上述火焰图，park_m()后一连串操做很显眼。咱们已经知道M表示Machine，一般认为是一个OS Thread，park_m()后续stopm()顾名思义就是这个把当前M给停用掉，告诉系统这个M暂时不用。

一切彷佛开始明朗了。每次tickWorkerMain开始等下一个tick的时候，也就是去读ticker.C这个channel的时候都由于时间没到channel为空，当前goroutine会被park掉，这个操做很轻，只须要更改一个标志。而此时由于系统空闲，并无别的goroutine可供调度，Go的scheduler就必须让这个M去sleep，而这个操做是较重的且有锁，最终futex的syscall被调用。更具体的，这还和Go的后台timer实现、system monitor实现有关（注意火焰图中runtime.sysmon），这里不展开。人人都会告诉你协程调度是很轻的操做，这固然没错。但他们都没有告诉你更重要的一点：协程调度反复高频出现没有goroutine可供调度的代价在Go的当前实现里是显著的。

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

而这一问题的影响是具体客观的：

• 用户会反复提问为什么系统空闲时占30%的%CPU，空闲时进程在top里始终排顶部不是个好事
• 在一个慢速的用电池的ARM核上有这东西就麻烦了

cgo解决

咱们也已经知道，C/C++作一样的事代价很轻。若是从不改业务逻辑出发，首先想到的就是不让M去sleep，不发生无goroutine可调度的状况。好比，能够用一个OS线程经过cgo独立于scheduler地去产生这个1kHz的tick，每秒从C代码去调用1000次所需的Go函数。这个思路很容易实现，无非是从Go代码里调用一个C函数，这个C函数每秒1000次的从sleep中醒来去调用Go里的1khz的tick的处理函数，具体就不贴具体代码了。

用这个思路修改了Dragonboat的代码一跑，空闲时的cpu负载大幅下降：

 

结果

上述workaround已经让这一问题对本身软件的影响极大下降了。去golang-nuts吐槽一下，再报golang的issue tracker，根本的问题仍是Go Scheduler的实现。用户用1kHz的ticker不该该是这样大费周章，标准库、runtime上直接提供更高效的实现才是真正解决方案。

 

在Dragonboat的开发中，这样的performance regression几乎每周都发生。从一秒十万次吞吐到一秒一千万吞吐的进化，是算法协议不断理解的深刻，也是对Go runtime习性的不断熟悉的一个过程。后面陆续会风向大量这样的性能优化实践知识，均以目前互联网后台最热门Golang为语言，素材均为任何应用均会涉及的通用场景。做为最好的教材，欢迎你们试用Dragonboat，也请你们点Star支持它的持续开发。