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

2020 年 6 月 12 日 InfoQ

作者 | Eliezer Yaacov

译者 | 良言

策划 | 万佳

10 年前，谷歌遇到一个由 C++ 编译时间过长造成的严重瓶颈，他们需要全新的解决方案。为应对这一挑战，谷歌工程师创建了一种叫 Go（又名 Golang）的新编程语言。Go 语言借鉴了 C++ 的优点（比如其性能和安全特性），同时结合了 Python 的开发速度，这让其能快速使用多个核心，实现并发计算。

在 Coralogix，我们解析客户日志来为它们提供相应的实时分析、警报和元数据等。为做到这一点，解析阶段必须非常快，但解析阶段却又非常复杂，并需要为每一个日志行服务加载大量规则。这是我们觉得采用 Golang 的原因之一。

这项新服务全天候运行在我们的生产环境中。虽然结果很不错，但是它仍然需要运行在高性能的机器上。这个 Go 服务运行在一台 8 核 CPU 和 36GB 内存的 AWS m4.2xlarge 实例上，每天解析超过数百亿的日志。

这个阶段，一切运行正常，可以将就，但这不是我们的风格，我们希望用更少的 AWS 实例来提供更多的功能，比如性能等。为实现这一目标，我们需要了解瓶颈的本质，以及如何能减少或完全消除它们。

问题分析

我们决定在服务上运行一些性能分析，并检查是什么导致 CPU 的高消耗，看看是否可以做些优化工作。

升级版本

首先，我们将 GO 升级到最新的稳定版本（软件生命周期中的关键一步）。此前，我们的版本是 1.12.4，现在用的是 1.13.8。

根据官方文档，1.13 版本在 runtime library 和一些对内存使用有很大影响的组件进行了重大改进。不管怎么说，使用最新的稳定版本很有意义，并且为我们节省了很多工作。

因此，内存消耗也从 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 文档可以参阅此处。

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

Go profiling

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

如果是这样的话，我们可以做两件事情：

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

观察一下实例类型，我们有大量的空闲内存，而 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 <HEAP.PROFILE.FILE>

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

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

list <FunctionName>

例如：

list reportRuleExecution

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

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

我们运行了一个新的性能分析会话来验证上述论点，结果证明它是正确的（我们可以看到这部分不再分配对象了）: