在Doris2.14发现一个现象,在高峰期,fe的审计日志耗时是7秒,但是从FE和BE日志上能看到是从FE的内存中获取数据的,没有到BE上运行查询。集群的版本信息是doris-2.1.4-rc03-e93678fd1e
fe的审计日志:
(PRD)[gbdopr@CNSZ1310136 log]$ cat fe.audit.log.20241016-*|grep a5054784d61-820c16cb7f624096
2024-10-16 08:40:12,271 [query] |Client=30.149.199.119:60220|User=PSS_ESALES_LIFE|Ctl=internal|Db=sx_dm_deptlabel_safe|State=EOF|ErrorCode=0|ErrorMessage=|Time(ms)=7538|ScanBytes=0|ScanRows=0|ReturnRows=1|StmtId=112739059|QueryId=aa18ba5054784d61-820c16cb7f624096|IsQuery=true|isNereids=true|feIp=30.164.32.14|Stmt=SELECT sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_life_fyc_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_life_fyc_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.dstce_dimd_perf_gap_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__dstce_dimd_perf_gap_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.dstce_dimd_perf_gap sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__dstce_dimd_perf_gap
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_is_life_dimd_hr_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_is_life_dimd_hr_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_is_life_dimd_hr sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_is_life_dimd_hr
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.life_dimd_has_ctnu_mons sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__life_dimd_has_ctnu_mons
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_is_life_dimd_mem_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_is_life_dimd_mem_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_is_life_dimd_mem sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_is_life_dimd_mem
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.empno sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__empno
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_perf_total_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_perf_total_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.cur_month_commission sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__cur_month_commission
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.cur_month_num_before_visit sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__cur_month_num_before_visit
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_num_diff_value_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_num_diff_value_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_life_lins_num sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_life_lins_num
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_pass_dimd_num_diff_value sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_pass_dimd_num_diff_value
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.dstce_sdiam_perf_gap_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__dstce_sdiam_perf_gap_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_is_life_sdiam_hr sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_is_life_sdiam_hr
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_is_life_sdiam_hr_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_is_life_sdiam_hr_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.dstce_sdiam_perf_gap sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__dstce_sdiam_perf_gap
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.dstce_gdiam_perf_gap_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__dstce_gdiam_perf_gap_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_is_life_gdiam_hr sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_is_life_gdiam_hr
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.dstce_gdiam_perf_gap sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__dstce_gdiam_perf_gap
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_is_life_gdiam_hr_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_is_life_gdiam_hr_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_is_life_doub_gdiam_hr sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_is_life_doub_gdiam_hr
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.dstce_doub_gdiam_perf_gap sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__dstce_doub_gdiam_perf_gap
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.curmo_is_life_doub_gdiam_hr_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__curmo_is_life_doub_gdiam_hr_bvis
, sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.dstce_doub_gdiam_perf_gap_bvis sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d__dstce_doub_gdiam_perf_gap_bvis
FROM sx_cdm_agt_comm_safe.DORIS_7185_DWD_AGENT_COMM_A_LCS_DIAMOND_PLUS_LIST_D AS sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
WHERE (sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.empno = '1194003717') AND (sx_cdm_agt_comm_safe__doris_7185_dwd_agent_comm_a_lcs_diamond_plus_list_d
.month = '2024-09-01') LIMIT 1|CpuTimeMS=0|ShuffleSendBytes=-1|ShuffleSendRows=-1|SqlHash=23440ee219e5a65b207b4be0fca0d69e|peakMemoryBytes=0|SqlDigest=d41d8cd98f00b204e9800998ecf8427e|TraceId=|WorkloadGroup=sjpt|FuzzyVariables=
fe.log
(PRD)[gbdopr@CNSZ1310136 log]$ cat fe.log|grep a5054784d61-820c16cb7f624096
2024-10-16 08:40:05,752 INFO (mysql-nio-pool-44567|842617) [StmtExecutor.handleQueryStmt():1686] Query aa18ba5054784d61-820c16cb7f624096 finished
BE节点
通过grep a5054784d61-820c16cb7f624096确认是没有在BE上运行
从上诉日志能看到,fe的只有在FE的内存上拿结果。
我们也从源码上跟踪,
发下调用FE 上执行executor.execute()的结尾会输出Query finished,然后调用auditAfterExec输出审计日志,这个时会计算查询的耗时。现在搞不懂是哪里慢了,Query finished -->审计日志输出时,还有哪些环节慢了,是用户取数据慢?