看下图，平时执行耗时6m左右的任务，26号耗时1h12m
![]
截图了任务的某个流程的sql，获取profile（profile见后面），这个sql耗时14m，平时应该也就几十秒
(https://ask.selectdb.com/uploads/post/5gBHt9Tt6mu.jpg)
以下是sql的profile，由于超长，分几段发：
Summary:
- Profile ID: ba6b36e6f8ec4712-86dddd01f3934aeb
- Task Type: QUERY
- Start Time: 2024-09-26 14:51:27
- End Time: 2024-09-26 15:06:25
- Total: 14m57s
- Task State: EOF
- User: root
- Default Catalog: internal
- Default Db: xh_spxl
- Sql Statement: /* ApplicationName=DBeaver for YashanDB 23.1.1 - SQLEditor <Script-6.sql> */ select b.starttime,a.id,b.groupid,b.endtime,a.groupid orgid,d.sname orgname,d.sfid orgfullid,b.userid,c.scode usercode,c.sname username,c.user_identity useridentity,
e.commoncust_type,b.camera_num,0 exempt_num,a.patrol_type,b.patrol_num,b.patrol_sec,1 user_num,a.rowcreatetime createtime,a.rowupdatetime updatetime,if(a.patrol_mode=2,2,1) patrol_mode
from jdbc_oracle_20.xh_base.xh_commoncust_patrol_log
inner join jdbc_oracle_20.xh_base.xh_commoncust_log b on a.id=b.patrol_id
inner join jdbc_oracle_20.xh_base.xh_sa_opperson c on b.userid=c.sid
inner join jdbc_oracle_20.xh_base.xh_sa_oporg d on a.groupid=d.sid
inner join jdbc_oracle_20.xh_base.xh_commoncust_group e on b.groupid=e.id
where a.patrol_type=2 and a.rowcreatetime>=('2024-09-25 00:00:00') and a.rowcreatetime<=('2024-09-25 23:59:59')
Execution Summary:
- Parse SQL Time: 3ms
- Nereids Analysis Time: 2s217ms
- Nereids Rewrite Time: 10ms
- Nereids Optimize Time: 8ms
- Nereids Translate Time: 3ms
- Workload Group: normal
- Analysis Time: 2s217ms
- Plan Time: 25ms
- JoinReorder Time: N/A
- CreateSingleNode Time: N/A
- QueryDistributed Time: N/A
- Init Scan Node Time: N/A
- Finalize Scan Node Time: N/A
- Get Splits Time: N/A
- Get Partitions Time: N/A
- Get Partition Files Time: N/A
- Create Scan Range Time: N/A
- Schedule Time: 37ms
- Fragment Assign Time: 3ms
- Fragment Serialize Time: 4ms
- Fragment RPC Phase1 Time: 25ms
- Fragment RPC Phase2 Time: 5ms
- Fragment Compressed Size: 49.24 KB
- Fragment RPC Count: 8
- Schedule Time Of BE: {"phase1":{"190.15.144.149: 8060":{"RPC Work Time":"14ms","RPC Latency From FE To BE":"10ms","RPC Work Queue Time":"0ms","RPC Latency From BE To FE":"-3ms"},"190.15.145.35: 8060":{"RPC Work Time":"5ms","RPC Latency From FE To BE":"11ms","RPC Work Queue Time":"0ms","RPC Latency From BE To FE":"-1ms"},"190.15.144.180: 8060":{"RPC Work Time":"7ms","RPC Latency From FE To BE":"15ms","RPC Work Queue Time":"0ms","RPC Latency From BE To FE":"-2ms"},"190.15.144.147: 8060":{"RPC Work Time":"4ms","RPC Latency From FE To BE":"13ms","RPC Work Queue Time":"0ms","RPC Latency From BE To FE":"-5ms"}},"phase2":{"190.15.144.149: 8060":{"RPC Work Time":"1ms","RPC Latency From FE To BE":"3ms","RPC Work Queue Time":"0ms","RPC Latency From BE To FE":"0ms"},"190.15.145.35: 8060":{"RPC Work Time":"0ms","RPC Latency From FE To BE":"3ms","RPC Work Queue Time":"0ms","RPC Latency From BE To FE":"-1ms"},"190.15.144.180: 8060":{"RPC Work Time":"0ms","RPC Latency From FE To BE":"9ms","RPC Work Queue Time":"0ms","RPC Latency From BE To FE":"-5ms"},"190.15.144.147: 8060":{"RPC Work Time":"1ms","RPC Latency From FE To BE":"6ms","RPC Work Queue Time":"0ms","RPC Latency From BE To FE":"-3ms"}}}
- Wait and Fetch Result Time: 14m55s
- Fetch Result Time: 14m55s
- Write Result Time: 0ms
- Doris Version: doris-2.1.6-rc04-653e315ba5
- Is Nereids: Yes
- Is Pipeline: Yes
- Is Cached: No
- Total Instances Num: 9
- Instances Num Per BE: 190.15.144.147:8060:1,190.15.144.149:8060:6,190.15.144.180:8060:1,190.15.145.35:8060:1
- Parallel Fragment Exec Instance Num: 16
- Trace ID:
- Transaction Commit Time: N/A
- Executed By Frontend: N/A
篇幅有限，截取一些关键的
Fragment 4:
Pipeline : 0(instance_num=1):
DATA_STREAM_SINK_OPERATOR (id=9,dst_id=9):
- BlocksProduced: sum 138, avg 138, max 138, min 138
- CloseTime: avg 17.57us, max 17.57us, min 17.57us
- ExecTime: avg 73.102ms, max 73.102ms, min 73.102ms
- InitTime: avg 22.807us, max 22.807us, min 22.807us
- InputRows: sum 140.269K (140269), avg 140.269K (140269), max 140.269K (140269), min 140.269K (140269)
- MemoryUsage: sum , avg , max , min
- PeakMemoryUsage: sum 0.00 , avg 0.00 , max 0.00 , min 0.00
- OpenTime: avg 34.725us, max 34.725us, min 34.725us
- RowsProduced: sum 140.269K (140269), avg 140.269K (140269), max 140.269K (140269), min 140.269K (140269)
- WaitForDependencyTime: avg 0ns, max 0ns, min 0ns
- WaitForRpcBufferQueue: avg 0ns, max 0ns, min 0ns
JDBC_SCAN_OPERATOR (id=8. table name = "XH_BASE"."XH_COMMONCUST_LOG"):
- PlanInfo
- TABLE: "XH_BASE"."XH_COMMONCUST_LOG"
- QUERY: SELECT "PATROL_ID", "STARTTIME", "ENDTIME", "USERID", "GROUPID", "CAMERA_NUM", "PATROL_NUM", "PATROL_SEC" FROM "XH_BASE"."XH_COMMONCUST_LOG"
- BlocksProduced: sum 138, avg 138, max 138, min 138
- CloseTime: avg 47.71us, max 47.71us, min 47.71us
- ExecTime: avg 15m, max 15m, min 15m
- InitTime: avg 295.948us, max 295.948us, min 295.948us
- MemoryUsage: sum , avg , max , min
- PeakMemoryUsage: sum 0.00 , avg 0.00 , max 0.00 , min 0.00
- OpenTime: avg 117.720us, max 117.720us, min 117.720us
- ProjectionTime: avg 0ns, max 0ns, min 0ns
- RowsProduced: sum 140.269K (140269), avg 140.269K (140269), max 140.269K (140269), min 140.269K (140269)
- WaitForDependency[JDBC_SCAN_OPERATOR_DEPENDENCY]Time: avg 14m59s, max 14m59s, min 14m59s
VScanner:
- MemoryUsage: sum , avg , max , min
- FreeBlocks: sum 10.41 MB, avg 10.41 MB, max 10.41 MB, min 10.41 MB
