教程:优化 Go 应用

在本教程中,您将部署一个配置为收集性能剖析文件数据的 Go 应用,而该应用的效率已被故意降低。您将使用 Profiler 界面查看性能剖析文件数据并确定可能的优化。然后,您可以修改并部署应用,并评估修改的效果。

准备工作

  1. 登录您的 Google 帐号。

    如果您还没有 Google 帐号,请注册新帐号

  2. 在 Google Cloud Console 的项目选择器页面上,选择或创建一个 Google Cloud 项目。

    转到项目选择器页面

  3. 如需为您的项目启用 Cloud Profiler API,请在 Google Cloud Console 导航窗格中点击 Profiler,或使用下面的按钮:

    转到 Profiler

  4. 如需打开 Cloud Shell,请点击 Google Cloud Console 工具栏中的激活 Cloud Shell

    激活 Cloud Shell。

    片刻之后,Google Cloud Console 内会打开一个 Cloud Shell 会话:

    Cloud Shell 会话。

示例应用

主要目标是最大限度地提高服务器可处理的每秒查询次数。次要目标是消除不必要的内存分配,从而减少内存用量。

使用 gRPC 框架的服务器可以接收一个字词或短语,然后返回该字词或短语在莎士比亚作品中出现的次数。

服务器每秒可处理的平均查询次数取决于服务器的负载测试。对于每轮测试,系统都会调用一个客户端模拟器,并指示其发出 20 个有序查询。在一轮完成时,将显示客户端模拟器发送的查询数量、所用时间以及每秒平均查询次数。

服务器代码的效率已被故意降低。

运行示例应用

下载并运行示例应用:

  1. 在 Cloud Shell 中,运行以下命令:

    git clone https://github.com/GoogleCloudPlatform/golang-samples.git
    cd golang-samples/profiler/shakesapp
    
  2. 运行应用(版本设置为 1 且轮数设置为 15):

    go run . -version 1 -num_rounds 15
    

    一两分钟后,系统会显示性能剖析文件数据。性能剖析文件数据类似于以下示例:

    CPU 使用时间的初始火焰图。

    在屏幕截图中,请注意性能剖析文件类型 (Profile type) 设置为 CPU time。这表示火焰图中显示 CPU 使用情况数据。

    Cloud Shell 中输出的示例如下所示:

    $ go run . -version 1 -num_rounds 15
    2020/08/27 17:27:34 Simulating client requests, round 1
    2020/08/27 17:27:34 Stackdriver Profiler Go Agent version: 20200618
    2020/08/27 17:27:34 profiler has started
    2020/08/27 17:27:34 creating a new profile via profiler service
    2020/08/27 17:27:51 Simulated 20 requests in 17.3s, rate of 1.156069 reqs / sec
    2020/08/27 17:27:51 Simulating client requests, round 2
    2020/08/27 17:28:10 Simulated 20 requests in 19.02s, rate of 1.051525 reqs / sec
    2020/08/27 17:28:10 Simulating client requests, round 3
    2020/08/27 17:28:29 Simulated 20 requests in 18.71s, rate of 1.068947 reqs / sec
    ...
    2020/08/27 17:44:32 Simulating client requests, round 14
    2020/08/27 17:46:04 Simulated 20 requests in 1m32.23s, rate of 0.216849 reqs / sec
    2020/08/27 17:46:04 Simulating client requests, round 15
    2020/08/27 17:47:52 Simulated 20 requests in 1m48.03s, rate of 0.185134 reqs / sec
    

    Cloud Shell 输出会显示每次迭代的所用时间以及平均请求率。应用启动时,条目“在 17.3 秒内模拟 20 个请求,速率为每秒 1.156069 个请求”表明服务器每秒执行大约 1 个请求。完成最后一轮之后,条目“在 1 分 48.03 秒内模拟 20 个请求,速率为每秒 0.185134 个请求”表明服务器每 5 秒执行大约 1 个请求。

使用 CPU 时间性能剖析文件尽可能提高每秒查询次数

最大限度地提高每秒查询次数的一种方法是识别 CPU 密集型方法并优化其实现。在本部分中,您将使用 CPU 时间性能剖析文件来识别服务器中的 CPU 密集型方法。

