This is an automated email from the ASF dual-hosted git repository. stigahuang pushed a commit to branch branch-4.4.1 in repository https://gitbox.apache.org/repos/asf/impala.git
commit 7d4a8537e66520637cb1707da2e2ddf835e05c36 Author: Riza Suminto <[email protected]> AuthorDate: Mon May 6 12:11:01 2024 -0700 IMPALA-13058: Init first_arrival_time_ and completion_time_ with -1 Impala run over ARM machine shows 'arch_sys_counter' clock source being used rather than more precise 'tsc'. This cause MonotonicStopwatch::Now() to use 'CLOCK_MONOTONIC_COARSE' rather than 'CLOCK_MONOTONIC'. This is what printed near the beginning of impalad log: I0506 13:49:15.429359 355337 init.cc:600] OS distribution: Red Hat Enterprise Linux 8.8 (Ootpa) OS version: Linux version 4.18.0-477.15.1.el8_8.aarch64 ... Clock: clocksource: 'arch_sys_counter', clockid_t: CLOCK_MONOTONIC_COARSE This difference in clock source causes test failure in test_runtime_filters.py::TestRuntimeFilters::test_basic_filters. This patch fixes the issue by initializing first_arrival_time_ and completion_time_ fields of Coordinator::FilterState with -1 and accept 0 as valid value for those fields. query_events_ initialization and start are also moved to the beginning of ClientRequestState's contructor. Testing: - Tweak row_regex pattern in runtime_filters.test. - Loop and pass test_runtime_filters.py in exhaustive mode 3 times in ARM machine. Change-Id: I1176e2118bb03414ab35049f50009ff0e8c63f58 Reviewed-on: http://gerrit.cloudera.org:8080/21405 Reviewed-by: Wenzhe Zhou <[email protected]> Tested-by: Impala Public Jenkins <[email protected]> --- be/src/runtime/coordinator-filter-state.h | 6 ++++-- be/src/runtime/coordinator.cc | 10 +++++----- be/src/service/client-request-state.cc | 19 ++++++++++--------- .../queries/QueryTest/runtime_filters.test | 4 ++-- 4 files changed, 21 insertions(+), 18 deletions(-) diff --git a/be/src/runtime/coordinator-filter-state.h b/be/src/runtime/coordinator-filter-state.h index 0a8f189c8..fd490f79f 100644 --- a/be/src/runtime/coordinator-filter-state.h +++ b/be/src/runtime/coordinator-filter-state.h @@ -76,7 +76,9 @@ class Coordinator::FilterState { std::vector<FilterTarget>* targets() { return &targets_; } const std::vector<FilterTarget>& targets() const { return targets_; } int64_t first_arrival_time() const { return first_arrival_time_; } + bool has_first_arrival_time() const { return first_arrival_time_ > -1; } int64_t completion_time() const { return completion_time_; } + bool has_completion_time() const { return completion_time_ > -1; } const TRuntimeFilterDesc& desc() const { return desc_; } bool is_bloom_filter() const { return desc_.type == TRuntimeFilterType::BLOOM; } bool is_min_max_filter() const { return desc_.type == TRuntimeFilterType::MIN_MAX; } @@ -158,10 +160,10 @@ class Coordinator::FilterState { InListFilterPB in_list_filter_; /// Time at which first local filter arrived. - int64_t first_arrival_time_ = 0L; + int64_t first_arrival_time_ = -1L; /// Time at which all local filters arrived. - int64_t completion_time_ = 0L; + int64_t completion_time_ = -1L; /// Per-object lock so that we can avoid holding the global routing table /// lock for every filter update. diff --git a/be/src/runtime/coordinator.cc b/be/src/runtime/coordinator.cc index 73a1a4e4f..a1572ee6c 100644 --- a/be/src/runtime/coordinator.cc +++ b/be/src/runtime/coordinator.cc @@ -670,14 +670,14 @@ string Coordinator::FilterDebugString() { row.push_back(join(partition_filter, ", ")); if (filter_mode_ == TRuntimeFilterMode::GLOBAL) { - int pending_count = state.completion_time() != 0L ? 0 : state.pending_count(); + int pending_count = state.has_completion_time() ? 0 : state.pending_count(); row.push_back(Substitute("$0 ($1)", pending_count, state.num_producers())); - if (state.first_arrival_time() == 0L) { + if (!state.has_first_arrival_time()) { row.push_back("N/A"); } else { row.push_back(PrettyPrinter::Print(state.first_arrival_time(), TUnit::TIME_NS)); } - if (state.completion_time() == 0L) { + if (!state.has_completion_time()) { row.push_back("N/A"); } else { row.push_back(PrettyPrinter::Print(state.completion_time(), TUnit::TIME_NS)); @@ -1630,8 +1630,8 @@ void Coordinator::FilterState::ApplyUpdate( const UpdateFilterParamsPB& params, Coordinator* coord, RpcContext* context) { DCHECK(enabled()); DCHECK_GT(pending_count_, 0); - DCHECK_EQ(completion_time_, 0L); - if (first_arrival_time_ == 0L) { + DCHECK(!has_completion_time()); + if (!has_first_arrival_time()) { first_arrival_time_ = coord->query_events_->ElapsedTime(); } diff --git a/be/src/service/client-request-state.cc b/be/src/service/client-request-state.cc index 99c70e088..86150ec29 100644 --- a/be/src/service/client-request-state.cc +++ b/be/src/service/client-request-state.cc @@ -112,6 +112,16 @@ ClientRequestState::ClientRequestState(const TQueryCtx& query_ctx, Frontend* fro start_time_us_(UnixMicros()), fetch_rows_timeout_us_(MICROS_PER_MILLI * query_options().fetch_rows_timeout_ms), parent_driver_(query_driver) { + bool is_external_fe = session_type() == TSessionType::EXTERNAL_FRONTEND; + // "Impala Backend Timeline" was specifically chosen to exploit the lexicographical + // ordering defined by the underlying std::map holding the timelines displayed in + // the web UI. This helps ensure that "Frontend Timeline" is displayed before + // "Impala Backend Timeline". + query_events_ = summary_profile_->AddEventSequence( + is_external_fe ? "Impala Backend Timeline" : "Query Timeline"); + query_events_->Start(); + profile_->AddChild(summary_profile_); + #ifndef NDEBUG profile_->AddInfoString("DEBUG MODE WARNING", "Query profile created while running a " "DEBUG build of Impala. Use RELEASE builds to measure query performance."); @@ -130,15 +140,6 @@ ClientRequestState::ClientRequestState(const TQueryCtx& query_ctx, Frontend* fro rpc_read_timer_ = ADD_TIMER(server_profile_, "RPCReadTimer"); rpc_write_timer_ = ADD_TIMER(server_profile_, "RPCWriteTimer"); rpc_count_ = ADD_COUNTER(server_profile_, "RPCCount", TUnit::UNIT); - bool is_external_fe = session_type() == TSessionType::EXTERNAL_FRONTEND; - // "Impala Backend Timeline" was specifically chosen to exploit the lexicographical - // ordering defined by the underlying std::map holding the timelines displayed in - // the web UI. This helps ensure that "Frontend Timeline" is displayed before - // "Impala Backend Timeline". - query_events_ = summary_profile_->AddEventSequence( - is_external_fe ? "Impala Backend Timeline" : "Query Timeline"); - query_events_->Start(); - profile_->AddChild(summary_profile_); profile_->set_name("Query (id=" + PrintId(query_id()) + ")"); summary_profile_->AddInfoString("Session ID", PrintId(session_id())); diff --git a/testdata/workloads/functional-query/queries/QueryTest/runtime_filters.test b/testdata/workloads/functional-query/queries/QueryTest/runtime_filters.test index 00c6c96a6..da06821d1 100644 --- a/testdata/workloads/functional-query/queries/QueryTest/runtime_filters.test +++ b/testdata/workloads/functional-query/queries/QueryTest/runtime_filters.test @@ -195,10 +195,10 @@ select STRAIGHT_JOIN count(*) from alltypes a 0 ---- RUNTIME_PROFILE aggregation(SUM, FiltersReceived): $NUM_FILTER_UPDATES -row_regex: .*REMOTE.*ms.*ms.*true +row_regex: .*REMOTE.*.s .*.s .*true ---- RUNTIME_PROFILE: table_format=kudu aggregation(SUM, FiltersReceived): 3 -row_regex: .*REMOTE.*ms.*ms.*true +row_regex: .*REMOTE.*.s .*.s .*true ====
