查询分析 - 导入分析 - 《Apache Doris v3.0 中文文档》

导入计划树
查看导入 Profile

Doris 提供了一个图形化的命令以帮助用户更方便的分析一个具体的导入。本文介绍如何使用该功能。

备注

该功能目前仅针对 Broker Load 的分析。

导入计划树

如果你对 Doris 的查询计划树还不太了解，请先阅读之前的文章 Doris 查询分析。

一个 Broker Load 请求的执行过程，也是基于 Doris 的查询框架的。一个 Broker Load 作业会根据导入请求中 DATA INFILE 子句的个数将作业拆分成多个子任务。每个子任务可以视为是一个独立的导入执行计划。一个导入计划的组成只会有一个 Fragment，其组成如下：

1. ┌─────────────┐
2. │OlapTableSink│
3. └─────────────┘
4. │
5. ┌──────────────┐
6. │BrokerScanNode│
7. └──────────────┘

BrokerScanNode 主要负责去读源数据并发送给 OlapTableSink，而 OlapTableSink 负责将数据按照分区分桶规则发送到对应的节点，由对应的节点负责实际的数据写入。

而这个导入执行计划的 Fragment 会根据导入源文件的数量、BE 节点的数量等参数，划分成一个或多个 Instance。每个 Instance 负责一部分数据导入。

多个子任务的执行计划是并发执行的，而一个执行计划的多个 Instance 也是并行执行。

查看导入 Profile

用户可以通过以下命令打开会话变量 is_report_success：

1. SET is_report_success=true;

然后提交一个 Broker Load 导入请求，并等到导入执行完成。Doris 会产生该导入的一个 Profile。Profile 包含了一个导入各个子任务、Instance 的执行详情，有助于我们分析导入瓶颈。

备注

目前不支持查看未执行成功的导入作业的 Profile。

我们可以通过如下命令先获取 Profile 列表：

1. mysql> show load profile "/"\G
2. *************************** 1. row ***************************
3. JobId: 20010
4. QueryId: 980014623046410a-af5d36f23381017f
5. User: root
6. DefaultDb: default_cluster:test
7. SQL: LOAD LABEL xxx
8. QueryType: Load
9. StartTime: 2023-03-07 19:48:24
10. EndTime: 2023-03-07 19:50:45
11. TotalTime: 2m21s
12. QueryState: N/A
13. TraceId:
14. AnalysisTime: NULL
15. PlanTime: NULL
16. ScheduleTime: NULL
17. FetchResultTime: NULL
18. WriteResultTime: NULL
19. WaitAndFetchResultTime: NULL
20. *************************** 2. row ***************************
21. JobId: N/A
22. QueryId: 7cc2d0282a7a4391-8dd75030185134d8
23. User: root
24. DefaultDb: default_cluster:test
25. SQL: insert into xxx
26. QueryType: Load
27. StartTime: 2023-03-07 19:49:15
28. EndTime: 2023-03-07 19:49:15
29. TotalTime: 102ms
30. QueryState: OK
31. TraceId:
32. AnalysisTime: 825.277us
33. PlanTime: 4.126ms
34. ScheduleTime: N/A
35. FetchResultTime: 0ns
36. WriteResultTime: 0ns
37. WaitAndFetchResultTime: N/A

这个命令会列出当前保存的所有导入 Profile。每行对应一个导入。其中 QueryId 列为导入作业的 ID。这个 ID 也可以通过 SHOW LOAD 语句查看拿到。我们可以选择我们想看的 Profile 对应的 QueryId，查看具体情况。

查看一个 Profile 分为 3 个步骤：

1. 查看子任务总览

通过以下命令查看有导入作业的子任务概况：

1. mysql> show load profile "/980014623046410a-af5d36f23381017f";
2. +-----------------------------------+------------+
3. | TaskId                            | ActiveTime |
4. +-----------------------------------+------------+
5. | 980014623046410a-af5d36f23381017f | 3m14s      |
6. +-----------------------------------+------------+

如上图，表示 980014623046410a-af5d36f23381017f 这个导入作业总共有一个子任务，其中 ActiveTime 表示这个子任务中耗时最长的 Instance 的执行时间。

2. 查看指定子任务的 Instance 概况

当我们发现一个子任务耗时较长时，可以进一步查看该子任务的各个 Instance 的执行耗时：

1. mysql> show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f";
2. +-----------------------------------+------------------+------------+
3. | Instances                         | Host             | ActiveTime |
4. +-----------------------------------+------------------+------------+
5. | 980014623046410a-88e260f0c43031f2 | 10.81.85.89:9067 | 3m7s       |
6. | 980014623046410a-88e260f0c43031f3 | 10.81.85.89:9067 | 3m6s       |
7. | 980014623046410a-88e260f0c43031f4 | 10.81.85.89:9067 | 3m10s      |
8. | 980014623046410a-88e260f0c43031f5 | 10.81.85.89:9067 | 3m14s      |
9. +-----------------------------------+------------------+------------+

这里展示了 980014623046410a-af5d36f23381017f 这个子任务的四个 Instance 耗时，并且还展示了 Instance 所在的执行节点。

3. 查看具体 Instance

我们可以继续查看某一个具体的 Instance 上各个算子的详细 Profile：

1. mysql> show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f/980014623046410a-88e260f0c43031f5"\G
2. *************************** 1. row ***************************
3. Instance:
4. ┌-----------------------------------------┐
5. │[-1: OlapTableSink]                      │
6. │(Active: 2m17s, non-child: 70.91)        │
7. │  - Counters:                            │
8. │      - CloseWaitTime: 1m53s             │
9. │      - ConvertBatchTime: 0ns            │
10. │      - MaxAddBatchExecTime: 1m46s       │
11. │      - NonBlockingSendTime: 3m11s       │
12. │      - NumberBatchAdded: 782            │
13. │      - NumberNodeChannels: 1            │
14. │      - OpenTime: 743.822us              │
15. │      - RowsFiltered: 0                  │
16. │      - RowsRead: 1.599729M (1599729)    │
17. │      - RowsReturned: 1.599729M (1599729)│
18. │      - SendDataTime: 11s761ms           │
19. │      - TotalAddBatchExecTime: 1m46s     │
20. │      - ValidateDataTime: 9s802ms        │
21. └-----------------------------------------┘
22. │
23. ┌-----------------------------------------------------┐
24. │[0: BROKER_SCAN_NODE]                                │
25. │(Active: 56s537ms, non-child: 29.06)                 │
26. │  - Counters:                                        │
27. │      - BytesDecompressed: 0.00                      │
28. │      - BytesRead: 5.77 GB                           │
29. │      - DecompressTime: 0ns                          │
30. │      - FileReadTime: 34s263ms                       │
31. │      - MaterializeTupleTime(*): 45s54ms             │
32. │      - NumDiskAccess: 0                             │
33. │      - PeakMemoryUsage: 33.03 MB                    │
34. │      - RowsRead: 1.599729M (1599729)                │
35. │      - RowsReturned: 1.599729M (1599729)            │
36. │      - RowsReturnedRate: 28.295K /sec               │
37. │      - TotalRawReadTime(*): 1m20s                   │
38. │      - TotalReadThroughput: 30.39858627319336 MB/sec│
39. │      - WaitScannerTime: 56s528ms                    │
40. └-----------------------------------------------------┘

上图展示了子任务 980014623046410a-af5d36f23381017f 中，Instance 980014623046410a-88e260f0c43031f5 的各个算子的具体 Profile。

通过以上 3 个步骤，我们可以逐步排查一个导入任务的执行瓶颈。