识别 CPU 使用时间

火焰图的根帧列出了应用在 10 秒的收集间隔内使用的总计 CPU 时间:

火焰图根帧的展开视图。

在此示例中,服务使用了 2.37 s。当系统在单个核心上运行时,2.37 秒的 CPU 使用时间相当于该核心的利用率为 23.7%。如需了解详情,请参阅可用的性能剖析类型

修改应用

评估更改

如需评估更改,请执行以下操作:

  1. 运行应用(将应用版本设置为 2):

    go run . -version 2 -num_rounds 40
    

    后面的部分显示,与未经修改的应用相比,使用优化后执行一轮所需的时间大大减少。为了确保应用的执行时间足够长以便收集和上传性能剖析文件,增加了轮数。

  2. 等待应用完成,然后查看此版本应用的性能剖析文件数据:

    • 点击立即以加载最新的性能剖析文件数据。如需了解详情,请参阅时间范围
    • 版本菜单中,选择 2

如果是一个示例,火焰图如下所示:

显示版本 2 的 CPU 使用时间的火焰图。

在上图中,根帧显示了 7.8 s 的值。由于更改了字符串匹配函数,应用使用的 CPU 时间从 2.37 秒增加到 7.8 秒,也即应用对 CPU 核心的利用率从 23.7% 变为 78%。

帧宽度是对 CPU 使用时间的成比例测量。在此示例中,GetMatchCount 帧的宽度表示函数使用了应用的所有 CPU 使用时间的约 49%。在原始火焰图中,此帧的宽度大约为图表宽度的 72%。如需查看确切的 CPU 使用时间,您可以使用帧提示,也可以使用聚焦函数列表

显示版本 2 的 CPU 使用时间的聚焦函数列表。

Cloud Shell 中的输出显示修改后的版本每秒完成大约 5.8 个请求:

$ go run . -version 2 -num_rounds 40
2020/08/27 18:21:40 Simulating client requests, round 1
2020/08/27 18:21:40 Stackdriver Profiler Go Agent version: 20200618
2020/08/27 18:21:40 profiler has started
2020/08/27 18:21:40 creating a new profile via profiler service
2020/08/27 18:21:44 Simulated 20 requests in 3.67s, rate of 5.449591 reqs / sec
2020/08/27 18:21:44 Simulating client requests, round 2
2020/08/27 18:21:47 Simulated 20 requests in 3.72s, rate of 5.376344 reqs / sec
2020/08/27 18:21:47 Simulating client requests, round 3
2020/08/27 18:21:51 Simulated 20 requests in 3.58s, rate of 5.586592 reqs / sec
...
2020/08/27 18:23:51 Simulating client requests, round 39
2020/08/27 18:23:54 Simulated 20 requests in 3.46s, rate of 5.780347 reqs / sec
2020/08/27 18:23:54 Simulating client requests, round 40
2020/08/27 18:23:58 Simulated 20 requests in 3.4s, rate of 5.882353 reqs / sec

对应用的微小更改有两个不同的效果:

  • 每秒请求数从每秒 1 个增加到每秒 5.8 个。

  • 每个请求的 CPU 时间从 23.7% 减少到 13.4%(计算方法是将 CPU 利用率除以每秒请求数)。

    请注意,虽然 CPU 使用时间从 2.37 秒(相当于单个 CPU 核心 23.7% 的利用率)增加到 7.8 秒(相当于单个 CPU 核心 78% 的利用率),但每个请求的 CPU 时间减少了。

使用分配的堆性能剖析文件提高资源使用率

本部分介绍如何使用堆和分配的堆性能剖析文件来识别应用中的分配密集型方法:

  • 堆性能剖析文件显示收集性能剖析文件时程序的堆中分配的内存量。

  • 分配的堆性能剖析文件显示收集性能剖析文件的时间间隔内程序的堆中分配的总内存量。通过将这些值除以 10 秒(性能剖析文件收集间隔),可以将这些值转换为分配速率。

