• 一步一步理解 Impala query profile（一）
  • 一步一步理解 Impala query profile（二）
    • 一步一步理解 Impala query profile（三）
      • 一步一步理解 Impala query profile（四）

          • 一步一步理解 Impala query profile（一）

          很多 Impala 用户不知道如何阅读 Impala query profile 来了解一个查询背后正在执行的操作，从而在此基础上对查询进行调优以充分发挥查询的性能。因此我想写一篇简单的文章来分享我的经验，并希望它可以对希望了解更多信息的人有所帮助。

          这是本系列的第 1 部分，我将介绍一些 Impala query profile 的基础知识和查看 Profile 时特别要注意的内容。

          获取 Impala query profile

          首先，获取 Impala query profile 有两种方法，最简单的方法是在 impala-shell 中运行查询后执行 “PROFILE” 语句，如下所示：

          也可以在 CDH 的 Web 页面（Cloudera Manager Web UI）上点击 CM > Impala > Queries，找到刚刚运行的查询，然后点击 Query Details：

          img

          接着向下滚动找到 “Download Profile” 按钮：

          img

          你也可以到执行查询的 Impala Daemon（impalad 节点，该节点在 Impala 集群中为 coordinator 角色）节点的 Web 界面来下载 query profile 信息：

          该 Web 界面会展示出在当前 Impala Daemon 节点执行的 SQL 列表：

          img

          然后点击对应 SQL 后的 “Details” 链接转到 “Profile” tab 页：

          img

          获取了 Profile 之后，接下来我们开始剖析 Profile。

          Profile 解析

          下面是 Query Profile 的一段文本，该段文本是 Profile 最上面的概要（Summary）部分：

          我们将其分为几个部分来介绍，这里面有一些频繁用到的重要信息：

          1、查询 ID：

          该 ID 唯一标识在 Impala 中运行过的 SQL，这对于从 Impala Daemon 日志中用 ID 查询相关的信息很有用，只需搜索此查询 ID，就可以了解 SQL 运行细节和相关的错误信息。

          2、Session 类型：

          这可以告诉我们连接来自哪里。BEESWAX 意味着查询是从 impala-shell 客户端运行的。如果从 Hue 运行，类型将是 HIVESERVER2，因为 Hue 是通过 HIVESERVER2 thrift 连接的。

          3、查询起止时间：

          这可以告诉我们查询运行了多长时间，此时间包括会话空闲时间（session idle time）。因此，如果你看到在 Hue 运行一个简单的查询用了几秒钟返回结果，是由于 Hue 会保持会话打开直到会话关闭或用户运行另一个查询，因此此处的时间可能比正常显示的时间更长。如果通过 impala-shell 运行，则开始时间和结束时间应与运行时间完全匹配，因为 impala-shell 在查询完成后会立即关闭查询处理程序。

          4、查询状态：

          这表明查询是否成功完成。OK 表示查询成功执行完成。如果有错误，通常会在此处显示，例如，被用户取消（cancelled by user）、会话超时（session timeout）、异常（Exceptions）等。

          5、Impala 版本：

          该信息显示运行查询的 Impala 版本，如果你发现它与你安装的 Impala 版本不匹配，则说明未正确安装某些部分。

          6、运行查询的用户信息：

          该信息表示运行查询的用户。

          7、查询所用的数据库：

          该信息表示查询所使用的数据库。

          8、查询语句：

          如果你帮助其他人排查问题，则需要此信息，因为需要了解查询的构造方式以及涉及的表，在许多情况下，对查询的简单重写将有助于解决问题或提高查询性能。

          9、执行查询的 impalad 节点：

          该信息显示运行查询的 Impala daemon 服务的主机，通常被称为 Coordinator，这有助于我们选择从哪个主机查找 INFO、WARNING 和 ERROR 级别的日志。

          10、查询选项：

          该信息显示当前查询使用了哪些查询选项（QUERY OPTIONS），这有助于我们判断是否在用户级别（user level）或池级别（pool level）覆盖了查询选项。一个示例是将 Impala Daemon 的内存设置为 120GB，但小查询仍然失败，并抛出 OutOfMemory 异常，通过该信息可以帮助我们验证用户是否在会话中将 MEM_LIMIT 参数设置了太小的值（可能导致 OutOfMemory 异常）。

          总结

          本系列的第 1 部分介绍了查询的摘要（Summary）部分以帮助我们了解 Query Profile 的基本信息，在本系列的下一部分，将详细介绍查询计划以及 Profile 的执行摘要（Execution Summary）部分。

          编译自：IMPALA QUERY PROFILE EXPLAINED – PART 1

          一步一步理解 Impala query profile（二）

          在上一篇文章中，我们介绍了 Impala query profie 的概要部分，在本篇文章我们介绍 Profile 的查询计划（Query Plan）和执行概要（Execution Summary）部分。

          Profile 的查询计划和执行概要如下所示：

          接下来我们来逐一提取和介绍上面 Profile 片段中的信息：

          1、表 / 列统计信息：

          前两行仅说明资源信息，它们不是很重要，也不经常使用。

          但是，下一行非常重要，因为 Impala 告诉我们是否检测到查询所涉及的表具有最新的统计信息，这一点非常关键，因为 Impala 使用表 / 列统计信息（table/column statistics information）来进行资源预估（resource estimation），并执行查询计划来确定运行查询的最佳策略，如果统计信息不是最新的，Impala 最终将使用错误的查询计划，从而影响整体查询性能。

          在上面的示例中，我们可以看到 default.sample_07 表缺少统计信息，Impala 在查询计划中给出了警告来提示用户需要在该表上执行 COMPUTE STATS 来消除这个警告信息。关于表统计的更多信息，请参阅 Table and Column Statistics。

          2、查询计划详情：

          查询计划（Query plan）是 Impala profile 中最重要的部分之一，我们需要知道如何读取它，因为它告诉我们如何扫描（scan）表、交换数据（data exchange）和连接（join）以获得最终结果。

          如果查询很复杂，查询计划也可能会变得非常复杂，让我们从这个简单的查询开始，以了解它的基本信息。需要记住的一件事是，我们需要反向阅读这些信息，来理解 Impala 的执行计划。

          2.1、HDFS 扫描：

          第一步通常从 HDFS 扫描（HDFS Scan）开始：

          从上面的片段中我们可以获取下面这些有用的信息：

          2.2、Aggregation 操作：

          HDFS 扫描完成后，Impala 需要做聚合（Aggregation），因为我们的 SQL 语句中使用了 COUNT(*)：

          这里没有太多要解释的，这个步骤执行的是聚合操作。

          2.3、Fragment 信息：

          00:SCAN HDFS 和 01:AGGREGATE 片段上的 SCAN 和 Aggregation 操作都属于片段（FRAGMENT）F00，它在一个主机和一个实例上运行。F00 这个片段 ID 可以用来在 Profile 的后面部分找到实际的片段统计信息，它可以告诉我们这个片段在运行时如何运行的详细信息。我们还将在本系列的后面部分讨论这个问题。

          2.4、Exchange 操作：

          在每个工作节点（worker node）上完成聚合之后，需要将每个工作节点的结果交换给协调器节点（coordinator），这个步骤主要做的是这个操作，之后，协调器节点需要对这些结果进行最后的汇总 / 合并（aggregation/merger）：

          以上两个操作都属于同一个片段 01，该片段又可以用来引用 Profile 数据的其余部分，以获取关于查询的更详细的统计信息：

          现在，让我们来看看 Profile 的执行概要部分：

          在这里你可以找到这些有用的信息：

          如果查询中有连接（join）操作，Profile 的总结信息中还将向我们展示连接操作中使用了什么连接策略：广播连接（Broadcast Join）还是随机连接（Shuffle Join）。在本系列的最后一部分，我将用一个更复杂的 query profile 让大家了解更多信息。

          编译自：[https://www.ericlin.me/2019/04/impala-query-profile-explained-part-2/)

          一步一步理解 Impala query profile（三）

          在本博客系列的第 3 部分，我将仍然关注查询计划（Query Plan）和执行摘要（Execution Summary），但是将使用真实数据（Kaggle’s Flights Delay database），来执行一个更复杂的查询。

          测试用的数据库有三张表：

          查询语句如下：

          该查询将连接航班（flights）表和机场（airports）表生成一个报表，该报表可以告诉我们 2015 年期间每个航空公司的航班取消率，报表结果如下：

          查询计划和执行概要的详细信息如下：

          这次我们先跳到执行摘要部分，因为它更容易看到，而且通常是我在帮助 CDH 用户排查 Impala 查询相关问题时首先要检查的部分。从上面的执行摘要信息中，我们可以看到在查询执行期间发生了什么：

          1、从 HDFS 扫描上 flight_delay.flights 表的数据平均花费 2 秒时间（2s052ms）

          2、Impala 估算到 flight_delay.flights 表的数据为 582 万行，和实际返回的行数相同，这表明表统计信息是最新的

          3、Impala 估算到扫描 flight_delay.flights 表需要 176MB 内存，但是实际上只用到 40MB，这符合预期，因为估计内存不可能和实际使用的内存相同，我们的想法是尽可能地接近

          4、由于数据量大，Impala 对文件进行了分割，并在 4 台主机上执行扫描操作，从而分散负载

          5、当 flight_delay.flights 表扫描完成之后，Impala 开始扫描另一张表 flight_delay.airlines。该表的估计行数和实际返回行数相同，说明表统计信息也是最新的。由于该表只有 14 行，所以只需要 97 毫秒就可以扫描它

          6、由于表很小，只有 14 行，Impala 只使用 1 台主机来执行扫描操作

          7、下一步是广播（broadcast）较小的表 flight_delay 到执行查询的所有节点 (在我的示例中是 4 台主机 (广播))

          8、广播完成之后，Impala 对 flight_delay.airlines 和 flight_delay.flights 表执行 Hash Join 操作，花费 177ms、10MB 内存

          9、由于我们调用了 COUNT 聚合函数，Impala 被要求执行聚合操作，该操作在 4 台主机上运行，花费 280ms、10MB 内存并返回 55 行

          10、因为上面的步骤是在 4 个工作节点上执行的，所以 Impala 需要合并（merge）来自它们的结果，这是通过内部交换数据（exchanging the data internally）实现的，然后对中间结果（intermediate result）执行最后的聚合

          11、因为我们的查询中有 ORDER BY，因此在第 10 步完成后执行排序操作

          你可以将 Summary 部分中的操作编号 (比如 00、01、02 等) 与查询计划（Query Plan）部分中的编号相匹配，查询计划部分将告诉你相关操作的更多细节。我在第 2 部分中提到的细节，如果你需要参考，请参考前面的文章。

          现在，让我们看看 Profile 的 Planner Timeline 和 Query Timeline 部分：

          每行的信息都很容易理解，我们可以看到运行查询计划花费了 15ms，从 17ms 开始向 admission 提交查询计划，从 28ms 开始在工作节点上执行查询计划，在 4.28s 时准备好最后一行数据并在 4.31s 时第一行数据被客户端获取（fetch）。这使你可以很清楚地了解每个阶段所花的时间，如果任何阶段都很慢，那将是非常明显的，然后我们可以开始进一步深入研究，以了解可能发生了什么。

          因为我的查询很快，所以在这里看到它不是很有趣，让我们看看另一个真实的生产 Impala query profile：

          这取自一个真实案例，Impala 查询运行了很长时间，客户想要找出原因。从查询时间轴（Query Timeline）中，我们可以清楚地看到，从开始执行（一共两个执行后端（All 2 execution backends））到数据可用（可用行（Rows available））几乎花费了 6 分钟（5m51s）。这 6 分钟的执行可能是正常的，就像有很多大数据集的连接（join）一样，查询运行几分钟是很常见的。

          但是，我们可以注意到 Impala 花了 30 分钟将数据传递回客户端，因为第一行在第 6 分钟获取，而最后一行在第 36 分钟获取。因此，从这里，我们可以怀疑 Impala 协调器（coordinator）和客户端之间可能存在一些网络问题（当从客户端，如 impala-shell 或 Hue，到 Impala 协调器主机获取数据时）。另一种可能性是客户端可能在获取结果时也在执行其他操作，如在屏幕上打印，因为返回的数据可能很大，该操作可能很耗时。

          因此，这部分概要信息可以指引我们找到寻找瓶颈的正确方向。

          这是 Impala profile 系列的第 3 部分，详细介绍了如何将查询计划部分中显示的操作号与概要文件部分的最后部分联系起来，概要文件部分显示了每个操作的详细度量，包括平均操作和每个主机上的单独操作。

          编译自：IMPALA QUERY PROFILE EXPLAINED – PART 3

          一步一步理解 Impala query profile（四）

          在本系列的第三部分，我使用了一个示例来详细地介绍 Impala query profile。在这一部分中，我将使用一个真实生产系统的 Impala Profile 文件，解释我在遇到问题时阅读 Profile 文件的步骤，并逐渐找到引起问题的真正原因。如果你错过了我的文章的前 3 个部分，你可以点击以下链接阅读一下：

          好了，我们开始吧。由于 Profile 文件本身相当大，因为它涉及到多个 Impalad 进程，所以如果我将完整的内容在页面上显示出来，页面就会很难看。因此，请从这个链接下载，并在你本地电脑或浏览器上来查看这个文件。

          这个查询的问题是，不知道出于什么原因，之前执行相同的查询几分钟内就可以完成，但现在要花 1 个多小时才能完成。这个 Profile 文件只是其中的一个例子，实际上，当时在这个集群中运行的所有查询都有相同的问题。所以请花点时间看一下这个 Profile，看看你是否能获取什么有用的信息，并对问题产生的场景有一个大致的了解。

          现在，让我们一起来看看排查该问题的步骤。

          1、由于用户反馈查询时间比正常情况下长，我想知道的第一件事是到底花费了多长时间？所以首先，我在 Profile 的开头查看查询开始和结束的时间：

          我发现，现在完成查询需要 1 小时 14 分钟，这与用户的反馈是相符的。

          2、由于用户取消，查询异常失败：

          用户已经没有耐心了，不得不取消查询，因为它运行了太长时间，这里没什么好担心的。

          3、接下来，我检查了查询的复杂程度：

          为了可读性，我重新格式化了。可以看到这个查询非常简单，是一个带有子查询条件的直接 SELECT 语句。

          4、接下来我看到的是协调（Coordinator）节点的主机名称：

          如果我不能从这个 Profile 文件得出任何结论，那么下一步应该是获取这个主机上的 impalad 日志。但是现在，我只能继续，因为我还没有日志。

          5、正如我在上一篇文章中提到的，Profile 文件接下来的部分是查询计划（Query Plan），通常我会先跳过这部分，然后跳到概要（Summary）部分，以了解每个操作花了多长时间，并查看是否有什么明显的信息可能会让我有所发现：

          我在这里找到了几个关键的信息：

          很快，我就注意到扫描 HDFS（SCAN HDFS）操作的 “Avg Time” 和 “Max Time” 的差别很大，平均时间为 3 分 7 秒，但是 29 个主机中的一个主机的最长时间为 56 分 13 秒。继续往下读，我还注意到第二次扫描 HDFS 操作也有相同的问题，分别是 44 秒和 13 分 18 秒。

          因此，我的下一个想法是确定哪些主机的执行速度比其他主机慢，以及是否来自同一主机。为此，我使用字符串 “id=0” 来搜索 Profile 文件，“0” 是 Summary 部分 “00:SCAN HDFS” 中每一行开头的操作编号。

          我从文件开头搜索到了 “id=0” 的第一部分：

          我发现 TotalTime 为 3.1 分钟，与 Summary 部分中看到的 3.7 分钟相匹配，因此这是 Averaged Fragment。 为了确认，我向后滚动并看到以下内容：

          继续搜索文件，我来到下面部分 (第二个实例 “id=0”)：

          这个告诉我花了 2.1 分钟，比平均 3.1 分钟要快，然后我回滚到前面以确认主机：

          现在，可以看到我找到的三个主要信息：

          接下来我使用 grep 过滤出我想要的内容。由于 Profile 文件已缩进，因此我使用 egrep 执行了下面的操作：

          结果如下：

          我省略了其他不相关的信息，只留下了我感兴趣的信息。现在我可以清楚地看到哪个服务器节点是瓶颈，它是主机 xxxxx-xxx-cdh-cdn015.xxx.XXXXXX.com，用时 56.2 分钟，而其他所有主机用时约 40 秒至 2 分钟。

          现在，我记得另一个 HDFS SCAN 具有相同的问题，即操作 01（01：SCAN HDFS），所以我执行了相同的 egrep 命令（请记住，不同操作的缩进可能不同，所以我需要在 Profile 文件中搜索到那个操作，然后将其之前的空格完全复制粘贴，以获得我想要的结果）：

          结果再次证实了同样的结论：

          很明显，同样的主机 xxxxx-xxx-cdh-cdn015.xxx.XXXXXX.com 也有同样的问题，它的运行速度比其他主机慢得多，13.3 分钟比 28.16 秒。

          然后我得出结论，该服务器出现了一些问题，需要修复。

          为了确认我经过排查得出的结论，我要求用户停掉这个主机上的 Impalad 进程并再次测试他们的查询，他们确认问题已经解决，后来他们反馈说他们发现那台服务器硬件有问题，已经对其停机维护了。

          编译自：IMPALA QUERY PROFILE EXPLAINED – PART 4