在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 -->审计日志输出时,还有哪些环节慢了，是用户取数据慢？