启用堆性能剖析文件收集

  1. 运行应用(应用版本设置为 3 并启用堆和分配的堆性能剖析文件收集)。

    go run . -version 3 -num_rounds 40 -heap -heap_alloc
    
  2. 等待应用完成,然后查看此版本应用的性能剖析文件数据:

    • 点击立即以加载最新的性能剖析文件数据。
    • 版本菜单中,选择 3
    • Profiler type 菜单中,选择分配的堆

    如果是一个示例,火焰图如下所示:

    版本 3 的分配的堆性能剖析文件的火焰图。

确定堆分配速率

根帧显示了收集性能剖析文件的 10 秒内分配的堆总量(对所有性能剖析文件计算出的平均值)。在此示例中,根帧显示平均分配了 1.535 GiB 的内存。

修改应用

评估更改

如需评估更改,请执行以下操作:

  1. 运行应用(将应用版本设置为 4):

    go run . -version 4 -num_rounds 60 -heap -heap_alloc
    
  2. 等待应用完成,然后查看此版本应用的性能剖析文件数据:

    • 点击立即以加载最新的性能剖析文件数据。
    • 版本菜单中,选择 4
    • Profiler type 菜单中,选择分配的堆
  3. 要量化更改 readFiles 对堆分配速率的影响,请比较版本 4 和版本 3 收集的分配的堆性能剖析文件:

    版本 4 和版本 3 分配的堆性能剖析文件的比较。

    根帧的提示表明,与版本 3 相比,版本 4 中性能剖析文件收集期间的平均分配内存量减少了 1.301 GiB。readFiles.func1 的提示显示减少了 1.045 GiB:

    分配的堆性能剖析文件类型的 readfiles 提示的比较。

  4. 要量化对垃圾回收的影响,请配置 CPU 时间性能剖析文件的比较。以下屏幕截图中应用了一个过滤条件以显示 Go 垃圾回收进程 runtime.gcBgMarkWorker.* 的堆栈。屏幕截图显示垃圾回收的 CPU 用量从 16.8% 减少到 4.97%。

    v4 和 v3 后台垃圾回收进程的 CPU 使用时间的比较。

  5. 要确定应用每秒处理的请求数是否发生了变化,请查看 Cloud Shell 中的输出。在此示例中,版本 4 每秒最多完成 15 个请求,大大高于版本 3 的每秒 5.8 个请求。

    $ go run . -version 4 -num_rounds 60 -heap -heap_alloc
    2020/08/27 21:51:42 Simulating client requests, round 1
    2020/08/27 21:51:42 Stackdriver Profiler Go Agent version: 20200618
    2020/08/27 21:51:42 profiler has started
    2020/08/27 21:51:42 creating a new profile via profiler service
    2020/08/27 21:51:44 Simulated 20 requests in 1.47s, rate of 13.605442 reqs / sec
    2020/08/27 21:51:44 Simulating client requests, round 2
    2020/08/27 21:51:45 Simulated 20 requests in 1.3s, rate of 15.384615 reqs / sec
    2020/08/27 21:51:45 Simulating client requests, round 3
    2020/08/27 21:51:46 Simulated 20 requests in 1.31s, rate of 15.267176 reqs / sec
    ...
    

    应用每秒处理的查询次数增加可能会导致用于垃圾回收的时间减少。

  • 您可以通过查看堆性能剖析文件更充分地了解修改对 readFiles 的影响。版本 4 和版本 3 堆性能剖析文件的比较显示,堆用量从 70.95 MiB 减少到了 18.47 MiB:

    版本 4 和版本 3 的堆用量比较。

总结

在本快速入门中,CPU 时间和分配的堆性能剖析文件用于识别应用的潜在优化。目标是尽可能增加每秒请求数,并消除不必要的分配。

  • 通过使用 CPU 时间性能剖析文件,识别出了 CPU 密集型函数。应用简单的更改后,服务器的请求率从每秒大约 1 次提高到每秒 5.8 次。

  • 通过使用分配的堆性能剖析文件,识别出 shakesapp/server.go 函数 readFiles 具有较高的分配速率。优化 readFiles 后,服务器的请求率增加到每秒 15 个请求,并且 10 秒性能剖析文件收集期间分配的平均内存量减少了 1.301 GiB。

后续步骤

如需了解如何运行 Cloud Profiler 代理,请参阅: