怎样优化一个Go服务以减少40%的CPU使用率？

作者 | Eliezer Yaacov
策划 | 万佳
通过优化一个 Go 服务，Coralogix 公司的工程师成功减少了 40% 的 CPU 使用率。
10 年前，谷歌遇到一个由 C++ 编译时间过长造成的严重瓶颈，他们需要全新的解决方案。为应对这一挑战，谷歌工程师创建了一种叫 Go（又名 Golang）的新编程语言。Go 语言借鉴了 C++ 的优点（比如其性能和安全特性），同时结合了 Python 的开发速度，这让其能快速使用多个核心，实现并发计算。
在 Coralogix，我们解析客户日志来为它们提供相应的实时分析、警报和元数据等。为做到这一点，解析阶段必须非常快，但解析阶段却又非常复杂，并需要为每一个日志行服务加载大量规则。这是我们觉得采用 Golang 的原因之一。
这项新服务全天候运行在我们的生产环境中。虽然结果很不错，但是它仍然需要运行在高性能的机器上。这个 Go 服务运行在一台 8 核 CPU 和 36GB 内存的 AWS m4.2xlarge 实例上，每天解析超过数百亿的日志。这个阶段，一切运行正常，可以将就，但这不是我们的风格，我们希望用更少的 AWS 实例来提供更多的功能，比如性能等。为实现这一目标，我们需要了解瓶颈的本质，以及如何能减少或完全消除它们。

1
问题分析
我们决定在服务上运行一些性能分析，并检查是什么导致 CPU 的高消耗，看看是否可以做些优化工作。
升级版本
首先，我们将 GO 升级到最新的稳定版本（软件生命周期中的关键一步）。此前，我们的版本是 1.12.4，现在用的是 1.13.8。
根据官方文档，1.13 版本在 runtime library 和一些对内存使用有很大影响的组件进行了重大改进。不管怎么说，使用最新的稳定版本很有意义，并且为我们节省了很多工作。
https://golang.org/doc/devel/release.html
因此，内存消耗也从 800MB 左右优化到 180MB 左右。
分析开始
其次，为更好地理解我们的工作流程，并了解我们在哪里花费时间和资源，我们开始进行分析。
分析不同的服务和编程语言可能看起来非常复杂并令人生畏，但是在 Go 中，它实际上非常简单，仅用几个命令就可以实现。Go 有一个叫”pprof”的专门工具，可以通过监听路由（默认端口为 6060）在应用程序中启用该工具，并使用 Go 包来管理 HTTP 连接

import _ "net/http/pprof"

然后，在主函数或者路由包中启用如下操作:

go func() {

    log.Println(http.ListenAndServe("localhost:6060",nil))

}()

现在我们可以启动服务并连接到

Http://localhost:6060/debug/pprof

完整的 Go 文档可以参阅此处。
https://golang.org/pkg/net/http/pprof
pprof 的默认配置是每隔 30 秒对 CPU 使用率进行采样。我们可以调整一些配置从而实现对 CPU 使用率、heap usage 等参数的采样。我们主要关注的是 CPU 的使用情况，因此在生产阶段中，我们采取一个 30 秒间隔的性能采样，并发现下图中的显示内容（注意：这是在我们升级了 Go 版本并将 Go 的内部组件降到最低之后的结果）：

Go profiling
如你所见，我们发现很多与运行时库（runtime package ）相关的活动，其中需要特别指出是 GC（垃圾收集）：几乎 29% 的 CPU 被 GC 使用，这还只是消耗最多的前 20 个对象。由于 Go 的 GC 已经非常快并做了很大优化，最好的实践就是不要去改变或修改它。由于我们的内存消耗非常低（与前一个 Go 版本相比），所以主要问题变成了高对象分配率。
如果是这样的话，我们可以做两件事情：

1. 调整 Go GC 活动来适应我们的服务行为，也就是说，我们需要延迟 GC 的触发来减少其运行频率。作为代价，我们将不得不消耗更多的内存。
2. 找出代码中分配了太多对象的函数、区域或行。

