This is an automated email from the ASF dual-hosted git repository. kxiao pushed a commit to branch branch-2.0-beta in repository https://gitbox.apache.org/repos/asf/doris.git
commit c3ef8e0a294f800cbd0614f5f570d381b2876371 Author: wangbo <[email protected]> AuthorDate: Tue Jun 6 08:55:52 2023 +0800 [fix](executor)Fix duplicate timer and add open timer #20448 1 Currently, Node's total timer couter has timed twice(in Open and alloc_resource), this may cause timer in profile is not correct. 2 Add more timer to find more code which may cost much time. --- be/src/vec/exec/join/vhash_join_node.cpp | 5 ++++- be/src/vec/exec/join/vhash_join_node.h | 3 +++ be/src/vec/exec/scan/vscan_node.cpp | 6 +++++- be/src/vec/exec/scan/vscan_node.h | 2 ++ 4 files changed, 14 insertions(+), 2 deletions(-) diff --git a/be/src/vec/exec/join/vhash_join_node.cpp b/be/src/vec/exec/join/vhash_join_node.cpp index 2e91f199c2..cd6bea45e9 100644 --- a/be/src/vec/exec/join/vhash_join_node.cpp +++ b/be/src/vec/exec/join/vhash_join_node.cpp @@ -457,6 +457,8 @@ Status HashJoinNode::prepare(RuntimeState* state) { _probe_side_output_timer = ADD_TIMER(probe_phase_profile, "ProbeWhenProbeSideOutputTime"); _join_filter_timer = ADD_TIMER(runtime_profile(), "JoinFilterTimer"); + _open_timer = ADD_TIMER(runtime_profile(), "OpenTime"); + _allocate_resource_timer = ADD_TIMER(runtime_profile(), "AllocateResourceTime"); _push_down_timer = ADD_TIMER(runtime_profile(), "PublishRuntimeFilterTime"); _push_compute_timer = ADD_TIMER(runtime_profile(), "PushDownComputeTime"); @@ -744,14 +746,15 @@ void HashJoinNode::_prepare_probe_block() { Status HashJoinNode::open(RuntimeState* state) { SCOPED_TIMER(_runtime_profile->total_time_counter()); + SCOPED_TIMER(_open_timer); RETURN_IF_ERROR(VJoinNodeBase::open(state)); RETURN_IF_CANCELLED(state); return Status::OK(); } Status HashJoinNode::alloc_resource(doris::RuntimeState* state) { + SCOPED_TIMER(_allocate_resource_timer); RETURN_IF_ERROR(VJoinNodeBase::alloc_resource(state)); - SCOPED_TIMER(_runtime_profile->total_time_counter()); for (size_t i = 0; i < _runtime_filter_descs.size(); i++) { if (auto bf = _runtime_filters[i]->get_bloomfilter()) { RETURN_IF_ERROR(bf->init_with_fixed_length()); diff --git a/be/src/vec/exec/join/vhash_join_node.h b/be/src/vec/exec/join/vhash_join_node.h index 33ae53f923..408dacce02 100644 --- a/be/src/vec/exec/join/vhash_join_node.h +++ b/be/src/vec/exec/join/vhash_join_node.h @@ -290,6 +290,9 @@ private: RuntimeProfile::Counter* _build_side_merge_block_timer; RuntimeProfile::Counter* _build_runtime_filter_timer; + RuntimeProfile::Counter* _open_timer; + RuntimeProfile::Counter* _allocate_resource_timer; + RuntimeProfile::Counter* _build_blocks_memory_usage; RuntimeProfile::Counter* _hash_table_memory_usage; RuntimeProfile::HighWaterMarkCounter* _build_arena_memory_usage; diff --git a/be/src/vec/exec/scan/vscan_node.cpp b/be/src/vec/exec/scan/vscan_node.cpp index cf5516471c..692b65376d 100644 --- a/be/src/vec/exec/scan/vscan_node.cpp +++ b/be/src/vec/exec/scan/vscan_node.cpp @@ -150,22 +150,26 @@ Status VScanNode::prepare(RuntimeState* state) { // could add here, not in the _init_profile() function _get_next_timer = ADD_TIMER(_runtime_profile, "GetNextTime"); _acquire_runtime_filter_timer = ADD_TIMER(_runtime_profile, "AcuireRuntimeFilterTime"); + + _open_timer = ADD_TIMER(_runtime_profile, "OpenTime"); + _alloc_resource_timer = ADD_TIMER(_runtime_profile, "AllocateResourceTime"); return Status::OK(); } Status VScanNode::open(RuntimeState* state) { SCOPED_TIMER(_runtime_profile->total_time_counter()); + SCOPED_TIMER(_open_timer); RETURN_IF_CANCELLED(state); return ExecNode::open(state); } Status VScanNode::alloc_resource(RuntimeState* state) { + SCOPED_TIMER(_alloc_resource_timer); if (_opened) { return Status::OK(); } _input_tuple_desc = state->desc_tbl().get_tuple_descriptor(_input_tuple_id); _output_tuple_desc = state->desc_tbl().get_tuple_descriptor(_output_tuple_id); - SCOPED_TIMER(_runtime_profile->total_time_counter()); RETURN_IF_ERROR(ExecNode::alloc_resource(state)); RETURN_IF_ERROR(_acquire_runtime_filter()); RETURN_IF_ERROR(_process_conjuncts()); diff --git a/be/src/vec/exec/scan/vscan_node.h b/be/src/vec/exec/scan/vscan_node.h index c447505a61..69692b032d 100644 --- a/be/src/vec/exec/scan/vscan_node.h +++ b/be/src/vec/exec/scan/vscan_node.h @@ -343,6 +343,8 @@ protected: RuntimeProfile::Counter* _num_scanners; RuntimeProfile::Counter* _get_next_timer = nullptr; + RuntimeProfile::Counter* _open_timer = nullptr; + RuntimeProfile::Counter* _alloc_resource_timer = nullptr; RuntimeProfile::Counter* _acquire_runtime_filter_timer = nullptr; // time of get block from scanner RuntimeProfile::Counter* _scan_timer = nullptr; --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
