跳到主要内容

慢 SQL 分析工具:Explain 与 Profile

性能分析工具用于在已定位到慢 SQL 后,进一步确定性能瓶颈所在环节。上一节诊断工具帮助业务和运维人员定位到具体的慢 SQL,本章节介绍如何分析这些慢 SQL 的性能瓶颈。

开篇 Checklist:开始分析前,请确认你已具备以下条件:

  • 已通过诊断工具定位到具体的慢 SQL
  • 可访问 Doris FE 并具备执行 EXPLAIN 的权限
  • 可获取该 SQL 的 Profile(已开启 Profile 收集)
  • 可访问 BE 节点用于查看系统级性能指标(CPU/内存/IO/网络)

SQL 执行的两阶段与三类瓶颈

一条 SQL 的执行过程分为两个阶段:

  1. 计划生成阶段:负责生成执行计划。
  2. 计划执行阶段:负责执行具体计划。

任一阶段出问题都可能导致性能瓶颈:

  • 计划差:即使执行器再优秀,也无法获得好性能。
  • 执行手段不合适:即使计划正确,也容易产生瓶颈。
  • 基础设施缺陷或配置错误:执行器性能与硬件、系统架构紧密相关。

工具与瓶颈类型对应关系

瓶颈类型推荐分析工具主要用途
计划层瓶颈Doris Explain查看 SQL 执行计划,定位计划生成问题
执行层瓶颈Doris Profile查看运行时各 operator 详细执行信息
系统级瓶颈top/free/perf/sar 等观察系统 CPU/内存/IO/网络运行状态

下文分别介绍这三类工具。

Doris Explain:分析计划层瓶颈

一句话定义

执行计划是对一条 SQL 具体执行方式和过程的描述。例如,对于两表连接的 SQL,执行计划会展示两张表的访问方式、连接方式以及连接顺序等。

用途

Doris Explain 工具可方便地展示一个 SQL 执行计划的详细信息。通过分析 Explain 输出,可帮助使用者快速定位计划层瓶颈,针对不同情况进行计划层调优。

Explain 类型对比

Doris 提供多种粒度的 Explain,用于不同的分析场景:

Explain 类型输出内容适用场景
Explain Verbose最终物理计划查看实际下发到 BE 的物理计划
Explain All Plan各阶段逻辑计划跟踪逻辑计划的演变过程
Explain Memo Plan基于成本优化过程计划分析 CBO 优化器的决策
Explain Shape Plan计划形态快速查看计划骨架与结构

各种 Explain 的具体使用方法和输出解释,请参考执行计划 Explain 文档。

典型计划层瓶颈

通过分析 Explain 输出,可快速定位以下常见计划层瓶颈:

  • Filter 未下推到基表:未提前过滤数据,导致参与计算的数据量过多。
  • 连接条件未推导到另一侧:两表 Inner 等值连接中,一侧的过滤条件未推导到另一侧,导致另一侧表数据未提前过滤。

使用 Doris Explain 进行计划层调优的案例,详见计划调优章节。

Doris Profile:分析执行层瓶颈

一句话定义

Profile 是 SQL 实际执行时各 operator 的详细耗时与运行指标记录,用于定位执行层性能瓶颈。

与 Explain 的区别

Explain 描述 SQL 执行的规划(如 t1 与 t2 表连接被规划为 Hash Join,t1 在 build 侧、t2 在 probe 侧);Profile 描述 SQL 执行的实际过程(如 build 耗时多少、probe 耗时多少)。

Profile 文件结构

Profile 文件包含以下主要部分:

  1. 查询基本信息:包括 ID、时间、数据库等。
  2. SQL 语句以及执行计划
  3. FE 耗时:包括 Plan Time、Schedule Time 等。
  4. BE 各 operator 执行耗时:包括 Merged Profile 和 Execution Profile。

执行侧详细信息主要在最后一部分,下文重点介绍 Profile 提供的执行信息。

Merged Profile

Merged Profile 提供各 operator 在所有并发上聚合后的核心指标,便于快速定位瓶颈。Doris 中每个 operator 按用户设置的并发数并发执行,Merged Profile 计算每个指标的 Max、Avg、Min 值。

示例(以 EXCHANGE_OPERATOR 为例):

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

核心指标说明

指标名称指标含义
BlocksProduced产生的 Data Block 数量
CloseTimeOperator 在 close 阶段的耗时
ExecTimeOperator 在各阶段执行的总耗时
InitTimeOperator 在 Init 阶段的耗时
MemoryUsageOperator 在执行阶段的内存用量
OpenTimeOperator 在 Open 阶段的耗时
ProjectionTimeOperator 在做 projection 的耗时
RowsProducedOperator 返回的行数
WaitForDependencyTimeOperator 等待自身执行条件依赖的时间

WaitForDependencyTime 因 operator 而异。例如上述 EXCHANGE_OPERATOR 中,条件依赖是上游算子通过 RPC 发送数据,因此该指标实际是在等待上游算子发送数据。

Execution Profile

Execution Profile 展示某个具体并发实例的详细指标,相比 Merged Profile 更细粒度,并包含 operator 特化指标。

示例(以 id=4 的 EXCHANGE_OPERATOR 为例):

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

例如 LocalBytesReceived 是 EXCHANGE_OPERATOR 特化指标,其他 operator 没有,因此未包含在 Merged Profile 中。

PipelineTask 执行时间

在 Doris 中,一个 PipelineTask 由多个 operator 组成。分析 PipelineTask 执行耗时,需重点关注以下三个方面:

关注点含义说明
ExecuteTimePipelineTask 实际执行时间,约等于该 task 中所有 operator 的 ExecTime 之和
WaitWorkerTimetask 等待执行 Worker 的时间,主要取决于集群负载
等待执行依赖的时间所有 operator dependency 等待时间之和(task 可执行需 dependency 全部满足)

简化示例

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 包含两个 operator(DATA_STREAM_SINK_OPERATOR 和 AGGREGATION_OPERATOR)。其中 DATA_STREAM_SINK_OPERATOR 有两个依赖(WaitForBroadcastBuffer 和 WaitForRpcBufferQueue),AGGREGATION_OPERATOR 有一个依赖(AGGREGATION_OPERATOR_DEPENDENCY)。该 task 耗时分布如下:

耗时类型数值说明
执行总时间1.656 ms约等于两个 operator 的 ExecTime 之和
等待 Worker 时间63.868 us当前集群负载不高,task 就绪后立即有 Worker 来执行
等待执行依赖时间10.495 ms等于所有 dependency 等待时间之和

使用 Profile 进行执行层调优的案例,详见执行调优章节。

系统级性能工具

系统级工具可辅助定位 SQL 执行期的性能瓶颈,观察系统资源运行状态。

系统资源常用 Linux 工具主要用途
CPUtop、perf、sar观察 CPU 使用率与热点函数
内存top、free、sar观察内存使用与交换情况
磁盘 IOiostat、sar观察磁盘读写速率与等待时间
网络sar、netstat观察网络流量与连接状态

常见问题

Q1:Explain、Profile、系统工具,应先用哪一个?

按从高到低的优先级排查:先看 Explain 排除计划问题;计划合理后看 Profile 定位执行慢的 operator;若 operator 本身耗时合理但整体慢,再看 系统工具

Q2:Merged Profile 和 Execution Profile 选哪个?

先看 Merged Profile 快速识别 operator 间的耗时差异;当怀疑某个并发实例异常或需查看 operator 特化指标时,再看 Execution Profile

Q3:PipelineTask 整体很慢,但 ExecuteTime 不高,是什么原因?

通常是 WaitWorkerTime 高(集群负载高)或 等待依赖时间高(上游算子未及时产出数据),需结合 dependency 名称定位上游瓶颈。

Q4:WaitForDependencyTime 为 0,但 WaitForData0 很高?

WaitForData0 是 EXCHANGE_OPERATOR 等待上游 RPC 数据的具体依赖。该指标高通常意味着上游算子产出数据慢,应进一步排查上游 operator。

总结

性能分析工具是快速定位性能瓶颈的重要前提。

  • Doris Explain:定位计划层瓶颈。
  • Doris Profile:定位执行层瓶颈(Merged Profile + Execution Profile + PipelineTask 时间)。
  • 系统级工具:辅助定位硬件、操作系统层瓶颈。

熟练组合使用这三类工具,可对 Doris 慢 SQL 性能瓶颈进行端到端定位与解决。