观察一下实例类型，我们有大量的空闲内存，而 CPU 数量则被机器类型所限制。因此我们需要调整这个比率。从 Golang 早期开始，就有一个阀值（flag）被大多数开发人员所忽视：GOGC。该阀值的缺省值为 100，它的主要工作就是告诉系统何时触发 GC。当堆达到其初始大小的 100% 时，默认值将触发 GC 进程。将默认值更改为更高数字则延迟 GC 触发，反之，将更快地触发 GC。我们开始针对不同的数值进行基准测试，最终发现当 GOGC=2000 时，我们能获得最佳性能。
这将我们的内存使用量从 200 MB 立刻增加到 2.7 GB（这还是在我们更新 Go 版本减少了内存消耗之后），并将我们的 CPU 使用率降低 10%。
下面的截图展示了这些基准测试的结果:

Gogc=2000 的结果
CPU 使用率排名前 4 的函数变成了我们的服务函数，这才说得过去。现在，总的 GC 使用量变成了约 13%，比之前的一半还少。
继续深入
我们本可以就此打住，但我们还是决定继续去调查分配这么多对象的位置以及原因。很多时候，分配对象都有一个很好的理由（例如在流处理的情况下，我们为每条消息都创建了很多新对象，因为它与下一条消息无关，需要移除它），但在某些情况下，有一种简单的方法可以优化并极大地减少对象创建。
首先，让我们运行一个和之前相同的命令，只做一个小小的变动，采用 heap dump：

Http://localhost:6060/debug/pprof/heap

为了查询结果文件，我们可以在代码文件目录中运行如下命令来分析调试结果：

go tool pprof -allocobjects 

我们的截图看起来是这样的:

除第三行外，一切似乎都很合理。第三行是一个监控函数，在每个 Coralogix 规则解析阶段的末尾向我们的 Promethes 导出者（exporter）输出报告。为获取进一步的信息，我们运行以下命令:

list 

例如：

list reportRuleExecution

然后，我们得到以下结果：

这两个对 WithLabelValues 的调用其实是针对度量的 Prometheus 调用（我们让产品来决定是否真的需要它）。此外，我们看到第一行创建了大量对象（占该函数总分配对象的 10%）。通过进一步研究，我们发现这是一个将客户 ID 从 int 转换为 string 的过程。该过程非常重要，但考虑到数据库中的客户数量有限，我们不应该为迎合 Prometheus 而将变量作为字符串接收。
因此，我们没有在每次创建一个新字符串并在函数结束时丢弃它（浪费了分配时间和 GC 的更多工作），而是在对象初始化时定义了一个映射，映射了从 1 到 10 万之间的所有数字以及一个相对应的”get”操作。
我们运行了一个新的性能分析会话来验证上述论点，结果证明它是正确的（我们可以看到这部分不再分配对象了）:

这并不是一个非常大的改动，但总的来说，这为我们节省了另一个 GC 活动，更具体地说，大约 1% 的 CPU 使用率。
最终状态显示在下面的截图中：

2
最终结果
内存使用：~1.3GB -> ~2.7GB
CPU 使用：~2.55 均值和~5.05 峰值 -> ~2.13 均值和~2.9 峰值。
Golang 优化之前的 CPU 使用率：

Golang 优化之后的 CPU 使用率：

总的来说，我们的改进主要体现在峰值时间段，每秒处理的日志数量提升了。这意味着我们的基础设施不再需要针对异常值进行调优，而且变得更加稳定。

3
总结
通过分析 Go 解析服务，我们能定位出问题区域，更好地理解我们的服务，并决定在哪里（如果有的话）投入时间来做改进工作。大多数性能分析工作最终都会参照用户使用情况对阀值或配置进行调优，从而获得更好的性能。
延展阅读：
https://medium.com/coralogix-engineering/optimizing-a-golang-service-to-reduce-over-40-cpu-366b67c67ef9

点个在看少个 bug
:point_down: