Doris 的Explain 和 Profile

什么是 explain？

执行计划是对一条 SQL 具体的执行方式和执行过程的描述。例如，对于一个涉及两表连接的 SQL，执行计划会展示这两张表的访问方式信息、连接方式信息，以及各个操作之间的顺序。

在 Doris 系统中提供了 Explain 工具，它可以展示一个 SQL 的具体执行计划的详细信息。通过对 Explain 输出的计划进行分析，可以帮助使用者定位计划层面的瓶颈，从而针对不同的情况进行执行计划层面的调优。

Doris 提供了多种不同粒度的 Explain 工具，如 Explain Verbose、Explain All Plan、Explain Memo Plan、Explain Shape Plan，分别用于展示最终物理计划、各阶段逻辑计划、基于成本优化过程的计划、计划形态等。

获取 Explain 输出后，业务人员或者 DBA 就可以分析当前计划的性能瓶颈。例如，通过分析执行计划发现 Filter 没有下推到基表，导致没有提前过滤数据，使得参与计算的数据量过多，从而导致性能问题。

又如，两表的 Inner 等值连接中，连接条件一侧的过滤条件没有推导到另外一侧，导致没有对推导一侧的表进行提前过滤，也可能导致性能问题等。此类性能瓶颈都可以通过分析 Explain 的输出来定位和解决。

explain的作用

下面几个示例分别演示，explain能看到的主要信息：

1. 通过执行计划区分新老优化器

自从2.0版本及以后的版本中，我们的sql默认都是走新优化器，如果在某些时候发现sql执行速度过慢，或者有语法兼容性问题，可以先排查一下是否回退到老优化器了，具体排查方法如下：
通过执行 explain + sql 来观察执行结果：
如图所示：
在这里插入图片描述

上图显示的，就是走的新优化器。

老优化器则如下所示：
在这里插入图片描述

正常来说，我们一个sql都会走新优化器，特别是2.1的版本，如果sql走了老优化器，需要把优化器的自动回退关闭掉，具体操作为：set enable_fallback_to_original_planner = false ，如果是一些dml语句走了老优化器，则需要注意 experimental_enable_nereids_dml_with_pipeline 该参数的值是否打开。
注意：生产环境中请勿关闭新优化器 experimental_enable_nereids_planner

2. 通过explain 判断分区分桶裁剪效果

一般来说，我们查询的sql都会携带过滤条件，这些查询条件都尽可能的优先满足分区分桶的裁剪，这样能尽可能避免无关数据扫描io的浪费，通过explain能够观察到我们的sql对于分区分桶裁剪的效果，如下图所示：
主要查看 OlapScanNode 节点中的 partitions 和 tablets的扫描情况：
有效的分区裁剪：
在这里插入图片描述

有效的分桶裁剪：
在这里插入图片描述

在分区数量特别多，tablets 数量比较多的场景下，有效的分区分桶裁剪，能大幅加速查询的速度。

3. 物化视图透明改写

在固定维度聚合的场景，我们可以针对明细表构建单表物化视图来加速，如下例所示：
原本的查询如下：

select lo_orderkey,sum(lo_supplycost) from lineorder group by lo_orderkey；

如果是直接查询明细表，需要将所有的 lo_orderkey和lo_supplycost 扫描参与计算，代价较大，我们可以在上面构建物化视图，如下：

CREATE MATERIALIZED VIEW single_mv as select lo_orderkey,sum(lo_supplycost) from lineorder_mv group by lo_orderkey;

这样，如果还是查询相同的逻辑，就能够直接命中物化视图的结果，提供加速，我们可以通过explain来确定，是否命中了物化视图：
具体位置在 OlapScanNode 节点中的table中，会显示命中的物化视图的名字，如下图所示
在这里插入图片描述

4. join优化

selectdb常见的join方式如下面几幅图所示：

Colocated Join

前提：两张表都以等值条件中的字段为distribute key，需要在建表时申明
[图片]

Bucket Shuffle Join

前提：其中一张表以等值条件中的字段为distribute key
在这里插入图片描述

Broadcast Join

前提：其中一张表是小表

在这里插入图片描述

Shuffle Join

缺点：左右两张表都需要重新分布，数据移动量大，性能低
优点：可以处理所有等值join，适应性强
在这里插入图片描述

不同的join方式，对应的计算代价不一样，这里需要根据合适的数据分布特征，选用对应的join方式。

手动Hint控制 join方式

在某些时候，如果优化器生成的执行计划，所走的join方式不是我们认为最好的join方式，我们可以手动通过Hint的方式来控制join的方式，目前提供两种方式供选择：[shuffle] 和 [broadcast]
如下图所示：

explain select count(*) from lineorder join customer on customer.c_custkey = lineorder.lo_orderkey;

上面的sql在执行时，join方式如下所示：
[图片]

最终走了Bucket Shuffle Join，我们如果不想让他走这种join方式，我们可以手动Hint来控制，如下图所示：

explain select count(*) from lineorder join [broadcast] customer  on customer.c_custkey = lineorder.lo_orderkey;

上面的语句中，我们通过指定 [broadcast] 的方式，强制让该sql走 broadcast join ，我们可以观察对应的执行计划：
在这里插入图片描述

手动 hint控制join顺序

某些时候，如果统计信息没有搜集的很好，可能会导致我们的sql在join时，不能够只能调整 join两表的顺序，我们可以通过Leading Hint 的方式指导 Doris 优化器确定查询计划中的表连接顺序。具体示例如下：

explain select count(*) from customer join lineorder on customer.c_custkey = lineorder.lo_orderkey;

该sql默认的join顺序如下：
在这里插入图片描述

即order 在前，customer在后
我们可以使用如下方式来调整join的顺序：

explain select /*+ LEADING(customer lineorder)*/  count(*) from customer join lineorder on customer.c_custkey = lineorder.lo_orderkey;

在这里插入图片描述

Runtime Filter 优化
Runtime Filter 是一个强大的技术，它能够把参与join表的join条件，下推到其他表的过滤中去，以此来减少数据扫描量。
如何确定Runtime Filter是否生效：

explain select count(*) from customer join lineorder on customer.c_custkey = lineorder.lo_orderkey where lineorder.lo_orderkey = 13281;

我们可以观察 explain中 join Node和scan Node 中有没有以下的关键信息：
在这里插入图片描述

上图就代表Runtime Filter生效。同时，在2.1的版本中Runtime Filter是默认打开的，如果不确定，可以通过参数runtime_filter_mode是否为global。

profile 介绍

获取profile

在 Doris 执行查询时，当碰到查询性能未达预期时，建议做进一步分析情况。本文将全面阐述如何在 Doris 中对查询进行性能分析。

在 Doris 中，由于 Profile 收集会产生一定的开销，因此默认情况下它是关闭的。若要进行查询性能分析，我们首先需要将其开启，具体操作为在 MySQL Client 中执行以下命令：
set enable_profile = true;

根据query ID 排查慢查询

查询性能问题分析的首要步骤是获取待分析查询的 QueryID。这个 QueryID 可以从fe/log/fe.audit.log日志文件中找到。
以 TPC-H 中的某条特定查询为例，通过查看日志信息，我们可以发现该查询的 QueryID 为

QueryId=704185c15570441b-98ad0634c88584f0。
2024-08-20 14:37:23,729 [query] IClient=127.0.0.1:33570|User=root|Ctl=internal Db=regression_test_tpch_sf0_1_p1I|State=EOF|ErrorCode=0|ErrorMessage=|Time(ms)=153|ScanBytes=0|ScanRows=0|ReturnRows=1|StmtId=1191|QueryId=704185c15570441b-98ad0634c88584f0|IsQuery=true|isNereids=true|feIp=168.45.0.1|StmtType=SELECT|Stmt=SELECT sum(l_extendedprice) / 7.0 AS avg_yearly FROM lineitem, part WHERE p_partkey = l_partkey AND p_brand_ "Brand#23" AND p_container = "MED BOX" AND l_quantity < ( SELECT 0.2*avg(l_quantity) FROM lineitem WHERE l_partkey= p_partkey) |CpuTimeMS=401ShuffleSendBytes=0|ShuffleSendRows=0|SqlHash=ес2e14fac69b9711dc305e218f1e94b8|peakMemoryBytes=33792|SqlDigest=|cloudClusterName=UNKNOWN|TraceId=|WcorkloadGroup=normal|FuzzyVariables=|scanBytesFromLocalStorage=0|scanBytesFromRemoteStorage=0

Profile 分析查询性能

在获取 QueryID 后，可以通过访问对应 FE 的 WebUI 来检索 Profile 文本。例如，通过访问链接http://{fe_ip}:{http_port}/QueryProfile/704185c15570441b-98ad0634c88584f0，即可获取到相应的 Profile 信息，查看更多详细信息，可以下载 profile_704185c15570441b-98ad0634c88584f0.txt 文件。

Profile 文件结构

Profile 文件中包含以下几个主要的部分：

查询基本信息：包括 ID，时间，数据库等
SQL 语句以及执行计划。
FE 的耗时（Plan Time, Schedule Time 等）。
BE 在执行过程中各个 Operator 的执行耗时（包括 Merged Profile、Execution Profile、以及 Execution Profile 中的每个 PipelineTask）。
在慢查询中，通常耗时主要集中在 BE 的执行过程，接下来将主要介绍这部分的分析过程。

通过 Merged Profile 进行 BE 执行分析

为了帮助用户更准确地分析性能瓶颈，Doris 提供了各个 Operator 聚合后的 Profile 结果。
以 EXCHANGE_OPERATOR（id=4）为例：

EXCHANGE_OPERATOR  (id=4):
    -  BlocksProduced:  sum  0,  avg  0,  max  0,  min  0
    -  CloseTime:  avg  34.133us,  max  38.287us,  min  29.979us
    -  ExecTime:  avg  700.357us,  max  706.351us,  min  694.364us
    -  InitTime:  avg  648.104us,  max  648.604us,  min  647.605us
    -  MemoryUsage:  sum  ,  avg  ,  max  ,  min  
        -  PeakMemoryUsage:  sum  0.00  ,  avg  0.00  ,  max  0.00  ,  min  0.00  
    -  OpenTime:  avg  4.541us,  max  5.943us,  min  3.139us
    -  ProjectionTime:  avg  0ns,  max  0ns,  min  0ns
    -  RowsProduced:  sum  0,  avg  0,  max  0,  min  0
    -  WaitForDependencyTime:  avg  0ns,  max  0ns,  min  0ns
        -  WaitForData0:  avg  9.434ms,  max  9.476ms,  min  9.391ms

Merged Profile 对每个 Operator 的核心指标进行了合并。核心指标及其含义如下：
暂时无法在飞书文档外展示此内容
在 Doris 中，每个 Operator 根据用户设置的并发数并发执行。因此，Merged Profile 对每个执行并发的每个指标都计算出了 Max、Avg 和 Min 的值。
其中，WaitForDependencyTime 指标在不同 Operator 对应有不同的值，因为每个 Operator 执行的条件依赖不同。例如，在这个 EXCHANGE_OPERATOR 的例子中，条件依赖是有数据被上游的算子通过 RPC 发送过来。因此，这里的 WaitForDependencyTime 实际上就是在等待上游算子发送数据的时间。

通过 Execution Profile 进行 BE 执行分析

区别于 Merged Profile，Execution Profile 展示的是具体的某个并发中的详细指标。
还是以 EXCHANGE_OPERATOR（id=4）为例：

EXCHANGE_OPERATOR  (id=4):(ExecTime:  706.351us)
      -  BlocksProduced:  0
      -  CloseTime:  38.287us
      -  DataArrivalWaitTime:  0ns
      -  DecompressBytes:  0.00  
      -  DecompressTime:  0ns
      -  DeserializeRowBatchTimer:  0ns
      -  ExecTime:  706.351us
      -  FirstBatchArrivalWaitTime:  0ns
      -  InitTime:  647.605us
      -  LocalBytesReceived:  0.00  
      -  MemoryUsage:  
          -  PeakMemoryUsage:  0.00  
      -  OpenTime:  5.943us
      -  ProjectionTime:  0ns
      -  RemoteBytesReceived:  0.00  
      -  RowsProduced:  0
      -  SendersBlockedTotalTimer(*):  0ns
      -  WaitForDependencyTime:  0ns
          -  WaitForData0:  9.476ms

备注
在该 Profile 中，LocalBytesReceived 是 Exchange Operator 特有的一个指标，其他 Operator 中并不存在，因此它也没有被包含在 Merged Profile 中。

PipelineTask 执行时间分析

在 Doris 中，一个 PipelineTask 由多个 Operator 组成。当分析一个 PipelineTask 的执行耗时时，需要重点关注以下几个方面：

ExecuteTime：表示整个 PipelineTask 的实际执行时间，它大约等于该 Task 中所有 Operator 的 ExecTime 之和。
WaitWorkerTime：表示 Task 等待执行 Worker 的时间。当 Task 处于 runnable 状态时，它需要等待一个空闲的 Worker 来执行，该耗时主要取决于集群的负载情况。
等待执行依赖的时间：一个 Task 可以执行的依赖条件是每个 Operator 的 Dependency 全部满足执行条件，而 Task 等待执行依赖的时间就是将这些依赖的等待时间相加。
以上述例子中的其中一个 Task 为例：


- PipelineTask  (index=1):(ExecTime:  4.773ms)
ExecuteTime:  1.656ms
      -  CloseTime:  90.402us
      -  GetBlockTime:  11.235us
      -  OpenTime:  1.448ms
      -  PrepareTime:  1.555ms
      -  SinkTime:  14.228us
WaitWorkerTime:  63.868us
    DATA_STREAM_SINK_OPERATOR  (id=8,dst_id=8):(ExecTime:  1.688ms)
      -  WaitForDependencyTime:  0ns
          -  WaitForBroadcastBuffer:  0ns
          -  WaitForRpcBufferQueue:  0ns
    AGGREGATION_OPERATOR  (id=7  ,  nereids_id=648):(ExecTime:  398.12us)
      -  WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time:  10.495ms

该 task 包含了 DATA_STREAM_SINK_OPERATOR 和 AGGREGATION_OPERATOR 两个 Operator。其中：
- DATA_STREAM_SINK_OPERATOR 有两个依赖，分别是 WaitForBroadcastBuffer 和 WaitForRpcBufferQueue
- AGGREGATION_OPERATOR 有一个依赖，为 AGGREGATION_OPERATOR_DEPENDENCY。
因此，当前 Task 的耗时分布如下：

ExecuteTime（执行总时间）：1.656ms（约等于两个 Operator 的 ExecTime 总和）
WaitWorkerTime（等待 Worker 的时间）：63.868us（说明当前集群负载不高，Task 就绪以后立即就有 Worker 来执行）
等待执行依赖的时间：10.495ms（WaitForBroadcastBuffer + WaitForRpcBufferQueue + WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time）即当前 task 的所有 Dependency 相加得到的总的等待时间。

性能问题通用排查思路

在 Doris 执行查询的过程中，通常可以依据以下四个步骤来排查性能问题：

定位算子执行性能问题
算子执行缓慢是日常生产环境中较为常见的一类问题。在定位过程中，可以根据 Merged Profile 中的 Plan Tree，梳理出每个 Operator 的 ExecTime 和 WaitForDependencyTime。

若 ExecTime 较慢，则表明当前算子存在性能问题，这可能是算子本身执行性能不佳，也可能是执行规划的 Plan 不够优化所导致的。
若 ExecTime 很快，但 WaitForDependencyTime 很长，则说明性能瓶颈不在当前算子，需沿着 Plan Tree 继续查找其子节点。

定位数据倾斜问题
在定位算子性能问题的过程中，若发现某个算子的 ExecTime 的最小值（Min）和最大值（Max）相差悬殊，则需观察该算子的数据量（RowsProduced）是否同样存在显著差异。若是，则说明发生了数据倾斜。
定位 RPC 延迟过大的问题
当遍历完整个 Plan Tree 之后，若未能找到任何执行缓慢的算子，接下来需排查是否因 RPC 延迟过大而导致的性能问题。
在此过程中，需找到 Execution Profile 中的每个 DATA_STREAM_SINK_OPERATOR，并检查其中的 RpcMaxTime 是否存在异常值。该指标指明了 RPC 过程中耗时最长的一次调用，若其值过大，则代表 RPC 延迟较高，可能是网络问题所致。
定位集群负载过高导致的性能问题
在 Doris 的执行引擎中，执行线程数量是固定的。因此，当集群负载很高时，每个 Task 需等待空闲的执行 Worker 来执行。可以通过 Execution Profile 中的每个 PipelineTask 下，查看WaitWorkerTime 指标来获取等待时间的信息，以进一步判断。