亚马逊AWS官方博客

利用 Amazon CodeGuru Profiler 调查性能问题

Original URL：https://aws.amazon.com/blogs/machine-learning/investigating-performance-issues-with-amazon-codeguru-profiler/

Amazon CodeGuru（预览版）能够分析应用程序的性能特征，并自动提供性能改善建议。Amazon CodeGuru Profiler 提供交互式可视化图形界面，以显示应用程序的运行时间耗费在什么地方。这些火焰图是功能强大的工具，可帮助您排查哪些代码方法造成延迟或使用过多 CPU 资源。本博文将说明如何理解火焰图以及在下列情况下如何使用火焰图：

  1. 分析应用程序的性能概况，并了解它与您知道的代码之间的关系
  2. 发现性能概况中的明显异常
  3. 调查延迟问题
  4. 寻找 CPU 利用率优化方法和降低成本的机会

分析应用程序

打开分析组

在开始分析应用程序之前，演示应用程序让您无需进行任何设置即可快速开始使用 CodeGuru Profiler。只要具有 AWS 账户，就能使用演示应用程序。要访问演示应用程序，请在 Amazon CodeGuru 控制台中依次选择 Profiler、分析组。本博文使用 DemoProfilingGroup-WithoutIssues。

如果您在分析组页面中选择该组，则会看到火焰图。以下屏幕截图显示了此演示应用程序的火焰图。

什么是火焰图？

火焰图显示分层方法，就像您在堆栈跟踪中看到的一样。CodeGuru Profiler 在指定时段内（例如 5 分钟）定期从应用程序内运行的代码中拍摄堆栈跟踪的快照，并将这些快照显示在一个可视化图形中。水平条称为火焰，表示每个方法。CodeGuru Profiler 在堆栈跟踪中发现某个方法的频率越高，对应的火焰在图形中就越宽。在样本足够多的情况下，您可以看到应用程序在每个方法中耗费的时间百分比。

火焰图包含两个时间概念：

  • CPU 活跃时间 – 是指处理器在方法中忙碌工作的时间。要查看该时间，请使用“CPU”视图模式。
  • 挂钟时间 – 也将进程处于等待状态的时间考虑在内。要查看该时间，请使用“延迟”视图模式。

演示应用程序做了什么？

要理解可视化图形显示的内容，您应知道被分析的实际应用程序在做什么。

此演示应用程序运行了两个独立线程。一个线程供任务发布者使用，以在 Amazon SQS 队列内添加任务。另一个线程用于运行图像处理器，以执行以下操作：

  1. 从队列中获取任务
  2. 将图像下载到 Amazon S3 存储桶
  3. 将图像复制到本地磁盘
  4. 转换图像，然后将图像上传到 S3 存储桶
  5. 删除本地磁盘中的图像
  6. 从队列中删除任务

下图展示了此架构。

了解概览的主要部分

打开分析组的概况后，默认可视化类型是“CPU 概览”视图模式。如果将鼠标移到任一火焰上，它会显示函数的完整名称和附加信息。例如，在以下屏幕截图中，可以看到此时段内观察到的 CPU 活跃时间有 51.65% 耗费在 PNGImageWriter.encodePass 函数上。

特定火焰下方的火焰表示调用了该特定火焰的函数，而特定火焰上方的火焰表示该特定火焰调用的函数。以下屏幕截图说明了不同函数。

从下往上，您可以看到线程如何启动，并且可以看到 ImageProcessor 和 TaskPublisher 类正在使用中。位于 ImageProcessor.run 函数正上方的是它调用的函数。下表总结了上一个屏幕截图中带有编号的每项操作及其用途。

 

操作 用途 图形中的火焰名称
1 从 SQS 队列中获取任务 AmazonSQSClient.receiveMessage
2 从 S3 存储桶中获取图像数据 AmazonS3Client.getObject
3 将图像数据复制到文件 IOUtils.copy
4 转换图像数据，然后上传到 S3 存储桶

ImageProcessor$BrightenImageProcessor.brightenAndUpload

ImageProcessor$BWImageProcessor.monochromeAndUpload
5 删除文件 不适用（此操作的速度非常快，未能采样）
6 删除 SQS 队列中的消息 AmazonSQSClient.deleteMessage

使用此可视化图形时，务必要注意以下几点：

  • 从同一上下文中调用的不同函数按字母顺序而不是按执行顺序水平显示。例如，在上一个屏幕截图中，可以看到操作 6 出现在操作 3 左侧。
  • 堆栈跟踪中的所有步骤都会显示在可视化图形中。某些步骤可能会造成误解。如果上方只有一个相同宽度的函数，这表示它只是中间函数，并且您无需担心每个火焰。例如，在 ImageProcessor 类调用私有类 BrightenImageProcessor.brightenAndUpload 时，Java 会创建一个 BrightenImageProcessor.access$300 方法，而且该方法显示在图形中。

大型的平坦函数表示耗费大量 CPU 资源的函数。您应找出这些函数，并确保应用程序支持耗费相应的时间来执行这些函数。在本例中，对于作为图像处理工具的应用程序来说，较大的deflateBytes是可以理解的，在我们编写PNG图像时会调用它。

通过查看此视图，我能了解到什么信息？

大部分 CPU 时间都用在 ImageProcessor 中，而且，在此函数中，大部分时间用来执行对图像进行转换的操作 4。PNRImageWriter 通过 Deflater 执行压缩，占用了大约 50% 的 CPU 活跃时间。

该进程多次调用 AWS 服务（Amazon SQS 和 Amazon S3）。Amazon S3 调用只占用极少的 CPU 时间（例如，在上一个屏幕截图中，ImageProcessor 中的步骤 2 几乎不可见）。但是，它可能仍然影响到延迟。

CodeGuru Profiler 如何显示异常情况

以下使用案例说明 CodeGuru Profiler 如何显示异常情况。

异常情况简介

本使用案例是真实错误的简化版本。假设您添加以下代码以跟踪已处理的消息，并且对每条 SQS 消息调用该代码：

   static final List<Message> existingMessagesList = new ArrayList<Message>();
    
   void trackMessages(Message message) {
        if (!existingMessagesList.contains(message)) {
            existingMessagesList.add(message);
        }
    }

遗憾的是，虽然您预计消息可能只有少数几条，但每个 Message 对象都不同，因此，随着应用程序的运行，消息列表不断增长。在这种情况下，并不适合从长列表中搜索消息。

发现概况中的异常

应用程序运行的时间越长，它使用的 CPU 时间也越长。在生产环境下运行应用程序之前，有时很难发现这种问题，因为要运行很长时间才会出现这种问题。运行一段时间后，概况将如以下屏幕截图所示。

现在出现了一个占据大部分宽度的大型 trackMessages 火焰。它指示此函数使用了多少 CPU 时间。

其他火焰全都变小了。您仍要耗费同样多的 CPU 时间来执行这些函数，但它们现在变小了，原因是 trackMessages 使用了比以前更多的 CPU 时间。请记住，所有函数的宽度都是相对于其他函数的宽度显示的。

通过查看在 ArrayList.indexOf 上耗费的所有时间，可以知道您正在长列表中进行搜索，并且您应使用哈希映射或确保减少该列表中包含的项。

降低延迟

如果您有基于服务的应用程序，则可能会想通过执行以下操作之一来降低某项服务的延迟：

  • 放大您想改进的函数。如果应用程序不受 CPU 限制，您可能不会关注此可视化图形的其他部分 – 它们可能是您用于其他服务调用或独立线程中的函数，而且不会影响到您关注的部分。
  • 切换到“延迟”视图。如前所述，默认 CPU 视图仅显示 CPU 活跃时间，不显示挂钟时间。相比之下，“延迟”视图同时显示处于活跃线程状态和等待线程状态的样本，从而告知您实际时间耗费在什么地方。在“延迟”视图中，不同颜色显示时间在不同线程状态下的具体分布，因此，您可以知道哪个部分正在积极处理、受阻或正在等待。

“CPU”视图与“延迟”视图对比

以下屏幕截图放大了“CPU”视图中的 ImageProcessor.run 函数。

在“CPU”视图中，可以看到用于从 Amazon S3 中获取对象的调用可忽略不计（仅占总时间的 0.40%）。

以下屏幕截图放大了“延迟”视图中的 ImageProcessor.run 函数。

在“延迟”视图中，可以看到该函数占用了总时间的 5.31%，原因是它需要时间来等待响应。

使用案例：外部调用的速度异常缓慢

在本使用案例中，从 Amazon S3 中获取对象的函数的调用出现了问题。例如，您在错误的区域进行调用，而该调用现在的速度变慢了许多。在本使用案例中，“CPU”视图没有变化，但“延迟”视图现在如以下屏幕截图所示。

对 AmazonS3Client.getObject 的调用占用了总时间的 36% 而不是 5%，而且是 ImageProcess.run 的最大部分。如果您很熟悉平常的概况视图，则立即就能发现此问题。如果不熟悉，则可以在此视图中看到进程的哪个部分占用了较长时间及具有改进余地。

CPU 利用率优化方法和降低成本的机会

以下使用案例说明了如何优化 CPU 利用率并找到降低成本的机会。

利用“热点”可视化图形找到易于改进之处

对于此使用案例，本博文使用另一个演示应用程序：DemoProfilingGroup-WithIssues 分析组。它同样是图像处理应用程序，但存在一些效率低下的地方。我们的目标是找到这些效率最低的地方。

您可以使用“热点”可视化图形，而不是默认的“概览”可视化图形。它将整个图形中 CPU 利用率最高的函数显示在顶部，这在您想找出总共导致 CPU 利用率很高的底层函数时很有用。

例如，对于本使用案例，“概览”可视化图形含有多个以 ZipFile.entry 结束的堆栈。这些堆栈单独来看并不显眼，原因是它们各自占用了总时间的 4% 左右。但是，在“热点”视图中，可以看到它们总共达到总时间的 20% 左右。请参见以下屏幕截图。

从此可视化图形中了解到的信息

您仍将看到在压缩和写入 PNG 图像的堆栈，也就是前面看到的操作 4。如果没有效率低下问题，则它应占用 CPU 活跃时间的 50% 左右。

您可以轻松识别的另外两个大型堆栈是 A 和 B。如果将光标悬停在火焰上，它会以黄色突出显示，因此，在您查看调用方时，可以看到 A 主要来自日志记录，而 B 主要与构建 AmazonSQSClient 对象有关。

检查函数

AWS 客户端通常设计为可重用，因此，耗费大量时间来构建这些客户端并非最佳做法。要更深入地调查此问题，您可以右键单击 AmazonSQSClient.<init> 火焰并选择检查。 以下屏幕截图显示了第三个可视化图形，它由“概览”和“热点”混合而成，但聚焦于一个函数。火焰上方是它调用的其他函数，而下方是已调用它的不同函数。

从此可视化图形中了解到的信息

在所有应用程序代码中，36% 的 CPU 活跃时间耗费在构建 AmazonSQSClient 对象上。看起来您每次需要使用客户端时都会创建客户端，而不是创建一个静态实例，然后进行重用。

在可视化图形的顶部部分，可以看到它的时间主要耗费在加载类上。

在底部部分，可以看到有一个地方调用了此构造函数。您的代码的第一个函数可能是您可以修复这个问题的地方。

要修复此代码，请找到 sqsClient 函数。请参阅以下代码：

public class Main {
    static AmazonSQS sqsClient() {
       return AmazonSQSClientBuilder.standard().build();
    }
}

将上面的代码改为以下代码：

public class Main {
    static AmazonSQS sharedSqsClient = 
AmazonSQSClientBuilder.standard().build();
    static AmazonSQS sqsClient() {
        return sharedSqsClient;
    }
}

这处微小的代码改动可以节省多达 36% 的 CPU 使用时间。

建议

应用程序存在许多常见的效率问题。为了让每位开发人员无需执行相同的调查工作，CodeGuru Profiler 努力做到自动检测效率问题。

在执行本博文详细介绍的调查过程之前，您应查看 CodeGuru Profiler 是否为您提供了建议。在 CodeGuru 控制台上，在分析组下选择您的分析组。如果提供了建议，则选择建议。

在以下屏幕截图中，可以看到演示概况含有四条建议。

您刚才解决的问题是 CodeGuru Profiler 检测到的问题之一。以下屏幕截图显示了针对此问题的第一条建议。

该建议说明了出现问题的地方和解决问题的方法。在本使用案例中，第一条建议恰好对应您已找出并解决的问题。在开始调查之前，请务必查看建议报告，这可能会让您节省一些时间。

应用程序是否处于空闲状态？

如果您查看自己不太了解的应用程序的分析组，并且寻找降低成本的机会，请记住一点：应用程序可能大部分时间都处于空闲状态。（例如，基于事务且接收的请求非常少的应用程序大部分时间都耗费在等待调用上。） 在本使用案例中，处理样本的代码非常少，因此火焰图可能不准确，而且降低成本的机会微乎其微。您应查看Amazon EC2的队列规模是否适合低流量。您或许可以通过释放一些Amazon EC2 实例来节约更多成本。

您可以通过以下迹象快速找出处于空闲状态的应用程序：

  • 没有非常小的火焰。由于只有少数几个样本，因此与一个样本对应的宽度大于正常值。
  • 即使是大型火焰，其 RUNNABLE 或 NATIVE 时间量也很小。
  • 表示 CodeGuru Profiler 开销的火焰 (ProfilingCommand.run) 大于普通火焰，原因是它几乎是此应用程序中处理的唯一事务。

结论

本博文讨论了一些主要使用案例，在其中 CodeGuru Profiler 可以帮助您找到性能问题和降低成本的机会。每个使用案例都说明了如何使用不同的可视化图形来改善 CPU 利用率或降低延迟。

要更深入研究本博文中的演示应用程序概况，请访问 Amazon CodeGuru 控制台，然后自己查看概况，或者新建一个分析组并引入您自己的应用程序。

关于作者

Pierre Marieu 是一位软件开发工程师，在位于伦敦的 Amazon CodeGuru Profiler 团队工作。他喜欢制作工具，帮助其他软件工程师解决日常生活问题。他以前在 Amadeus IT 工作，为旅游行业开发软件。