You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@doris.apache.org by mo...@apache.org on 2023/04/09 02:01:14 UTC
[doris] 11/12: [fix](profile) fix show load query profile (#18487)
This is an automated email from the ASF dual-hosted git repository.
morningman pushed a commit to branch branch-1.2-lts
in repository https://gitbox.apache.org/repos/asf/doris.git
commit 9766cbd115a5d9202e89e2c555d1a571339e46eb
Author: Mingyu Chen <mo...@163.com>
AuthorDate: Sun Apr 9 08:41:18 2023 +0800
[fix](profile) fix show load query profile (#18487)
Sometimes, `show load profile` will only show part of the insert opertion's profile.
This is because we assume that for all load operation(including insert), there is only one fragment in the plan.
But actually, there will be more than 1 fragment in plan. eg:
`insert into tbl1 select * from tbl1 limit 1` will have 2 fragments.
This PR mainly changes:
1. modify the `show load profile`
Before: `show load profile "/queryid/taskid/instanceid";`
After: `show load profile "/queryid/taskid/fragmentid/instanceid";`
2. Modify the display of `ReadColumns` in OlapScanNode
Because for wide table, the line of `ReadColumns` may be too long for show in profile.
So I wrap it and each line contains at most 10 columns names.
3. Fix tvf not working with pipeline engine, follow up #18376
---
docs/en/docs/admin-manual/query-profile.md | 6 ++
.../Show-Statements/SHOW-LOAD-PROFILE.md | 96 ++++++++++++---------
docs/zh-CN/docs/admin-manual/query-profile.md | 6 +-
.../Show-Statements/SHOW-LOAD-PROFILE.md | 97 +++++++++++++---------
.../apache/doris/analysis/ShowLoadProfileStmt.java | 19 ++++-
.../doris/analysis/ShowQueryProfileStmt.java | 7 +-
.../java/org/apache/doris/qe/ShowExecutor.java | 17 +++-
7 files changed, 157 insertions(+), 91 deletions(-)
diff --git a/docs/en/docs/admin-manual/query-profile.md b/docs/en/docs/admin-manual/query-profile.md
index 03e6ebd595..ac5f631e01 100644
--- a/docs/en/docs/admin-manual/query-profile.md
+++ b/docs/en/docs/admin-manual/query-profile.md
@@ -28,6 +28,11 @@ under the License.
This document focuses on introducing the **Running Profile** which recorded runtime status of Doris in query execution. Using these statistical information, we can understand the execution of frgment to become a expert of Doris's **debugging and tuning**.
+You can also refer to following statements to view profile in command line:
+
+- [SHOW QUERY PROFILE](../sql-manual/sql-reference/Show-Statements/SHOW-QUERY-PROFILE.md)
+- [SHOW LOAD PROFILE](../sql-manual/sql-reference/Show-Statements/SHOW-LOAD-PROFILE.md)
+
## Noun Interpretation
* **FE**: Frontend, frontend node of Doris. Responsible for metadata management and request access.
@@ -39,6 +44,7 @@ This document focuses on introducing the **Running Profile** which recorded runt
## Basic concepts
FE splits the query plan into fragments and distributes them to BE for task execution. BE records the statistics of **Running State** when executing fragment. BE print the outputs statistics of fragment execution into the log. FE can also collect these statistics recorded by each fragment and print the results on FE's web page.
+
## Specific operation
Turn on the report switch on FE through MySQL command
diff --git a/docs/en/docs/sql-manual/sql-reference/Show-Statements/SHOW-LOAD-PROFILE.md b/docs/en/docs/sql-manual/sql-reference/Show-Statements/SHOW-LOAD-PROFILE.md
index d17e1cb0ce..0225f1a543 100644
--- a/docs/en/docs/sql-manual/sql-reference/Show-Statements/SHOW-LOAD-PROFILE.md
+++ b/docs/en/docs/sql-manual/sql-reference/Show-Statements/SHOW-LOAD-PROFILE.md
@@ -50,6 +50,12 @@ grammar:
show load profile "/";
show load profile "/[queryId]"
+
+show load profile "/[queryId]/[TaskId]"
+
+show load profile "/[queryId]/[TaskId]/[FragmentId]/"
+
+show load profile "/[queryId]/[TaskId]/[FragmentId]/[InstanceId]"
````
This command will list all currently saved import profiles. Each line corresponds to one import. where the QueryId column is the ID of the import job. This ID can also be viewed through the SHOW LOAD statement. We can select the QueryId corresponding to the Profile we want to see to see the specific situation
@@ -109,10 +115,56 @@ WaitAndFetchResultTime: N/A
+-----------------------------------+------------+
````
-3. View the Instance overview of the specified subtask
+3. View the plan tree of the specified subtask
+
+ ```sql
+ show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f";
+
+ ┌───────────────────────┐
+ │[-1: OlapTableSink] │
+ │Fragment: 0 │
+ │MaxActiveTime: 86.541ms│
+ └───────────────────────┘
+ │
+ │
+ ┌───────────────────┐
+ │[1: VEXCHANGE_NODE]│
+ │Fragment: 0 │
+ └───────────────────┘
+ ┌─────────────────────────┴───────┐
+ │ │
+ ┌─────────────┐ ┌───────────────────────┐
+ │[MemoryUsage]│ │[1: VDataStreamSender] │
+ │Fragment: 0 │ │Fragment: 1 │
+ └─────────────┘ │MaxActiveTime: 34.882ms│
+ └───────────────────────┘
+ │
+ │
+ ┌───────────────────────────┐
+ │[0: VNewOlapScanNode(tbl1)]│
+ │Fragment: 1 │
+ └───────────────────────────┘
+ ┌─────────────────┴───────┐
+ │ │
+ ┌─────────────┐ ┌───────────┐
+ │[MemoryUsage]│ │[VScanner] │
+ │Fragment: 1 │ │Fragment: 1│
+ └─────────────┘ └───────────┘
+ ┌───────┴─────────┐
+ │ │
+ ┌─────────────────┐ ┌─────────────┐
+ │[SegmentIterator]│ │[MemoryUsage]│
+ │Fragment: 1 │ │Fragment: 1 │
+ └─────────────────┘ └─────────────┘
+
+ ```sql
+
+ This will show the plan tree and fragment id on it
+
+4. View the Instance overview of the specified subtask
```sql
- mysql> show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f/980014623046410a-88e260f0c43031f5"\G
+ mysql> show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f/1"\G
+-----------------------------------+------------------+------------+
| Instances | Host | ActiveTime |
+-----------------------------------+------------------+------------+
@@ -126,84 +178,48 @@ WaitAndFetchResultTime: N/A
4. Continue to view the detailed Profile of each operator on a specific Instance
```sql
- mysql> show load profile "/10441/980014623046410a-88e260f0c43031f1/980014623046410a-88e260f0c43031f5"\G
+ mysql> show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f/1/980014623046410a-88e260f0c43031f5"\G
*************************** 1. row ***************************
Instance:
┌-----------------------------------------┐
-
│[-1: OlapTableSink] │
-
│(Active: 2m17s, non-child: 70.91) │
-
│ - Counters: │
-
│ - CloseWaitTime: 1m53s │
-
│ - ConvertBatchTime: 0ns │
-
│ - MaxAddBatchExecTime: 1m46s │
-
│ - NonBlockingSendTime: 3m11s │
-
│ - NumberBatchAdded: 782 │
-
│ - NumberNodeChannels: 1 │
-
│ - OpenTime: 743.822us │
-
│ - RowsFiltered: 0 │
-
│ - RowsRead: 1.599729M (1599729) │
-
│ - RowsReturned: 1.599729M (1599729)│
-
│ - SendDataTime: 11s761ms │
-
│ - TotalAddBatchExecTime: 1m46s │
-
│ - ValidateDataTime: 9s802ms │
-
└-----------------------------------------┘
-
│
-
┌-----------------------------------------------------┐
-
│[0: BROKER_SCAN_NODE] │
-
│(Active: 56s537ms, non-child: 29.06) │
-
│ - Counters: │
-
│ - BytesDecompressed: 0.00 │
-
│ - BytesRead: 5.77 GB │
-
│ - DecompressTime: 0ns │
-
│ - FileReadTime: 34s263ms │
-
│ - MaterializeTupleTime(*): 45s54ms │
-
│ - NumDiskAccess: 0 │
-
│ - PeakMemoryUsage: 33.03 MB │
-
│ - RowsRead: 1.599729M (1599729) │
-
│ - RowsReturned: 1.599729M (1599729) │
-
- │ - RowsReturnedRate: 28.295K sec │
-
+ │ - RowsReturnedRate: 28.295K sec │
│ - TotalRawReadTime(*): 1m20s │
-
│ - TotalReadThroughput: 30.39858627319336 MB/sec│
-
│ - WaitScannerTime: 56s528ms │
-
└-----------------------------------------------------┘
````
diff --git a/docs/zh-CN/docs/admin-manual/query-profile.md b/docs/zh-CN/docs/admin-manual/query-profile.md
index a2d765a4e5..c305a6a07e 100644
--- a/docs/zh-CN/docs/admin-manual/query-profile.md
+++ b/docs/zh-CN/docs/admin-manual/query-profile.md
@@ -30,6 +30,10 @@ under the License.
本文档主要介绍Doris在查询执行的统计结果。利用这些统计的信息，可以更好的帮助我们了解Doris的执行情况，并有针对性的进行相应**Debug与调优工作**。
+也可以参考如下语法在命令行中查看导入和查询的 Profile：
+
+- [SHOW QUERY PROFILE](../sql-manual/sql-reference/Show-Statements/SHOW-QUERY-PROFILE.md)
+- [SHOW LOAD PROFILE](../sql-manual/sql-reference/Show-Statements/SHOW-LOAD-PROFILE.md)
## 名词解释
@@ -273,4 +277,4 @@ OLAP_SCAN_NODE (id=0):(Active: 1.2ms, % non-child: 0.00%)
- PeakReservation: Reservation的峰值
- PeakUnpinnedBytes: unpin的内存数据量
- PeakUsedReservation: Reservation的内存使用量
- - ReservationLimit: BufferPool的Reservation的限制量
\ No newline at end of file
+ - ReservationLimit: BufferPool的Reservation的限制量
diff --git a/docs/zh-CN/docs/sql-manual/sql-reference/Show-Statements/SHOW-LOAD-PROFILE.md b/docs/zh-CN/docs/sql-manual/sql-reference/Show-Statements/SHOW-LOAD-PROFILE.md
index f53f195b67..a63c182b11 100644
--- a/docs/zh-CN/docs/sql-manual/sql-reference/Show-Statements/SHOW-LOAD-PROFILE.md
+++ b/docs/zh-CN/docs/sql-manual/sql-reference/Show-Statements/SHOW-LOAD-PROFILE.md
@@ -50,6 +50,12 @@ SET [GLOBAL] enable_profile=true;
show load profile "/";
show load profile "/[queryId]"
+
+show load profile "/[queryId]/[TaskId]"
+
+show load profile "/[queryId]/[TaskId]/[FragmentId]/"
+
+show load profile "/[queryId]/[TaskId]/[FragmentId]/[InstanceId]"
```
这个命令会列出当前保存的所有导入 Profile。每行对应一个导入。其中 QueryId 列为导入作业的 ID。这个 ID 也可以通过 SHOW LOAD 语句查看拿到。我们可以选择我们想看的 Profile 对应的 QueryId，查看具体情况
@@ -108,11 +114,56 @@ WaitAndFetchResultTime: N/A
| 980014623046410a-af5d36f23381017f | 3m14s |
+-----------------------------------+------------+
```
+3. 查看子任务的执行树：
-3. 查看指定子任务的 Instance 概况
+ ```sql
+ show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f";
+
+ ┌───────────────────────┐
+ │[-1: OlapTableSink] │
+ │Fragment: 0 │
+ │MaxActiveTime: 86.541ms│
+ └───────────────────────┘
+ │
+ │
+ ┌───────────────────┐
+ │[1: VEXCHANGE_NODE]│
+ │Fragment: 0 │
+ └───────────────────┘
+ ┌─────────────────────────┴───────┐
+ │ │
+ ┌─────────────┐ ┌───────────────────────┐
+ │[MemoryUsage]│ │[1: VDataStreamSender] │
+ │Fragment: 0 │ │Fragment: 1 │
+ └─────────────┘ │MaxActiveTime: 34.882ms│
+ └───────────────────────┘
+ │
+ │
+ ┌───────────────────────────┐
+ │[0: VNewOlapScanNode(tbl1)]│
+ │Fragment: 1 │
+ └───────────────────────────┘
+ ┌─────────────────┴───────┐
+ │ │
+ ┌─────────────┐ ┌───────────┐
+ │[MemoryUsage]│ │[VScanner] │
+ │Fragment: 1 │ │Fragment: 1│
+ └─────────────┘ └───────────┘
+ ┌───────┴─────────┐
+ │ │
+ ┌─────────────────┐ ┌─────────────┐
+ │[SegmentIterator]│ │[MemoryUsage]│
+ │Fragment: 1 │ │Fragment: 1 │
+ └─────────────────┘ └─────────────┘
```sql
- mysql> show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f";
+
+ 这一层会显示子任务的查询树，其中标注了 Fragment id。
+
+4. 查看指定Fragment 的 Instance 概况
+
+ ```sql
+ mysql> show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f/1";
+-----------------------------------+------------------+------------+
| Instances | Host | ActiveTime |
+-----------------------------------+------------------+------------+
@@ -123,87 +174,51 @@ WaitAndFetchResultTime: N/A
+-----------------------------------+------------------+------------+
```
-4. 继续查看某一个具体的 Instance 上各个算子的详细 Profile
+5. 继续查看某一个具体的 Instance 上各个算子的详细 Profile
```sql
- mysql> show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f/980014623046410a-88e260f0c43031f5"\G
+ mysql> show load profile "/980014623046410a-af5d36f23381017f/980014623046410a-af5d36f23381017f/1/980014623046410a-88e260f0c43031f5"\G
*************************** 1. row ***************************
Instance:
┌-----------------------------------------┐
-
│[-1: OlapTableSink] │
-
│(Active: 2m17s, non-child: 70.91) │
-
│ - Counters: │
-
│ - CloseWaitTime: 1m53s │
-
│ - ConvertBatchTime: 0ns │
-
│ - MaxAddBatchExecTime: 1m46s │
-
│ - NonBlockingSendTime: 3m11s │
-
│ - NumberBatchAdded: 782 │
-
│ - NumberNodeChannels: 1 │
-
│ - OpenTime: 743.822us │
-
│ - RowsFiltered: 0 │
-
│ - RowsRead: 1.599729M (1599729) │
-
│ - RowsReturned: 1.599729M (1599729)│
-
│ - SendDataTime: 11s761ms │
-
│ - TotalAddBatchExecTime: 1m46s │
-
│ - ValidateDataTime: 9s802ms │
-
└-----------------------------------------┘
-
│
-
┌-----------------------------------------------------┐
-
│[0: BROKER_SCAN_NODE] │
-
│(Active: 56s537ms, non-child: 29.06) │
-
│ - Counters: │
-
│ - BytesDecompressed: 0.00 │
-
│ - BytesRead: 5.77 GB │
-
│ - DecompressTime: 0ns │
-
│ - FileReadTime: 34s263ms │
-
│ - MaterializeTupleTime(*): 45s54ms │
-
│ - NumDiskAccess: 0 │
-
│ - PeakMemoryUsage: 33.03 MB │
-
│ - RowsRead: 1.599729M (1599729) │
-
│ - RowsReturned: 1.599729M (1599729) │
-
- │ - RowsReturnedRate: 28.295K sec │
-
+ │ - RowsReturnedRate: 28.295K sec │
│ - TotalRawReadTime(*): 1m20s │
-
│ - TotalReadThroughput: 30.39858627319336 MB/sec│
-
│ - WaitScannerTime: 56s528ms │
-
└-----------------------------------------------------┘
```
diff --git a/fe/fe-core/src/main/java/org/apache/doris/analysis/ShowLoadProfileStmt.java b/fe/fe-core/src/main/java/org/apache/doris/analysis/ShowLoadProfileStmt.java
index 5175348674..91cbfc3c4e 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/analysis/ShowLoadProfileStmt.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/analysis/ShowLoadProfileStmt.java
@@ -40,6 +40,7 @@ public class ShowLoadProfileStmt extends ShowStmt {
public enum PathType {
QUERY_IDS,
TASK_IDS,
+ FRAGMENTS,
INSTANCES,
SINGLE_INSTANCE
}
@@ -49,6 +50,7 @@ public class ShowLoadProfileStmt extends ShowStmt {
private String jobId = "";
private String taskId = "";
+ private String fragmentId = "";
private String instanceId = "";
public ShowLoadProfileStmt(String idPath) {
@@ -67,6 +69,10 @@ public class ShowLoadProfileStmt extends ShowStmt {
return taskId;
}
+ public String getFragmentId() {
+ return fragmentId;
+ }
+
public String getInstanceId() {
return instanceId;
}
@@ -85,8 +91,8 @@ public class ShowLoadProfileStmt extends ShowStmt {
}
pathType = PathType.QUERY_IDS;
String[] parts = idPath.split("/");
- if (parts.length > 4) {
- throw new AnalysisException("Path must in format '/jobId/taskId/instanceId'");
+ if (parts.length > 5) {
+ throw new AnalysisException("Path must in format '/jobId/taskId/fragmentId/instanceId'");
}
for (int i = 0; i < parts.length; i++) {
@@ -100,9 +106,13 @@ public class ShowLoadProfileStmt extends ShowStmt {
break;
case 2:
taskId = parts[i];
- pathType = PathType.INSTANCES;
+ pathType = PathType.FRAGMENTS;
break;
case 3:
+ fragmentId = parts[i];
+ pathType = PathType.INSTANCES;
+ break;
+ case 4:
instanceId = parts[i];
pathType = PathType.SINGLE_INSTANCE;
break;
@@ -130,6 +140,8 @@ public class ShowLoadProfileStmt extends ShowStmt {
return ShowQueryProfileStmt.META_DATA_QUERY_IDS;
case TASK_IDS:
return META_DATA_TASK_IDS;
+ case FRAGMENTS:
+ return ShowQueryProfileStmt.META_DATA_FRAGMENTS;
case INSTANCES:
return ShowQueryProfileStmt.META_DATA_INSTANCES;
case SINGLE_INSTANCE:
@@ -139,3 +151,4 @@ public class ShowLoadProfileStmt extends ShowStmt {
}
}
}
+
diff --git a/fe/fe-core/src/main/java/org/apache/doris/analysis/ShowQueryProfileStmt.java b/fe/fe-core/src/main/java/org/apache/doris/analysis/ShowQueryProfileStmt.java
index b36cd30159..f595069825 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/analysis/ShowQueryProfileStmt.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/analysis/ShowQueryProfileStmt.java
@@ -63,7 +63,7 @@ public class ShowQueryProfileStmt extends ShowStmt {
public enum PathType {
QUERY_IDS,
- FRAGMETNS,
+ FRAGMENTS,
INSTANCES,
SINGLE_INSTANCE
}
@@ -120,7 +120,7 @@ public class ShowQueryProfileStmt extends ShowStmt {
continue;
case 1:
queryId = parts[i];
- pathType = PathType.FRAGMETNS;
+ pathType = PathType.FRAGMENTS;
break;
case 2:
fragmentId = parts[i];
@@ -152,7 +152,7 @@ public class ShowQueryProfileStmt extends ShowStmt {
switch (pathType) {
case QUERY_IDS:
return META_DATA_QUERY_IDS;
- case FRAGMETNS:
+ case FRAGMENTS:
return META_DATA_FRAGMENTS;
case INSTANCES:
return META_DATA_INSTANCES;
@@ -163,3 +163,4 @@ public class ShowQueryProfileStmt extends ShowStmt {
}
}
}
+
diff --git a/fe/fe-core/src/main/java/org/apache/doris/qe/ShowExecutor.java b/fe/fe-core/src/main/java/org/apache/doris/qe/ShowExecutor.java
index c93807ef2e..a6bd0ee5ef 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/qe/ShowExecutor.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/qe/ShowExecutor.java
@@ -1990,7 +1990,7 @@ public class ShowExecutor {
case QUERY_IDS:
rows = ProfileManager.getInstance().getQueryWithType(ProfileManager.ProfileType.QUERY);
break;
- case FRAGMETNS: {
+ case FRAGMENTS: {
ProfileTreeNode treeRoot = ProfileManager.getInstance().getFragmentProfileTree(showStmt.getQueryId(),
showStmt.getQueryId());
if (treeRoot == null) {
@@ -2049,12 +2049,22 @@ public class ShowExecutor {
rows = ProfileManager.getInstance().getLoadJobTaskList(showStmt.getJobId());
break;
}
+ case FRAGMENTS: {
+ ProfileTreeNode treeRoot = ProfileManager.getInstance().getFragmentProfileTree(showStmt.getJobId(),
+ showStmt.getJobId());
+ if (treeRoot == null) {
+ throw new AnalysisException("Failed to get fragment tree for load: " + showStmt.getJobId());
+ }
+ List<String> row = Lists.newArrayList(ProfileTreePrinter.printFragmentTree(treeRoot));
+ rows.add(row);
+ break;
+ }
case INSTANCES: {
// For load profile, there should be only one fragment in each execution profile
// And the fragment id is 0.
List<Triple<String, String, Long>> instanceList
= ProfileManager.getInstance().getFragmentInstanceList(showStmt.getJobId(),
- showStmt.getTaskId(), "0");
+ showStmt.getTaskId(), ((ShowLoadProfileStmt) stmt).getFragmentId());
if (instanceList == null) {
throw new AnalysisException("Failed to get instance list for task: " + showStmt.getTaskId());
}
@@ -2069,7 +2079,7 @@ public class ShowExecutor {
// For load profile, there should be only one fragment in each execution profile.
// And the fragment id is 0.
ProfileTreeNode treeRoot = ProfileManager.getInstance().getInstanceProfileTree(showStmt.getJobId(),
- showStmt.getTaskId(), "0", showStmt.getInstanceId());
+ showStmt.getTaskId(), showStmt.getFragmentId(), showStmt.getInstanceId());
if (treeRoot == null) {
throw new AnalysisException("Failed to get instance tree for instance: "
+ showStmt.getInstanceId());
@@ -2487,3 +2497,4 @@ public class ShowExecutor {
resultSet = new ShowResultSet(showStmt.getMetaData(), results);
}
}
+
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org